EWS Managed API is lying to me!

EWS Managed API is lying to me!

  • Comments 0

I have been working with Exchange Web Services(EWS) for a long time and this is the first time I saw that the EWS was lying to me! The code was executing a FindItem call on a list of folders and all of a sudden it threw the following error: “Error occurred: The request failed. The remote server returned an error: (401) Unauthorized”.

Why would that happen? If it was an authentication problem then why did my previous call work? The first step was to check the IIS Logs on the CAS server and below is what we find:

7/11/2012  10.171.230.40    POST /EWS/Exchange.asmx    SoapAction=FindItem 443    ExchangeServicesClient/14.03.0067.001    200     63025
7/11/2012 10.171.230.40 POST /EWS/Exchange.asmx SoapAction=FindItem 443 ExchangeServicesClient/14.03.0067.001 200 21809
7/11/2012 10.171.230.40 POST /EWS/Exchange.asmx SoapAction=FindItem 443 ExchangeServicesClient/14.03.0067.001 302 196752
7/11/2012 10.171.230.40 POST /EWS/Exchange.asmx SoapAction=FindItem 443 ExchangeServicesClient/14.03.0067.001 302 196643

I chose to show only the relevant columns above. I you notice the highlighted values, the 302 is the HTTP Status code which means that the object has been temporarily moved. The last column is the time taken in milliseconds to execute the FindItem request. In the above case it was more than 3 minutes which is not good and means we have a LOTS of scope to optimize the code.

But, why do I get the 302? I turned my attention to the Event Logs on the CAS box and I did not have to search too much. Below is what I saw:

Log Name:      Application
Source: ASP.NET 2.0.50727.0
Date: 7/11/2012 12:58:05 PM
Event ID: 1309
Task Category: Web Event
Level: Warning
Keywords: Classic
User: N/A
Computer: myserver.contoso.com
Description:
Event code: 3001
Event message: The request has been aborted.
Event time: 7/11/2012 12:58:05 PM
Event time (UTC): 7/11/2012 4:58:05 PM
Event ID: 38a627eada914200923e244e9c83f7c8
Event sequence: 6230694
Event occurrence: 37
Event detail code: 0

Application information:
Application domain: /LM/W3SVC/1/ROOT/EWS-1-129851299999841294
Trust level: Full
Application Virtual Path: /EWS
Application Path: C:\Program Files\Microsoft\Exchange Server\ClientAccess\exchweb\EWS\
Machine name: myserver

Process information:
Process ID: 1152
Process name: w3wp.exe
Account name: NT AUTHORITY\SYSTEM

Exception information:
Exception type: HttpException
Exception message: Request timed out.

Request information:
Request URL: https://myserver.contoso.com:443/EWS/Exchange.asmx
Request path: /EWS/Exchange.asmx
User host address: 10.171.230.40
User: DOMAIN\Username
Is authenticated: True
Authentication Type: Negotiate
Thread account name: NT AUTHORITY\SYSTEM

Thread information:
Thread ID: 26
Thread account name: NT AUTHORITY\SYSTEM
Is impersonating: False
Stack trace:

Now the picture is clearer! Since the request was running for more that 110 seconds which is default timeout in ASP.NET 2.0, the request was being aborted, which resulted in a 302 in the IIS logs. Now why did EWS Managed API return 401, frankly I did not bother to find!

To validate the cause we went ahead and increased the executionTimeout from 110 to 240 in the Web.Config for EWS and then we did not see the issue any more. This was done for TESTING only and is definitely not recommended.

There are two possible solutions to this issue:
1) Optimize your code and use filters and paging while doing FindItems (Recommended).
2) Increase the executionTimeout setting in the Web.Config(Not Recommended – can be tried only If optimization does not work ).

Enjoy!

Leave a Comment
  • Please add 7 and 4 and type the answer here:
  • Post