Apple IOS ActiveSync Gal Lookup Bad Design

I’ve been working an apple IOS issue at work for the past month caused by bad design on the phone side. The customers complain “messages take up to 30 minutes to send, and or it takes 30 minutes to receive messages” I boiled the issue down to Exchange throttling the phone due to poor search behavior on all versions of Apple IOS. When you are in the mail client on IPhone and you type in an email address the phone sends a gal lookup request to the Exchange server for every key stroke. The broader a search (less letters) the more expensive it is for Exchange process to AD lookup. Exchange ActiveSync polices throttle based on Percent time in AD. Heavy email users are going over budget and being blocked for a short period of time at the server to prevent server performance issues that might affect other users.

The Windows phone has the correct behavior here. It searches your local contacts, and frequent contacts cache in your mailbox, then presents you with the option to search the server if the person you are looking for is not present in those two local lists. Most lookups have near zero server impact due to the local searches. Vs. IPhone searches having server impact with every key stroke. The best I have come up with for a solution on the Exchange server is to limit the length of a GAL search to two characters to avoid the most expensive searches for single letters.

Below is a sanitized for public consumption version of an email I sent to an internal team that helps external customers develop for ActiveSync it has supporting evidence you can use to see if you are hitting the same issue if you run into similar complaints.

======================================

Short || Can ya’ll make Apple stop searching the GAL one letter at a time by default on IOS devices – they should be more like WP8 and search local then present the “search the gal” option. Much less expensive for our servers.

Long Version || Gentleman we are tracking two cases for XXXXXXXXX where customers are calling in complaining IOS devices stop working for X period of time. We’ve tracked this down in CAS and Activesync device logs to devices doing full gal searches one letter at a time causing % time in AD throttling for the user. I personally see this as a design issue Apple should address.

Supporting notes

 

We can see in the IIS logs the account is being throttled when the SendMail command is sent:

2013-02-02 18:27:20 XXXXXXXXXXXXXXXXXXXXXX POST /Microsoft-Server-ActiveSync/default.eas User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=SendMail&Log=V141_LdapC1_LdapL16_S111_Error:OverBudget_Mbx:XXXXXXXXXXXXXXXXXXXXXXXX Throttle44995_Budget:(D)Conn%3a2%2cHangingConn%3a0%2cAD%3a12000%2f12000%2f0%25%2cCAS%3a27000%2f-5209%2f54%25%2cAB%3a12000%2f-19336%2f53%25%2cRPC%3a12000%2f11623%2f1%25%2cFC%3a1000%2f0%2cPolicy%3aDefaultThrottlingPolicy%5F068b2849-c3bb-48f7-92c7-16ceda02a065%2cNorm_ 443 tms\155606 XXXXXXXXXXXX HTTP/1.1 Apple-iPhone5C1/1001.525 – – XXXXXXXXXXX 200 0 0 342 865 45105

 
 

Just before this over budget we see the device was attempting to perform a couple of searches:

2013-02-02 18:26:05 W3SVC1 XXXXXXXXXXXXXXXXXXXX POST /Microsoft-Server-ActiveSync/default.eas User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=Search&Log=V141_Srv:51a0c0d0s0e0r0A0sd_LdapC5_LdapL16_RpcC25_RpcL63_Pk4254639292_Pic0_As:AllowedI_Mbx:XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX _Throttle0_Budget:(A)Conn%3a1%2cHangingConn%3a0%2cAD%3a12000%2f12000%2f0%25%2cCAS%3a27000%2f26050%2f2%25%2cAB%3a12000%2f11813%2f1%25%2cRPC%3a12000%2f11668%2f1%25%2cFC%3a1000%2f0%2cPolicy%3aDefaultThrottlingPolicy%5F068b2849-c3bb-48f7-92c7-16ceda02a065%2cNorm_ 443 tms\155606 XXXXXXXXXXXXX HTTP/1.1 Apple-iPhone5C1/1001.525 – – XXXXXXXXXXXXXXXXX 200 0 0 2423 474 467

 
 

2013-02-02 18:26:55 W3SVC1 XXXXXXXXXXXXXXXXX POST /Microsoft-Server-ActiveSync/default.eas User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=Search&Log=V141_Srv:51a0c0d0s0e0r0A0sd_LdapC5_LdapL15_RpcC25_RpcL125_Pk4254639292_Pic0_As:AllowedI_Mbx:XXXXXXXXXXXXXXXXXXX _Throttle0_Budget:(A)Conn%3a0%2cHangingConn%3a0%2cAD%3a12000%2f12000%2f0%25%2cCAS%3a27000%2f26361%2f2%25%2cAB%3a12000%2f12000%2f0%25%2cRPC%3a12000%2f11745%2f1%25%2cFC%3a1000%2f0%2cPolicy%3aDefaultThrottlingPolicy%5F068b2849-c3bb-48f7-92c7-16ceda02a065%2cNorm_ 443 tms\155606 XXXXXXXXXXX HTTP/1.1 Apple-iPhone5C1/1001.525 – – XXXXXXXXXXXXXXXXX 200 0 0 1550 472 50761

 
 

As you can see from the highlighted sections the percent time in AD for the address book climbs to the maximum limit of 12000. We can correlate these IIS entries with the ActiveSync mailbox log for the device and actually see what data was sent in the search request:

Log Entry: 410

—————–

RequestTime :

02/02/2013 18:26:05

RequestHeader :

POST /Microsoft-Server-ActiveSync/default.eas?User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=Search HTTP/1.1

RequestBody :

<?xml version=”1.0″ encoding=”utf-8″ ?>

<Search xmlns=”Search:”>

<Store>

<Name bytes=”3″/>

<Query>rus</Query>

ResponseTime :

02/02/2013 18:26:05

 
 

 
 

Log Entry: 411

—————–

RequestTime :

02/02/2013 18:26:05

RequestHeader :

POST /Microsoft-Server-ActiveSync/default.eas?User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=Search HTTP/1.1

RequestBody :

<?xml version=”1.0″ encoding=”utf-8″ ?>

<Search xmlns=”Search:”>

<Store>

<Name bytes=”3″/>

<Query>r</Query>

ResponseTime :

02/02/2013 18:26:55

 
 

Then we reproduced the issue again and we can see the same behavior, but this time there were six searches:

2013-02-02 19:48:33 W3SVC1 XXXXXXXXXXXXXXXXXPOST /Microsoft-Server-ActiveSync/default.eas User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=Search&Log=V141_Srv:26a0c0d0s0e0r0A0sd_LdapC6_LdapL78_RpcC20_RpcL47_Pk4254639292_Pic0_As:AllowedI_Mbx:XXXXXXXXXXXXXXXXX_Throttle0_Budget:(A)Conn%3a1%2cHangingConn%3a0%2cAD%3a12000%2f11985%2f1%25%2cCAS%3a27000%2f21275%2f10%25%2cAB%3a12000%2f7877%2f7%25%2cRPC%3a12000%2f11172%2f2%25%2cFC%3a1000%2f0%2cPolicy%3aDefaultThrottlingPolicy%5F068b2849-c3bb-48f7-92c7-16ceda02a065%2cNorm_ 443 tms\155606 XXXXXXXXXXXXXXXXXHTTP/1.1 Apple-iPhone5C1/1001.525 – – XXXXXXXXXXXXXXXXX200 0 0 1332 474 202

2013-02-02 19:48:34 W3SVC1 XXXXXXXXXXXXXXXXXPOST /Microsoft-Server-ActiveSync/default.eas User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=Search&Log=V141_Srv:1a0c0d0s0e0r0A0sd_LdapC6_LdapL78_RpcC20_RpcL47_Pk4254639292_Pic0_As:AllowedI_Mbx:XXXXXXXXXXXXXXXXX_Throttle0_Budget:(A)Conn%3a1%2cHangingConn%3a0%2cAD%3a12000%2f11985%2f1%25%2cCAS%3a27000%2f21088%2f10%25%2cAB%3a12000%2f7768%2f8%25%2cRPC%3a12000%2f11127%2f2%25%2cFC%3a1000%2f0%2cPolicy%3aDefaultThrottlingPolicy%5F068b2849-c3bb-48f7-92c7-16ceda02a065%2cNorm_ 443 tms\155606 XXXXXXXXXXXXXXXXXHTTP/1.1 Apple-iPhone5C1/1001.525 – – XXXXXXXXXXXXXXXXX200 0 0 466 475 265

2013-02-02 19:48:36 W3SVC1 XXXXXXXXXXXXXXXXXPOST /Microsoft-Server-ActiveSync/default.eas User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=Search&Log=V141_Srv:51a0c0d0s0e0r0A0sd_LdapC5_LdapL15_RpcC20_RpcL31_Pk4254639292_Pic0_As:AllowedI_Mbx:XXXXXXXXXXXXXXXXX_Throttle0_Budget:(A)Conn%3a2%2cHangingConn%3a0%2cAD%3a12000%2f11985%2f1%25%2cCAS%3a27000%2f20264%2f12%25%2cAB%3a12000%2f7084%2f9%25%2cRPC%3a12000%2f11052%2f2%25%2cFC%3a1000%2f0%2cPolicy%3aDefaultThrottlingPolicy%5F068b2849-c3bb-48f7-92c7-16ceda02a065%2cNorm_ 443 tms\155606 XXXXXXXXXXXXXXXXXHTTP/1.1 Apple-iPhone5C1/1001.525 – – XXXXXXXXXXXXXXXXX200 0 0 1626 474 545

2013-02-02 19:48:37 W3SVC1 XXXXXXXXXXXXXXXXXPOST /Microsoft-Server-ActiveSync/default.eas User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=Search&Log=V141_Srv:51a0c0d0s0e0r0A0sd_LdapC5_LdapL16_RpcC20_RpcL63_Pk4254639292_Pic0_As:AllowedI_Mbx:XXXXXXXXXXXXXXXXX_Throttle0_Budget:(A)Conn%3a2%2cHangingConn%3a0%2cAD%3a12000%2f11985%2f1%25%2cCAS%3a27000%2f17812%2f16%25%2cAB%3a12000%2f4668%2f13%25%2cRPC%3a12000%2f11007%2f2%25%2cFC%3a1000%2f0%2cPolicy%3aDefaultThrottlingPolicy%5F068b2849-c3bb-48f7-92c7-16ceda02a065%2cNorm_ 443 tms\155606 XXXXXXXXXXXXXXXXXHTTP/1.1 Apple-iPhone5C1/1001.525 – – XXXXXXXXXXXXXXXXX200 0 0 2512 473 545

2013-02-02 19:48:38 W3SVC1 XXXXXXXXXXXXXXXXXPOST /Microsoft-Server-ActiveSync/default.eas User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=Search&Log=V141_Srv:51a0c0d0s0e0r0A0sd_LdapC5_LdapL16_RpcC20_RpcL63_Pk4254639292_Pic0_As:AllowedI_Mbx:XXXXXXXXXXXXXXXXX_Throttle0_Budget:(A)Conn%3a3%2cHangingConn%3a0%2cAD%3a12000%2f11985%2f1%25%2cCAS%3a27000%2f16459%2f18%25%2cAB%3a12000%2f3377%2f15%25%2cRPC%3a12000%2f10977%2f2%25%2cFC%3a1000%2f0%2cPolicy%3aDefaultThrottlingPolicy%5F068b2849-c3bb-48f7-92c7-16ceda02a065%2cNorm_ 443 tms\155606 XXXXXXXXXXXXXXXXXHTTP/1.1 Apple-iPhone5C1/1001.525 – – XXXXXXXXXXXXXXXXX200 0 0 2423 474 467

2013-02-02 19:48:47 W3SVC1 XXXXXXXXXXXXXXXXXPOST /Microsoft-Server-ActiveSync/default.eas User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=Search&Log=V141_Srv:51a0c0d0s0e0r0A0sd_LdapC5_LdapL16_RpcC20_RpcL31_Pk4254639292_Pic0_As:AllowedI_Mbx:XXXXXXXXXXXXXXXXX_Throttle0_Budget:(A)Conn%3a1%2cHangingConn%3a0%2cAD%3a12000%2f11985%2f1%25%2cCAS%3a27000%2f20933%2f11%25%2cAB%3a12000%2f7691%2f8%25%2cRPC%3a12000%2f11082%2f2%25%2cFC%3a1000%2f0%2cPolicy%3aDefaultThrottlingPolicy%5F068b2849-c3bb-48f7-92c7-16ceda02a065%2cNorm_ 443 tms\155606 XXXXXXXXXXXXXXXXXHTTP/1.1 Apple-iPhone5C1/1001.525 – – XXXXXXXXXXXXXXXXX200 0 0 1645 473 12043

2013-02-02 19:49:36 W3SVC1 XXXXXXXXXXXXXXXXXPOST /Microsoft-Server-ActiveSync/default.eas User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=SendMail&Log=V141_LdapC1_S111_Error:OverBudget_Mbx:XXXXXXXXXXXXXXXXX_Throttle44756_Budget:(D)Conn%3a2%2cHangingConn%3a0%2cAD%3a12000%2f11985%2f1%25%2cCAS%3a27000%2f-5190%2f54%25%2cAB%3a12000%2f-19143%2f52%25%2cRPC%3a12000%2f11414%2f1%25%2cFC%3a1000%2f0%2cPolicy%3aDefaultThrottlingPolicy%5F068b2849-c3bb-48f7-92c7-16ceda02a065%2cNorm_ 443 tms\155606 XXXXXXXXXXXXXXXXXHTTP/1.1 Apple-iPhone5C1/1001.525 – – XXXXXXXXXXXXXXXXX200 0 0 342 865 45099 

 

Log Entry: 449

—————–

RequestTime :

02/02/2013 19:48:34

RequestHeader :

POST /Microsoft-Server-ActiveSync/default.eas?User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=Search HTTP/1.1

RequestBody :

<?xml version=”1.0″ encoding=”utf-8″ ?>

<Search xmlns=”Search:”>

<Store>

<Name bytes=”3″/>

<Query>tea</Query>

ResponseTime :

02/02/2013 19:48:34

 
 

Log Entry: 450

—————–

RequestTime :

02/02/2013 19:48:34

RequestHeader :

POST /Microsoft-Server-ActiveSync/default.eas?User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=Search HTTP/1.1

RequestBody :

<?xml version=”1.0″ encoding=”utf-8″ ?>

<Search xmlns=”Search:”>

<Store>

<Name bytes=”3″/>

<Query>teat</Query>

ResponseTime :

02/02/2013 19:48:34

 
 

Log Entry: 451

—————–

RequestTime :

02/02/2013 19:48:36

RequestHeader :

POST /Microsoft-Server-ActiveSync/default.eas?User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=Search HTTP/1.1

RequestBody :

<?xml version=”1.0″ encoding=”utf-8″ ?>

<Search xmlns=”Search:”>

<Store>

<Name bytes=”3″/>

<Query>tem</Query>

ResponseTime :

02/02/2013 19:48:36

 
 

Log Entry: 452

—————–

RequestTime :

02/02/2013 19:48:38

RequestHeader :

POST /Microsoft-Server-ActiveSync/default.eas?User=155606&DeviceId=ApplC39JDALFF38W&DeviceType=iPhone&Cmd=Search HTTP/1.1

RequestBody :

<?xml version=”1.0″ encoding=”utf-8″ ?>

<Search xmlns=”Search:”>

<Store>

<Name bytes=”3″/>

<Query>ru</Query>

ResponseTime :

02/02/2013 19:48:38

 

As a result you will not see the Send Mail requests in the ActiveSync mailbox log because these requests are throttled and not processed for the mailbox.

 

Related Posts with Thumbnails

About Kevinm