hc-httpclient-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Sam Crawford <samcrawf...@gmail.com>
Subject Re: ProtocolException being thrown for seemingly valid response
Date Tue, 14 Apr 2009 16:28:16 GMT
Ah ha, thanks very much for taking the time to investigate - I'll go beat
find out what app server is being used and beat them up !
All the best,

Sam


2009/4/14 Oleg Kalnichevski <olegk@apache.org>

> On Tue, Apr 14, 2009 at 02:01:22PM +0100, Sam Crawford wrote:
> > Apologies, it looks like the mailing list may have bounced my email
> earlier
> > due to it being marked as spam. I've reattached it...
> >
> > Thanks
> >
> > Sam
> >
>
> Hi Sam
>
> This one turned out quite tricky. It took me a while to figure what was
> wrong with the messages.
>
> The last two HTTP responses look almost perfectly okay. The catch is
> that 304 response MAY NOT have a response body at all.
>
> RFC 2616:
> ---
> 10.3.5 304 Not Modified
>
> If the client has performed a conditional GET request and access is
> allowed, but the document has not been modified, the server SHOULD
> respond with this status code. The 304 response MUST NOT contain a
> message-body, and thus is always terminated by the first empty line
> after the header fields.
> ---
>
> The 0000 bit you are seeing is the closing chunk of the chunk coded
> body. It is perfectly well formed. The trouble is that the response body
> was not meant to be there in the first place.
>
> The servlet engine your application is talking to appears broken.
>
> Hope this helps
>
> Oleg
>
> >
> > 2009/4/14 Oleg Kalnichevski <olegk@apache.org>
> >
> > > 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 <samcrawford@gmail.com>
> > > >
> > > > > 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 <olegk@apache.org>
> > > > >
> > > > > 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:
> 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
> > >
> > >
>
>
> >
> > ---------------------------------------------------------------------
> > 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
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message