hc-httpclient-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From kra...@darkfluid.com
Subject Re: 501 Method not implemented with successive POST requests
Date Thu, 12 Aug 2010 18:26:24 GMT
  Hello,

as requested the wire / context log of the issue:

best regards
Werner


2010/08/12 20:20:13:218 CEST [DEBUG] SingleClientConnManager - Get 
connection for route HttpRoute[{}->http://localhost:8080]
2010/08/12 20:20:13:468 CEST [DEBUG] RequestAddCookies - CookieSpec 
selected: best-match
2010/08/12 20:20:13:484 CEST [DEBUG] DefaultHttpClient - Attempt 1 to 
execute request
2010/08/12 20:20:13:484 CEST [DEBUG] DefaultClientConnection - Sending 
request: POST /test/secure/ HTTP/1.1
2010/08/12 20:20:13:484 CEST [DEBUG] wire - >> "POST /test/secure/ 
HTTP/1.1[EOL]"
2010/08/12 20:20:13:484 CEST [DEBUG] wire - >> "Content-Length: 35[EOL]"
2010/08/12 20:20:13:484 CEST [DEBUG] wire - >> "Content-Type: 
application/x-www-form-urlencoded; charset=UTF-8[EOL]"
2010/08/12 20:20:13:484 CEST [DEBUG] wire - >> "Host: localhost:8080[EOL]"
2010/08/12 20:20:13:484 CEST [DEBUG] wire - >> "Connection: Keep-Alive[EOL]"
2010/08/12 20:20:13:484 CEST [DEBUG] wire - >> "User-Agent: 
Apache-HttpClient/4.0.1 (java 1.5)[EOL]"
2010/08/12 20:20:13:484 CEST [DEBUG] wire - >> "Expect: 100-Continue[EOL]"
2010/08/12 20:20:13:484 CEST [DEBUG] wire - >> "[EOL]"
2010/08/12 20:20:13:484 CEST [DEBUG] headers - >> POST /test/secure/ 
HTTP/1.1
2010/08/12 20:20:13:484 CEST [DEBUG] headers - >> Content-Length: 35
2010/08/12 20:20:13:484 CEST [DEBUG] headers - >> Content-Type: 
application/x-www-form-urlencoded; charset=UTF-8
2010/08/12 20:20:13:484 CEST [DEBUG] headers - >> Host: localhost:8080
2010/08/12 20:20:13:484 CEST [DEBUG] headers - >> Connection: Keep-Alive
2010/08/12 20:20:13:484 CEST [DEBUG] headers - >> User-Agent: 
Apache-HttpClient/4.0.1 (java 1.5)
2010/08/12 20:20:13:484 CEST [DEBUG] headers - >> Expect: 100-Continue
2010/08/12 20:20:15:500 CEST [DEBUG] wire - >> 
"j_username=tomcat&j_password=tomcat"
2010/08/12 20:20:15:671 CEST [DEBUG] wire - << "HTTP/1.1 200 OK[EOL]"
2010/08/12 20:20:15:671 CEST [DEBUG] wire - << "Server: 
Apache-Coyote/1.1[EOL]"
2010/08/12 20:20:15:671 CEST [DEBUG] wire - << "Set-Cookie: 
JSESSIONID=DA224C1B02E94524187858267D70A830; Path=/test; HttpOnly[EOL]"
2010/08/12 20:20:15:671 CEST [DEBUG] wire - << "Content-Type: 
text/html;charset=ISO-8859-1[EOL]"
2010/08/12 20:20:15:671 CEST [DEBUG] wire - << "Content-Length: 711[EOL]"
2010/08/12 20:20:15:671 CEST [DEBUG] wire - << "Date: Thu, 12 Aug 2010 
18:20:15 GMT[EOL]"
2010/08/12 20:20:15:671 CEST [DEBUG] wire - << "[EOL]"
2010/08/12 20:20:15:671 CEST [DEBUG] DefaultClientConnection - Receiving 
response: HTTP/1.1 200 OK
2010/08/12 20:20:15:671 CEST [DEBUG] headers - << HTTP/1.1 200 OK
2010/08/12 20:20:15:687 CEST [DEBUG] headers - << Server: Apache-Coyote/1.1
2010/08/12 20:20:15:687 CEST [DEBUG] headers - << Set-Cookie: 
JSESSIONID=DA224C1B02E94524187858267D70A830; Path=/test; HttpOnly
2010/08/12 20:20:15:687 CEST [DEBUG] headers - << Content-Type: 
text/html;charset=ISO-8859-1
2010/08/12 20:20:15:687 CEST [DEBUG] headers - << Content-Length: 711
2010/08/12 20:20:15:687 CEST [DEBUG] headers - << Date: Thu, 12 Aug 2010 
18:20:15 GMT
2010/08/12 20:20:15:703 CEST [DEBUG] ResponseProcessCookies - Cookie 
accepted: "[version: 0][name: JSESSIONID][value: 
DA224C1B02E94524187858267D70A830][domain: localhost][path: 
/test][expiry: null]".
2010/08/12 20:20:15:703 CEST [DEBUG] DefaultHttpClient - Connection can 
be kept alive indefinitely
Response Status: HTTP/1.1 200 OK
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << "<!DOCTYPE HTML PUBLIC 
"-//W3C//DTD HTML 4.01 Transitional//EN">[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << "<html>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << "[0x9]<head>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << 
"[0x9][0x9]<title>Authentication required</title>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << "[0x9]</head>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << "[0x9]<body>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << "[0x9][0x9]<form 
method="POST" 
action='j_security_check;jsessionid=DA224C1B02E94524187858267D70A830' 
 >[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << "[0x9][0x9][0x9]<table 
border="0" cellspacing="5">[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << 
"[0x9][0x9][0x9][0x9]<tr>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << 
"[0x9][0x9][0x9][0x9][0x9]<th align="right">Username:</th>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << 
"[0x9][0x9][0x9][0x9][0x9]<td align="left"><input type="text" 
name="j_username"></td>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << 
"[0x9][0x9][0x9][0x9]</tr>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << 
"[0x9][0x9][0x9][0x9]<tr>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << 
"[0x9][0x9][0x9][0x9][0x9]<th align="right">Password:</th>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << 
"[0x9][0x9][0x9][0x9][0x9]<td align="left"><input type="password" 
name="j_password"></td>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << 
"[0x9][0x9][0x9][0x9]</tr>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << 
"[0x9][0x9][0x9][0x9]<tr>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << 
"[0x9][0x9][0x9][0x9][0x9]<td align="right"><input type="submit" 
value="Login"></td>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << 
"[0x9][0x9][0x9][0x9][0x9]<td align="left"><input 
type="Reset"></td>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << 
"[0x9][0x9][0x9][0x9]</tr>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << 
"[0x9][0x9][0x9]</table>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << "[0x9][0x9]</form>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << "[0x9]</body>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] wire - << "</html>[\r][\n]"
2010/08/12 20:20:15:703 CEST [DEBUG] SingleClientConnManager - Releasing 
connection 
org.apache.http.impl.conn.SingleClientConnManager$ConnAdapter@f84386
2010/08/12 20:20:15:703 CEST [DEBUG] SingleClientConnManager - Get 
connection for route HttpRoute[{}->http://localhost:8080]
2010/08/12 20:20:15:703 CEST [DEBUG] DefaultHttpClient - Stale 
connection check
2010/08/12 20:20:15:718 CEST [DEBUG] RequestAddCookies - CookieSpec 
selected: best-match
2010/08/12 20:20:15:718 CEST [DEBUG] RequestAddCookies - Cookie 
[version: 0][name: JSESSIONID][value: 
DA224C1B02E94524187858267D70A830][domain: localhost][path: 
/test][expiry: null] match [localhost:8080/test/secure/j_security_check]
2010/08/12 20:20:15:718 CEST [DEBUG] DefaultHttpClient - Attempt 1 to 
execute request
2010/08/12 20:20:15:718 CEST [DEBUG] DefaultClientConnection - Sending 
request: POST /test/secure/j_security_check HTTP/1.1
2010/08/12 20:20:15:718 CEST [DEBUG] wire - >> "POST 
/test/secure/j_security_check HTTP/1.1[EOL]"
2010/08/12 20:20:15:718 CEST [DEBUG] wire - >> "Content-Length: 35[EOL]"
2010/08/12 20:20:15:718 CEST [DEBUG] wire - >> "Content-Type: 
application/x-www-form-urlencoded; charset=UTF-8[EOL]"
2010/08/12 20:20:15:718 CEST [DEBUG] wire - >> "Host: localhost:8080[EOL]"
2010/08/12 20:20:15:718 CEST [DEBUG] wire - >> "Connection: Keep-Alive[EOL]"
2010/08/12 20:20:15:718 CEST [DEBUG] wire - >> "User-Agent: 
Apache-HttpClient/4.0.1 (java 1.5)[EOL]"
2010/08/12 20:20:15:718 CEST [DEBUG] wire - >> "Expect: 100-Continue[EOL]"
2010/08/12 20:20:15:718 CEST [DEBUG] wire - >> "Cookie: 
JSESSIONID=DA224C1B02E94524187858267D70A830[EOL]"
2010/08/12 20:20:15:718 CEST [DEBUG] wire - >> "Cookie2: $Version=1[EOL]"
2010/08/12 20:20:15:718 CEST [DEBUG] wire - >> "[EOL]"
2010/08/12 20:20:15:718 CEST [DEBUG] headers - >> POST 
/test/secure/j_security_check HTTP/1.1
2010/08/12 20:20:15:718 CEST [DEBUG] headers - >> Content-Length: 35
2010/08/12 20:20:15:718 CEST [DEBUG] headers - >> Content-Type: 
application/x-www-form-urlencoded; charset=UTF-8
2010/08/12 20:20:15:718 CEST [DEBUG] headers - >> Host: localhost:8080
2010/08/12 20:20:15:718 CEST [DEBUG] headers - >> Connection: Keep-Alive
2010/08/12 20:20:15:718 CEST [DEBUG] headers - >> User-Agent: 
Apache-HttpClient/4.0.1 (java 1.5)
2010/08/12 20:20:15:718 CEST [DEBUG] headers - >> Expect: 100-Continue
2010/08/12 20:20:15:718 CEST [DEBUG] headers - >> Cookie: 
JSESSIONID=DA224C1B02E94524187858267D70A830
2010/08/12 20:20:15:718 CEST [DEBUG] headers - >> Cookie2: $Version=1
2010/08/12 20:20:17:718 CEST [DEBUG] wire - >> 
"j_username=tomcat&j_password=tomcat"
2010/08/12 20:20:17:750 CEST [DEBUG] wire - << "HTTP/1.1 302 Moved 
Temporarily[EOL]"
2010/08/12 20:20:17:750 CEST [DEBUG] wire - << "Server: 
Apache-Coyote/1.1[EOL]"
2010/08/12 20:20:17:750 CEST [DEBUG] wire - << "Location: 
http://localhost:8080/test/secure/[EOL]"
2010/08/12 20:20:17:750 CEST [DEBUG] wire - << "Content-Length: 0[EOL]"
2010/08/12 20:20:17:750 CEST [DEBUG] wire - << "Date: Thu, 12 Aug 2010 
18:20:17 GMT[EOL]"
2010/08/12 20:20:17:750 CEST [DEBUG] wire - << "[EOL]"
2010/08/12 20:20:17:750 CEST [DEBUG] DefaultClientConnection - Receiving 
response: HTTP/1.1 302 Moved Temporarily
2010/08/12 20:20:17:750 CEST [DEBUG] headers - << HTTP/1.1 302 Moved 
Temporarily
2010/08/12 20:20:17:750 CEST [DEBUG] headers - << Server: Apache-Coyote/1.1
2010/08/12 20:20:17:750 CEST [DEBUG] headers - << Location: 
http://localhost:8080/test/secure/
2010/08/12 20:20:17:750 CEST [DEBUG] headers - << Content-Length: 0
2010/08/12 20:20:17:750 CEST [DEBUG] headers - << Date: Thu, 12 Aug 2010 
18:20:17 GMT
2010/08/12 20:20:17:750 CEST [DEBUG] DefaultHttpClient - Connection can 
be kept alive indefinitely
2010/08/12 20:20:17:750 CEST [DEBUG] SingleClientConnManager - Releasing 
connection 
org.apache.http.impl.conn.SingleClientConnManager$ConnAdapter@19dfbff
2010/08/12 20:20:17:750 CEST [DEBUG] SingleClientConnManager - Get 
connection for route HttpRoute[{}->http://localhost:8080]
2010/08/12 20:20:17:750 CEST [DEBUG] DefaultHttpClient - Stale 
connection check
Response Status: HTTP/1.1 302 Moved Temporarily
==> REDIRECT to http://localhost:8080/test/secure/
2010/08/12 20:20:17:750 CEST [DEBUG] RequestAddCookies - CookieSpec 
selected: best-match
2010/08/12 20:20:17:750 CEST [DEBUG] RequestAddCookies - Cookie 
[version: 0][name: JSESSIONID][value: 
DA224C1B02E94524187858267D70A830][domain: localhost][path: 
/test][expiry: null] match [localhost:8080/test/secure/]
2010/08/12 20:20:17:750 CEST [DEBUG] DefaultHttpClient - Attempt 1 to 
execute request
2010/08/12 20:20:17:750 CEST [DEBUG] DefaultClientConnection - Sending 
request: POST /test/secure/ HTTP/1.1
2010/08/12 20:20:17:750 CEST [DEBUG] wire - >> "POST /test/secure/ 
HTTP/1.1[EOL]"
2010/08/12 20:20:17:750 CEST [DEBUG] wire - >> "Content-Length: 18[EOL]"
2010/08/12 20:20:17:750 CEST [DEBUG] wire - >> "Content-Type: 
application/x-www-form-urlencoded; charset=UTF-8[EOL]"
2010/08/12 20:20:17:750 CEST [DEBUG] wire - >> "Host: localhost:8080[EOL]"
2010/08/12 20:20:17:750 CEST [DEBUG] wire - >> "Connection: Keep-Alive[EOL]"
2010/08/12 20:20:17:750 CEST [DEBUG] wire - >> "User-Agent: 
Apache-HttpClient/4.0.1 (java 1.5)[EOL]"
2010/08/12 20:20:17:750 CEST [DEBUG] wire - >> "Expect: 100-Continue[EOL]"
2010/08/12 20:20:17:750 CEST [DEBUG] wire - >> "Cookie: 
JSESSIONID=DA224C1B02E94524187858267D70A830[EOL]"
2010/08/12 20:20:17:765 CEST [DEBUG] wire - >> "Cookie2: $Version=1[EOL]"
2010/08/12 20:20:17:765 CEST [DEBUG] wire - >> "[EOL]"
2010/08/12 20:20:17:765 CEST [DEBUG] headers - >> POST /test/secure/ 
HTTP/1.1
2010/08/12 20:20:17:765 CEST [DEBUG] headers - >> Content-Length: 18
2010/08/12 20:20:17:765 CEST [DEBUG] headers - >> Content-Type: 
application/x-www-form-urlencoded; charset=UTF-8
2010/08/12 20:20:17:765 CEST [DEBUG] headers - >> Host: localhost:8080
2010/08/12 20:20:17:765 CEST [DEBUG] headers - >> Connection: Keep-Alive
2010/08/12 20:20:17:765 CEST [DEBUG] headers - >> User-Agent: 
Apache-HttpClient/4.0.1 (java 1.5)
2010/08/12 20:20:17:765 CEST [DEBUG] headers - >> Expect: 100-Continue
2010/08/12 20:20:17:765 CEST [DEBUG] headers - >> Cookie: 
JSESSIONID=DA224C1B02E94524187858267D70A830
2010/08/12 20:20:17:765 CEST [DEBUG] headers - >> Cookie2: $Version=1
2010/08/12 20:20:17:781 CEST [DEBUG] wire - << "HTTP/1.1 100 Continue[EOL]"
2010/08/12 20:20:17:781 CEST [DEBUG] wire - << "[EOL]"
2010/08/12 20:20:17:781 CEST [DEBUG] DefaultClientConnection - Receiving 
response: HTTP/1.1 100 Continue
2010/08/12 20:20:17:781 CEST [DEBUG] headers - << HTTP/1.1 100 Continue
2010/08/12 20:20:17:781 CEST [DEBUG] wire - >> "testName=testValue"
2010/08/12 20:20:17:781 CEST [DEBUG] wire - << "HTTP/1.1 200 OK[EOL]"
2010/08/12 20:20:17:781 CEST [DEBUG] wire - << "Server: 
Apache-Coyote/1.1[EOL]"
2010/08/12 20:20:17:781 CEST [DEBUG] wire - << "Set-Cookie: 
JSESSIONID=A5FB87E6199EADB2AB18010DA295EC99; Path=/test; HttpOnly[EOL]"
2010/08/12 20:20:17:781 CEST [DEBUG] wire - << "Content-Length: 20[EOL]"
2010/08/12 20:20:17:781 CEST [DEBUG] wire - << "Date: Thu, 12 Aug 2010 
18:20:17 GMT[EOL]"
2010/08/12 20:20:17:781 CEST [DEBUG] wire - << "[EOL]"
2010/08/12 20:20:17:781 CEST [DEBUG] DefaultClientConnection - Receiving 
response: HTTP/1.1 200 OK
2010/08/12 20:20:17:781 CEST [DEBUG] headers - << HTTP/1.1 200 OK
2010/08/12 20:20:17:781 CEST [DEBUG] headers - << Server: Apache-Coyote/1.1
2010/08/12 20:20:17:781 CEST [DEBUG] headers - << Set-Cookie: 
JSESSIONID=A5FB87E6199EADB2AB18010DA295EC99; Path=/test; HttpOnly
2010/08/12 20:20:17:781 CEST [DEBUG] headers - << Content-Length: 20
2010/08/12 20:20:17:781 CEST [DEBUG] headers - << Date: Thu, 12 Aug 2010 
18:20:17 GMT
2010/08/12 20:20:17:796 CEST [DEBUG] ResponseProcessCookies - Cookie 
accepted: "[version: 0][name: JSESSIONID][value: 
A5FB87E6199EADB2AB18010DA295EC99][domain: localhost][path: 
/test][expiry: null]".
2010/08/12 20:20:17:796 CEST [DEBUG] DefaultHttpClient - Connection can 
be kept alive indefinitely
2010/08/12 20:20:17:796 CEST [DEBUG] wire - << 
"HelloTomcatServlet[\r][\n]"Response Status: HTTP/1.1 200 OK

2010/08/12 20:20:17:796 CEST [DEBUG] SingleClientConnManager - Releasing 
connection 
org.apache.http.impl.conn.SingleClientConnManager$ConnAdapter@10b4b2f
2010/08/12 20:20:17:796 CEST [DEBUG] SingleClientConnManager - Get 
connection for route HttpRoute[{}->http://localhost:8080]
2010/08/12 20:20:17:796 CEST [DEBUG] DefaultHttpClient - Stale 
connection check
2010/08/12 20:20:17:796 CEST [DEBUG] RequestAddCookies - CookieSpec 
selected: best-match
2010/08/12 20:20:17:796 CEST [DEBUG] RequestAddCookies - Cookie 
[version: 0][name: JSESSIONID][value: 
A5FB87E6199EADB2AB18010DA295EC99][domain: localhost][path: 
/test][expiry: null] match [localhost:8080/test/secure/]
2010/08/12 20:20:17:796 CEST [DEBUG] DefaultHttpClient - Attempt 1 to 
execute request
2010/08/12 20:20:17:796 CEST [DEBUG] DefaultClientConnection - Sending 
request: POST /test/secure/ HTTP/1.1
2010/08/12 20:20:17:796 CEST [DEBUG] wire - >> "POST /test/secure/ 
HTTP/1.1[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - >> "Content-Length: 18[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - >> "Content-Type: 
application/x-www-form-urlencoded; charset=UTF-8[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - >> "Host: localhost:8080[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - >> "Connection: Keep-Alive[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - >> "User-Agent: 
Apache-HttpClient/4.0.1 (java 1.5)[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - >> "Expect: 100-Continue[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - >> "Cookie: 
JSESSIONID=A5FB87E6199EADB2AB18010DA295EC99[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - >> "Cookie2: $Version=1[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - >> "[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] headers - >> POST /test/secure/ 
HTTP/1.1
2010/08/12 20:20:17:796 CEST [DEBUG] headers - >> Content-Length: 18
2010/08/12 20:20:17:796 CEST [DEBUG] headers - >> Content-Type: 
application/x-www-form-urlencoded; charset=UTF-8
2010/08/12 20:20:17:796 CEST [DEBUG] headers - >> Host: localhost:8080
2010/08/12 20:20:17:796 CEST [DEBUG] headers - >> Connection: Keep-Alive
2010/08/12 20:20:17:796 CEST [DEBUG] headers - >> User-Agent: 
Apache-HttpClient/4.0.1 (java 1.5)
2010/08/12 20:20:17:796 CEST [DEBUG] headers - >> Expect: 100-Continue
2010/08/12 20:20:17:796 CEST [DEBUG] headers - >> Cookie: 
JSESSIONID=A5FB87E6199EADB2AB18010DA295EC99
2010/08/12 20:20:17:796 CEST [DEBUG] headers - >> Cookie2: $Version=1
2010/08/12 20:20:17:796 CEST [DEBUG] wire - << "HTTP/1.1 100 Continue[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - << "[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] DefaultClientConnection - Receiving 
response: HTTP/1.1 100 Continue
2010/08/12 20:20:17:796 CEST [DEBUG] headers - << HTTP/1.1 100 Continue
2010/08/12 20:20:17:796 CEST [DEBUG] wire - >> "testName=testValue"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - << "HTTP/1.1 501 Not 
Implemented[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - << "Server: 
Apache-Coyote/1.1[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - << "Pragma: No-cache[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - << "Cache-Control: 
no-cache[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - << "Expires: Thu, 01 Jan 
1970 01:00:00 CET[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - << "Content-Type: 
text/html;charset=utf-8[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - << "Content-Length: 1278[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - << "Date: Thu, 12 Aug 2010 
18:20:17 GMT[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - << "Connection: close[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] wire - << "[EOL]"
2010/08/12 20:20:17:796 CEST [DEBUG] DefaultClientConnection - Receiving 
response: HTTP/1.1 501 Not Implemented
2010/08/12 20:20:17:796 CEST [DEBUG] headers - << HTTP/1.1 501 Not 
Implemented
2010/08/12 20:20:17:796 CEST [DEBUG] headers - << Server: Apache-Coyote/1.1
2010/08/12 20:20:17:796 CEST [DEBUG] headers - << Pragma: No-cache
2010/08/12 20:20:17:796 CEST [DEBUG] headers - << Cache-Control: no-cache
2010/08/12 20:20:17:796 CEST [DEBUG] headers - << Expires: Thu, 01 Jan 
1970 01:00:00 CET
2010/08/12 20:20:17:796 CEST [DEBUG] headers - << Content-Type: 
text/html;charset=utf-8
2010/08/12 20:20:17:796 CEST [DEBUG] headers - << Content-Length: 1278
2010/08/12 20:20:17:796 CEST [DEBUG] headers - << Date: Thu, 12 Aug 2010 
18:20:17 GMT
2010/08/12 20:20:17:796 CEST [DEBUG] headers - << Connection: close
2010/08/12 20:20:17:812 CEST [DEBUG] SingleClientConnManager - Releasing 
connection 
org.apache.http.impl.conn.SingleClientConnManager$ConnAdapter@1abab88
2010/08/12 20:20:17:812 CEST [DEBUG] SingleClientConnManager - Released 
connection open but not reusable.
2010/08/12 20:20:17:812 CEST [DEBUG] DefaultClientConnection - 
Connection shut down
2010/08/12 20:20:17:812 CEST [DEBUG] SingleClientConnManager - Get 
connection for route HttpRoute[{}->http://localhost:8080]Response 
Status: HTTP/1.1 501 Not Implemented

2010/08/12 20:20:17:812 CEST [DEBUG] RequestAddCookies - CookieSpec 
selected: best-match
2010/08/12 20:20:17:812 CEST [DEBUG] RequestAddCookies - Cookie 
[version: 0][name: JSESSIONID][value: 
A5FB87E6199EADB2AB18010DA295EC99][domain: localhost][path: 
/test][expiry: null] match [localhost:8080/test/secure/]
2010/08/12 20:20:17:812 CEST [DEBUG] DefaultHttpClient - Attempt 1 to 
execute request
2010/08/12 20:20:17:812 CEST [DEBUG] DefaultClientConnection - Sending 
request: POST /test/secure/ HTTP/1.1
2010/08/12 20:20:17:812 CEST [DEBUG] wire - >> "POST /test/secure/ 
HTTP/1.1[EOL]"
2010/08/12 20:20:17:812 CEST [DEBUG] wire - >> "Content-Length: 18[EOL]"
2010/08/12 20:20:17:812 CEST [DEBUG] wire - >> "Content-Type: 
application/x-www-form-urlencoded; charset=UTF-8[EOL]"
2010/08/12 20:20:17:812 CEST [DEBUG] wire - >> "Host: localhost:8080[EOL]"
2010/08/12 20:20:17:812 CEST [DEBUG] wire - >> "Connection: Keep-Alive[EOL]"
2010/08/12 20:20:17:812 CEST [DEBUG] wire - >> "User-Agent: 
Apache-HttpClient/4.0.1 (java 1.5)[EOL]"
2010/08/12 20:20:17:812 CEST [DEBUG] wire - >> "Expect: 100-Continue[EOL]"
2010/08/12 20:20:17:812 CEST [DEBUG] wire - >> "Cookie: 
JSESSIONID=A5FB87E6199EADB2AB18010DA295EC99[EOL]"
2010/08/12 20:20:17:812 CEST [DEBUG] wire - >> "Cookie2: $Version=1[EOL]"
2010/08/12 20:20:17:812 CEST [DEBUG] wire - >> "[EOL]"
2010/08/12 20:20:17:812 CEST [DEBUG] headers - >> POST /test/secure/ 
HTTP/1.1
2010/08/12 20:20:17:812 CEST [DEBUG] headers - >> Content-Length: 18
2010/08/12 20:20:17:812 CEST [DEBUG] headers - >> Content-Type: 
application/x-www-form-urlencoded; charset=UTF-8
2010/08/12 20:20:17:812 CEST [DEBUG] headers - >> Host: localhost:8080
2010/08/12 20:20:17:812 CEST [DEBUG] headers - >> Connection: Keep-Alive
2010/08/12 20:20:17:812 CEST [DEBUG] headers - >> User-Agent: 
Apache-HttpClient/4.0.1 (java 1.5)
2010/08/12 20:20:17:812 CEST [DEBUG] headers - >> Expect: 100-Continue
2010/08/12 20:20:17:812 CEST [DEBUG] headers - >> Cookie: 
JSESSIONID=A5FB87E6199EADB2AB18010DA295EC99
2010/08/12 20:20:17:812 CEST [DEBUG] headers - >> Cookie2: $Version=1
2010/08/12 20:20:17:828 CEST [DEBUG] wire - << "HTTP/1.1 100 Continue[EOL]"
2010/08/12 20:20:17:828 CEST [DEBUG] wire - << "[EOL]"
2010/08/12 20:20:17:828 CEST [DEBUG] DefaultClientConnection - Receiving 
response: HTTP/1.1 100 Continue
2010/08/12 20:20:17:828 CEST [DEBUG] headers - << HTTP/1.1 100 Continue
2010/08/12 20:20:17:828 CEST [DEBUG] wire - >> "testName=testValue"
2010/08/12 20:20:17:828 CEST [DEBUG] wire - << "HTTP/1.1 200 OK[EOL]"
2010/08/12 20:20:17:828 CEST [DEBUG] wire - << "Server: 
Apache-Coyote/1.1[EOL]"
2010/08/12 20:20:17:828 CEST [DEBUG] wire - << "Content-Length: 20[EOL]"
2010/08/12 20:20:17:828 CEST [DEBUG] wire - << "Date: Thu, 12 Aug 2010 
18:20:17 GMT[EOL]"Response Status: HTTP/1.1 200 OK

2010/08/12 20:20:17:828 CEST [DEBUG] wire - << "[EOL]"
2010/08/12 20:20:17:828 CEST [DEBUG] DefaultClientConnection - Receiving 
response: HTTP/1.1 200 OK
2010/08/12 20:20:17:828 CEST [DEBUG] headers - << HTTP/1.1 200 OK
2010/08/12 20:20:17:828 CEST [DEBUG] headers - << Server: Apache-Coyote/1.1
2010/08/12 20:20:17:828 CEST [DEBUG] headers - << Content-Length: 20
2010/08/12 20:20:17:828 CEST [DEBUG] headers - << Date: Thu, 12 Aug 2010 
18:20:17 GMT
2010/08/12 20:20:17:828 CEST [DEBUG] DefaultHttpClient - Connection can 
be kept alive indefinitely
2010/08/12 20:20:17:828 CEST [DEBUG] wire - << "HelloTomcatServlet[\r][\n]"
2010/08/12 20:20:17:828 CEST [DEBUG] SingleClientConnManager - Releasing 
connection 
org.apache.http.impl.conn.SingleClientConnManager$ConnAdapter@18a7efd
2010/08/12 20:20:17:828 CEST [DEBUG] SingleClientConnManager - Get 
connection for route HttpRoute[{}->http://localhost:8080]
2010/08/12 20:20:17:828 CEST [DEBUG] DefaultHttpClient - Stale 
connection check
2010/08/12 20:20:17:875 CEST [DEBUG] RequestAddCookies - CookieSpec 
selected: best-match
2010/08/12 20:20:17:875 CEST [DEBUG] RequestAddCookies - Cookie 
[version: 0][name: JSESSIONID][value: 
A5FB87E6199EADB2AB18010DA295EC99][domain: localhost][path: 
/test][expiry: null] match [localhost:8080/test/secure/]
2010/08/12 20:20:17:875 CEST [DEBUG] DefaultHttpClient - Attempt 1 to 
execute request
2010/08/12 20:20:17:875 CEST [DEBUG] DefaultClientConnection - Sending 
request: POST /test/secure/ HTTP/1.1
2010/08/12 20:20:17:875 CEST [DEBUG] wire - >> "POST /test/secure/ 
HTTP/1.1[EOL]"
2010/08/12 20:20:17:875 CEST [DEBUG] wire - >> "Content-Length: 18[EOL]"
2010/08/12 20:20:17:890 CEST [DEBUG] wire - >> "Content-Type: 
application/x-www-form-urlencoded; charset=UTF-8[EOL]"
2010/08/12 20:20:17:890 CEST [DEBUG] wire - >> "Host: localhost:8080[EOL]"
2010/08/12 20:20:17:890 CEST [DEBUG] wire - >> "Connection: Keep-Alive[EOL]"
2010/08/12 20:20:17:890 CEST [DEBUG] wire - >> "User-Agent: 
Apache-HttpClient/4.0.1 (java 1.5)[EOL]"
2010/08/12 20:20:17:890 CEST [DEBUG] wire - >> "Expect: 100-Continue[EOL]"
2010/08/12 20:20:17:890 CEST [DEBUG] wire - >> "Cookie: 
JSESSIONID=A5FB87E6199EADB2AB18010DA295EC99[EOL]"
2010/08/12 20:20:17:890 CEST [DEBUG] wire - >> "Cookie2: $Version=1[EOL]"
2010/08/12 20:20:17:890 CEST [DEBUG] wire - >> "[EOL]"
2010/08/12 20:20:17:890 CEST [DEBUG] headers - >> POST /test/secure/ 
HTTP/1.1
2010/08/12 20:20:17:890 CEST [DEBUG] headers - >> Content-Length: 18
2010/08/12 20:20:17:890 CEST [DEBUG] headers - >> Content-Type: 
application/x-www-form-urlencoded; charset=UTF-8
2010/08/12 20:20:17:890 CEST [DEBUG] headers - >> Host: localhost:8080
2010/08/12 20:20:17:890 CEST [DEBUG] headers - >> Connection: Keep-Alive
2010/08/12 20:20:17:890 CEST [DEBUG] headers - >> User-Agent: 
Apache-HttpClient/4.0.1 (java 1.5)
2010/08/12 20:20:17:890 CEST [DEBUG] headers - >> Expect: 100-Continue
2010/08/12 20:20:17:890 CEST [DEBUG] headers - >> Cookie: 
JSESSIONID=A5FB87E6199EADB2AB18010DA295EC99
2010/08/12 20:20:17:890 CEST [DEBUG] headers - >> Cookie2: $Version=1
2010/08/12 20:20:17:890 CEST [DEBUG] wire - << "HTTP/1.1 100 Continue[EOL]"
2010/08/12 20:20:17:890 CEST [DEBUG] wire - << "[EOL]"
2010/08/12 20:20:17:890 CEST [DEBUG] DefaultClientConnection - Receiving 
response: HTTP/1.1 100 Continue
2010/08/12 20:20:17:890 CEST [DEBUG] headers - << HTTP/1.1 100 Continue
2010/08/12 20:20:17:890 CEST [DEBUG] wire - >> "testName=testValue"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - << "HTTP/1.1 200 OK[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - << "Server: 
Apache-Coyote/1.1[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - << "Content-Length: 20[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - << "Date: Thu, 12 Aug 2010 
18:20:17 GMT[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - << "[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] DefaultClientConnection - Receiving 
response: HTTP/1.1 200 OK
2010/08/12 20:20:17:906 CEST [DEBUG] headers - << HTTP/1.1 200 OK
2010/08/12 20:20:17:906 CEST [DEBUG] headers - << Server: Apache-Coyote/1.1
2010/08/12 20:20:17:906 CEST [DEBUG] headers - << Content-Length: 20
2010/08/12 20:20:17:906 CEST [DEBUG] headers - << Date: Thu, 12 Aug 2010 
18:20:17 GMT
2010/08/12 20:20:17:906 CEST [DEBUG] DefaultHttpClient - Connection can 
be kept alive indefinitely
2010/08/12 20:20:17:906 CEST [DEBUG] wire - << "HelloTomcatServlet[\r][\n]"
Response Status: HTTP/1.1 200 OK
2010/08/12 20:20:17:906 CEST [DEBUG] SingleClientConnManager - Releasing 
connection 
org.apache.http.impl.conn.SingleClientConnManager$ConnAdapter@1971afc
2010/08/12 20:20:17:906 CEST [DEBUG] SingleClientConnManager - Get 
connection for route HttpRoute[{}->http://localhost:8080]
2010/08/12 20:20:17:906 CEST [DEBUG] DefaultHttpClient - Stale 
connection check
2010/08/12 20:20:17:906 CEST [DEBUG] RequestAddCookies - CookieSpec 
selected: best-match
2010/08/12 20:20:17:906 CEST [DEBUG] RequestAddCookies - Cookie 
[version: 0][name: JSESSIONID][value: 
A5FB87E6199EADB2AB18010DA295EC99][domain: localhost][path: 
/test][expiry: null] match [localhost:8080/test/secure/]
2010/08/12 20:20:17:906 CEST [DEBUG] DefaultHttpClient - Attempt 1 to 
execute request
2010/08/12 20:20:17:906 CEST [DEBUG] DefaultClientConnection - Sending 
request: POST /test/secure/ HTTP/1.1
2010/08/12 20:20:17:906 CEST [DEBUG] wire - >> "POST /test/secure/ 
HTTP/1.1[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - >> "Content-Length: 18[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - >> "Content-Type: 
application/x-www-form-urlencoded; charset=UTF-8[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - >> "Host: localhost:8080[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - >> "Connection: Keep-Alive[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - >> "User-Agent: 
Apache-HttpClient/4.0.1 (java 1.5)[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - >> "Expect: 100-Continue[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - >> "Cookie: 
JSESSIONID=A5FB87E6199EADB2AB18010DA295EC99[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - >> "Cookie2: $Version=1[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - >> "[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] headers - >> POST /test/secure/ 
HTTP/1.1
2010/08/12 20:20:17:906 CEST [DEBUG] headers - >> Content-Length: 18
2010/08/12 20:20:17:906 CEST [DEBUG] headers - >> Content-Type: 
application/x-www-form-urlencoded; charset=UTF-8
2010/08/12 20:20:17:906 CEST [DEBUG] headers - >> Host: localhost:8080
2010/08/12 20:20:17:906 CEST [DEBUG] headers - >> Connection: Keep-Alive
2010/08/12 20:20:17:906 CEST [DEBUG] headers - >> User-Agent: 
Apache-HttpClient/4.0.1 (java 1.5)
2010/08/12 20:20:17:906 CEST [DEBUG] headers - >> Expect: 100-Continue
2010/08/12 20:20:17:906 CEST [DEBUG] headers - >> Cookie: 
JSESSIONID=A5FB87E6199EADB2AB18010DA295EC99
2010/08/12 20:20:17:906 CEST [DEBUG] headers - >> Cookie2: $Version=1
2010/08/12 20:20:17:906 CEST [DEBUG] wire - << "HTTP/1.1 100 Continue[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - << "[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] DefaultClientConnection - Receiving 
response: HTTP/1.1 100 Continue
2010/08/12 20:20:17:906 CEST [DEBUG] headers - << HTTP/1.1 100 Continue
2010/08/12 20:20:17:906 CEST [DEBUG] wire - >> "testName=testValue"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - << "HTTP/1.1 200 OK[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - << "Server: 
Apache-Coyote/1.1[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - << "Content-Length: 20[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - << "Date: Thu, 12 Aug 2010 
18:20:17 GMT[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] wire - << "[EOL]"
2010/08/12 20:20:17:906 CEST [DEBUG] DefaultClientConnection - Receiving 
response: HTTP/1.1 200 OK
2010/08/12 20:20:17:906 CEST [DEBUG] headers - << HTTP/1.1 200 OK
2010/08/12 20:20:17:906 CEST [DEBUG] headers - << Server: Apache-Coyote/1.1
2010/08/12 20:20:17:906 CEST [DEBUG] headers - << Content-Length: 20
2010/08/12 20:20:17:906 CEST [DEBUG] headers - << Date: Thu, 12 Aug 2010 
18:20:17 GMT
2010/08/12 20:20:17:906 CEST [DEBUG] DefaultHttpClient - Connection can 
be kept alive indefinitely
2010/08/12 20:20:17:906 CEST [DEBUG] wire - << "HelloTomcatServlet[\r][\n]"
2010/08/12 20:20:17:906 CEST [DEBUG] SingleClientConnManager - Releasing 
connection 
org.apache.http.impl.conn.SingleClientConnManager$ConnAdapter@16cd7d5
2010/08/12 20:20:17:906 CEST [DEBUG] DefaultClientConnection - 
Connection shut down
Response Status: HTTP/1.1 200 OK





On 12.08.2010 14:30, Oleg Kalnichevski wrote:
> On Wed, 2010-08-11 at 21:02 +0200, krabat@darkfluid.com wrote:
>> Hello HttpComponents-Users,
>>
>> I'm facing a strange issue when using HttpComponents with successive
>> POST requests against a simple Tomcat servlet (Form-based POST
>> Authentication is enabled). After a sucessfull authentication, the
>> client requests the same protected resource a few times in a row, but
>> the second request always returns a "501 Method not implemented" status.
>> All other requests succeed .
>>
>> The following communication takes place:
>> 1. Client requests a protected resource; Tomcat returns the login page
>> (HTTP200)
>> 2. Client provides the user credentials and calls the auth check page;
>> If successful Tomcat returns a redirect (HTTP302)
>> 3. Client sets the location from the redirect for the next
>> request(identical to URI from #1) and requests it; Tomcat returns the
>> page (HTTP200)
>> 4. Client requests the same page again; Tomcat returns a HTTP501 -
>> Method not implemented
>> 5. Client requests the same page again; Tomcat returns the page (HTTP200)
>> 6. Client requests the same page again; Tomcat returns the page (HTTP200)
>> 7. Client requests the same page again; Tomcat returns the page (HTTP200)
>>
>>
>> The log message regarding the 501 says: '"testName=testValuePOST
>> /test/secure/ HTTP/1.1" 501 1278', which may indicate that the entity
>> and the HTTP-method name somehow got mixed up!?
> Please post a wire / context log of the session
>
> http://hc.apache.org/httpcomponents-client-4.0.1/logging.html
>
> Oleg
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
> For additional commands, e-mail: httpclient-users-help@hc.apache.org
>
>

---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org


Mime
View raw message