On Tue, Apr 14, 2009 at 01:15:32PM +0100, Sam Crawford wrote: > Scrub my earlier suspicion, I'm consuming the full contents of the HTTP > response regardless of the response code. > Watching this in a debugger, I see that the HttpResponse returned by the > second request (using method.execute(...)) returned null on the call to > response.getEntity(). This should have returned me the stream containing > "0000", no? > > Thanks, > > Sam >
Sam I could not find the wirelog. I will not be able to do much without a wirelog of the session. Oleg > 2009/4/14 Sam Crawford <[email protected]> > > > Oleg, > > Thanks for getting back to me. I've been able to reproduce the issue fairly > > easily and have a wire capture from a development environment. See attached. > > > > There are three requests in the wire capture, all for the same content. > > > > Lines 1-122 show the initial request, the subsequent 200 reply, and all > > works well > > > > Lines 124-203 show the re-request for the same URL, with the server > > responding 304 Unmodified, and this works well > > > > Lines 205-324 show the re-request for the same URL, with the 304 > > Unmodified ? this request produces the exception after waiting 30 seconds > > > > Looking at the wire captures alongside the tcpdump captures, I think I may > > see the cause of the issue... > > > > In the second request/response a bunch of headers are sent back with the > > 304 reply. In the tcpdump capture, I see "0000" is returned as the body of > > the response, although this is not shown in the wire capture (at this > > point). > > > > In the third request/response we see "0000" as the first line of the > > response in the HttpClient wire capture (which is not present in the tcpdump > > capture), *then* the 304 headers, then another "0000" string. > > Please correct me if I'm wrong, but it looks as though HttpClient is not > > consuming the "0000" string in the second response, which causes it to spill > > over to the third response, and thus mistakenly leads the HttpClient to > > believe that it's not received the response from the third request. > > > > I'm going to have another skim over my code now... I have a nasty feeling > > that I may not be consuming the response of 304 reply. > > > > Thanks, > > > > Sam > > > > > > 2009/4/14 Oleg Kalnichevski <[email protected]> > > > > On Tue, Apr 14, 2009 at 12:17:18AM +0100, Sam Crawford wrote: > >> > Evening all, > >> > > >> > I'm encountering an odd issue with HttpClient 4.0b2 and HttpCore 4.0 GA. > >> > Sending a fairly benign request to a server running JIRA is causing > >> > HttpClient to throw a ProtocolException with the message "The server > >> failed > >> > to respond with a valid HTTP response" after waiting 30 seconds. 30 > >> seconds > >> > is incidentally the connection and query timeout I defined in the > >> HttpClient > >> > parameters. > >> > > >> > It looks to me like the HttpClient is not recognising that the server > >> has > >> > responded completely. The headers being sent back from the server look > >> okay > >> > to me. > >> > > >> > A tcpdump capture of the communication that triggered the error is shown > >> > below, alongside a stacktrace from the application, and the options I > >> set on > >> > the ThreadSafeClientConnManager and HttpClient. > >> > > >> > Any suggestions would be much appreciated. > >> > > >> > Thanks again, > >> > > >> > Sam > >> > > >> > >> Sam, > >> > >> Could you please post a complete wire / context log of the session? > >> > >> http://hc.apache.org/httpcomponents-client/logging.html > >> > >> Oleg > >> > >> > >> > > >> > #### TCPDUMP CAPTURE OF HTTP COMMUNICATION #### > >> > > >> > GET /JRA/s/330/1/_/styles/combined.css HTTP/1.1 > >> > accept: */* > >> > referer: > >> > http://jira.company.com/JRA/secure/ViewUserIssueColumns!default.jspa > >> > accept-language: en-gb > >> > ua-cpu: x86 > >> > if-modified-since: Sun, 12 Apr 2009 06:41:46 GMT > >> > if-none-match: "1239518506000" > >> > user-agent: Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; .NET CLR > >> > 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.04506.30; .NET CLR > >> 3.0.04506.648; > >> > .NET CLR 3.5.21022; InfoPath.2) > >> > Host: jira.company.com:80 > >> > pragma: no-cache > >> > Connection: Keep-Alive > >> > Cookie: ARPT=YZPUQIS10.132.147.33CKMLK; > >> > > >> JSESSIONID=xpLZJj7fly2Ymnnmp4TgC2YyPnG4ZF684hWqZbvTGwHMqTkzKwxG!119119743 > >> > > >> > HTTP/1.1 304 Not Modified > >> > Cache-Control: private > >> > Date: Mon, 13 Apr 2009 22:39:59 GMT > >> > Transfer-Encoding: chunked > >> > Content-Type: text/css; charset=UTF-8 > >> > Expires: Thu, 11 Apr 2019 22:39:59 GMT > >> > Last-Modified: Sun, 12 Apr 2009 06:41:46 GMT > >> > ETag: "1239518506000" > >> > X-Powered-By: Servlet/2.4 JSP/2.0 > >> > > >> > 0000 > >> > > >> > > >> > > >> > #### STACKTRACE FROM APPLICATION (Note 30 second delay between making > >> > request and the exception) ##### > >> > > >> > > >> [#|2009-04-13T23:40:00.010+0100|INFO|sun-appserver9.1|javax.enterprise.system.stream.out|_ThreadID=24;_ThreadName=httpSSLWorkerThread-8080-3;| > >> > Mon Apr 13 23:40:00 BST 2009|com.a.b.c.ProxyFilter|D|Forwarding GET > >> > /JRA/s/330/1/7/_/styles/global.css|#] > >> > > >> > > >> [#|2009-04-13T23:40:31.449+0100|INFO|sun-appserver9.1|javax.enterprise.system.stream.out|_ThreadID=23;_ThreadName=httpSSLWorkerThread-8080-2;| > >> > Mon Apr 13 23:40:31 BST > >> 2009|com.a.b.c.ProxyFilter|E|ClientProtocolException > >> > thrown when fetching > >> /JRA/s/330/1/_/includes/js/combined-javascript.js|#] > >> > > >> > > >> [#|2009-04-13T23:40:31.451+0100|WARNING|sun-appserver9.1|javax.enterprise.system.stream.err|_ThreadID=23;_ThreadName=httpSSLWorkerThread-8080-2; > >> > > >> _RequestID=6d978520-35f4-45ac-a79e-bce8ae9712e6;|org.apache.http.client.ClientProtocolException > >> > at > >> > > >> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:557) > >> > at > >> > > >> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:487) > >> > at > >> com.a.b.c.ProxyFilter.processProxyRequest(ProxyFilter.java:175) > >> > at com.a.b.c.ProxyFilter.doFilter(ProxyFilter.java:108) > >> > at > >> > > >> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:230) > >> > at > >> > > >> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:198) > >> > at com.a.b.c.UserInjectFilter.doFilter(UserInjectFilter.java:52) > >> > at > >> > > >> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:230) > >> > at > >> > > >> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:198) > >> > at > >> > > >> com.sun.identity.agents.filter.AmAgentBaseFilter.allowRequestToContinue(AmAgentBaseFilter.java:126) > >> > at > >> > > >> com.sun.identity.agents.filter.AmAgentBaseFilter.doFilter(AmAgentBaseFilter.java:75) > >> > at > >> > > >> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:230) > >> > at > >> > > >> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:198) > >> > at > >> > > >> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:288) > >> > at > >> > > >> org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:271) > >> > at > >> > > >> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:202) > >> > at > >> > > >> org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632) > >> > at > >> > > >> org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577) > >> > at > >> com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:94) > >> > at > >> > > >> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:206) > >> > at > >> > > >> org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632) > >> > at > >> > > >> org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577) > >> > at > >> > > >> org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:571) > >> > at > >> > org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:1080) > >> > at > >> > > >> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:150) > >> > at > >> > > >> org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632) > >> > at > >> > > >> org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577) > >> > at > >> > > >> org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:571) > >> > at > >> > org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:1080) > >> > at > >> > org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:272) > >> > at > >> > > >> com.sun.enterprise.web.connector.grizzly.DefaultProcessorTask.invokeAdapter(DefaultProcessorTask.java:637) > >> > at > >> > > >> com.sun.enterprise.web.connector.grizzly.DefaultProcessorTask.doProcess(DefaultProcessorTask.java:568) > >> > at > >> > > >> com.sun.enterprise.web.connector.grizzly.DefaultProcessorTask.process(DefaultProcessorTask.java:813) > >> > at > >> > > >> com.sun.enterprise.web.connector.grizzly.DefaultReadTask.executeProcessorTask(DefaultReadTask.java:341) > >> > at > >> > > >> com.sun.enterprise.web.connector.grizzly.DefaultReadTask.doTask(DefaultReadTask.java:263) > >> > at > >> > > >> com.sun.enterprise.web.connector.grizzly.DefaultReadTask.doTask(DefaultReadTask.java:214) > >> > at > >> > com.sun.enterprise.web.connector.grizzly.TaskBase.run(TaskBase.java:265) > >> > at > >> > > >> com.sun.enterprise.web.connector.grizzly.ssl.SSLWorkerThread.run(SSLWorkerThread.java:106) > >> > Caused by: org.apache.http.ProtocolException: The server failed to > >> respond > >> > with a valid HTTP response > >> > at > >> > > >> org.apache.http.impl.conn.DefaultResponseParser.parseHead(DefaultResponseParser.java:93) > >> > at > >> > > >> org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:210) > >> > at > >> > > >> org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:271) > >> > at > >> > > >> org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:235) > >> > at > >> > > >> org.apache.http.impl.conn.AbstractClientConnAdapter.receiveResponseHeader(AbstractClientConnAdapter.java:259) > >> > at > >> > > >> org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:292) > >> > at > >> > > >> org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:126) > >> > at > >> > > >> org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:410) > >> > at > >> > > >> org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:555) > >> > ... 37 more > >> > |#] > >> > > >> > > >> > > >> > ##### HTTP CLIENT SETTINGS ###### > >> > > >> > HttpConnectionParams.setTcpNoDelay(params, true); > >> > HttpConnectionParams.setLinger(params, 30); > >> > HttpConnectionParams.setConnectionTimeout(params, 30000); > >> > HttpConnectionParams.setSoTimeout(params, 30000); > >> > HttpProtocolParams.setVersion(params, HttpVersion.HTTP_1_1); > >> > HttpClientParams.setRedirecting(params, false); > >> > HttpProtocolParams.setUseExpectContinue(params, false); > >> > ConnManagerParams.setMaxConnectionsPerRoute(params, new > >> > ConnPerRouteBean(50)); > >> > ConnManagerParams.setMaxTotalConnections(params, 500); > >> > HttpClientParams.setCookiePolicy(params, > >> > CookiePolicy.BROWSER_COMPATIBILITY); > >> > >> --------------------------------------------------------------------- > >> To unsubscribe, e-mail: [email protected] > >> For additional commands, e-mail: [email protected] > >> > >> > > --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
