You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@commons.apache.org by Adrian Sutton <ad...@ephox.com> on 2002/10/02 06:58:55 UTC
[httpclient] Reused connection is not fully read before reuse with NTLM
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: <ma...@jakarta.apache.org>
For additional commands, e-mail: <ma...@jakarta.apache.org>