On 17/02/2020 15:07, Michael Osipov wrote:
> Folks,
>
> I am recently working an issue with Maven Wagon and HttpClient and
> noticed that Tomcat responds with 500 while I would expect 408 in this
> case.
>
> Tried very simple code on Tomcat 8.5.51:
>> @Override
>> protected void doPut(HttpServletRequest request,
>> HttpServletResponse response)
>> throws ServletException, IOException {
>> System.out.print(request.getPathInfo() + " ");
>>
>> if (!request.getServletPath().startsWith("/redirected")) {
>> String location = request.getContextPath() +
>> "/redirected/repo" + request.getPathInfo();
>>
>> response.setStatus(HttpServletResponse.SC_TEMPORARY_REDIRECT);
>> response.setHeader("Location", location);
>> System.out.println("REDIRECT");
>> return;
>> }
>>
>> String fileLoc = request.getPathInfo();
>> Path filePath = MAVEN_CENTRAL.resolve(fileLoc.substring(1));
>>
>> Files.copy(request.getInputStream(), filePath,
>> StandardCopyOption.REPLACE_EXISTING);
>> response.setStatus(HttpServletResponse.SC_OK);
>> System.out.println("OK");
>> }
>
> client code (4.5.11):
>> public static void main(String[] args) throws IOException {
>>
>> try (CloseableHttpClient client =
>> HttpClientBuilder.create().setRedirectStrategy(new
>> WagonRedirectStrategy()).build()) {
>>
>> HttpPut put = new
>> HttpPut("http://localhost:8080/bb/repo/my.file";);
>>
>> byte[] bytes = "I am a checksum".getBytes();
>> try(InputStream is = new ByteArrayInputStream(bytes)) {
>>
>> put.setEntity(new InputStreamEntity(is, bytes.length));
>> RequestConfig config =
>> RequestConfig.custom().setExpectContinueEnabled(true).build();
>> put.setConfig(config);
>>
>> CloseableHttpResponse response = client.execute(put);
>> System.out.println(response.getStatusLine());
>> response.getEntity().writeTo(System.out);
>> response.close();
>> }
>> }
>> }
>
> Debug log from client:
>> [main] DEBUG org.apache.http.client.protocol.RequestAddCookies -
>> CookieSpec selected: default
>> [main] DEBUG org.apache.http.client.protocol.RequestAuthCache - Auth
>> cache not set in the context
>> [main] DEBUG
>> org.apache.http.impl.conn.PoolingHttpClientConnectionManager -
>> Connection request: [route: {}->http://localhost:8080][total
>> available: 0; route allocated: 0 of 2; total allocated: 0 of 20]
>> [main] DEBUG
>> org.apache.http.impl.conn.PoolingHttpClientConnectionManager -
>> Connection leased: [id: 0][route: {}->http://localhost:8080][total
>> available: 0; route allocated: 1 of 2; total allocated: 1 of 20]
>> [main] DEBUG org.apache.http.impl.execchain.MainClientExec - Opening
>> connection {}->http://localhost:8080
>> [main] DEBUG
>> org.apache.http.impl.conn.DefaultHttpClientConnectionOperator -
>> Connecting to localhost/127.0.0.1:8080
>> [main] DEBUG
>> org.apache.http.impl.conn.DefaultHttpClientConnectionOperator -
>> Connection established 127.0.0.1:53913<->127.0.0.1:8080
>> [main] DEBUG org.apache.http.impl.execchain.MainClientExec - Executing
>> request PUT /bb/repo/my.file HTTP/1.1
>> [main] DEBUG org.apache.http.impl.execchain.MainClientExec - Target
>> auth state: UNCHALLENGED
>> [main] DEBUG org.apache.http.impl.execchain.MainClientExec - Proxy
>> auth state: UNCHALLENGED
>> [main] DEBUG org.apache.http.headers - http-outgoing-0 >> PUT
>> /bb/repo/my.file HTTP/1.1
>> [main] DEBUG org.apache.http.headers - http-outgoing-0 >>
>> Content-Length: 15
>> [main] DEBUG org.apache.http.headers - http-outgoing-0 >> Host:
>> localhost:8080
>> [main] DEBUG org.apache.http.headers - http-outgoing-0 >> Connection:
>> Keep-Alive
>> [main] DEBUG org.apache.http.headers - http-outgoing-0 >> User-Agent:
>> Apache-HttpClient/4.5.11 (Java/1.7.0_252)
>> [main] DEBUG org.apache.http.headers - http-outgoing-0 >> Expect:
>> 100-continue
>> [main] DEBUG org.apache.http.headers - http-outgoing-0 >>
>> Accept-Encoding: gzip,deflate
>> [main] DEBUG org.apache.http.headers - http-outgoing-0 << HTTP/1.1 100
>> [main] DEBUG org.apache.http.headers - http-outgoing-0 << HTTP/1.1 307
>> [main] DEBUG org.apache.http.headers - http-outgoing-0 << Location:
>> /bb/redirected/repo/my.file
>> [main] DEBUG org.apache.http.headers - http-outgoing-0 <<
>> Content-Length: 0
>> [main] DEBUG org.apache.http.headers - http-outgoing-0 << Date: Mon,
>> 17 Feb 2020 15:01:15 GMT
>> [main] DEBUG org.apache.http.headers - http-outgoing-0 << Connection:
>> close
>> [main] DEBUG
>> org.apache.http.impl.conn.DefaultManagedHttpClientConnection -
>> http-outgoing-0: Close connection
>> [main] DEBUG org.apache.http.impl.execchain.MainClientExec -
>> Connection discarded
>> [main] DEBUG
>> org.apache.http.impl.conn.PoolingHttpClientConnectionManager -
>> Connection released: [id: 0][route: {}->http://localhost:8080][total
>> available: 0; route allocated: 0 of 2; total allocated: 0 of 20]
>> [main] DEBUG org.apache.http.impl.execchain.RedirectExec - Redirecting
>> to 'http://localhost:8080/bb/redirected/repo/my.file' via
>> {}->http://localhost:8080
>> [main] DEBUG org.apache.http.client.protocol.RequestAddCookies -
>> CookieSpec selected: default
>> [main] DEBUG org.apache.http.client.protocol.RequestAuthCache - Auth
>> cache not set in the context
>> [main] DEBUG
>> org.apache.http.impl.conn.PoolingHttpClientConnectionManager -
>> Connection request: [route: {}->http://localhost:8080][total
>> available: 0; route allocated: 0 of 2; total allocated: 0 of 20]
>> [main] DEBUG
>> org.apache.http.impl.conn.PoolingHttpClientConnectionManager -
>> Connection leased: [id: 1][route: {}->http://localhost:8080][total
>> available: 0; route allocated: 1 of 2; total allocated: 1 of 20]
>> [main] DEBUG org.apache.http.impl.execchain.MainClientExec - Opening
>> connection {}->http://localhost:8080
>> [main] DEBUG
>> org.apache.http.impl.conn.DefaultHttpClientConnectionOperator -
>> Connecting to localhost/127.0.0.1:8080
>> [main] DEBUG
>> org.apache.http.impl.conn.DefaultHttpClientConnectionOperator -
>> Connection established 127.0.0.1:53914<->127.0.0.1:8080
>> [main] DEBUG org.apache.http.impl.execchain.MainClientExec - Executing
>> request PUT /bb/redirected/repo/my.file HTTP/1.1
>> [main] DEBUG org.apache.http.impl.execchain.MainClientExec - Target
>> auth state: UNCHALLENGED
>> [main] DEBUG org.apache.http.impl.execchain.MainClientExec - Proxy
>> auth state: UNCHALLENGED
>> [main] DEBUG org.apache.http.headers - http-outgoing-1 >> PUT
>> /bb/redirected/repo/my.file HTTP/1.1
>> [main] DEBUG org.apache.http.headers - http-outgoing-1 >>
>> Content-Length: 15
>> [main] DEBUG org.apache.http.headers - http-outgoing-1 >> Host:
>> localhost:8080
>> [main] DEBUG org.apache.http.headers - http-outgoing-1 >> Connection:
>> Keep-Alive
>> [main] DEBUG org.apache.http.headers - http-outgoing-1 >> User-Agent:
>> Apache-HttpClient/4.5.11 (Java/1.7.0_252)
>> [main] DEBUG org.apache.http.headers - http-outgoing-1 >> Expect:
>> 100-continue
>> [main] DEBUG org.apache.http.headers - http-outgoing-1 >>
>> Accept-Encoding: gzip,deflate
>> [main] DEBUG org.apache.http.headers - http-outgoing-1 << HTTP/1.1 100
>> [main] DEBUG org.apache.http.headers - http-outgoing-1 << HTTP/1.1 500
>> [main] DEBUG org.apache.http.headers - http-outgoing-1 <<
>> Content-Type: text/html;charset=utf-8
>> HTTP/1.1 500 [main] DEBUG org.apache.http.headers - http-outgoing-1 <<
>> Content-Language: en
>> [main] DEBUG org.apache.http.headers - http-outgoing-1 <<
>> Content-Length: 3185
>> [main] DEBUG org.apache.http.headers - http-outgoing-1 << Date: Mon,
>> 17 Feb 2020 15:01:35 GMT
>> [main] DEBUG org.apache.http.headers - http-outgoing-1 << Connection:
>> close
>> [main] DEBUG
>> org.apache.http.impl.conn.DefaultManagedHttpClientConnection -
>> http-outgoing-1: Close connection
>> [main] DEBUG org.apache.http.impl.execchain.MainClientExec -
>> Connection discarded
>> [main] DEBUG
>> org.apache.http.impl.conn.PoolingHttpClientConnectionManager -
>> Connection released: [id: 1][route: {}->http://localhost:8080][total
>> available: 0; route allocated: 0 of 2; total allocated: 0 of 20]
>> [main] DEBUG
>> org.apache.http.impl.conn.PoolingHttpClientConnectionManager -
>> Connection manager is shutting down
>> <!doctype html><html lang="en"><head><title>HTTP Status 500 – Internal
>> Server Error</title><style type="text/css">body
>> {font-family:Tahoma,Arial,sans-serif;} h1, h2, h3, b
>> {color:white;background-color:#525D76;} h1 {font-size:22px;} h2
>> {font-size:16px;} h3 {font-size:14px;} p {font-size:12px;} a
>> {color:black;} .line
>> {height:1px;background-color:#525D76;border:none;}</style></head><body><h1>HTTP
>> Status 500 – Internal Server Error</h1><hr class="line"
>> /><p><b>Type</b> Exception Report</p><p><b>Message</b>
>> java.net.SocketTimeoutException</p><p><b>Description</b> The server
>> encountered an unexpected condition that prevented it from fulfilling
>> the
>> request.</p><p><b>Exception</b></p><pre>org.apache.catalina.connector.ClientAbortException:
>> java.net.SocketTimeoutException
>>
>> org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:348)
>>
>>
>> org.apache.catalina.connector.InputBuffer.checkByteBufferEof(InputBuffer.java:663)
>>
>> org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:370)
>>
>> org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:152)
>>
>> java.nio.file.Files.copy(Files.java:2735)
>> java.nio.file.Files.copy(Files.java:2854)
>> aa.Test2.doPut(Test2.java:67)
>> javax.servlet.http.HttpServlet.service(HttpServlet.java:663)
>> javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
>> org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
>>
>> </pre><p><b>Root Cause</b></p><pre>java.net.SocketTimeoutException
>>
>> org.apache.tomcat.util.net.NioBlockingSelector.read(NioBlockingSelector.java:201)
>>
>> org.apache.tomcat.util.net.NioSelectorPool.read(NioSelectorPool.java:235)
>>
>> org.apache.tomcat.util.net.NioSelectorPool.read(NioSelectorPool.java:216)
>>
>>
>> org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.fillReadBuffer(NioEndpoint.java:1282)
>>
>>
>> org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.read(NioEndpoint.java:1225)
>>
>>
>> org.apache.coyote.http11.Http11InputBuffer.fill(Http11InputBuffer.java:737)
>>
>>
>> org.apache.coyote.http11.Http11InputBuffer.access$300(Http11InputBuffer.java:42)
>>
>>
>> org.apache.coyote.http11.Http11InputBuffer$SocketInputBuffer.doRead(Http11InputBuffer.java:1120)
>>
>>
>> org.apache.coyote.http11.filters.IdentityInputFilter.doRead(IdentityInputFilter.java:140)
>>
>>
>> org.apache.coyote.http11.Http11InputBuffer.doRead(Http11InputBuffer.java:262)
>>
>> org.apache.coyote.Request.doRead(Request.java:581)
>>
>> org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:344)
>>
>>
>> org.apache.catalina.connector.InputBuffer.checkByteBufferEof(InputBuffer.java:663)
>>
>> org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:370)
>>
>> org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:152)
>>
>> java.nio.file.Files.copy(Files.java:2735)
>> java.nio.file.Files.copy(Files.java:2854)
>> aa.Test2.doPut(Test2.java:67)
>> javax.servlet.http.HttpServlet.service(HttpServlet.java:663)
>> javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
>> org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
>>
>> </pre><p><b>Note</b> The full stack trace of the root cause is
>> available in the server logs.</p><hr class="line" /><h3>Apache
>> Tomcat/8.5.51</h3></body></html>[main] DEBUG
>> org.apache.http.impl.conn.PoolingHttpClientConnectionManager -
>> Connection manager shut down
>
>
> So the server tries to read those advertised 15 bytes from the client
> while the input stream on client side has been exhausted. The reqest
> times out.
>
> I don't understand why I don't get a 408 according to RFC 7231, section
> 6.5.7: The 408 (Request Timeout) status code indicates that the server
> did not receive a complete request message within the time that it was
> prepared to wait...
>
> Jetty 9.4.x suffers from the same problem while HTTPd does send a
> request timeout.
>
> Ideas?
<quote source="Servlet 4.0 spec, section 10.9.2">
If a servlet generates an error that is not handled by the error page
mechanism as described above, the container must ensure to send a
response with status 500.
</quote>
Note the "must" in the above quote.
Even if Tomcat ignored the above requirement, I'm not sure if Tomcat
always has enough information about what the application is doing to
correctly identify when it should use a 408 rather than a 500 status code.
The simplest solution would be to handle the SocketTimeoutException in
the application and return a 408 when appropriate.
Mark
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
