I've found a problem with the integration of NTLM into HttpClient that I'd appreciate some advice on how to solve.
The problem is that NTLM (unlike any other authentication process) requires the same connection to be used both to receive the challenge and to respond. In basic and digest authentication the connection is closed when an unauthorized response is recieved, but with NTLM it's kept open. This would work quite well except that when an unauthorized message is received, the body of the response isn't read. Now, the question that lingers in my mind is where we should put the fix. We could change the currently empty processResponseBody(HttpState state, HttpConnection conn) in HttpMethodBase to: protected void processResponseBody(HttpState state, HttpConnection conn) { log.trace("enter processResponseBody(HttpState state, HttpConnection conn)"); getResponseBody(); } Alternatively, this call could be added to readResponseBody so that it actually works as advertised. which would ensure that the body of the message is always read and thus ensure that this problem doesn't crop up again in the future (I'm not sure I can think of any other place this would pop up though), the downside of that is the waste of memory, time and bandwidth if the connection would have been closed anyway. The other option is to add a call to getResponseBody() in the Authenticator class when NTLM authentication is used. That seems somewhat out of place for this kind of thing though and any other authentication scheme that leaves connections open would have problems. It's worth noting that if GetMethod is set to use disk, it will buffer the response to disk and everything will work correctly. Any preferences/other options? Adrian Sutton. ------------ I've included a full trace to show what's happening below but let me extract just the key lines here first so you don't get too lost in it all. [DEBUG] wire - ->> "GET /DAV/test%20dir/help.gif HTTP/1.1 " [\r\n] ... [DEBUG] wire - ->> "Authorization: NTLM TlRMTVNTUAABAAAABlIAAAAAAAAsAAAADAAMACAAAAAxOTIuMTY4LjAuNDM= " [\r\n] <-- This is message 1 of NTLM authentication. The connection must be kept alive from here in. ... This is the section where the bug actually lies. Despite readResponseBody being called, the body is never read but instead the InputStream is just stored for later. This means that later when we try to read from the stream again, we get the body of this response before the start of the next response. [DEBUG] wire - -<< "HTTP/1.1 401 Access Denied" [\r\n] [TRACE] HttpMethod - -enter HttpMethodBase.readResponseHeaders(HttpState,HttpConnection) [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "Server: Microsoft-IIS/5.0" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "Date: Wed, 02 Oct 2002 04:34:14 GMT" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "WWW-Authenticate: NTLM TlRMTVNTUAACAAAACgAKADAAAAAGAoEATXpvbJTDtnYAAAAAAAAAAJ4AngA6AAAASU5UUkFFUEhP WAIAFABJAE4AVABSAEEARQBQAEgATwBYAAEAEgBCAE8AQQBSAEQAUgBPAE8ATQAEACgAaQBuAHQA cgBhAGUAcABoAG8AeAAuAGUAcABoAG8AeAAuAGMAbwBtAAMAPABCAG8AYQByAGQAcgBvAG8AbQAu AGkAbgB0AHIAYQBlAHAAaABvAHgALgBlAHAAaABvAHgALgBjAG8AbQAAAAAA" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "Content-Length: 20" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "Content-Type: text/html" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [TRACE] HttpMethod - -enter HttpMethodBase.processResponseHeaders(HttpState, HttpConnection) [TRACE] GetMethod - -enter GetMethod.readResponseBody(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.readResponseBody(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.readResponseBody(HttpState, HttpConnection) [TRACE] HttpConnection - -enter HttpConnection.getResponseInputStream(HttpMethod) [TRACE] HttpMethod - -enter writeRemainingRequestBody(HttpState, HttpConnection) [DEBUG] HttpMethod - -Authorization required [TRACE] HttpMethod - -enter HttpMethodBase.processAuthenticationResponse(HttpState, HttpConnection) .... Note below how the last line of the previous response is prepended to the first line of the next, thus causing readStatusLine to discard the line (in an attempt to avoid processing the end of the previous response). However, it will never find another status line because it just missed it. [TRACE] HttpMethod - -enter HttpMethodBase.readStatusLine(HttpState, HttpConnection) [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "<A HREF="/">Home</A>HTTP/1.1 200 OK" [\r\n] .... [DEBUG] wire - -<< "GIF89aAyyyyiii???III?????????AAA??????|||ssspppiii```___PPPCCC@@@:::000&& & !u,@Oa!?aN,e:>T???HZ???!" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() In the end we wind up skipping over the entire response and hanging when we try to read past the end. We hang there until the server times out and closes the connection. ---------------------- [TRACE] HttpMethod - -Attempt number 1 to write request [DEBUG] HttpMethod - -Opening the connection. [TRACE] HttpConnection - -enter HttpConnection.open() [TRACE] HttpMethod - -enter HttpMethodBase.writeRequest(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.writeRequestLine(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.generateRequestLine(HttpConnection, String, String, String, String) [TRACE] HttpConnection - -enter HttpConnection.print(String) [TRACE] HttpConnection - -enter HttpConnection.write(byte[]) [TRACE] HttpConnection - -enter HttpConnection.write(byte[], int, int) [DEBUG] wire - ->> "GET /DAV/test%20dir/help.gif HTTP/1.1 " [\r\n] [TRACE] HttpMethod - -enter HttpMethodBase.writeRequestHeaders(HttpState,HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.addRequestHeaders(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.addUserAgentRequestHeaders(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.addHostRequestHeader(HttpState, HttpConnection) [DEBUG] HttpMethod - -Request to add Host header ignored: header already added [TRACE] HttpMethod - -enter HttpMethodBase.addCookieRequestHeader(HttpState, HttpConnection) [TRACE] HttpState - -enter HttpState.getCookies() [TRACE] Cookie - -enter Cookie.createCookieHeader(String, int, String, boolean, Date, Cookie[]) [TRACE] HttpMethod - -enter HttpMethodBase.addAuthorizationRequestHeader(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.addProxyAuthorizationRequestHeader(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.addContentLengthRequestHeader(HttpState, HttpConnection) [TRACE] HttpConnection - -enter HttpConnection.print(String) [TRACE] HttpConnection - -enter HttpConnection.write(byte[]) [TRACE] HttpConnection - -enter HttpConnection.write(byte[], int, int) [DEBUG] wire - ->> "Authorization: NTLM TlRMTVNTUAABAAAABlIAAAAAAAAsAAAADAAMACAAAAAxOTIuMTY4LjAuNDM= " [\r\n] [TRACE] HttpConnection - -enter HttpConnection.print(String) [TRACE] HttpConnection - -enter HttpConnection.write(byte[]) [TRACE] HttpConnection - -enter HttpConnection.write(byte[], int, int) [DEBUG] wire - ->> "Host: " [\r\n] [TRACE] HttpConnection - -enter HttpConnection.print(String) [TRACE] HttpConnection - -enter HttpConnection.write(byte[]) [TRACE] HttpConnection - -enter HttpConnection.write(byte[], int, int) [DEBUG] wire - ->> "User-Agent: Jakarta Commons-HttpClient/2.0M1 " [\r\n] [TRACE] HttpConnection - -enter HttpConnection.writeLine() [DEBUG] wire - ->> [\r\n] [TRACE] HttpMethod - -enter HttpMethodBase.readResponse(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.readStatusLine(HttpState, HttpConnection) [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "HTTP/1.1 401 Access Denied" [\r\n] [TRACE] HttpMethod - -enter HttpMethodBase.readResponseHeaders(HttpState,HttpConnection) [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "Server: Microsoft-IIS/5.0" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "Date: Wed, 02 Oct 2002 04:34:14 GMT" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "WWW-Authenticate: NTLM TlRMTVNTUAACAAAACgAKADAAAAAGAoEATXpvbJTDtnYAAAAAAAAAAJ4AngA6AAAASU5UUkFFUEhP WAIAFABJAE4AVABSAEEARQBQAEgATwBYAAEAEgBCAE8AQQBSAEQAUgBPAE8ATQAEACgAaQBuAHQA cgBhAGUAcABoAG8AeAAuAGUAcABoAG8AeAAuAGMAbwBtAAMAPABCAG8AYQByAGQAcgBvAG8AbQAu AGkAbgB0AHIAYQBlAHAAaABvAHgALgBlAHAAaABvAHgALgBjAG8AbQAAAAAA" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "Content-Length: 20" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "Content-Type: text/html" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [TRACE] HttpMethod - -enter HttpMethodBase.processResponseHeaders(HttpState, HttpConnection) [TRACE] GetMethod - -enter GetMethod.readResponseBody(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.readResponseBody(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.readResponseBody(HttpState, HttpConnection) [TRACE] HttpConnection - -enter HttpConnection.getResponseInputStream(HttpMethod) [TRACE] HttpMethod - -enter writeRemainingRequestBody(HttpState, HttpConnection) [DEBUG] HttpMethod - -Authorization required [TRACE] HttpMethod - -enter HttpMethodBase.processAuthenticationResponse(HttpState, HttpConnection) [TRACE] Authenticator - -enter Authenticator.authenticate(HttpMethod, HttpState) [TRACE] Authenticator - -enter Authenticator.authenticate(HttpMethod, HttpState, Header, String) [TRACE] Authenticator - -enter parseAuthenticateHeader(Header) [DEBUG] Authenticator - -Attempting to parse authenticate header: 'WWW-Authenticate: NTLM TlRMTVNTUAACAAAACgAKADAAAAAGAoEATXpvbJTDtnYAAAAAAAAAAJ4AngA6AAAASU5UUkFFUEhP WAIAFABJAE4AVABSAEEARQBQAEgATwBYAAEAEgBCAE8AQQBSAEQAUgBPAE8ATQAEACgAaQBuAHQA cgBhAGUAcABoAG8AeAAuAGUAcABoAG8AeAAuAGMAbwBtAAMAPABCAG8AYQByAGQAcgBvAG8AbQAu AGkAbgB0AHIAYQBlAHAAaABvAHgALgBlAHAAaABvAHgALgBjAG8AbQAAAAAA ' [DEBUG] Authenticator - -s=0 q1=-1 q2=-1 c=293 [DEBUG] Authenticator - -ntlm=>NTLM TlRMTVNTUAACAAAACgAKADAAAAAGAoEATXpvbJTDtnYAAAAAAAAAAJ4AngA6AAAASU5UUkFFUEhP WAIAFABJAE4AVABSAEEARQBQAEgATwBYAAEAEgBCAE8AQQBSAEQAUgBPAE8ATQAEACgAaQBuAHQA cgBhAGUAcABoAG8AeAAuAGUAcABoAG8AeAAuAGMAbwBtAAMAPABCAG8AYQByAGQAcgBvAG8AbQAu AGkAbgB0AHIAYQBlAHAAaABvAHgALgBlAHAAaABvAHgALgBjAG8AbQAAAAAA [TRACE] Authenticator - -enter Authenticator.ntlm(String, HttpMethod, HttpState, String) [TRACE] HttpState - -enter HttpState.getCredentials(String) [DEBUG] Authenticator - -Replying to challenge with: NTLM TlRMTVNTUAADAAAAGAAYAFIAAAAAAAAAagAAAAAAAABAAAAABgAGAEAAAAAMAAwARgAAAAAAAABq AAAABlIAAEFEUklBTjE5Mi4xNjguMC40MwpooV7yo7TrGoC50e8xNt+JxETVfkWohw== [TRACE] HttpMethod - -HttpMethodBase.addRequestHeader(Header) [DEBUG] HttpMethod - -HttpMethodBase.execute(): Server demanded authentication credentials, will try again. [DEBUG] HttpMethod - -Execute loop try 3 [TRACE] HttpMethod - -enter HttpMethodBase.processRequest(HttpState, HttpConnection) [TRACE] HttpMethod - -Attempt number 1 to write request [TRACE] HttpMethod - -enter HttpMethodBase.writeRequest(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.writeRequestLine(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.generateRequestLine(HttpConnection, String, String, String, String) [TRACE] HttpConnection - -enter HttpConnection.print(String) [TRACE] HttpConnection - -enter HttpConnection.write(byte[]) [TRACE] HttpConnection - -enter HttpConnection.write(byte[], int, int) [DEBUG] wire - ->> "GET /DAV/test%20dir/help.gif HTTP/1.1 " [\r\n] [TRACE] HttpMethod - -enter HttpMethodBase.writeRequestHeaders(HttpState,HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.addRequestHeaders(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.addUserAgentRequestHeaders(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.addHostRequestHeader(HttpState, HttpConnection) [DEBUG] HttpMethod - -Request to add Host header ignored: header already added [TRACE] HttpMethod - -enter HttpMethodBase.addCookieRequestHeader(HttpState, HttpConnection) [TRACE] HttpState - -enter HttpState.getCookies() [TRACE] Cookie - -enter Cookie.createCookieHeader(String, int, String, boolean, Date, Cookie[]) [TRACE] HttpMethod - -enter HttpMethodBase.addAuthorizationRequestHeader(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.addProxyAuthorizationRequestHeader(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.addContentLengthRequestHeader(HttpState, HttpConnection) [TRACE] HttpConnection - -enter HttpConnection.print(String) [TRACE] HttpConnection - -enter HttpConnection.write(byte[]) [TRACE] HttpConnection - -enter HttpConnection.write(byte[], int, int) [DEBUG] wire - ->> "Authorization: NTLM TlRMTVNTUAADAAAAGAAYAFIAAAAAAAAAagAAAAAAAABAAAAABgAGAEAAAAAMAAwARgAAAAAAAABq AAAABlIAAEFEUklBTjE5Mi4xNjguMC40MwpooV7yo7TrGoC50e8xNt+JxETVfkWohw== " [\r\n] [TRACE] HttpConnection - -enter HttpConnection.print(String) [TRACE] HttpConnection - -enter HttpConnection.write(byte[]) [TRACE] HttpConnection - -enter HttpConnection.write(byte[], int, int) [DEBUG] wire - ->> "Host: " [\r\n] [TRACE] HttpConnection - -enter HttpConnection.print(String) [TRACE] HttpConnection - -enter HttpConnection.write(byte[]) [TRACE] HttpConnection - -enter HttpConnection.write(byte[], int, int) [DEBUG] wire - ->> "User-Agent: Jakarta Commons-HttpClient/2.0M1 " [\r\n] [TRACE] HttpConnection - -enter HttpConnection.writeLine() [DEBUG] wire - ->> [\r\n] [TRACE] HttpMethod - -enter HttpMethodBase.readResponse(HttpState, HttpConnection) [TRACE] HttpMethod - -enter HttpMethodBase.readStatusLine(HttpState, HttpConnection) [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "<A HREF="/">Home</A>HTTP/1.1 200 OK" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "Server: Microsoft-IIS/5.0" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "Date: Wed, 02 Oct 2002 04:34:20 GMT" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "Content-Type: image/gif" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "Accept-Ranges: bytes" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "Last-Modified: Wed, 24 Jul 2002 05:35:46 GMT" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "ETag: "0259df5d332c21:7f1"" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "Content-Length: 342" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() [TRACE] HttpConnection - -enter HttpConnection.readLine() [DEBUG] wire - -<< "GIF89aAyyyyiii???III?????????AAA??????|||ssspppiii```___PPPCCC@@@:::000&& & !u,@Oa!?aN,e:>T???HZ???!" [\r\n] [TRACE] HttpConnection - -enter HttpConnection.readLine() Adrian Sutton, Software Engineer Ephox Corporation www.ephox.com This email and any files transmitted with it are confidential and intended solely for the use of the individual to whom they are addressed. Opinions contained in this email do not necessarily reflect the opinions of Ephox Corporation. If you have received this email in error please notify the sender immediately and delete all copies of the correspondence from your computer and/or computer network. No warranty is given that this message upon its receipt is virus free and the sender in this respect accepts no liability. -- To unsubscribe, e-mail: <mailto:[EMAIL PROTECTED]> For additional commands, e-mail: <mailto:[EMAIL PROTECTED]>