Re: 501 Method not implemented with successive POST requests
Christopher Schultz wrote: You'd be amazed how fast a reproducable bug can be fixed ;) Particularly if it can also be repeated or duplicated. ;-) - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: 501 Method not implemented with successive POST requests
Thanks folks, I submitted the issue as a bug: https://issues.apache.org/bugzilla/show_bug.cgi?id=49779 Hans 2010/8/19 Christopher Schultz ch...@christopherschultz.net: -BEGIN PGP SIGNED MESSAGE- Hash: SHA1 Pid/Hans, On 8/16/2010 5:53 AM, Pid wrote: On 16/08/2010 09:52, Hans Wahn wrote: I'd like to provide more information. Any suggestions what is the best way to accomplish that? See above, regarding trace log. Also, providing a stack trace if there is one from the error log and any access log data. You might consider *not* sending the 100 header and just proceeding as normal. Also, can you try your tests against a similarly-configured Tomcat 6.0.29 instance? It may be that some code has changed in Tomcat 7 and some regression occurred. Especially if you have a super-simple test case (and it looks like you do: you have an automated client that makes a limited and deterministic set of requests, and you can probably whip-together a skeleton webapp that behaves badly on command), you should probably file this as a bug and submit everything you've got: HTTP conversation logs, the example webapp, and the automated client. You'd be amazed how fast a reproducable bug can be fixed ;) - -chris -BEGIN PGP SIGNATURE- Version: GnuPG v1.4.10 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iEYEARECAAYFAkxsrQUACgkQ9CaO5/Lv0PDeOACfR5A4AkbA5JxEX5zihfSAL9BS c4kAnRQB0BT8N8jUO65Oniq0y1e0QGB5 =6gqR -END PGP SIGNATURE- - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: 501 Method not implemented with successive POST requests
-BEGIN PGP SIGNED MESSAGE- Hash: SHA1 Pid/Hans, On 8/16/2010 5:53 AM, Pid wrote: On 16/08/2010 09:52, Hans Wahn wrote: I'd like to provide more information. Any suggestions what is the best way to accomplish that? See above, regarding trace log. Also, providing a stack trace if there is one from the error log and any access log data. You might consider *not* sending the 100 header and just proceeding as normal. Also, can you try your tests against a similarly-configured Tomcat 6.0.29 instance? It may be that some code has changed in Tomcat 7 and some regression occurred. Especially if you have a super-simple test case (and it looks like you do: you have an automated client that makes a limited and deterministic set of requests, and you can probably whip-together a skeleton webapp that behaves badly on command), you should probably file this as a bug and submit everything you've got: HTTP conversation logs, the example webapp, and the automated client. You'd be amazed how fast a reproducable bug can be fixed ;) - -chris -BEGIN PGP SIGNATURE- Version: GnuPG v1.4.10 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iEYEARECAAYFAkxsrQUACgkQ9CaO5/Lv0PDeOACfR5A4AkbA5JxEX5zihfSAL9BS c4kAnRQB0BT8N8jUO65Oniq0y1e0QGB5 =6gqR -END PGP SIGNATURE- - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: 501 Method not implemented with successive POST requests
I'd like to provide more information. Any suggestions what is the best way to accomplish that? Hans 2010/8/16 Pid p...@pidster.com: On 13/08/2010 23:24, André Warnier wrote: Pid wrote: On 13/08/2010 11:52, Hans Wahn wrote: 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] headers - HTTP/1.1 100 Continue 2010/08/12 20:20:17:796 CEST [DEBUG] wire - testName=testValue I suspect that the value pair is being sent as a body, but the server is expecting a header. What is the proper thing for a client to send after receiving the 100 Continue message? as per RFC2616, 8.2.3 Requirements for HTTP/1.1 origin servers: - Upon receiving a request which includes an Expect request-header field with the 100-continue expectation, an origin server MUST either respond with 100 (Continue) status and continue to read from the input stream, or respond with a final status code. The origin server MUST NOT wait for the request body before sending the 100 (Continue) response. If it responds with a final status code, it MAY close the transport connection or it MAY continue to read and discard the rest of the request. It MUST NOT perform the requested method if it returns a final status code. So it looks like the client is right in that case, to just send the body. But to me it loks as if the server send the 100 Continue status, and then went away, and that indeed when the client sends this body, it is interpreted by the server as a new request, which should start with a request line. This could be a server bug, or else it is the client which has created a new connection and sends the body onto it. I am not quite sure at this point if we are seeing everything in the trace log. Anyway, something is badly out of sync. Agreed. More information required. p - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: 501 Method not implemented with successive POST requests
On 16/08/2010 09:52, Hans Wahn wrote: I'd like to provide more information. Any suggestions what is the best way to accomplish that? Hans 2010/8/16 Pid p...@pidster.com: On 13/08/2010 23:24, André Warnier wrote: Pid wrote: On 13/08/2010 11:52, Hans Wahn wrote: 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] headers - HTTP/1.1 100 Continue 2010/08/12 20:20:17:796 CEST [DEBUG] wire - testName=testValue I suspect that the value pair is being sent as a body, but the server is expecting a header. What is the proper thing for a client to send after receiving the 100 Continue message? as per RFC2616, 8.2.3 Requirements for HTTP/1.1 origin servers: - Upon receiving a request which includes an Expect request-header field with the 100-continue expectation, an origin server MUST either respond with 100 (Continue) status and continue to read from the input stream, or respond with a final status code. The origin server MUST NOT wait for the request body before sending the 100 (Continue) response. If it responds with a final status code, it MAY close the transport connection or it MAY continue to read and discard the rest of the request. It MUST NOT perform the requested method if it returns a final status code. So it looks like the client is right in that case, to just send the body. But to me it loks as if the server send the 100 Continue status, and then went away, and that indeed when the client sends this body, it is interpreted by the server as a new request, which should start with a request line. This could be a server bug, or else it is the client which has created a new connection and sends the body onto it. I am not quite sure at this point if we are seeing everything in the trace log. Anyway, something is badly out of sync. Agreed. More information required. See above, regarding trace log. Also, providing a stack trace if there is one from the error log and any access log data. You might consider *not* sending the 100 header and just proceeding as normal. p - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org signature.asc Description: OpenPGP digital signature
Re: 501 Method not implemented with successive POST requests
On 13/08/2010 23:24, André Warnier wrote: Pid wrote: On 13/08/2010 11:52, Hans Wahn wrote: 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] headers - HTTP/1.1 100 Continue 2010/08/12 20:20:17:796 CEST [DEBUG] wire - testName=testValue I suspect that the value pair is being sent as a body, but the server is expecting a header. What is the proper thing for a client to send after receiving the 100 Continue message? as per RFC2616, 8.2.3 Requirements for HTTP/1.1 origin servers: - Upon receiving a request which includes an Expect request-header field with the 100-continue expectation, an origin server MUST either respond with 100 (Continue) status and continue to read from the input stream, or respond with a final status code. The origin server MUST NOT wait for the request body before sending the 100 (Continue) response. If it responds with a final status code, it MAY close the transport connection or it MAY continue to read and discard the rest of the request. It MUST NOT perform the requested method if it returns a final status code. So it looks like the client is right in that case, to just send the body. But to me it loks as if the server send the 100 Continue status, and then went away, and that indeed when the client sends this body, it is interpreted by the server as a new request, which should start with a request line. This could be a server bug, or else it is the client which has created a new connection and sends the body onto it. I am not quite sure at this point if we are seeing everything in the trace log. Anyway, something is badly out of sync. Agreed. More information required. p - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org signature.asc Description: OpenPGP digital signature
Re: 501 Method not implemented with successive POST requests
On 13/08/2010 10:07, Hans Wahn wrote: Hello Tomcat-Users, I'm facing a strange issue when using HttpComponents with successive POST requests against a simple Tomcat 7 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 login resource; 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 resource again; Tomcat returns a HTTP501 - Method not implemented 5. Client requests the same resource again; Tomcat returns the page (HTTP200) 6. Client requests the same resource again; Tomcat returns the page (HTTP200) 7. Client requests the same resource again; Tomcat returns the page (HTTP200) The access log message regarding the 501 says: 'testName=testValuePOST /test/secure/ HTTP/1.1 501 1278', which may What is the exact header body of the 302 redirect from Tomcat in #2? Given that the client performs steps 3 4, can you check what's being *sent* by the client, not what's being received by Tomcat? Are you sure the client isn't making that error? What is the client code which makes the request here? p indicate that the entity data and the HTTP-method name somehow got mixed up!? Strangely the HTTP501 does not appear in case of a JSP for the requested resource, only if facing a form-based POST authentication Servlet in Tomcat 7. The servlet does only implement post and get(which calls the doPost) and returns just a string. The client code should be fine since I already posted this issue on the HTTPComponents mailing list and the data sent over the wire seems to be right. I'd like to attach the zipped webapp dir along with the simple client souce code, but along with the HTTPComponents libraries it's ~450KB and I don't know the attachment policy of this list. How can I provide further helpfull information? Thanks for helping in advance best regards Hans - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org signature.asc Description: OpenPGP digital signature
Re: 501 Method not implemented with successive POST requests
Thanks for looking into this issue. What is the exact header body of the 302 redirect from Tomcat in #2? 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] 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 Given that the client performs steps 3 4, can you check what's being *sent* by the client, not what's being received by Tomcat? Client sent data step3 (request redirect uri): 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] 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] Client sent data step4 (re-requesting the same uri): 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] 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] ... Are you sure the client isn't making that error? What is the client code which makes
Re: 501 Method not implemented with successive POST requests
On 13/08/2010 11:52, Hans Wahn wrote: Thanks for looking into this issue. What is the exact header body of the 302 redirect from Tomcat in #2? 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] 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 Given that the client performs steps 3 4, can you check what's being *sent* by the client, not what's being received by Tomcat? Client sent data step3 (request redirect uri): 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] 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] Client sent data step4 (re-requesting the same uri): 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] 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
Re: 501 Method not implemented with successive POST requests
For the below, isn't there an alternative method of configuring the client to automatically follow redirects? I asked the same question and Oleg Kalniche (HTTPComponents developer) replied: There are several cases when automatic redirections is prohibited by the HTTP specification. You can provide a custom RedirectHandler (4.0) or RedirectStrategy (4.1) implementation in order to override those restrictions. Per default HttpClient automatically redirects 302 responses only for GET and HEAD methods. It is also weird that the first response after the redirect is ok, but the next fails while all responses after the failure are fine. best regards Hans 2010/8/13 Pid p...@pidster.com: On 13/08/2010 11:52, Hans Wahn wrote: Thanks for looking into this issue. What is the exact header body of the 302 redirect from Tomcat in #2? 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] 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 Given that the client performs steps 3 4, can you check what's being *sent* by the client, not what's being received by Tomcat? Client sent data step3 (request redirect uri): 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] 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] Client sent data step4 (re-requesting the same uri): 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
Re: 501 Method not implemented with successive POST requests
Hans Wahn wrote: For the below, isn't there an alternative method of configuring the client to automatically follow redirects? I asked the same question and Oleg Kalniche (HTTPComponents developer) replied: There are several cases when automatic redirections is prohibited by the HTTP specification. You can provide a custom RedirectHandler (4.0) or RedirectStrategy (4.1) implementation in order to override those restrictions. Per default HttpClient automatically redirects 302 responses only for GET and HEAD methods. It is also weird that the first response after the redirect is ok, but the next fails while all responses after the failure are fine. Hi. First, congratulations on the excellent information you are providing about the problem. Wish everyone did similarly. Here are a couple of considerations that might be relevant or not to the issue at hand, but maybe this gives you an idea. From the HTTP RFC point of view, a POST request is something that might trigger a change of the data on the server side (think POST-ing a payment from your bank account). That is why a POST cannot just be repeated, without at least asking the client about it (you do not want to risk paying twice). In a general sense, it is also risky to use a POST as the first request to an area submitted to authentication. Remember that HTTP is, at the base, a connection-less protocol (each request/response is independent of the others, and the server could have processed a million other requests before this client makes his second request). The first time the client makes the POST (request + headers + data), the client is not yet authenticated. So the server has to refuse, and send back a request for authentication, before accepting the POST (e.g. the authentication form, or a 401 response). Then the client has to respond to this authentication request (in this case, by submitting the login form contents). Then the server has to verify the credentials, and if they are ok, then the client could now re-submit its POST. But there is an inherent problem there : where has the POST data from the first unsuccesful POST gone in the meantime ? And can the client just re-submit that same POST now, with the same data ? What if the server, upon the succesful authentication, had somehow remembered it and processed it ? (that is why in most browsers, you get a warning popup when moving back to a previous page and try to issue the same POST request as before). There are schemes to overcome the above issue, where the server indeed remembers the POST body and does an internal redirect when the authentication has succeeded. But I wonder if this works with a form-based authentication scheme. My second consideration is that by examining you data, I see that each request seems to be split in 2 phases : 1) client sends the request line and the headers, including a Expect: 100-Continue header 1a) server responds HTTP/1.1 100 Continue[EOL] 2) client sends the request body I am unfamiliar with that scheme (which may be very correct in HTTP terms). But maybe that is when the server and/or client get confused, when this is mixed with an authentication scheme ? Or maybe the client is not just supposed to send the rest of the request without a header of some sort ? Third consideration : in the requests from the client to the server, I see a Connection: Keep-Alive header. But I see no such headers coming back from the server. Maybe it is implied in that case (I have not rechecked the RFC). But could this not be the origin of the problem ? If the server sends a 100 Continue, but then closes the connection, then the next client request which just sends the remaining body (on a new connection?), may be interpreted by the server as a new request (on this new connection), and thus not be understood properly, and generate this method not implemented. HTH, somehow - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: 501 Method not implemented with successive POST requests
Thanks for your friendly words and explanations. Due to your thought the POST data of the first request may get processed too late and mixup things, I altered the client source, so the user credentials are only send after the inital call (on the second request). Also the POST test data testName=testValue is only send after the 302 redirect. Sadly the responses stay the same as before. Now, I don't know what to try next to narrow the problem down. Still, I'm unsure if the problem lies in the clientCode/API or on the Tomcat side? Any suggestions? best regards Hans 2010/8/13 André Warnier a...@ice-sa.com: Hans Wahn wrote: For the below, isn't there an alternative method of configuring the client to automatically follow redirects? I asked the same question and Oleg Kalniche (HTTPComponents developer) replied: There are several cases when automatic redirections is prohibited by the HTTP specification. You can provide a custom RedirectHandler (4.0) or RedirectStrategy (4.1) implementation in order to override those restrictions. Per default HttpClient automatically redirects 302 responses only for GET and HEAD methods. It is also weird that the first response after the redirect is ok, but the next fails while all responses after the failure are fine. Hi. First, congratulations on the excellent information you are providing about the problem. Wish everyone did similarly. Here are a couple of considerations that might be relevant or not to the issue at hand, but maybe this gives you an idea. From the HTTP RFC point of view, a POST request is something that might trigger a change of the data on the server side (think POST-ing a payment from your bank account). That is why a POST cannot just be repeated, without at least asking the client about it (you do not want to risk paying twice). In a general sense, it is also risky to use a POST as the first request to an area submitted to authentication. Remember that HTTP is, at the base, a connection-less protocol (each request/response is independent of the others, and the server could have processed a million other requests before this client makes his second request). The first time the client makes the POST (request + headers + data), the client is not yet authenticated. So the server has to refuse, and send back a request for authentication, before accepting the POST (e.g. the authentication form, or a 401 response). Then the client has to respond to this authentication request (in this case, by submitting the login form contents). Then the server has to verify the credentials, and if they are ok, then the client could now re-submit its POST. But there is an inherent problem there : where has the POST data from the first unsuccesful POST gone in the meantime ? And can the client just re-submit that same POST now, with the same data ? What if the server, upon the succesful authentication, had somehow remembered it and processed it ? (that is why in most browsers, you get a warning popup when moving back to a previous page and try to issue the same POST request as before). There are schemes to overcome the above issue, where the server indeed remembers the POST body and does an internal redirect when the authentication has succeeded. But I wonder if this works with a form-based authentication scheme. My second consideration is that by examining you data, I see that each request seems to be split in 2 phases : 1) client sends the request line and the headers, including a Expect: 100-Continue header 1a) server responds HTTP/1.1 100 Continue[EOL] 2) client sends the request body I am unfamiliar with that scheme (which may be very correct in HTTP terms). But maybe that is when the server and/or client get confused, when this is mixed with an authentication scheme ? Or maybe the client is not just supposed to send the rest of the request without a header of some sort ? Third consideration : in the requests from the client to the server, I see a Connection: Keep-Alive header. But I see no such headers coming back from the server. Maybe it is implied in that case (I have not rechecked the RFC). But could this not be the origin of the problem ? If the server sends a 100 Continue, but then closes the connection, then the next client request which just sends the remaining body (on a new connection?), may be interpreted by the server as a new request (on this new connection), and thus not be understood properly, and generate this method not implemented. HTH, somehow - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: 501 Method not implemented with successive POST requests
Hans Wahn wrote: Thanks for your friendly words and explanations. Due to your thought the POST data of the first request may get processed too late and mixup things, I altered the client source, so the user credentials are only send after the inital call (on the second request). No, what I really meant was something like this : do the authentication before even the first POST. The client should first request some resource inside the protected area, but with a GET (for example, some static page). That will trigger the authentication cycle (login page sent by the server, response with credentials by the client, server sending the original requested page back (or a redirect to it). Then, when the client has received this first static resource (and is authenticated for that protected area), have it do the POST. Then the POST itself will not be interrupted and/or repeated by the authentication cycle. But, if you are doing this using a form authentication, then there must be something (some information) which is sent in the POST, which allows the server to determine that the client is already authenticated. Normally, one does this by creating a session at the server level, saving the authentication data inside that session information, then returning a cookie to the client with the id of that session. The client then, upon subsequent calls, adds this cookie to the requests, and this is what allows the server to retrieve the corresponding saved session information, including that the client is already authenticated, and thus to decide that it does not have to authenticate the client again. I believe that most of this should be automatic, handled automatically by tomat and your HttpClient, via the JSESSIONID cookie. But re-examining your messages to the list and looking at your steps 3 and 4, I see that the value of the JSESSIONID cookie changes in-between : in step 3, you have : 2010/08/12 20:20:17:750 CEST [DEBUG] wire - Cookie: JSESSIONID=DA224C1B02E94524187858267D70A830[EOL] while in step 4, you have : 2010/08/12 20:20:17:796 CEST [DEBUG] wire - Cookie: JSESSIONID=A5FB87E6199EADB2AB18010DA295EC99[EOL] These are 2 different session-id's, thus I would think 2 distinct sessions. Are you sure that there is not something wrong in your authentication logic ? Or is it I who do not understand how these things are supposed to work ? (generic question to the list) - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: 501 Method not implemented with successive POST requests
On 13/08/2010 11:52, Hans Wahn wrote: 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] headers - HTTP/1.1 100 Continue 2010/08/12 20:20:17:796 CEST [DEBUG] wire - testName=testValue I suspect that the value pair is being sent as a body, but the server is expecting a header. What is the proper thing for a client to send after receiving the 100 Continue message? p 2010/08/12 20:20:17:796 CEST [DEBUG] wire - HTTP/1.1 501 Not signature.asc Description: OpenPGP digital signature
Re: 501 Method not implemented with successive POST requests
Pid wrote: On 13/08/2010 11:52, Hans Wahn wrote: 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] headers - HTTP/1.1 100 Continue 2010/08/12 20:20:17:796 CEST [DEBUG] wire - testName=testValue I suspect that the value pair is being sent as a body, but the server is expecting a header. What is the proper thing for a client to send after receiving the 100 Continue message? as per RFC2616, 8.2.3 Requirements for HTTP/1.1 origin servers: - Upon receiving a request which includes an Expect request-header field with the 100-continue expectation, an origin server MUST either respond with 100 (Continue) status and continue to read from the input stream, or respond with a final status code. The origin server MUST NOT wait for the request body before sending the 100 (Continue) response. If it responds with a final status code, it MAY close the transport connection or it MAY continue to read and discard the rest of the request. It MUST NOT perform the requested method if it returns a final status code. So it looks like the client is right in that case, to just send the body. But to me it loks as if the server send the 100 Continue status, and then went away, and that indeed when the client sends this body, it is interpreted by the server as a new request, which should start with a request line. This could be a server bug, or else it is the client which has created a new connection and sends the body onto it. I am not quite sure at this point if we are seeing everything in the trace log. Anyway, something is badly out of sync. - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
