You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@synapse.apache.org by Ra...@spb.de on 2009/09/02 15:09:08 UTC

Connection timeout problem

Hi,

I'm trying to run a pre-1.3 nightly build version of Synapse.
Unfortunately I'm getting lots of connection timeout messages in the logs:

ERROR [org.apache.synapse.transport.nhttp.ServerHandler] Connection 
Timeout - before message body was fully read : [/127.0.0.18:56740]

Web service clients are getting a HTTP 502 error with about 10 % 
frequency.
I tried increasing http.connection.timeout and http.socket.timeout but 
that did not change the behaviour.

The released version Synapse 1.2 is no option for me, because the issue 
SYNAPSE-404 freezes the entire ESB and forces a restart about 3 times per 
day, which is not feasible for productive use. But using Synapse 1.2 does 
not show the timeout messages and runs with no HTTP 502 errors (as long as 
it hasn't run into SYNAPSE-404).

What causes the connection timeouts and how can I prevent them?
BTW I'm desperately awaiting the release of 1.3 as there are 8 critical 
fixes (and 1 blocker) since 1.2 that have not gone into a release yet.

Thanks for your help.

Kind regards,

Ralph Henze.

Re: Antwort: Re: Antwort: Re: Antwort: Re: Connection timeout problem

Posted by "Asankha C. Perera" <as...@apache.org>.
Hi Ralph / Supun
> For future versions of Synapse it would be desirable that synapse gets the ability to respond with "100 Continue" responses. This would prevent interoperability issues with older .net clients like this.
>
> Asankha provided us with a quick fix; perhaps it would be possible that his fix flows into the Synapse trunk?
>   
I've committed the fix against SYNAPSE-231

cheers
asankha

-- 
Asankha C. Perera
AdroitLogic, http://adroitlogic.org

http://esbmagic.blogspot.com





Antwort: Re: Antwort: Re: Antwort: Re: Connection timeout problem

Posted by Ra...@spb.de.
Hi Suprun,

yes, we have a solution for this.

Our analysis showed that the timeouts were due to a misbehaviour of our 
.net service client.
The client is sending a "100-continue" HTTP header and waits infinitely 
for a "100 Continue" response before sending the request body, resulting 
in timeouts.
This behaviour is not according to HTTP 1.1 spec, though.

Synapse by now is not responding to 100-continue headers and waits for the 
client to send the request body (according to HTTP 1.1).

For future versions of Synapse it would be desirable that synapse gets the 
ability to respond with "100 Continue" responses.
This would prevent interoperability issues with older .net clients like 
this.

Asankha provided us with a quick fix; perhaps it would be possible that 
his fix flows into the Synapse trunk?

Thank you and cheers!

i. A. Ralph Henze
Dipl.-Informatiker (Univ.)
Sparda-Datenverarbeitung eG
AE-ABS/Softwarearchitektur


Supun Kamburugamuva <su...@gmail.com> schrieb am 26.10.2009 05:04:58:

> [Bild entfernt] 
> 
> Re: Antwort: Re: Antwort: Re: Connection timeout problem
> 
> Supun Kamburugamuva 
> 
> an:
> 
> user
> 
> 26.10.2009 05:05
> 
> [Bild entfernt] 
> 
> Von:
> 
> Supun Kamburugamuva <su...@gmail.com>
> 
> An:
> 
> user@synapse.apache.org
> 
> Bitte Antwort an user@synapse.apache.org
> 
> Hi Ralph,
> 
> Did you get a solution to this problem?
> 
> Thanks,
> Supun..
> 
> On Thu, Sep 3, 2009 at 1:13 AM, Asankha C. Perera 
<as...@apache.org>wrote:
> 
> > Hi Ralph
> > > The GET /soap/ requests are those issued by the monitoring system. 
The
> > > monitoring assumes that the esb is available if the list of services 
is
> > > retrieved or there is a problem/outage otherwise.
> > >
> > Typically it would be better to issue a real call through Synapse 
itself
> > for monitoring purposes. I think Eric might be able to tell you more
> > about the monitoring etc they do in their deployment environment.
> > > In our infrastructure there is an Apache HTTP server that is placed 
in
> > > front of synapse, so that the tcp connection client from synapse's
> > > perspective is always the HTTP server. The HTTP server terminates 
SSL
> > > connections and connects to synapse via mod_proxy. Do you presume 
that a
> > > possible solution lies in HTTP server configuration?
> > >
> > >
> > >> It seems like you issue a GET /soap/ request? I also saw many of 
those..
> > >> what is the purpose of issuing that? Anyway.. this seems like a 
harmless
> > >> possible bug - where the connection gets timedout - but Synapse 
thinks
> > >> its response was not fully read by the client. This could happen if 
the
> > >> client just looks at the header of the response, and does not read 
the
> > >> entity body - which will prevent the HTTP connection from being 
re-used
> > >> again (i.e. as a keepalive) - however, I also suspect a slight bug 
in
> > >> the code where this message could be dumped in a harmless case. Do 
you
> > >> see an actual error at the client side?
> > >>
> > >
> > > Yes, there is an effect at the service client side. About 10 percent 
of
> > > client requests are responded with HTTP error code 502.
> > Synapse does not return 502.. so this is returned by Apache.. but the
> > reason behind would need some investigation.. If you could re-create
> > this with a single request and get me a tcpdump it would be great
> > >  I'm not sure of
> > > how that behaviour relates to the timeout message, because there are 
a
> > lot
> > > more timeout messages in the log than actual client errors. But we 
didn't
> > > have that when we were on synapse 1.2. But as stated earlier, 
synapse 1.2
> > > freezed up to 3 times a day and had to be restarted, which we assume 
is a
> > > consequence of bug SYNAPSE-404.
> > >
> > > Are you planning to prepare a fix?
> > >
> > Yes, I could fix the issue I suspect - but that would not solve the 
502
> > issue.. what I noticed is that Synapse may report the "Connection
> > Timeout - before message body was fully read " message when the remote
> > party (i.e. client to synapse) terminated its socket - since that was
> > what was happening in your logs
> >
> > cheers
> > asankha
> >
> > --
> > Asankha C. Perera
> > AdroitLogic, http://adroitlogic.org
> >
> > http://esbmagic.blogspot.com
> >
> >
> >
> >
> >
> 
> 
> -- 
> Software Engineer, WSO2 Inc
> http://wso2.org
> supunk.blogspot.com
> 

Re: Antwort: Re: Antwort: Re: Connection timeout problem

Posted by Supun Kamburugamuva <su...@gmail.com>.
Hi Ralph,

Did you get a solution to this problem?

Thanks,
Supun..

On Thu, Sep 3, 2009 at 1:13 AM, Asankha C. Perera <as...@apache.org>wrote:

> Hi Ralph
> > The GET /soap/ requests are those issued by the monitoring system. The
> > monitoring assumes that the esb is available if the list of services is
> > retrieved or there is a problem/outage otherwise.
> >
> Typically it would be better to issue a real call through Synapse itself
> for monitoring purposes. I think Eric might be able to tell you more
> about the monitoring etc they do in their deployment environment.
> > In our infrastructure there is an Apache HTTP server that is placed in
> > front of synapse, so that the tcp connection client from synapse's
> > perspective is always the HTTP server. The HTTP server terminates SSL
> > connections and connects to synapse via mod_proxy. Do you presume that a
> > possible solution lies in HTTP server configuration?
> >
> >
> >> It seems like you issue a GET /soap/ request? I also saw many of those..
> >> what is the purpose of issuing that? Anyway.. this seems like a harmless
> >> possible bug - where the connection gets timedout - but Synapse thinks
> >> its response was not fully read by the client. This could happen if the
> >> client just looks at the header of the response, and does not read the
> >> entity body - which will prevent the HTTP connection from being re-used
> >> again (i.e. as a keepalive) - however, I also suspect a slight bug in
> >> the code where this message could be dumped in a harmless case. Do you
> >> see an actual error at the client side?
> >>
> >
> > Yes, there is an effect at the service client side. About 10 percent of
> > client requests are responded with HTTP error code 502.
> Synapse does not return 502.. so this is returned by Apache.. but the
> reason behind would need some investigation.. If you could re-create
> this with a single request and get me a tcpdump it would be great
> >  I'm not sure of
> > how that behaviour relates to the timeout message, because there are a
> lot
> > more timeout messages in the log than actual client errors. But we didn't
> > have that when we were on synapse 1.2. But as stated earlier, synapse 1.2
> > freezed up to 3 times a day and had to be restarted, which we assume is a
> > consequence of bug SYNAPSE-404.
> >
> > Are you planning to prepare a fix?
> >
> Yes, I could fix the issue I suspect - but that would not solve the 502
> issue.. what I noticed is that Synapse may report the "Connection
> Timeout - before message body was fully read " message when the remote
> party (i.e. client to synapse) terminated its socket - since that was
> what was happening in your logs
>
> cheers
> asankha
>
> --
> Asankha C. Perera
> AdroitLogic, http://adroitlogic.org
>
> http://esbmagic.blogspot.com
>
>
>
>
>


-- 
Software Engineer, WSO2 Inc
http://wso2.org
supunk.blogspot.com

Re: Antwort: Re: Antwort: Re: Connection timeout problem

Posted by "Asankha C. Perera" <as...@apache.org>.
Hi Ralph
> The GET /soap/ requests are those issued by the monitoring system. The 
> monitoring assumes that the esb is available if the list of services is 
> retrieved or there is a problem/outage otherwise.
>   
Typically it would be better to issue a real call through Synapse itself
for monitoring purposes. I think Eric might be able to tell you more
about the monitoring etc they do in their deployment environment.
> In our infrastructure there is an Apache HTTP server that is placed in 
> front of synapse, so that the tcp connection client from synapse's 
> perspective is always the HTTP server. The HTTP server terminates SSL 
> connections and connects to synapse via mod_proxy. Do you presume that a 
> possible solution lies in HTTP server configuration?
>
>   
>> It seems like you issue a GET /soap/ request? I also saw many of those..
>> what is the purpose of issuing that? Anyway.. this seems like a harmless
>> possible bug - where the connection gets timedout - but Synapse thinks
>> its response was not fully read by the client. This could happen if the
>> client just looks at the header of the response, and does not read the
>> entity body - which will prevent the HTTP connection from being re-used
>> again (i.e. as a keepalive) - however, I also suspect a slight bug in
>> the code where this message could be dumped in a harmless case. Do you
>> see an actual error at the client side?
>>     
>
> Yes, there is an effect at the service client side. About 10 percent of 
> client requests are responded with HTTP error code 502.
Synapse does not return 502.. so this is returned by Apache.. but the
reason behind would need some investigation.. If you could re-create
this with a single request and get me a tcpdump it would be great
>  I'm not sure of 
> how that behaviour relates to the timeout message, because there are a lot 
> more timeout messages in the log than actual client errors. But we didn't 
> have that when we were on synapse 1.2. But as stated earlier, synapse 1.2 
> freezed up to 3 times a day and had to be restarted, which we assume is a 
> consequence of bug SYNAPSE-404.
>
> Are you planning to prepare a fix?
>   
Yes, I could fix the issue I suspect - but that would not solve the 502
issue.. what I noticed is that Synapse may report the "Connection
Timeout - before message body was fully read " message when the remote
party (i.e. client to synapse) terminated its socket - since that was
what was happening in your logs

cheers
asankha

-- 
Asankha C. Perera
AdroitLogic, http://adroitlogic.org

http://esbmagic.blogspot.com





Antwort: Re: Antwort: Re: Connection timeout problem

Posted by Ra...@spb.de.
Hi Asankha,

thank you for your analysis.

The GET /soap/ requests are those issued by the monitoring system. The 
monitoring assumes that the esb is available if the list of services is 
retrieved or there is a problem/outage otherwise.

In our infrastructure there is an Apache HTTP server that is placed in 
front of synapse, so that the tcp connection client from synapse's 
perspective is always the HTTP server. The HTTP server terminates SSL 
connections and connects to synapse via mod_proxy. Do you presume that a 
possible solution lies in HTTP server configuration?

> It seems like you issue a GET /soap/ request? I also saw many of those..
> what is the purpose of issuing that? Anyway.. this seems like a harmless
> possible bug - where the connection gets timedout - but Synapse thinks
> its response was not fully read by the client. This could happen if the
> client just looks at the header of the response, and does not read the
> entity body - which will prevent the HTTP connection from being re-used
> again (i.e. as a keepalive) - however, I also suspect a slight bug in
> the code where this message could be dumped in a harmless case. Do you
> see an actual error at the client side?

Yes, there is an effect at the service client side. About 10 percent of 
client requests are responded with HTTP error code 502. I'm not sure of 
how that behaviour relates to the timeout message, because there are a lot 
more timeout messages in the log than actual client errors. But we didn't 
have that when we were on synapse 1.2. But as stated earlier, synapse 1.2 
freezed up to 3 times a day and had to be restarted, which we assume is a 
consequence of bug SYNAPSE-404.

Are you planning to prepare a fix?

Thanks again.

Cheers, Ralph.

Re: Antwort: Re: Connection timeout problem

Posted by "Asankha C. Perera" <as...@apache.org>.
Hi Ralph
> I attached the server log file.
> I asked my administrator to create a tcp trace and will forward it as
> soon as I get it.
Here is a filtered snippet of the log:
2009-09-02 16:59:32,307 DEBUG
[org.apache.synapse.transport.nhttp.ServerHandler] HTTP connection
[/127.0.0.18:46523]: GET /soap/ HTTP/1.1
2009-09-02 16:59:32,310 DEBUG
[org.apache.synapse.transport.nhttp.ServerHandler] HTTP connection
[/127.0.0.18:46523]: Output ready
2009-09-02 16:59:32,311 DEBUG
[org.apache.synapse.transport.nhttp.ServerHandler] HTTP connection
[/127.0.0.18:46523]: Content encoder [chunk-coded; completed: false]
.....
2009-09-02 16:59:32,313 DEBUG
[org.apache.synapse.transport.nhttp.ServerHandler] HTTP connection
[/127.0.0.18:46523]: Content encoder [chunk-coded; completed: true]
2009-09-02 16:59:32,313 DEBUG
[org.apache.synapse.transport.nhttp.ServerHandler] HTTP connection
[/127.0.0.18:46523]: Response ready
2009-09-02 17:01:33,278 DEBUG
[org.apache.synapse.transport.nhttp.ServerHandler] HTTP connection
[/127.0.0.18:46523]: Timeout

It seems like you issue a GET /soap/ request? I also saw many of those..
what is the purpose of issuing that? Anyway.. this seems like a harmless
possible bug - where the connection gets timedout - but Synapse thinks
its response was not fully read by the client. This could happen if the
client just looks at the header of the response, and does not read the
entity body - which will prevent the HTTP connection from being re-used
again (i.e. as a keepalive) - however, I also suspect a slight bug in
the code where this message could be dumped in a harmless case. Do you
see an actual error at the client side?

cheers
asankha

-- 
Asankha C. Perera
AdroitLogic, http://adroitlogic.org

http://esbmagic.blogspot.com





Antwort: Re: Connection timeout problem

Posted by Ra...@spb.de.
Hello Asanka,

thank you for your quick response.

I attached the server log file. 
I asked my administrator to create a tcp trace and will forward it as soon 
as I get it.



Cheers 
Ralph.

Asankha Perera <as...@gmail.com> schrieb am 02.09.2009 16:04:18:

> [Bild entfernt] 
> 
> Re: Connection timeout problem
> 
> Asankha C. Perera 
> 
> an:
> 
> user
> 
> 02.09.2009 16:05
> 
> Gesendet von:
> 
> Asankha Perera <as...@gmail.com>
> 
> Bitte Antwort an user
> 
> Hi Ralph
> > I'm trying to run a pre-1.3 nightly build version of Synapse.
> > Unfortunately I'm getting lots of connection timeout messages in the 
logs:
> >
> > ERROR [org.apache.synapse.transport.nhttp.ServerHandler] Connection 
> > Timeout - before message body was fully read : [/127.0.0.18:56740]
> >
> > Web service clients are getting a HTTP 502 error with about 10 % 
> > frequency.
> > I tried increasing http.connection.timeout and http.socket.timeout but 

> > that did not change the behaviour.
> > 
> Can you set the following on the lib/log4j.properties and send me a
> zipped trace
> 
> log4j.category.org.apache.synapse=DEBUG
> ..
> log4j.category.org.apache.synapse.transport.nhttp.util=DEBUG
> log4j.category.org.apache.http.impl.nio.reactor=DEBUG
> > The released version Synapse 1.2 is no option for me, because the 
issue 
> > SYNAPSE-404 freezes the entire ESB and forces a restart about 3 times 
per 
> > day, which is not feasible for productive use. But using Synapse 1.2 
does 
> > not show the timeout messages and runs with no HTTP 502 errors (as 
long as 
> > it hasn't run into SYNAPSE-404).
> >
> > What causes the connection timeouts and how can I prevent them?
> > 
> If possible, get a wireshark, tcpdump trace of the messages too and send 
me
> 
> cheers
> asankha
> 
> -- 
> Asankha C. Perera
> AdroitLogic, http://adroitlogic.org
> 
> http://esbmagic.blogspot.com
> 
> 
> 
> 

Re: Connection timeout problem

Posted by "Asankha C. Perera" <as...@apache.org>.
Hi Ralph
> I'm trying to run a pre-1.3 nightly build version of Synapse.
> Unfortunately I'm getting lots of connection timeout messages in the logs:
>
> ERROR [org.apache.synapse.transport.nhttp.ServerHandler] Connection 
> Timeout - before message body was fully read : [/127.0.0.18:56740]
>
> Web service clients are getting a HTTP 502 error with about 10 % 
> frequency.
> I tried increasing http.connection.timeout and http.socket.timeout but 
> that did not change the behaviour.
>   
Can you set the following on the lib/log4j.properties and send me a
zipped trace

log4j.category.org.apache.synapse=DEBUG
..
log4j.category.org.apache.synapse.transport.nhttp.util=DEBUG
log4j.category.org.apache.http.impl.nio.reactor=DEBUG
> The released version Synapse 1.2 is no option for me, because the issue 
> SYNAPSE-404 freezes the entire ESB and forces a restart about 3 times per 
> day, which is not feasible for productive use. But using Synapse 1.2 does 
> not show the timeout messages and runs with no HTTP 502 errors (as long as 
> it hasn't run into SYNAPSE-404).
>
> What causes the connection timeouts and how can I prevent them?
>   
If possible, get a wireshark, tcpdump trace of the messages too and send me

cheers
asankha

-- 
Asankha C. Perera
AdroitLogic, http://adroitlogic.org

http://esbmagic.blogspot.com