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?
Michael
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
