• Error "Cannot open Mailbox" when attempting to open an Exchange 2007 mailbox from Exchange 2010

    The scenario is that you are logged into a Exchange 2010 mailbox and want to access a shared calendar or mailbox on Exchange 2007.

     

    When attempting to open the mailbox, you may receive the following error/ (full call stack below):

    Request

    Url:
    https://server.company.com:443/owa/proxyLogon.owa

     

    Exception

    Exception type:
    Microsoft.Exchange.Data.Storage.StoragePermanentException

    Exception message: Cannot open mailbox /o=Company/ou=Administrative Group/cn=Recipients/cn=testuser1.

     

    First, we want to look at the Exception that failed inside of the callstack.

    In the Inner Exception:

    Exception type: Microsoft.Mapi.MapiExceptionCallFailed

    Exception message: MapiExceptionCallFailed: Unable to make
    connection to the server. (hr=0x80004005, ec=2084) Diagnostic context: Lid:
    23065 EcDoConnectEx called [length=86] Lid: 17913 EcDoConnectEx returned
    [ec=0x824][length=56][latency=58] Lid: 19778 Lid: 27970 StoreEc: 0x824 Lid:
    17730 Lid: 25922 StoreEc: 0x824

     

    80004005 = Generic Error (MAPI_E_CALL_FAILED)
    2084 = ERROR_DS_CANT_REM_MISSING_ATT (An attribute cannot be retrieved from AD for the logon)

     

    In troubleshooting the issue, we were able to figure out that the attribute that was missing was SharedCalendarTimezoneSetting.

    Background:

    There was new functionality that was added to Exchange 2007 SP3 RU1. This new functionality forces Exchange 2007 to check the delegate user's SharedCalendarTimeZone, which is used to determine what time zone to show the mailbox in. This works fine against an Exchange 2007 delegate mailboxes, but unfortunately it doesn’t work against Exchange 2010 mailboxes. The failure happens when the Exchange 2010 user attempts to access the Exchange 2007 mailbox and on login, we attempt to check this value in an attempt to learn how to present the data. This data doesn't exist and therefore the error is generated.

    Resolution:

    On Exchange 2007, set the default time zone setting:

    set-organizationalconfig -sharecalendartimezonesetting principal

    Note: This can be set to principal or delegate as the article explains, either will resolve the issue if we are running into this problem.

    If the parameter value is set to Principal, the time zone is shown in the principal’s time zone. If the parameter value is set to Delegate, the time zone is shown in the Delegate’s time zone.

    The Full Call stack:

     Microsoft.Exchange.Data.Storage.ConnectionCachePool.OpenMailbox(String
    serverDn, String userDn, String mailboxDn, Guid mailboxGuid, Guid mdbGuid,
    Object identity, ConnectFlag connectFlag, OpenStoreFlag openStoreFlag,
    CultureInfo cultureInfo, String clientInfoString, Boolean secondTry)

    Microsoft.Exchange.Data.Storage.ConnectionCachePool.OpenMailbox(String
    serverDn, String userDn, String mailboxDn, Guid mailboxGuid, Guid mdbGuid,
    Object identity, ConnectFlag connectFlag, OpenStoreFlag openStoreFlag,
    CultureInfo cultureInfo, String clientInfoString, Boolean secondTry)

    Microsoft.Exchange.Data.Storage.ConnectionCachePool.OpenMailbox(String
    serverDn, String userDn, String mailboxDn, Guid mailboxGuid, Guid mdbGuid,
    Object identity, ConnectFlag connectFlag, OpenStoreFlag openStoreFlag,
    CultureInfo cultureInfo, String clientInfoString)

    Microsoft.Exchange.Data.Storage.MailboxSession.Initialize(LogonType
    logonType, ExchangePrincipal owner, DelegateLogonUser delegateUser, Object
    identity, OpenMailboxSessionFlags flags)

    Microsoft.Exchange.Data.Storage.MailboxSession.CreateMailboxSession(LogonType
    logonType, ExchangePrincipal owner, DelegateLogonUser delegateUser, Object
    identity, OpenMailboxSessionFlags flags, CultureInfo cultureInfo, String
    clientInfoString)

    Microsoft.Exchange.Data.Storage.MailboxSession.Open(ExchangePrincipal
    mailboxOwner, IntPtr authenticatedUserHandle, CultureInfo cultureInfo, String
    clientInfoString)

    Microsoft.Exchange.Clients.Owa.Core.OwaClientSecurityContextIdentity.CreateMailboxSession(ExchangePrincipal
    exchangePrincipal, CultureInfo cultureInfo)

    Microsoft.Exchange.Clients.Owa.Core.UserOptions.LoadSharedCalendarTimezoneSetting(TimezoneSetting&
    setting)

    Microsoft.Exchange.Clients.Owa.Core.UserOptions.Load(IList`1
    properties)

    Microsoft.Exchange.Clients.Owa.Core.UserOptions.LoadAll()

    Microsoft.Exchange.Clients.Owa.Core.UserContext.Load(OwaContext
    owaContext)

    Microsoft.Exchange.Clients.Owa.Core.RequestDispatcher.CreateUserContext(OwaContext
    owaContext, UserContextKey userContextKey, UserContext& userContext)

    Microsoft.Exchange.Clients.Owa.Core.RequestDispatcher.PrepareRequestWithoutSession(OwaContext
    owaContext, UserContextCookie userContextCookie)

    Microsoft.Exchange.Clients.Owa.Core.RequestDispatcher.InternalDispatchRequest(OwaContext
    owaContext)

    Microsoft.Exchange.Clients.Owa.Core.RequestDispatcher.DispatchRequest(OwaContext
    owaContext)

    System.Web.HttpApplication.SyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()

    System.Web.HttpApplication.ExecuteStep(IExecutionStep step,
    Boolean& completedSynchronously)

     

    Inner Exception

    Exception type: Microsoft.Mapi.MapiExceptionCallFailed

    Exception message: MapiExceptionCallFailed: Unable to make
    connection to the server. (hr=0x80004005, ec=2084) Diagnostic context: Lid:
    23065 EcDoConnectEx called [length=86] Lid: 17913 EcDoConnectEx returned
    [ec=0x824][length=56][latency=58] Lid: 19778 Lid: 27970 StoreEc: 0x824 Lid:
    17730 Lid: 25922 StoreEc: 0x824

     

    Call stack

     

    Microsoft.Mapi.MapiExceptionHelper.ThrowIfError(String
    message, Int32 hresult, Int32 ec, DiagnosticContext diagCtx)

    Microsoft.Mapi.ExRpcConnection.Create(ConnectionCache
    connectionCache, ExRpcConnectionCreateFlag createFlags, ConnectFlag connectFlags,
    String serverDn, String userDn, String user, String domain, String password,
    String httpProxyServerName, Int32 ulConMod, Int32 lcidString, Int32 lcidSort,
    Int32 cpid, Int32 cReconnectIntervalInMins, Int32 cbRpcBufferSize, Int32
    cbAuxBufferSize)

    Microsoft.Mapi.ConnectionCache.OpenMapiStore(String
    mailboxDn, Guid mailboxGuid, Guid mdbGuid, ClientIdentityInfo clientIdentity,
    String userDnAs, OpenStoreFlag openStoreFlags, CultureInfo cultureInfo, String
    applicationId)

    Microsoft.Mapi.ConnectionCache.OpenMailbox(String mailboxDn,
    Guid mailboxGuid, Guid mdbGuid, ClientIdentityInfo clientIdentity, String
    userDnAs, OpenStoreFlag openStoreFlags, CultureInfo cultureInfo, String
    applicationId)

    Microsoft.Exchange.Data.Storage.ConnectionCachePool.OpenMailbox(String
    serverDn, String userDn, String mailboxDn, Guid mailboxGuid, Guid mdbGuid,
    Object identity, ConnectFlag connectFlag, OpenStoreFlag openStoreFlag,
    CultureInfo cultureInfo, String clientInfoString, Boolean secondTry)

  • Troubleshooting EWS requests using IIS logs with Logparser

    The problem:

     We have very valuable data inside of the IIS logs that can greatly assist in troubleshooting Exchange Web Service clients.  The problem is that all of the data exists in one field (cs-uri-query) inside of the IIS logs.

    An example cs-uri-query field for a EWS call:

    ;RC:111111ac-1111-1111-1111-111112c1111;Init>>Conn:0,HangingConn:0,AD:30000/30000/0%,CAS:54000/54000/0%,AB:30000/30000/0%,RPC:36000/36000/0%,FC:1000/0,Policy:DefaultThrottlingPolicy_3333333-3333-3333-3333-333333333333,Norm,Sub:5000/0;SoapAction=GetUserAvailability;AddressCount=1;MessageId=urn:uuid:db01111-da7c-4f46-b89d-1111be7aaaaa;Requester=S-3-3-33-3333223333-3333333333-3333673333-3323333;local=1;Threads.Worker.Available=1198;Threads.Worker.InUse=0;Threads.IO.Available=1194;Threads.IO.InUse=1;Failures=0;MailboxRPC.TimeTaken=0;MailboxRPC.RequestCount=0;AD.TimeTaken=0;AD.RequestCount=2;Request.CPU.Main=0;Local.FirstThreadExecute=0;Local.LongPole.Elapsed.TimeTaken=53;Local.LongPole.Elapsed.Destination=server.company.com;LocalLongPole.TimeTaken=3;LocalLongPole.RequestCount=28;LocalLongPole.Destination=server2.company.com;TotalLocal.TimeTaken=53;TotalLocal.RequestCount=1;Thread.CPU.LongPole.TimeTaken=15;Thread.CPU.LongPole.Destination=LocalRequest.Execute;Request.Phase.PreQuery=5;Request.Phase.RequestDispatcher.BeginInvoke=0;Request.Phase.RequestDispatcher.Complete=54;Request.Phase.PostQuery=0;Request.CPU.Total=15;TimeInAS=59;[C]Queues:0msec/Execute:59msec;End(61ms)>>Conn:1,HangingConn:0,AD:30000/29996/1%,CAS:54000/53940/1%,AB:30000/30000/0%,RPC:36000/35972/1%,FC:1000/0,Policy:DefaultThrottlingPolicy_333333-3333-3333-3333-aaaaaaaaaaaa,Norm[Resources:(DC)dc.company.comHealth:-1%,HistLoad:0),(DC)dc2.company.com(Health:-1%,HistLoad:0),(Mdb)DatabaseName(Health:-1%,HistLoad:0),],Sub:5000/0;

     

    The solution:

    We will utilize logparser purely for speed

    Download Log Parser

     

    The LogParser Query:

    It took a bit of time to work around some of the logic, but this works well.

    Logparser.exe -i:iisw3c "SELECT time, date, cs-username, substr(substr(cs-uri-query, index_of(cs-uri-query, 'Impersonate')),0,index_of(substr(cs-uri-query, index_of(cs-uri-query, 'Impersonate')),';')) AS [Impersonate], substr(substr(cs-uri-query, index_of(cs-uri-query, 'SoapAction')),0,index_of(substr(cs-uri-query, index_of(cs-uri-query, 'SoapAction')),';')) AS [SoapAction], substr(substr(cs-uri-query,index_of(cs-uri-query, 'RC')),0,index_of(substr(cs-uri-query, index_of(cs-uri-query, 'RC')),';')) AS [RC Data], cs-uri-stem, substr(substr(cs-uri-query, index_of(cs-uri-query, 'Execute')),0,index_of(substr(cs-uri-query, index_of(cs-uri-query, 'Execute')),';')) AS [Time to Execute] INTO c:\logs\out.csv FROM c:\logs\*.log Where cs-username = 'Domain\ServAcct' AND cs-uri-query LIKE '%SoapAction%'"

    Note: output goes into the file specified after the INTO clause above. Input is taken from the FROM clause. Notice we are grabbing all .log files in a directory. We are also filtering for requests coming from one user, typipcally applications will authenticate as one user and Impersonate the intended target.

     

    What this query does:

    -Only fields that are sent by a specific user (Domain\ServAcct above)

    Splits the csi-uri-query to pull out:

    • who the above user is impersonating as
    • what the soapaction is
    • the RC field
    • The Execution time

     It took me a bit to understand the built in functions to sort the data we needed.

    The output:

     

     

    How fast is this?

    On my (rather speedy) laptop with about 650 megs of logs:

    Statistics:

    -----------

    Elements
    processed: 827827

    Elements
    output:    325218

    Execution
    time:     11.02 seconds

     

    Great, i see the data in Excel.... How can i make it useful?

     

    Sorting and Charting in Excel is extremely helpful, I'll go through a few scernios that shed some light on our issue

    Counts for each user:

     

    Row Labels

    Count of SoapAction

    Impersonate:Domain\User1

    1102

    SoapAction=m:ConvertId

    293

    SoapAction=m:CreateItem

    1

    SoapAction=m:FindFolder

    22

    SoapAction=m:FindItem

    310

    SoapAction=m:GetFolder

    11

    SoapAction=m:GetItem

    377

    SoapAction=m:UpdateItem

    88

    Impersonate:Domain\User2

    1013

    SoapAction=m:ConvertId

    285

    SoapAction=m:CreateItem

    1

    SoapAction=m:FindFolder

    22

    SoapAction=m:FindItem

    352

    SoapAction=m:GetFolder

    11

    SoapAction=m:GetItem

    286

    SoapAction=m:UpdateItem

    56

     

    Counts for each Action:

     

    Row Labels

    Count of SoapAction

    SoapAction=GetUserAvailability

    31

    SoapAction=m:ConvertId

    65685

    SoapAction=m:CreateItem

    1560

    SoapAction=m:DeleteItem

    1013

    SoapAction=m:ExpandDL

    12

    SoapAction=m:FindFolder

    49536

    SoapAction=m:FindItem

    102752

    SoapAction=m:GetFolder

    24804

    SoapAction=m:GetItem

    70584

    SoapAction=m:ResolveNames

    76

    SoapAction=m:UpdateItem

    9165

    Grand Total

    325218

     

     

    That looks great, how do I get that level of detail out of the logs?

    Note: I am using Excel 2010

     

    To Calculate Counts for each user:

     

    •  Open the .csv output in Excel
    • Without selecting any cells, click insert, PivotTable
    • At Select a Table or Range, the default should be all Cells, click New Worksheet
    • On the new worksheet with the PivotTable click Impersonate and SoapAction under PivotTable Field List (upper right)

     

    • Now drag SoapAction to the (Sum) Values box at the bottom right

    • Now we will want to fix the sort to list the user with the highest number of requests first
      • Highlight all of the values inside of “Count of SoapAction” column (not gathering the header or the total at the bottom)
      • Click the Data tab

    • Select Z to A to sort Largest to Smallest (Next to Sort, upper right)

    To Calculate Counts for each Action:

     

    • Open the .csv output in Excel
    • Without selecting any cells, click insert, PivotTable
    • At Select a Table or Range, the default should be all Cells, click New Worksheet
    • On the new worksheet with the PivotTable click SoapAction under PivotTable Field List (upper right)

     

    • Now drag SoapAction to the (Sum) Values box at the bottom right

     

    Now look at the worksheet with the Pivot Table, you should see the data sorted correctly. Using the same technique you can sort or chart the data by time to get an idea of when the bulk of requests are coming in

     

    -CaseyS

  • The server to which the application is connected cannot impersonate the requested user due to insufficient permission.

    PROBLEM:  When running The Transporter for either Lotus Notes or IMAP migrations you may encounter the following error: 

     

    Summary: 1 item(s). 0 succeeded, 1 failed.
    Elapsed time: 00:01:00


    email@address.com
    Failed

    Error:
    Migration does not happen for the user (email@address.com) due to some errors. All the mailbox items belonging to this user will be ignored.

    System.Web.Services.Protocols.SoapException: The server to which the application is connected cannot impersonate the requested user due to insufficient permission.
       at Microsoft.Exchange.Services.RequestSoapHeaderServiceExtension.ProcessSoapHeaders(SoapMessage message, Object responsibleObject)
       at Microsoft.Exchange.Services.RequestSoapHeaderServiceExtension.AfterDeserializeRequest(SoapMessage message)
       at Microsoft.Exchange.Services.ServiceExtensionManager.DoAfterDeserializeRequest(SoapMessage message)
       at Microsoft.Exchange.Services.ServiceExtensionManager.<>c__DisplayClass1.<ProcessMessage>b__0()
       at Microsoft.Exchange.Diagnostics.ExWatson.<>c__DisplayClass8.<SendReportOnUnhandledException>b__4()
       at Microsoft.Exchange.Common.IL.ILUtil.DoTryFilterCatch(TryDelegate tryDelegate, FilterDelegate filterDelegate, CatchDelegate catchDelegate)
       at Microsoft.Exchange.Diagnostics.ExWatson.SendReportOnUnhandledException(MethodDelegate methodDelegate, IsExceptionInteresting exceptionInteresting, Boolean terminating)
       at Microsoft.Exchange.Diagnostics.ExWatson.SendReportOnUnhandledException(MethodDelegate methodDelegate, IsExceptionInteresting exceptionInteresting)
       at Microsoft.Exchange.Services.Core.ServiceDiagnostics.TraceErrorOnUnhandledException(MethodDelegate methodDelegate)
       at Microsoft.Exchange.Services.ServiceExtensionManager.ProcessMessage(SoapMessage message)
       at System.Web.Services.Protocols.SoapMessage.RunExtensions(SoapExtension[] extensions, Boolean throwOnException)
       at System.Web.Services.Protocols.SoapServerProtocol.CreateServerInstance()
       at System.Web.Services.Protocols.WebServiceHandler.Invoke()
       at System.Web.Services.Protocols.WebServiceHandler.CoreProcessRequest()


    Warning:
    Impersonation failed for the user (email@address.com) Error: (ErrorImpersonationDeniedThe server to which the application is connected cannot impersonate the requested user due to insufficient permission.).

     

    RESOLUTION:

    This error lets you know that you lack permissions to impersonate the user. The Active Directory user used to perform the migration must have the permission to impersonate the users to inject mail into their mailboxes.

    This permission can be set using an Exchange Management Shell command:

    This adds the permission to one CAS (Client Access Server):
    Add-ADPermissions -Identity 'DN_of_ClientAccessServer' -User 'domain\username'  -ExtendedRights ms-Exch-EPI-Impersonation

    This adds the permission to all CAS servers:
    foreach ($exchangeServer in Get-ExchangeServer)
    {
         if ($exchangeServer.ServerRole -match 'ClientAccess')
         {
              Add-ADPermission -Identity $exchangeServer.DistinguishedName -User 'domain\user' -ExtendedRights ms-Exch-EPI-Impersonation
         }

    }
       
    Where domain\user is the user performing the migration.

  • Microsoft Exchange Transport Log Search service will not start and a series of 4999 events are logged

    Problem

    On Exchange 2010, you may notice the below event firing rapidly. In our scenerio we were seeing the service attempt to start and go down approximatly 420 times an hour, logging the below 4999 every time. The only action that was taken prior to this problem appearing was the instalation of Exchange 2010 Sp2. It has been noted that this same problem has occured while installing various RollUps (RUs) as well.

     Log Name:      Application
    Source:        MSExchange Common
    Event ID:      4999
    Task Category: General
    Level:         Error
    Keywords:      Classic
    User:          N/A
    Description:
    Watson report about to be sent for process id: #, with parameters: E12, c-RTL-AMD64, 14.02.0247.005, MSExchangeTransportLogSearch, MSExchangeTransportLogSearch, M.E.T.L.S.MailFlowStatistics.InitializeRecord, System.OutOfMemoryException, a3ee, 14.02.0247.003.
    ErrorReportingEnabled: False

     

    Resolution

    When we have seen the problem in the past, the problem has happened when a function attempted to format information from these files. The end result is a IndexOutofRangeException when trying to read the contents of temporary stored statistics.

    1. Rename the following directory (to preserve existing data for root cause if desired):

           Program Files\Microsoft\Exchange Server\V14\TransportRoles\Logs\ActiveUsersStats\Backup

    2. Restart the Microsoft Exchange Transport Log Search service


    Upon restarting the service a new Backup directory is created by the service and the error will not persist.

     

  • The request failed with HTTP status 401: Unauthorized \ Could not retrieve e12 webservice url

    PROBLEM: 

    When attempting to migrate a user with move-dominomailbox using the Transporter for Lotus Notes for Exchange 2007, you may receive the following error:

    The request failed with HTTP status 401: Unauthorized
    Could not retrieve e12 webservice url

     

    When running the same command with a -debug at the end of it, you may receive the following error:

    DEBUG: Pinging URL (https://server.domain.com/ews/exchange.asmx)
    DEBUG: Request failed with the error message (The request failed with HTTP status 401: Unauthorized.).

    RESOLUTION:

     If you run the Transporter for Lotus Notes on the CAS server that you have specified for the Availability Service URL, you will need to disable the loopback check (DisableLoopbackCheck) on this CAS server.

    Method 1: Disable the loopback check

    1. Click Start, click Run, type regedit , and then click OK.
    2. In Registry Editor, locate and then click the following registry key:

    HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Lsa

    3. Right-click Lsa, point to New, and then click DWORD Value.
    4. Type DisableLoopbackCheck , and then press ENTER.
    5. Right-click DisableLoopbackCheck, and then click Modify.
    6. In the Value data box, type 1 , and then click OK.
    7. Quit Registry Editor, and then restart your computer.

     

    Method 2: Specify host names

    To specify the host names that are mapped to the loopback address and can connect to Web sites on your computer, follow these steps:

    1. Click Start, click Run, type regedit , and then click OK.
    2. In Registry Editor, locate and then click the following registry key:

    HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Lsa\MSV1_0

    3. Right-click MSV1_0, point to New, and then click Multi-String Value.
    4. Type BackConnectionHostNames , and then press ENTER.
    5. Right-click BackConnectionHostNames, and then click Modify.
    6. In the Value data box, type the host name or the host names for the sites that are on the local computer, and then click OK.
    7. Quit Registry Editor, and then restart the IISAdmin service.

     

     

     

    MORE INFORMATION:

    You can additionally test this by connecting to the same URL (https://server.domain.com/ews/exchange.asmx) from both the CAS server itself, and from a different machine on the same domain. The CAS server will be unable to login and reprompt for credentials. The other machine will be able to log in fine and display the XML fine. This is an issue with how we only allow connections to the FQDN of the machine name, the external name we have specified in the url does not match this.

    ie. if the server name is server.internaldomainname.com and external to your company you specify it as server.domain.com.