You are viewing a plain text version of this content. The canonical link for it is here.
Posted to httpclient-users@hc.apache.org by Juhan Ernits <ju...@gmail.com> on 2012/06/29 08:16:15 UTC

Apache httpAsyncClient works fine but throws a HTTP protocol exception: Not a valid protocol version

Hi!

My setup: Apache HttpAsyncClient 4.0-beta1, dependencies as pulled by
Maven, httpcore and httpcore-nio 4.2-beta1. JREs tried are current
Oracle 1.7 and 1.6.

The simplest code that exhibits the problem is taken from
AsyncClientHttpExchange.java:

public static void main(String[] args) throws Exception {
    HttpAsyncClient httpclient = new DefaultHttpAsyncClient();
    httpclient.start();
    try {
        HttpGet request = new HttpGet("http://1.2.3.4/mygeturl?c=123&b=asdf");
        Future<HttpResponse> future = httpclient.execute(request, null);
        HttpResponse response = future.get();
        System.out.println("Response: " + response.getStatusLine());
        System.out.println("Shutting down");
    } finally {
        httpclient.shutdown();
    }
    System.out.println("Done");
}

The sample code works fine on Apache.org website, but I need to access
a page that does not contain any HTML, just 4 lines of plain text. I
can get the information I need out of the response, i.e. the
functionality I need works, but HttpAsyncClient throws a HTTP protocol
exception for some reason. By examining the log I could detect that
the problem occurs after the connection has been closed, but noting
useful for me happens to the response at that stage. It boggles my
mind why it happens in my case and not when accessing
http://www.apache.org.

Question: Can you spot an obvious problem? If not, could this be a
bug? I ran the code in the debugger and then the if condition leading
to the offending line

org.apache.http.message.BasicLineParser.parseProtocolVersion(BasicLineParser.java:144)

could not be reached. Also, search did not yield anything enlightening.

Any hints appreciated,

Juhan Ernits


The debug output is the following (with full wire debug):

2012/06/29 08:38:09:162 EEST [DEBUG]
PoolingClientAsyncConnectionManager - Connection request: [route:
{}->http://10.0.0.1][total kept alive: 0; route allocated: 0 of 2;
total allocated: 0 of 20]
2012/06/29 08:38:09:212 EEST [DEBUG]
PoolingClientAsyncConnectionManager - Connection leased: [id:
0][route: {}->http://10.0.0.1][total kept alive: 0; route allocated: 1
of 2; total allocated: 0 of 20]
2012/06/29 08:38:09:216 EEST [DEBUG] DefaultHttpAsyncClient -
Connection request suceeded:
[id:0][route:{}->http://10.0.0.1][state:null]
2012/06/29 08:38:09:243 EEST [DEBUG] IOSessionImpl - http-outgoing-0
0:0:0:0:0:0:0:0:52422<->10.0.0.1:80[ACTIVE][r:]: Set attribute
http.nio.exchange-handler
2012/06/29 08:38:09:243 EEST [DEBUG] IOSessionImpl - http-outgoing-0
0:0:0:0:0:0:0:0:52422<->10.0.0.1:80[ACTIVE][rw:]: Event set [w]
2012/06/29 08:38:09:243 EEST [DEBUG] HttpAsyncRequestExecutor -
http-outgoing-0 [ACTIVE]: Connected
2012/06/29 08:38:09:245 EEST [DEBUG] IOSessionImpl - http-outgoing-0
0:0:0:0:0:0:0:0:52422<->10.0.0.1:80[ACTIVE][rw:]: Set attribute
http.nio.http-exchange-state
2012/06/29 08:38:09:245 EEST [DEBUG] HttpAsyncRequestExecutor -
http-outgoing-0 [ACTIVE] Request ready
2012/06/29 08:38:09:245 EEST [DEBUG] IOSessionImpl - http-outgoing-0
0:0:0:0:0:0:0:0:52422<->10.0.0.1:80[ACTIVE][rw:]: Remove attribute
http.nio.exchange-handler
2012/06/29 08:38:09:246 EEST [DEBUG] DefaultHttpAsyncClient - Attempt
1 to execute request
2012/06/29 08:38:09:246 EEST [DEBUG] IOSessionImpl - http-outgoing-0
0:0:0:0:0:0:0:0:52422<->10.0.0.1:80[ACTIVE][rw:]: Set timeout 0
2012/06/29 08:38:09:248 EEST [DEBUG] RequestAddCookies - CookieSpec
selected: best-match
2012/06/29 08:38:09:263 EEST [DEBUG] RequestAuthCache - Auth cache not
set in the context
2012/06/29 08:38:09:263 EEST [DEBUG] RequestTargetAuthentication -
Target auth state: UNCHALLENGED
2012/06/29 08:38:09:264 EEST [DEBUG] RequestProxyAuthentication -
Proxy auth state: UNCHALLENGED
2012/06/29 08:38:09:264 EEST [DEBUG] headers - http-outgoing-0 >> GET
/mygetur?c=123&b=asdfffffffffffff HTTP/1.1
2012/06/29 08:38:09:265 EEST [DEBUG] headers - http-outgoing-0 >> Host: 10.0.0.1
2012/06/29 08:38:09:265 EEST [DEBUG] headers - http-outgoing-0 >>
Connection: Keep-Alive
2012/06/29 08:38:09:265 EEST [DEBUG] headers - http-outgoing-0 >>
User-Agent: Apache-HttpAsyncClient/4.0-beta1 (java 1.5)
2012/06/29 08:38:09:267 EEST [DEBUG] IOSessionImpl - http-outgoing-0
0:0:0:0:0:0:0:0:52422<->10.0.0.1:80[ACTIVE][rw:]: Event set [w]
2012/06/29 08:38:09:267 EEST [DEBUG] IOSessionImpl - http-outgoing-0
0:0:0:0:0:0:0:0:52422<->10.0.0.1:80[ACTIVE][rw:w]: 257 bytes written
2012/06/29 08:38:09:268 EEST [DEBUG] wire - http-outgoing-0 >> "GET
/mygetur?c=123&b=asdfffffffffffff HTTP/1.1[\r][\n]"
2012/06/29 08:38:09:268 EEST [DEBUG] wire - http-outgoing-0 >> "Host:
10.0.0.1[\r][\n]"
2012/06/29 08:38:09:268 EEST [DEBUG] wire - http-outgoing-0 >>
"Connection: Keep-Alive[\r][\n]"
2012/06/29 08:38:09:268 EEST [DEBUG] wire - http-outgoing-0 >>
"User-Agent: Apache-HttpAsyncClient/4.0-beta1 (java 1.5)[\r][\n]"
2012/06/29 08:38:09:268 EEST [DEBUG] wire - http-outgoing-0 >> "[\r][\n]"
2012/06/29 08:38:09:268 EEST [DEBUG] IOSessionImpl - http-outgoing-0
0:0:0:0:0:0:0:0:52422<->10.0.0.1:80[ACTIVE][r:w]: Event cleared [w]
2012/06/29 08:38:09:268 EEST [DEBUG] HttpAsyncRequestExecutor -
http-outgoing-0 [ACTIVE] Request ready
2012/06/29 08:38:09:665 EEST [DEBUG] IOSessionImpl - http-outgoing-0
0:0:0:0:0:0:0:0:52422<->10.0.0.1:80[ACTIVE][r:r]: 346 bytes read
2012/06/29 08:38:09:665 EEST [DEBUG] wire - http-outgoing-0 <<
"HTTP/1.1 200 OK[\r][\n]"
2012/06/29 08:38:09:665 EEST [DEBUG] wire - http-outgoing-0 << "Date:
Fri, 29 Jun 2012 05:38:21 GMT[\r][\n]"
2012/06/29 08:38:09:665 EEST [DEBUG] wire - http-outgoing-0 <<
"Server: Apache/2.2.16 (Debian)[\r][\n]"
2012/06/29 08:38:09:665 EEST [DEBUG] wire - http-outgoing-0 <<
"Content-Length: 2[
2012/06/29 08:38:09:665 EEST [DEBUG] wire - http-outgoing-0 << "Vary:
Accept-Encoding[\r][\n]"
2012/06/29 08:38:09:665 EEST [DEBUG] wire - http-outgoing-0 <<
"Keep-Alive: timeout=15, max=100[\r][\n]"
2012/06/29 08:38:09:665 EEST [DEBUG] wire - http-outgoing-0 <<
"Connection: Keep-Alive[\r][\n]"
2012/06/29 08:38:09:665 EEST [DEBUG] wire - http-outgoing-0 <<
"Content-Type: text/plain[\r][\n]"
2012/06/29 08:38:09:665 EEST [DEBUG] wire - http-outgoing-0 << "[\r][\n]"
2012/06/29 08:38:09:665 EEST [DEBUG] wire - http-outgoing-0 << "01[\n]"
2012/06/29 08:38:09:665 EEST [DEBUG] wire - http-outgoing-0 << "10.0.0.2[\n]"
2012/06/29 08:38:09:665 EEST [DEBUG] wire - http-outgoing-0 <<
"c=123&b=asdf[\n]"
2012/06/29 08:38:09:665 EEST [DEBUG] wire - http-outgoing-0 << "01[\n]"
2012/06/29 08:38:09:673 EEST [DEBUG] HttpAsyncRequestExecutor -
http-outgoing-0 [ACTIVE(133)] Response received
2012/06/29 08:38:09:673 EEST [DEBUG] headers - http-outgoing-0 <<
HTTP/1.1 200 OK
2012/06/29 08:38:09:673 EEST [DEBUG] headers - http-outgoing-0 <<
Date: Fri, 29 Jun 2012 05:38:21 GMT
2012/06/29 08:38:09:674 EEST [DEBUG] headers - http-outgoing-0 <<
Server: Apache/2.2.16 (Debian)
2012/06/29 08:38:09:674 EEST [DEBUG] headers - http-outgoing-0 <<
Content-Length: 2
2012/06/29 08:38:09:674 EEST [DEBUG] headers - http-outgoing-0 <<
Vary: Accept-Encoding
2012/06/29 08:38:09:674 EEST [DEBUG] headers - http-outgoing-0 <<
Keep-Alive: timeout=15, max=100
2012/06/29 08:38:09:674 EEST [DEBUG] headers - http-outgoing-0 <<
Connection: Keep-Alive
2012/06/29 08:38:09:674 EEST [DEBUG] headers - http-outgoing-0 <<
Content-Type: text/plain
2012/06/29 08:38:09:674 EEST [DEBUG] DefaultHttpAsyncClient -
Response: HTTP/1.1 200 OK
2012/06/29 08:38:09:680 EEST [DEBUG] HttpAsyncRequestExecutor -
http-outgoing-0 [ACTIVE(133)] Input ready
2012/06/29 08:38:09:681 EEST [DEBUG] DefaultHttpAsyncClient - Response
fully read
2012/06/29 08:38:09:682 EEST [DEBUG] DefaultHttpAsyncClient -
Connection can be kept alive for 15000 MILLISECONDS
2012/06/29 08:38:09:682 EEST [DEBUG] DefaultHttpAsyncClient - Response processed
2012/06/29 08:38:09:682 EEST [DEBUG] IOSessionImpl - http-outgoing-0
0:0:0:0:0:0:0:0:52422<->10.0.0.1:80[ACTIVE][r:r]: Remove attribute
http.nio.exchange-handler
2012/06/29 08:38:09:683 EEST [DEBUG]
PoolingClientAsyncConnectionManager - Connection released: [id:
0][route: {}->http://10.0.0.1][total kept alive: 1; route allocated: 1
of 2; total allocated: 1 of 20]
2012/06/29 08:38:09:683 EEST [DEBUG] HttpAsyncRequestExecutor -
http-outgoing-0 [ACTIVE(131)] [content length: 2; pos: 2; completed:
true]
Response: HTTP/1.1 200 OK
Shutting down
2012/06/29 08:38:09:683 EEST [DEBUG] IOSessionImpl - http-outgoing-0
0:0:0:0:0:0:0:0:52422<->10.0.0.1:80[ACTIVE][r:r]: 0 bytes read
2012/06/29 08:38:09:683 EEST [DEBUG]
PoolingClientAsyncConnectionManager - Connection manager is shutting
down
2012/06/29 08:38:09:683 EEST [DEBUG] IOSessionImpl - http-outgoing-0
0:0:0:0:0:0:0:0:52422<->10.0.0.1:80[ACTIVE][r:r]: Shutdown
2012/06/29 08:38:09:683 EEST [DEBUG] IOSessionImpl - http-outgoing-0
0.0.0.0:52422<->10.0.0.1:80[CLOSED][]: Shutdown
2012/06/29 08:38:09:683 EEST [ERROR] HttpAsyncRequestExecutor -
http-outgoing-0 [CLOSED] HTTP protocol exception: Not a valid protocol
version:  <org.apache.http.ProtocolException: Not a valid protocol
version: >org.apache.http.ProtocolException: Not a valid protocol
version:
    at org.apache.http.impl.nio.codecs.AbstractMessageParser.parse(AbstractMessageParser.java:186)
    at org.apache.http.impl.nio.DefaultNHttpClientConnection.consumeInput(DefaultNHttpClientConnection.java:159)
    at org.apache.http.impl.nio.DefaultHttpClientIODispatch.onInputReady(DefaultHttpClientIODispatch.java:125)
    at org.apache.http.impl.nio.DefaultHttpClientIODispatch.onInputReady(DefaultHttpClientIODispatch.java:50)
    at org.apache.http.impl.nio.reactor.AbstractIODispatch.inputReady(AbstractIODispatch.java:112)
    at org.apache.http.impl.nio.reactor.BaseIOReactor.validate(BaseIOReactor.java:220)
    at org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:284)
    at org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:106)
    at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:601)
    at java.lang.Thread.run(Unknown Source)
Caused by: org.apache.http.ParseException: Not a valid protocol version:
    at org.apache.http.message.BasicLineParser.parseProtocolVersion(BasicLineParser.java:144)
    at org.apache.http.message.BasicLineParser.parseStatusLine(BasicLineParser.java:402)
    at org.apache.http.impl.nio.codecs.DefaultHttpResponseParser.createMessage(DefaultHttpResponseParser.java:76)
    at org.apache.http.impl.nio.codecs.DefaultHttpResponseParser.createMessage(DefaultHttpResponseParser.java:56)
    at org.apache.http.impl.nio.codecs.AbstractMessageParser.parseHeadLine(AbstractMessageParser.java:135)
    at org.apache.http.impl.nio.codecs.AbstractMessageParser.parse(AbstractMessageParser.java:184)
    ... 9 more

2012/06/29 08:38:09:684 EEST [DEBUG] IOSessionImpl - http-outgoing-0
0.0.0.0:52422<->10.0.0.1:80[CLOSED][]: Shutdown
2012/06/29 08:38:09:684 EEST [DEBUG] HttpAsyncRequestExecutor -
http-outgoing-0 [CLOSED]: Disconnected
2012/06/29 08:38:09:685 EEST [DEBUG]
PoolingClientAsyncConnectionManager - Connection manager shut down
Done

---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org


Re: Apache httpAsyncClient works fine but throws a HTTP protocol exception: Not a valid protocol version

Posted by Juhan Ernits <ju...@gmail.com>.
Hi!

2012/6/29 Oleg Kalnichevski <ol...@apache.org>:
>
> [DEBUG] wire - http-outgoing-0 << "Content-Length: 2
>
> One cannot pack four lines of text into 2 bytes. The server sends back a
> response with expected content of 2 bytes but apparently also sends some
> trailing garbage that HttpAsyncClient interprets as a malformed, out of
> sync response.

Thank you! That was the obvious thing I missed during the dozen times
I went through the log. I need to talk to the people who set up the
server, this is not an Apache HttpAsyncClient bug.

-- 
Juhan

---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org


Re: Apache httpAsyncClient works fine but throws a HTTP protocol exception: Not a valid protocol version

Posted by Oleg Kalnichevski <ol...@apache.org>.
On Fri, 2012-06-29 at 09:16 +0300, Juhan Ernits wrote:
> Hi!
> 
> My setup: Apache HttpAsyncClient 4.0-beta1, dependencies as pulled by
> Maven, httpcore and httpcore-nio 4.2-beta1. JREs tried are current
> Oracle 1.7 and 1.6.
> 
> The simplest code that exhibits the problem is taken from
> AsyncClientHttpExchange.java:
> 
> public static void main(String[] args) throws Exception {
>     HttpAsyncClient httpclient = new DefaultHttpAsyncClient();
>     httpclient.start();
>     try {
>         HttpGet request = new HttpGet("http://1.2.3.4/mygeturl?c=123&b=asdf");
>         Future<HttpResponse> future = httpclient.execute(request, null);
>         HttpResponse response = future.get();
>         System.out.println("Response: " + response.getStatusLine());
>         System.out.println("Shutting down");
>     } finally {
>         httpclient.shutdown();
>     }
>     System.out.println("Done");
> }
> 
> The sample code works fine on Apache.org website, but I need to access
> a page that does not contain any HTML, just 4 lines of plain text.

[DEBUG] wire - http-outgoing-0 << "Content-Length: 2

One cannot pack four lines of text into 2 bytes. The server sends back a
response with expected content of 2 bytes but apparently also sends some
trailing garbage that HttpAsyncClient interprets as a malformed, out of
sync response.

Oleg

>  I
> can get the information I need out of the response, i.e. the
> functionality I need works, but HttpAsyncClient throws a HTTP protocol
> exception for some reason. By examining the log I could detect that
> the problem occurs after the connection has been closed, but noting
> useful for me happens to the response at that stage. It boggles my
> mind why it happens in my case and not when accessing
> http://www.apache.org.
> 
> Question: Can you spot an obvious problem? If not, could this be a
> bug? I ran the code in the debugger and then the if condition leading
> to the offending line
> 
> org.apache.http.message.BasicLineParser.parseProtocolVersion(BasicLineParser.java:144)
> 
> could not be reached. Also, search did not yield anything enlightening.
> 
> Any hints appreciated,
> 
> Juhan Ernits
> 



---------------------------------------------------------------------
To unsubscribe, e-mail: httpclient-users-unsubscribe@hc.apache.org
For additional commands, e-mail: httpclient-users-help@hc.apache.org