401 Unauthorized after NTLM authentication error: Unexpected state: MSG_TYPE1_GENERATED

Question

I would like to know what the error messages MSG_TYPE1_GENERATED and MSG_TYPE3_GENERATED (from httpClient/NTLMScheme.State enum) signify to help debug an issue we are having. Can someone please provide the documentation for these errors?

I have a server application which uses ews-java-api 2.0 for connecting to an Exchange Server 2016, configured with NTLM Authentication.   I have configured HttpClient version 4.5.2.   The server application uses an Exchange Service Account for retrieving rooms and meetings from the Exchange Server.   The rooms and meetings are successfully retrieved, but, after a while of successfully running, I see the following error in logs:  

ERROR org.apache.http.impl.auth.HttpAuthenticator - NTLM authentication error: Unexpected state: MSG_TYPE3_GENERATED

  This error is followed by some 401 Unauthorized errors received from Exchange Server and the application never recovers from this 401 error until restart (this usually happens a few times a day).

Caused by: microsoft.exchange.webservices.data.core.exception.http.HttpErrorException: The remote server returned an error: (401)Unauthorized
                at microsoft.exchange.webservices.data.core.request.ServiceRequestBase.getEwsHttpWebResponse(ServiceRequestBase.java:726)
                at microsoft.exchange.webservices.data.core.request.ServiceRequestBase.validateAndEmitRequest(ServiceRequestBase.java:640)
                ... 34 more
 

I am not sure if it is related to this issue, but sometimes after the MSG_TYPE3_GENERATED error log, I see a lot of timeouts:  

 Caused by: java.net.SocketTimeoutException: Read timed out
                    at java.net.SocketInputStream.socketRead0(Native Method)
                    at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
                    at java.net.SocketInputStream.read(SocketInputStream.java:170)
                    at java.net.SocketInputStream.read(SocketInputStream.java:141)
                    at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
                    at sun.security.ssl.InputRecord.read(InputRecord.java:503)
                    at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973)
                    at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930)
                    at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
                    at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:139)
                    at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:155)
                    at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:284)
                    at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
                    at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
                    at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
                    at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:165)
                    at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
                    at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
                    at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:271)
                    at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)
                    at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88)
                    at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
                    at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
                    at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
                    at microsoft.exchange.webservices.data.core.request.HttpClientWebRequest.executeRequest(HttpClientWebRequest.java:286)
                    at microsoft.exchange.webservices.data.core.request.ServiceRequestBase.getEwsHttpWebResponse(ServiceRequestBase.java:721)
                    ... 39 more

Sometimes I see MSG_TYPE1_GENERATED in error log instead of MSG_TYPE3_GENERATED.   I looked into the HttpClient library NTLMScheme.java source code and found the      

enum State {
        UNINITIATED,
        CHALLENGE_RECEIVED,
        MSG_TYPE1_GENERATED,
        MSG_TYPE2_RECEVIED,
        MSG_TYPE3_GENERATED,
        FAILED,
    }

but there does not seem to be any documentation regarding each value.   I tried to increase the version of HttpClient to 4.5.3 because I saw an issue in release notes which is related to NTLM (https://issues.apache.org/jira/browse/HTTPCLIENT-1779). After that my application seems to be more stable. I saw the MSG_TYPE3_GENERATED only once and the application has been running for several days.

Do you think upgrading the HttpClient from 4.5.2 to 4.5.3 did the trick?   Do you have any other suggestions?

Thanks, Alin

Dipteran

This sounds more like a threading issue to me. Are you sure your code is using HttpContext instances correctly? HttpContext class itself is threading safe but it may contain attributes that are not such as auth state or auth scheme. Instances of HttpClient should be used concurrently by multiple threads. – Haiduk

Hi Oleg, thanks for the tip. I'll investigate and come back to you with more details. – Dipteran

Hi Oleg. After performing some tests, I managed to reproduce this issue. – Dipteran

Please see my Answer bellow. Let me know what do you think. – Dipteran

Please raise a JIRA with the project – Haiduk

Hi Oleg. After performing lots of tests, I realised the problem was not in the HttpClient code, but we had some other changes in the ews-java-api library. Sorry for not testing enough before posting this issue. Thanks for all your support. – Dipteran

I am not 100% sure whether or not HttpClient correctly resets auth state in case of an I/O failure. HTTP exchanges when retried with the same context / inconsistent auth state may indeed be failing intermittently due to NTLM auth scheme still being stuck in the middle of a handshake – Haiduk

When I was able to easily reproduce this issue with the modified ews-java-api library, the handshake was indeed performed for each request. Once I removed my changes (I was actually releasing the connection after each request), I could not reproduce the issue in an isolated test. But indeed, it sounds like a bug in the HttpClient library. – Dipteran

I was able to reproduce the issue by setting a breakpoint during the NTLM auth handshake, waiting for the socket to be automatically closed and resuming execution. This will result in the httpclient library logging the MSG_TYPE1_GENERATED message. The authentication will fail but the library will not attempt to perform the authentication again and every single HTTP request after that will result in a 401 Unauthorized response. – Nazi

Please raise a JIRA with the project – Haiduk