You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hc.apache.org by Gary Gregory <ga...@gmail.com> on 2017/08/16 21:00:50 UTC
Core 4 and problem with socket timeout to origin server
Hi All (Oleg, really)
I am wondering how to fix/deal with the a timeout occurring in an async
proxy when an origin server takes too long to reply.
You can reproduce this issue with our asyn example NHttpReverseProxy:
Start it with: http://postman-echo.com 8888
Then run:
curl --verbose --max-time 1000 http://localhost:8888/delay/3
and you will get an EMPTY response from the server, no HTTP status code
where I would expect a 504 or 500.
The proxy prints out:
Reverse proxy to http://postman-echo.com:80
[client->proxy] connection open 127.0.0.1:8888<->127.0.0.1:61128
[client->proxy] 00000001 GET /delay/3 HTTP/1.1
[client->proxy] 00000001 request completed
[proxy->origin] connection open 192.168.0.112:61130<->52.44.234.173:80
[proxy->origin] 00000001 GET /delay/3 HTTP/1.1
[proxy->origin] 00000001 request completed
[client->proxy] connection closed 127.0.0.1:8888<->127.0.0.1:61128
[client<-proxy] 00000001 java.net.SocketTimeoutException
[proxy->origin] connection released 192.168.0.112:61130<->52.44.234.173:80
[proxy->origin] [total kept alive: 0; total allocated: 0 of 100]
[proxy->origin] connection closed 192.168.0.112:61130<->52.44.234.173:80
Curl prints:
* STATE: INIT => CONNECT handle 0x600057930; line 1410 (connection #-5000)
* Added connection 0. The cache now contains 1 members
* STATE: CONNECT => WAITRESOLVE handle 0x600057930; line 1446 (connection
#0)
* Trying ::1...
* TCP_NODELAY set
* STATE: WAITRESOLVE => WAITCONNECT handle 0x600057930; line 1527
(connection #0)
* Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 8888 (#0)
* STATE: WAITCONNECT => SENDPROTOCONNECT handle 0x600057930; line 1579
(connection #0)
* Marked for [keep alive]: HTTP default
* STATE: SENDPROTOCONNECT => DO handle 0x600057930; line 1597 (connection
#0)
> GET /delay/3 HTTP/1.1
> Host: localhost:8888
> User-Agent: curl/7.54.1
> Accept: */*
>
* STATE: DO => DO_DONE handle 0x600057930; line 1676 (connection #0)
* STATE: DO_DONE => WAITPERFORM handle 0x600057930; line 1801 (connection
#0)
* STATE: WAITPERFORM => PERFORM handle 0x600057930; line 1811 (connection
#0)
* STATE: PERFORM => DONE handle 0x600057930; line 1980 (connection #0)
* multi_done
* Empty reply from server
* Connection #0 to host localhost left intact
* Expire cleared
*curl: (52) Empty reply from server*
A bug in the example proxy? In HttpCore? Both? Or something missing in the
implementation of the example async proxy?
Thoughts?
Thank you,
Gary
Re: Core 4 and problem with socket timeout to origin server
Posted by Gary Gregory <ga...@gmail.com>.
I closed this issue, works like a charm.
Gary
On Aug 17, 2017 08:11, "Gary Gregory" <ga...@gmail.com> wrote:
> On Thu, Aug 17, 2017 at 8:00 AM, Oleg Kalnichevski <ol...@apache.org>
> wrote:
>
>> On Wed, 2017-08-16 at 16:37 -0600, Gary Gregory wrote:
>> > Oleg,
>> >
>> > I created a ticket and a branch for
>> > https://issues.apache.org/jira/browse/HTTPCORE-482
>> >
>> > Can you please review/update and merge if OK?
>> >
>> > Thank you,
>> > Gary
>> >
>>
>> Hi Gary
>>
>> The patch looks perfectly reasonable to me. I'll happily merge it for
>> you if you like.
>>
>
> Great! Thank you Oleg. I need this ASAP, so if you can't get to it by EOD,
> I'll go for it.
>
> Gary
>
>
>>
>> Cheers
>>
>> Oleg
>>
>> > On Wed, Aug 16, 2017 at 3:00 PM, Gary Gregory <garydgregory@gmail.com
>> > >
>> > wrote:
>> >
>> > > Hi All (Oleg, really)
>> > >
>> > > I am wondering how to fix/deal with the a timeout occurring in an
>> > > async
>> > > proxy when an origin server takes too long to reply.
>> > >
>> > > You can reproduce this issue with our asyn example
>> > > NHttpReverseProxy:
>> > >
>> > > Start it with: http://postman-echo.com 8888
>> > >
>> > > Then run:
>> > >
>> > > curl --verbose --max-time 1000 http://localhost:8888/delay/3
>> > >
>> > > and you will get an EMPTY response from the server, no HTTP status
>> > > code
>> > > where I would expect a 504 or 500.
>> > >
>> > > The proxy prints out:
>> > >
>> > > Reverse proxy to http://postman-echo.com:80
>> > > [client->proxy] connection open 127.0.0.1:8888<->127.0.0.1:61128
>> > > [client->proxy] 00000001 GET /delay/3 HTTP/1.1
>> > > [client->proxy] 00000001 request completed
>> > > [proxy->origin] connection open 192.168.0.112:61130<-
>> > > >52.44.234.173:80
>> > > [proxy->origin] 00000001 GET /delay/3 HTTP/1.1
>> > > [proxy->origin] 00000001 request completed
>> > > [client->proxy] connection closed 127.0.0.1:8888<->127.0.0.1:61128
>> > > [client<-proxy] 00000001 java.net.SocketTimeoutException
>> > > [proxy->origin] connection released 192.168.0.112:61130<-
>> > > >52.44.234.173:80
>> > > [proxy->origin] [total kept alive: 0; total allocated: 0 of 100]
>> > > [proxy->origin] connection closed 192.168.0.112:61130<-
>> > > >52.44.234.173:80
>> > >
>> > > Curl prints:
>> > >
>> > > * STATE: INIT => CONNECT handle 0x600057930; line 1410 (connection
>> > > #-5000)
>> > > * Added connection 0. The cache now contains 1 members
>> > > * STATE: CONNECT => WAITRESOLVE handle 0x600057930; line 1446
>> > > (connection
>> > > #0)
>> > > * Trying ::1...
>> > > * TCP_NODELAY set
>> > > * STATE: WAITRESOLVE => WAITCONNECT handle 0x600057930; line 1527
>> > > (connection #0)
>> > > * Trying 127.0.0.1...
>> > > * TCP_NODELAY set
>> > > * Connected to localhost (127.0.0.1) port 8888 (#0)
>> > > * STATE: WAITCONNECT => SENDPROTOCONNECT handle 0x600057930; line
>> > > 1579
>> > > (connection #0)
>> > > * Marked for [keep alive]: HTTP default
>> > > * STATE: SENDPROTOCONNECT => DO handle 0x600057930; line 1597
>> > > (connection
>> > > #0)
>> > > > GET /delay/3 HTTP/1.1
>> > > > Host: localhost:8888
>> > > > User-Agent: curl/7.54.1
>> > > > Accept: */*
>> > > >
>> > >
>> > > * STATE: DO => DO_DONE handle 0x600057930; line 1676 (connection
>> > > #0)
>> > > * STATE: DO_DONE => WAITPERFORM handle 0x600057930; line 1801
>> > > (connection
>> > > #0)
>> > > * STATE: WAITPERFORM => PERFORM handle 0x600057930; line 1811
>> > > (connection
>> > > #0)
>> > > * STATE: PERFORM => DONE handle 0x600057930; line 1980 (connection
>> > > #0)
>> > > * multi_done
>> > > * Empty reply from server
>> > > * Connection #0 to host localhost left intact
>> > > * Expire cleared
>> > > *curl: (52) Empty reply from server*
>> > >
>> > > A bug in the example proxy? In HttpCore? Both? Or something missing
>> > > in the
>> > > implementation of the example async proxy?
>> > >
>> > > Thoughts?
>> > >
>> > > Thank you,
>> > > Gary
>> > >
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: dev-unsubscribe@hc.apache.org
>> For additional commands, e-mail: dev-help@hc.apache.org
>>
>>
>
Re: Core 4 and problem with socket timeout to origin server
Posted by Gary Gregory <ga...@gmail.com>.
On Thu, Aug 17, 2017 at 8:00 AM, Oleg Kalnichevski <ol...@apache.org> wrote:
> On Wed, 2017-08-16 at 16:37 -0600, Gary Gregory wrote:
> > Oleg,
> >
> > I created a ticket and a branch for
> > https://issues.apache.org/jira/browse/HTTPCORE-482
> >
> > Can you please review/update and merge if OK?
> >
> > Thank you,
> > Gary
> >
>
> Hi Gary
>
> The patch looks perfectly reasonable to me. I'll happily merge it for
> you if you like.
>
Great! Thank you Oleg. I need this ASAP, so if you can't get to it by EOD,
I'll go for it.
Gary
>
> Cheers
>
> Oleg
>
> > On Wed, Aug 16, 2017 at 3:00 PM, Gary Gregory <garydgregory@gmail.com
> > >
> > wrote:
> >
> > > Hi All (Oleg, really)
> > >
> > > I am wondering how to fix/deal with the a timeout occurring in an
> > > async
> > > proxy when an origin server takes too long to reply.
> > >
> > > You can reproduce this issue with our asyn example
> > > NHttpReverseProxy:
> > >
> > > Start it with: http://postman-echo.com 8888
> > >
> > > Then run:
> > >
> > > curl --verbose --max-time 1000 http://localhost:8888/delay/3
> > >
> > > and you will get an EMPTY response from the server, no HTTP status
> > > code
> > > where I would expect a 504 or 500.
> > >
> > > The proxy prints out:
> > >
> > > Reverse proxy to http://postman-echo.com:80
> > > [client->proxy] connection open 127.0.0.1:8888<->127.0.0.1:61128
> > > [client->proxy] 00000001 GET /delay/3 HTTP/1.1
> > > [client->proxy] 00000001 request completed
> > > [proxy->origin] connection open 192.168.0.112:61130<-
> > > >52.44.234.173:80
> > > [proxy->origin] 00000001 GET /delay/3 HTTP/1.1
> > > [proxy->origin] 00000001 request completed
> > > [client->proxy] connection closed 127.0.0.1:8888<->127.0.0.1:61128
> > > [client<-proxy] 00000001 java.net.SocketTimeoutException
> > > [proxy->origin] connection released 192.168.0.112:61130<-
> > > >52.44.234.173:80
> > > [proxy->origin] [total kept alive: 0; total allocated: 0 of 100]
> > > [proxy->origin] connection closed 192.168.0.112:61130<-
> > > >52.44.234.173:80
> > >
> > > Curl prints:
> > >
> > > * STATE: INIT => CONNECT handle 0x600057930; line 1410 (connection
> > > #-5000)
> > > * Added connection 0. The cache now contains 1 members
> > > * STATE: CONNECT => WAITRESOLVE handle 0x600057930; line 1446
> > > (connection
> > > #0)
> > > * Trying ::1...
> > > * TCP_NODELAY set
> > > * STATE: WAITRESOLVE => WAITCONNECT handle 0x600057930; line 1527
> > > (connection #0)
> > > * Trying 127.0.0.1...
> > > * TCP_NODELAY set
> > > * Connected to localhost (127.0.0.1) port 8888 (#0)
> > > * STATE: WAITCONNECT => SENDPROTOCONNECT handle 0x600057930; line
> > > 1579
> > > (connection #0)
> > > * Marked for [keep alive]: HTTP default
> > > * STATE: SENDPROTOCONNECT => DO handle 0x600057930; line 1597
> > > (connection
> > > #0)
> > > > GET /delay/3 HTTP/1.1
> > > > Host: localhost:8888
> > > > User-Agent: curl/7.54.1
> > > > Accept: */*
> > > >
> > >
> > > * STATE: DO => DO_DONE handle 0x600057930; line 1676 (connection
> > > #0)
> > > * STATE: DO_DONE => WAITPERFORM handle 0x600057930; line 1801
> > > (connection
> > > #0)
> > > * STATE: WAITPERFORM => PERFORM handle 0x600057930; line 1811
> > > (connection
> > > #0)
> > > * STATE: PERFORM => DONE handle 0x600057930; line 1980 (connection
> > > #0)
> > > * multi_done
> > > * Empty reply from server
> > > * Connection #0 to host localhost left intact
> > > * Expire cleared
> > > *curl: (52) Empty reply from server*
> > >
> > > A bug in the example proxy? In HttpCore? Both? Or something missing
> > > in the
> > > implementation of the example async proxy?
> > >
> > > Thoughts?
> > >
> > > Thank you,
> > > Gary
> > >
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@hc.apache.org
> For additional commands, e-mail: dev-help@hc.apache.org
>
>
Re: Core 4 and problem with socket timeout to origin server
Posted by Oleg Kalnichevski <ol...@apache.org>.
On Wed, 2017-08-16 at 16:37 -0600, Gary Gregory wrote:
> Oleg,
>
> I created a ticket and a branch for
> https://issues.apache.org/jira/browse/HTTPCORE-482
>
> Can you please review/update and merge if OK?
>
> Thank you,
> Gary
>
Hi Gary
The patch looks perfectly reasonable to me. I'll happily merge it for
you if you like.
Cheers
Oleg
> On Wed, Aug 16, 2017 at 3:00 PM, Gary Gregory <garydgregory@gmail.com
> >
> wrote:
>
> > Hi All (Oleg, really)
> >
> > I am wondering how to fix/deal with the a timeout occurring in an
> > async
> > proxy when an origin server takes too long to reply.
> >
> > You can reproduce this issue with our asyn example
> > NHttpReverseProxy:
> >
> > Start it with: http://postman-echo.com 8888
> >
> > Then run:
> >
> > curl --verbose --max-time 1000 http://localhost:8888/delay/3
> >
> > and you will get an EMPTY response from the server, no HTTP status
> > code
> > where I would expect a 504 or 500.
> >
> > The proxy prints out:
> >
> > Reverse proxy to http://postman-echo.com:80
> > [client->proxy] connection open 127.0.0.1:8888<->127.0.0.1:61128
> > [client->proxy] 00000001 GET /delay/3 HTTP/1.1
> > [client->proxy] 00000001 request completed
> > [proxy->origin] connection open 192.168.0.112:61130<-
> > >52.44.234.173:80
> > [proxy->origin] 00000001 GET /delay/3 HTTP/1.1
> > [proxy->origin] 00000001 request completed
> > [client->proxy] connection closed 127.0.0.1:8888<->127.0.0.1:61128
> > [client<-proxy] 00000001 java.net.SocketTimeoutException
> > [proxy->origin] connection released 192.168.0.112:61130<-
> > >52.44.234.173:80
> > [proxy->origin] [total kept alive: 0; total allocated: 0 of 100]
> > [proxy->origin] connection closed 192.168.0.112:61130<-
> > >52.44.234.173:80
> >
> > Curl prints:
> >
> > * STATE: INIT => CONNECT handle 0x600057930; line 1410 (connection
> > #-5000)
> > * Added connection 0. The cache now contains 1 members
> > * STATE: CONNECT => WAITRESOLVE handle 0x600057930; line 1446
> > (connection
> > #0)
> > * Trying ::1...
> > * TCP_NODELAY set
> > * STATE: WAITRESOLVE => WAITCONNECT handle 0x600057930; line 1527
> > (connection #0)
> > * Trying 127.0.0.1...
> > * TCP_NODELAY set
> > * Connected to localhost (127.0.0.1) port 8888 (#0)
> > * STATE: WAITCONNECT => SENDPROTOCONNECT handle 0x600057930; line
> > 1579
> > (connection #0)
> > * Marked for [keep alive]: HTTP default
> > * STATE: SENDPROTOCONNECT => DO handle 0x600057930; line 1597
> > (connection
> > #0)
> > > GET /delay/3 HTTP/1.1
> > > Host: localhost:8888
> > > User-Agent: curl/7.54.1
> > > Accept: */*
> > >
> >
> > * STATE: DO => DO_DONE handle 0x600057930; line 1676 (connection
> > #0)
> > * STATE: DO_DONE => WAITPERFORM handle 0x600057930; line 1801
> > (connection
> > #0)
> > * STATE: WAITPERFORM => PERFORM handle 0x600057930; line 1811
> > (connection
> > #0)
> > * STATE: PERFORM => DONE handle 0x600057930; line 1980 (connection
> > #0)
> > * multi_done
> > * Empty reply from server
> > * Connection #0 to host localhost left intact
> > * Expire cleared
> > *curl: (52) Empty reply from server*
> >
> > A bug in the example proxy? In HttpCore? Both? Or something missing
> > in the
> > implementation of the example async proxy?
> >
> > Thoughts?
> >
> > Thank you,
> > Gary
> >
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@hc.apache.org
For additional commands, e-mail: dev-help@hc.apache.org
Re: Core 4 and problem with socket timeout to origin server
Posted by Gary Gregory <ga...@gmail.com>.
Oleg,
I created a ticket and a branch for
https://issues.apache.org/jira/browse/HTTPCORE-482
Can you please review/update and merge if OK?
Thank you,
Gary
On Wed, Aug 16, 2017 at 3:00 PM, Gary Gregory <ga...@gmail.com>
wrote:
> Hi All (Oleg, really)
>
> I am wondering how to fix/deal with the a timeout occurring in an async
> proxy when an origin server takes too long to reply.
>
> You can reproduce this issue with our asyn example NHttpReverseProxy:
>
> Start it with: http://postman-echo.com 8888
>
> Then run:
>
> curl --verbose --max-time 1000 http://localhost:8888/delay/3
>
> and you will get an EMPTY response from the server, no HTTP status code
> where I would expect a 504 or 500.
>
> The proxy prints out:
>
> Reverse proxy to http://postman-echo.com:80
> [client->proxy] connection open 127.0.0.1:8888<->127.0.0.1:61128
> [client->proxy] 00000001 GET /delay/3 HTTP/1.1
> [client->proxy] 00000001 request completed
> [proxy->origin] connection open 192.168.0.112:61130<->52.44.234.173:80
> [proxy->origin] 00000001 GET /delay/3 HTTP/1.1
> [proxy->origin] 00000001 request completed
> [client->proxy] connection closed 127.0.0.1:8888<->127.0.0.1:61128
> [client<-proxy] 00000001 java.net.SocketTimeoutException
> [proxy->origin] connection released 192.168.0.112:61130<->52.44.234.173:80
> [proxy->origin] [total kept alive: 0; total allocated: 0 of 100]
> [proxy->origin] connection closed 192.168.0.112:61130<->52.44.234.173:80
>
> Curl prints:
>
> * STATE: INIT => CONNECT handle 0x600057930; line 1410 (connection #-5000)
> * Added connection 0. The cache now contains 1 members
> * STATE: CONNECT => WAITRESOLVE handle 0x600057930; line 1446 (connection
> #0)
> * Trying ::1...
> * TCP_NODELAY set
> * STATE: WAITRESOLVE => WAITCONNECT handle 0x600057930; line 1527
> (connection #0)
> * Trying 127.0.0.1...
> * TCP_NODELAY set
> * Connected to localhost (127.0.0.1) port 8888 (#0)
> * STATE: WAITCONNECT => SENDPROTOCONNECT handle 0x600057930; line 1579
> (connection #0)
> * Marked for [keep alive]: HTTP default
> * STATE: SENDPROTOCONNECT => DO handle 0x600057930; line 1597 (connection
> #0)
> > GET /delay/3 HTTP/1.1
> > Host: localhost:8888
> > User-Agent: curl/7.54.1
> > Accept: */*
> >
> * STATE: DO => DO_DONE handle 0x600057930; line 1676 (connection #0)
> * STATE: DO_DONE => WAITPERFORM handle 0x600057930; line 1801 (connection
> #0)
> * STATE: WAITPERFORM => PERFORM handle 0x600057930; line 1811 (connection
> #0)
> * STATE: PERFORM => DONE handle 0x600057930; line 1980 (connection #0)
> * multi_done
> * Empty reply from server
> * Connection #0 to host localhost left intact
> * Expire cleared
> *curl: (52) Empty reply from server*
>
> A bug in the example proxy? In HttpCore? Both? Or something missing in the
> implementation of the example async proxy?
>
> Thoughts?
>
> Thank you,
> Gary
>