Login | Register For Free | Help
Search for: (Advanced)

Mailing List Archive: Apache: Users

How to debug 70014 and 70007 errors

 

 

Apache users RSS feed   Index | Next | Previous | View Threaded


gouin.ivan at gmail

Jul 25, 2012, 12:52 AM

Post #1 of 10 (1541 views)
Permalink
How to debug 70014 and 70007 errors

Hi,

I've got those error in my httpd error log:

[Wed Jul 25 08:10:55 2012] [error] (70014)End of file found: proxy:
prefetch request body failed to *.*.*.*:50300 (...) from ..... ()
[Wed Jul 25 00:13:18 2012] [error] (70007)The timeout specified has
expired: proxy: prefetch request body failed to to *.*.*.*:50300 (...)
from ..... ()

Those error occurs with client accessing a tomcat WS through mod_proxy .

Not all the requests are rejected for today, 416 out of 2194 got one of
these errors.

don't really know how to proceed to debug this error.
thanks for your help

--
*Ivan **
*


rainer.jung at kippdata

Jul 25, 2012, 2:02 AM

Post #2 of 10 (1516 views)
Permalink
Re: How to debug 70014 and 70007 errors [In reply to]

On 25.07.2012 09:52, ivan Gouin wrote:
> Hi,
>
> I've got those error in my httpd error log:
>
> [Wed Jul 25 08:10:55 2012] [error] (70014)End of file found: proxy:
> prefetch request body failed to *.*.*.*:50300 (...) from ..... ()
> [Wed Jul 25 00:13:18 2012] [error] (70007)The timeout specified has
> expired: proxy: prefetch request body failed to to *.*.*.*:50300 (...)
> from ..... ()

Maybe the Timeout has expired?

> Those error occurs with client accessing a tomcat WS through mod_proxy .
>
> Not all the requests are rejected for today, 416 out of 2194 got one of
> these errors.
>
> don't really know how to proceed to debug this error.
> thanks for your help

Add %D to your Tomcat and Apache Access Logs. It is the response time in
milloiseconds (Tomcat) resp. microseconds (Apache). If the number is
e.g. slightly above 60000000 for Apache and you had set a timeout of 60
seconds, then you know the problem is that the response takes to long.
You can then check Tomcats Access Log to see how long it actually took.
If it really takes to long in Tomcat, then take thread dumps to analyze
and switch to the Tomcat users mailing list.

HTH.

Rainer


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


gouin.ivan at gmail

Jul 25, 2012, 2:29 AM

Post #3 of 10 (1518 views)
Permalink
Re: How to debug 70014 and 70007 errors [In reply to]

Hi rainer,
For case 70007, the timeout expired, in access log , i've got a 300 second
timeout
In the same time, tomcat's access log haven't any trace of the
corresponding request.

For these request, response time is about 30-100ms

Apache is Apache/2.2.17
Tomcat is 6.0.26 (jdk1.6.0_24)

I'm preparing a tcpdump on each side to see if i can see something received
by tomcat .

Ivan


On 25 July 2012 11:02, Rainer Jung <rainer.jung [at] kippdata> wrote:

> On 25.07.2012 09:52, ivan Gouin wrote:
>
>> Hi,
>>
>> I've got those error in my httpd error log:
>>
>> [Wed Jul 25 08:10:55 2012] [error] (70014)End of file found: proxy:
>> prefetch request body failed to *.*.*.*:50300 (...) from ..... ()
>> [Wed Jul 25 00:13:18 2012] [error] (70007)The timeout specified has
>> expired: proxy: prefetch request body failed to to *.*.*.*:50300 (...)
>> from ..... ()
>>
>
> Maybe the Timeout has expired?
>
>
> Those error occurs with client accessing a tomcat WS through mod_proxy .
>>
>> Not all the requests are rejected for today, 416 out of 2194 got one of
>> these errors.
>>
>> don't really know how to proceed to debug this error.
>> thanks for your help
>>
>
> Add %D to your Tomcat and Apache Access Logs. It is the response time in
> milloiseconds (Tomcat) resp. microseconds (Apache). If the number is e.g.
> slightly above 60000000 for Apache and you had set a timeout of 60 seconds,
> then you know the problem is that the response takes to long. You can then
> check Tomcats Access Log to see how long it actually took. If it really
> takes to long in Tomcat, then take thread dumps to analyze and switch to
> the Tomcat users mailing list.
>
> HTH.
>
> Rainer
>
>
> ------------------------------**------------------------------**---------
> To unsubscribe, e-mail: users-unsubscribe [at] httpd**apache.org<users-unsubscribe [at] httpd>
> For additional commands, e-mail: users-help [at] httpd
>
>


--
*Ivan GOUIN**
*

***Mob (Suisse**)* : +41 (0)79 941 07 90

*Mail* : gouin.ivan [at] gmail


gouin.ivan at gmail

Jul 30, 2012, 7:37 AM

Post #4 of 10 (1496 views)
Permalink
Re: How to debug 70014 and 70007 errors [In reply to]

Hi,
Got some Tcpdump !
What i can see is that everytime when we got the issue, our httpd server
got an RST from the tomcat server.
Does someone have a clue on what's happening?

104 15:17:51.887648 X.X.X.X X.X.X.X TCP 551 50300 > 45371 [PSH, ACK]
Seq=459 Ack=1518 Win=49232 Len=485 TSval=702118294 TSecr=3875125094
105 15:17:51.927192 X.X.X.X X.X.X.X TCP 66 45371 > 50300 [ACK] Seq=1518
Ack=944 Win=16768 Len=0 TSval=3875125141 TSecr=702118294
106 15:17:57.705063 X.X.X.X X.X.X.X TCP 66 45349 > 50300 [FIN, ACK]
Seq=1 Ack=1 Win=152 Len=0 TSval=3875130918 TSecr=701960866
107 15:17:57.705128 X.X.X.X X.X.X.X TCP 74 45372 > 50300 [SYN] Seq=0
Win=14600 Len=0 MSS=1460 SACK_PERM=1 TSval=3875130918 TSecr=0 WS=128
*108 15:17:57.705236 X.X.X.X X.X.X.X TCP 60 50300 > 45349 [RST] Seq=1
Win=0 Len=0*
109 15:17:57.705314 X.X.X.X X.X.X.X TCP 78 50300 > 45372 [SYN, ACK]
Seq=0 Ack=1 Win=49232 Len=0 TSval=702118876 TSecr=3875130918 MSS=1460 WS=1
SACK_PERM=1



On 25 July 2012 11:29, ivan Gouin <gouin.ivan [at] gmail> wrote:

> Hi rainer,
> For case 70007, the timeout expired, in access log , i've got a 300
> second timeout
> In the same time, tomcat's access log haven't any trace of the
> corresponding request.
>
> For these request, response time is about 30-100ms
>
> Apache is Apache/2.2.17
> Tomcat is 6.0.26 (jdk1.6.0_24)
>
> I'm preparing a tcpdump on each side to see if i can see something
> received by tomcat .
>
> Ivan
>
>
> On 25 July 2012 11:02, Rainer Jung <rainer.jung [at] kippdata> wrote:
>
>> On 25.07.2012 09:52, ivan Gouin wrote:
>>
>>> Hi,
>>>
>>> I've got those error in my httpd error log:
>>>
>>> [Wed Jul 25 08:10:55 2012] [error] (70014)End of file found: proxy:
>>> prefetch request body failed to *.*.*.*:50300 (...) from ..... ()
>>> [Wed Jul 25 00:13:18 2012] [error] (70007)The timeout specified has
>>> expired: proxy: prefetch request body failed to to *.*.*.*:50300 (...)
>>> from ..... ()
>>>
>>
>> Maybe the Timeout has expired?
>>
>>
>> Those error occurs with client accessing a tomcat WS through mod_proxy .
>>>
>>> Not all the requests are rejected for today, 416 out of 2194 got one of
>>> these errors.
>>>
>>> don't really know how to proceed to debug this error.
>>> thanks for your help
>>>
>>
>> Add %D to your Tomcat and Apache Access Logs. It is the response time in
>> milloiseconds (Tomcat) resp. microseconds (Apache). If the number is e.g.
>> slightly above 60000000 for Apache and you had set a timeout of 60 seconds,
>> then you know the problem is that the response takes to long. You can then
>> check Tomcats Access Log to see how long it actually took. If it really
>> takes to long in Tomcat, then take thread dumps to analyze and switch to
>> the Tomcat users mailing list.
>>
>> HTH.
>>
>> Rainer
>>
>>
>> ------------------------------**------------------------------**---------
>> To unsubscribe, e-mail: users-unsubscribe [at] httpd**apache.org<users-unsubscribe [at] httpd>
>> For additional commands, e-mail: users-help [at] httpd
>>
>>
>
>
> --
> *Ivan GOUIN**
> *
>
> ***Mob (Suisse**)* : +41 (0)79 941 07 90
>
> *Mail* : gouin.ivan [at] gmail
>
>


--
*Ivan GOUIN**
*

***Mob (Suisse**)* : +41 (0)79 941 07 90

*Mail* : gouin.ivan [at] gmail


gouin.ivan at gmail

Aug 3, 2012, 8:23 AM

Post #5 of 10 (1450 views)
Permalink
Re: How to debug 70014 and 70007 errors [In reply to]

Here's what i see on the tcpdump:

Got a TCP connect 3-way handshake. (SYN/SYN-ACK/ACK)
Got 7 POST request who got a return code 200

After the 7 POST, got a [ FIN, ACK] from th server.
Then RST from the server

Then the 8th request who goes in time out

Is there some kind of timeout in a tcp keep alive?

Ivan




On 25 July 2012 11:29, ivan Gouin <gouin.ivan [at] gmail> wrote:

> Hi rainer,
> For case 70007, the timeout expired, in access log , i've got a 300
> second timeout
> In the same time, tomcat's access log haven't any trace of the
> corresponding request.
>
> For these request, response time is about 30-100ms
>
> Apache is Apache/2.2.17
> Tomcat is 6.0.26 (jdk1.6.0_24)
>
> I'm preparing a tcpdump on each side to see if i can see something
> received by tomcat .
>
> Ivan
>
>
> On 25 July 2012 11:02, Rainer Jung <rainer.jung [at] kippdata> wrote:
>
>> On 25.07.2012 09:52, ivan Gouin wrote:
>>
>>> Hi,
>>>
>>> I've got those error in my httpd error log:
>>>
>>> [Wed Jul 25 08:10:55 2012] [error] (70014)End of file found: proxy:
>>> prefetch request body failed to *.*.*.*:50300 (...) from ..... ()
>>> [Wed Jul 25 00:13:18 2012] [error] (70007)The timeout specified has
>>> expired: proxy: prefetch request body failed to to *.*.*.*:50300 (...)
>>> from ..... ()
>>>
>>
>> Maybe the Timeout has expired?
>>
>>
>> Those error occurs with client accessing a tomcat WS through mod_proxy .
>>>
>>> Not all the requests are rejected for today, 416 out of 2194 got one of
>>> these errors.
>>>
>>> don't really know how to proceed to debug this error.
>>> thanks for your help
>>>
>>
>> Add %D to your Tomcat and Apache Access Logs. It is the response time in
>> milloiseconds (Tomcat) resp. microseconds (Apache). If the number is e.g.
>> slightly above 60000000 for Apache and you had set a timeout of 60 seconds,
>> then you know the problem is that the response takes to long. You can then
>> check Tomcats Access Log to see how long it actually took. If it really
>> takes to long in Tomcat, then take thread dumps to analyze and switch to
>> the Tomcat users mailing list.
>>
>> HTH.
>>
>> Rainer
>>
>>
>> ------------------------------**------------------------------**---------
>> To unsubscribe, e-mail: users-unsubscribe [at] httpd**apache.org<users-unsubscribe [at] httpd>
>> For additional commands, e-mail: users-help [at] httpd
>>
>>
>
>
> --
> *Ivan GOUIN**
> *
>
> ***Mob (Suisse**)* : +41 (0)79 941 07 90
>
> *Mail* : gouin.ivan [at] gmail
>
>


--
*Ivan GOUIN**
*

***Mob (Suisse**)* : +41 (0)79 941 07 90

*Mail* : gouin.ivan [at] gmail


rainer.jung at kippdata

Aug 3, 2012, 8:32 AM

Post #6 of 10 (1459 views)
Permalink
Re: How to debug 70014 and 70007 errors [In reply to]

Hi Ivan,

On 03.08.2012 17:23, ivan Gouin wrote:
> Here's what i see on the tcpdump:
>
> Got a TCP connect 3-way handshake. (SYN/SYN-ACK/ACK)
> Got 7 POST request who got a return code 200
>
> After the 7 POST, got a [ FIN, ACK] from th server.
> Then RST from the server
>
> Then the 8th request who goes in time out
>
> Is there some kind of timeout in a tcp keep alive?

Your information is a bit to short. AFAIR we have three communication
nodes, client, proxy and origin server. In addition there was a timeout
happening suspected.

Your info on packets doesn't contain enough about who is communicating
("return code 200", "the server") not about the timing (what time
intervals are between packets.

Regards,

Rainer

> On 25 July 2012 11:29, ivan Gouin <gouin.ivan [at] gmail
> <mailto:gouin.ivan [at] gmail>> wrote:
>
> Hi rainer,
> For case 70007, the timeout expired, in access log , i've got a 300
> second timeout
> In the same time, tomcat's access log haven't any trace of the
> corresponding request.
>
> For these request, response time is about 30-100ms
>
> Apache is Apache/2.2.17
> Tomcat is 6.0.26 (jdk1.6.0_24)
>
> I'm preparing a tcpdump on each side to see if i can see something
> received by tomcat .
>
> Ivan
>
>
> On 25 July 2012 11:02, Rainer Jung <rainer.jung [at] kippdata
> <mailto:rainer.jung [at] kippdata>> wrote:
>
> On 25.07.2012 09 <tel:25.07.2012%2009>:52, ivan Gouin wrote:
>
> Hi,
>
> I've got those error in my httpd error log:
>
> [Wed Jul 25 08:10:55 2012] [error] (70014)End of file found:
> proxy:
> prefetch request body failed to *.*.*.*:50300 (...) from
> ..... ()
> [Wed Jul 25 00:13:18 2012] [error] (70007)The timeout
> specified has
> expired: proxy: prefetch request body failed to to
> *.*.*.*:50300 (...)
> from ..... ()
>
>
> Maybe the Timeout has expired?
>
>
> Those error occurs with client accessing a tomcat WS through
> mod_proxy .
>
> Not all the requests are rejected for today, 416 out of 2194
> got one of
> these errors.
>
> don't really know how to proceed to debug this error.
> thanks for your help
>
>
> Add %D to your Tomcat and Apache Access Logs. It is the response
> time in milloiseconds (Tomcat) resp. microseconds (Apache). If
> the number is e.g. slightly above 60000000 for Apache and you
> had set a timeout of 60 seconds, then you know the problem is
> that the response takes to long. You can then check Tomcats
> Access Log to see how long it actually took. If it really takes
> to long in Tomcat, then take thread dumps to analyze and switch
> to the Tomcat users mailing list.
>
> HTH.
>
> Rainer
>
>
> ------------------------------__------------------------------__---------
> To unsubscribe, e-mail: users-unsubscribe [at] httpd
> <mailto:users-unsubscribe [at] httpd>
> For additional commands, e-mail: users-help [at] httpd
> <mailto:users-help [at] httpd>
>
>
>
>
> --
> *Ivan GOUIN**
> *
>
> ***Mob (Suisse**)* : +41 (0)79 94107 90
>
> *Mail* : gouin.ivan [at] gmail <mailto:gouin.ivan [at] gmail>
>
>
>
>
> --
> *Ivan GOUIN**
> *
>
> ***Mob (Suisse**)* : +41 (0)79 94107 90
>
> *Mail* : gouin.ivan [at] gmail <mailto:gouin.ivan [at] gmail>

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


gouin.ivan at gmail

Aug 8, 2012, 7:20 AM

Post #7 of 10 (1421 views)
Permalink
Re: How to debug 70014 and 70007 errors [In reply to]

Hi,

Here's more information about my issue:

Here i will call
user : the application who post the request.
apache : the httpd server who receive request from the client and send them
to tomcat
tomcat: the web server tomcat, a Web Service application

Versions
user : Apache CXF client 2.2.9
apache: httpd 2.2.17 (tried a 2.2.22 too)
tomcat: 6.0.26 (jdk1.6.0_24)

Here's the post request send by user ( * are for anonymise)

POST /***/***/ws/v2?test HTTP/1.1
Content-Type: text/xml; charset=UTF-8
SOAPAction: ""
Authorization: Basic Z3ZkMHRhb2FwcDpkbmVlc3cyYQ==
Accept: */*
User-Agent: Apache CXF 2.2.9
Content-Length: 304
Host: ***
Connection: Keep-Alive

<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/
">************************</soap:Envelope>

Start at 11:56:57
Between 11:56:57.5357 and 11:56:58:4784: 4 request pass OK

Here's the sequence after that : (Time is of tomcat seem too be a little
shifted, user and apache are on the same host)

11:56:58.4817 user : POST request
*11:56:58.459722 tomcat TCP 551 50300 > 41323 [PSH, ACK] Seq=3187 Ack=3818
Win=22400 Len=485 TSval=345704305 TSecr=749474400 (HTTP 200)*
11:56:58.491981 apache TCP 551 50300 > 41323 [PSH, ACK] Seq=3187 Ack=3818
Win=22400 Len=485 TSval=345704305 TSecr=749474400 (HTTP 200)
11:56:58.492251 user HTTP/XML 594 HTTP/1.1 200 OK
*11:56:58.501457 tomcat TCP 66 41323 > 50300 [ACK] Seq=3818 Ack=3672
Win=15872 Len=0 TSval=749474449 TSecr=345704305*
11:56:58.531503 apache TCP 66 41323 > 50300 [ACK] Seq=3818 Ack=3672
Win=15872 Len=0 TSval=749474449 TSecr=345704305
11:56:58.585937 user TCP 60 45501 > 80 [ACK] Seq=2893 Ack=3948 Win=49640
Len=0
*11:57:03.492499 user TCP 54 80 > 45501 [FIN, ACK] Seq=3948 Ack=2893
Win=16640 Len=0*
11:57:03.494663 user TCP 60 45501 > 80 [ACK] Seq=2893 Ack=3949 Win=49640
Len=0
11:57:08.694657 user TCP 335 [TCP segment of a reassembled PDU]
11:57:08.694703 user TCP 54 80 > 45501 [RST] Seq=3949 Win=0 Len=0
11:57:08.694661 user HTTP/XML 358 POST /*/*/ws/v2?test HTTP/1.1
11:57:08.694763 user TCP 54 80 > 45501 [RST] Seq=3949 Win=0 Len=0
*11:57:18.466178 tomcat TCP 66 50300 > 41323 [FIN, ACK] Seq=3672 Ack=3818
Win=22400 Len=0 TSval=345724311 TSecr=749474449*
11:57:18.498510 apache TCP 66 50300 > 41323 [FIN, ACK] Seq=3672 Ack=3818
Win=22400 Len=0 TSval=345724311 TSecr=749474449
*11:57:18.508720 tomcat TCP 66 41323 > 50300 [ACK] Seq=3818 Ack=3673
Win=15872 Len=0 TSval=749494456 TSecr=345724311*
11:57:18.538771 apache TCP 66 41323 > 50300 [ACK] Seq=3818 Ack=3673
Win=15872 Len=0 TSval=749494456 TSecr=345724311

What make me mad is why apache send a FIN/ACK closing the communication??
Is there a time out somewhere?
This seems to happen about 5 second after the last ACK
Or 6 second the opening of the socket ( at 11:56:57.53)

thanks for yours help

On 3 August 2012 17:32, Rainer Jung <rainer.jung [at] kippdata> wrote:

> Hi Ivan,
>
>
> On 03.08.2012 17:23, ivan Gouin wrote:
>
>> Here's what i see on the tcpdump:
>>
>> Got a TCP connect 3-way handshake. (SYN/SYN-ACK/ACK)
>> Got 7 POST request who got a return code 200
>>
>> After the 7 POST, got a [ FIN, ACK] from th server.
>> Then RST from the server
>>
>> Then the 8th request who goes in time out
>>
>> Is there some kind of timeout in a tcp keep alive?
>>
>
> Your information is a bit to short. AFAIR we have three communication
> nodes, client, proxy and origin server. In addition there was a timeout
> happening suspected.
>
> Your info on packets doesn't contain enough about who is communicating
> ("return code 200", "the server") not about the timing (what time intervals
> are between packets.
>
> Regards,
>
> Rainer
>
> On 25 July 2012 11:29, ivan Gouin <gouin.ivan [at] gmail
>> <mailto:gouin.ivan [at] gmail>> wrote:
>>
>> Hi rainer,
>> For case 70007, the timeout expired, in access log , i've got a 300
>> second timeout
>> In the same time, tomcat's access log haven't any trace of the
>> corresponding request.
>>
>> For these request, response time is about 30-100ms
>>
>> Apache is Apache/2.2.17
>> Tomcat is 6.0.26 (jdk1.6.0_24)
>>
>> I'm preparing a tcpdump on each side to see if i can see something
>> received by tomcat .
>>
>> Ivan
>>
>>
>> On 25 July 2012 11:02, Rainer Jung <rainer.jung [at] kippdata
>> <mailto:rainer.jung [at] kippdata**de <rainer.jung [at] kippdata>>> wrote:
>>
>>
>> On 25.07.2012 09 <tel:25.07.2012%2009>:52, ivan Gouin wrote:
>>
>> Hi,
>>
>> I've got those error in my httpd error log:
>>
>> [Wed Jul 25 08:10:55 2012] [error] (70014)End of file found:
>> proxy:
>> prefetch request body failed to *.*.*.*:50300 (...) from
>> ..... ()
>> [Wed Jul 25 00:13:18 2012] [error] (70007)The timeout
>> specified has
>> expired: proxy: prefetch request body failed to to
>> *.*.*.*:50300 (...)
>> from ..... ()
>>
>>
>> Maybe the Timeout has expired?
>>
>>
>> Those error occurs with client accessing a tomcat WS through
>> mod_proxy .
>>
>> Not all the requests are rejected for today, 416 out of 2194
>> got one of
>> these errors.
>>
>> don't really know how to proceed to debug this error.
>> thanks for your help
>>
>>
>> Add %D to your Tomcat and Apache Access Logs. It is the response
>> time in milloiseconds (Tomcat) resp. microseconds (Apache). If
>> the number is e.g. slightly above 60000000 for Apache and you
>> had set a timeout of 60 seconds, then you know the problem is
>> that the response takes to long. You can then check Tomcats
>> Access Log to see how long it actually took. If it really takes
>> to long in Tomcat, then take thread dumps to analyze and switch
>> to the Tomcat users mailing list.
>>
>> HTH.
>>
>> Rainer
>>
>>
>> ------------------------------**__----------------------------**
>> --__---------
>> To unsubscribe, e-mail: users-unsubscribe [at] httpd**he.org<http://apache.org>
>> <mailto:users-unsubscribe@**httpd.apache.org<users-unsubscribe [at] httpd>
>> >
>>
>> For additional commands, e-mail: users-help [at] httpd
>> <mailto:users-help [at] httpd**apache.org<users-help [at] httpd>
>> >
>>
>>
>>
>>
>> --
>> *Ivan GOUIN**
>> *
>>
>> ***Mob (Suisse**)* : +41 (0)79 94107 90
>>
>> *Mail* : gouin.ivan [at] gmail <mailto:gouin.ivan [at] gmail>
>>
>>
>>
>>
>> --
>> *Ivan GOUIN**
>> *
>>
>> ***Mob (Suisse**)* : +41 (0)79 94107 90
>>
>> *Mail* : gouin.ivan [at] gmail <mailto:gouin.ivan [at] gmail>
>>
>
> ------------------------------**------------------------------**---------
> To unsubscribe, e-mail: users-unsubscribe [at] httpd**apache.org<users-unsubscribe [at] httpd>
> For additional commands, e-mail: users-help [at] httpd
>
>


--
*Ivan GOUIN**
*

***Mob (Suisse**)* : +41 (0)79 941 07 90

*Mail* : gouin.ivan [at] gmail


gouin.ivan at gmail

Aug 9, 2012, 6:11 AM

Post #8 of 10 (1430 views)
Permalink
Re: How to debug 70014 and 70007 errors [In reply to]

Hi Rainer,

Seems like KeepAliveTimeout Directive was able to resolve my issue

Thanks for your helps




On 8 August 2012 16:20, ivan Gouin <gouin.ivan [at] gmail> wrote:

> Hi,
>
> Here's more information about my issue:
>
> Here i will call
> user : the application who post the request.
> apache : the httpd server who receive request from the client and send
> them to tomcat
> tomcat: the web server tomcat, a Web Service application
>
> Versions
> user : Apache CXF client 2.2.9
> apache: httpd 2.2.17 (tried a 2.2.22 too)
> tomcat: 6.0.26 (jdk1.6.0_24)
>
> Here's the post request send by user ( * are for anonymise)
>
> POST /***/***/ws/v2?test HTTP/1.1
> Content-Type: text/xml; charset=UTF-8
> SOAPAction: ""
> Authorization: Basic Z3ZkMHRhb2FwcDpkbmVlc3cyYQ==
> Accept: */*
> User-Agent: Apache CXF 2.2.9
> Content-Length: 304
> Host: ***
> Connection: Keep-Alive
>
> <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/
> ">************************</soap:Envelope>
>
> Start at 11:56:57
> Between 11:56:57.5357 and 11:56:58:4784: 4 request pass OK
>
> Here's the sequence after that : (Time is of tomcat seem too be a little
> shifted, user and apache are on the same host)
>
> 11:56:58.4817 user : POST request
> *11:56:58.459722 tomcat TCP 551 50300 > 41323 [PSH, ACK] Seq=3187
> Ack=3818 Win=22400 Len=485 TSval=345704305 TSecr=749474400 (HTTP 200)*
> 11:56:58.491981 apache TCP 551 50300 > 41323 [PSH, ACK] Seq=3187 Ack=3818
> Win=22400 Len=485 TSval=345704305 TSecr=749474400 (HTTP 200)
> 11:56:58.492251 user HTTP/XML 594 HTTP/1.1 200 OK
> *11:56:58.501457 tomcat TCP 66 41323 > 50300 [ACK] Seq=3818 Ack=3672
> Win=15872 Len=0 TSval=749474449 TSecr=345704305*
> 11:56:58.531503 apache TCP 66 41323 > 50300 [ACK] Seq=3818 Ack=3672
> Win=15872 Len=0 TSval=749474449 TSecr=345704305
> 11:56:58.585937 user TCP 60 45501 > 80 [ACK] Seq=2893 Ack=3948 Win=49640
> Len=0
> *11:57:03.492499 user TCP 54 80 > 45501 [FIN, ACK] Seq=3948 Ack=2893
> Win=16640 Len=0*
> 11:57:03.494663 user TCP 60 45501 > 80 [ACK] Seq=2893 Ack=3949 Win=49640
> Len=0
> 11:57:08.694657 user TCP 335 [TCP segment of a reassembled PDU]
> 11:57:08.694703 user TCP 54 80 > 45501 [RST] Seq=3949 Win=0 Len=0
> 11:57:08.694661 user HTTP/XML 358 POST /*/*/ws/v2?test HTTP/1.1
> 11:57:08.694763 user TCP 54 80 > 45501 [RST] Seq=3949 Win=0 Len=0
> *11:57:18.466178 tomcat TCP 66 50300 > 41323 [FIN, ACK] Seq=3672 Ack=3818
> Win=22400 Len=0 TSval=345724311 TSecr=749474449*
> 11:57:18.498510 apache TCP 66 50300 > 41323 [FIN, ACK] Seq=3672 Ack=3818
> Win=22400 Len=0 TSval=345724311 TSecr=749474449
> *11:57:18.508720 tomcat TCP 66 41323 > 50300 [ACK] Seq=3818 Ack=3673
> Win=15872 Len=0 TSval=749494456 TSecr=345724311*
> 11:57:18.538771 apache TCP 66 41323 > 50300 [ACK] Seq=3818 Ack=3673
> Win=15872 Len=0 TSval=749494456 TSecr=345724311
>
> What make me mad is why apache send a FIN/ACK closing the communication??
> Is there a time out somewhere?
> This seems to happen about 5 second after the last ACK
> Or 6 second the opening of the socket ( at 11:56:57.53)
>
> thanks for yours help
>
> On 3 August 2012 17:32, Rainer Jung <rainer.jung [at] kippdata> wrote:
>
>> Hi Ivan,
>>
>>
>> On 03.08.2012 17:23, ivan Gouin wrote:
>>
>>> Here's what i see on the tcpdump:
>>>
>>> Got a TCP connect 3-way handshake. (SYN/SYN-ACK/ACK)
>>> Got 7 POST request who got a return code 200
>>>
>>> After the 7 POST, got a [ FIN, ACK] from th server.
>>> Then RST from the server
>>>
>>> Then the 8th request who goes in time out
>>>
>>> Is there some kind of timeout in a tcp keep alive?
>>>
>>
>> Your information is a bit to short. AFAIR we have three communication
>> nodes, client, proxy and origin server. In addition there was a timeout
>> happening suspected.
>>
>> Your info on packets doesn't contain enough about who is communicating
>> ("return code 200", "the server") not about the timing (what time intervals
>> are between packets.
>>
>> Regards,
>>
>> Rainer
>>
>> On 25 July 2012 11:29, ivan Gouin <gouin.ivan [at] gmail
>>> <mailto:gouin.ivan [at] gmail>> wrote:
>>>
>>> Hi rainer,
>>> For case 70007, the timeout expired, in access log , i've got a 300
>>> second timeout
>>> In the same time, tomcat's access log haven't any trace of the
>>> corresponding request.
>>>
>>> For these request, response time is about 30-100ms
>>>
>>> Apache is Apache/2.2.17
>>> Tomcat is 6.0.26 (jdk1.6.0_24)
>>>
>>> I'm preparing a tcpdump on each side to see if i can see something
>>> received by tomcat .
>>>
>>> Ivan
>>>
>>>
>>> On 25 July 2012 11:02, Rainer Jung <rainer.jung [at] kippdata
>>> <mailto:rainer.jung [at] kippdata**de <rainer.jung [at] kippdata>>> wrote:
>>>
>>>
>>> On 25.07.2012 09 <tel:25.07.2012%2009>:52, ivan Gouin wrote:
>>>
>>> Hi,
>>>
>>> I've got those error in my httpd error log:
>>>
>>> [Wed Jul 25 08:10:55 2012] [error] (70014)End of file found:
>>> proxy:
>>> prefetch request body failed to *.*.*.*:50300 (...) from
>>> ..... ()
>>> [Wed Jul 25 00:13:18 2012] [error] (70007)The timeout
>>> specified has
>>> expired: proxy: prefetch request body failed to to
>>> *.*.*.*:50300 (...)
>>> from ..... ()
>>>
>>>
>>> Maybe the Timeout has expired?
>>>
>>>
>>> Those error occurs with client accessing a tomcat WS through
>>> mod_proxy .
>>>
>>> Not all the requests are rejected for today, 416 out of 2194
>>> got one of
>>> these errors.
>>>
>>> don't really know how to proceed to debug this error.
>>> thanks for your help
>>>
>>>
>>> Add %D to your Tomcat and Apache Access Logs. It is the response
>>> time in milloiseconds (Tomcat) resp. microseconds (Apache). If
>>> the number is e.g. slightly above 60000000 for Apache and you
>>> had set a timeout of 60 seconds, then you know the problem is
>>> that the response takes to long. You can then check Tomcats
>>> Access Log to see how long it actually took. If it really takes
>>> to long in Tomcat, then take thread dumps to analyze and switch
>>> to the Tomcat users mailing list.
>>>
>>> HTH.
>>>
>>> Rainer
>>>
>>>
>>> ------------------------------**__----------------------------**
>>> --__---------
>>> To unsubscribe, e-mail: users-unsubscribe [at] httpd**he.org<http://apache.org>
>>> <mailto:users-unsubscribe@**httpd.apache.org<users-unsubscribe [at] httpd>
>>> >
>>>
>>> For additional commands, e-mail: users-help [at] httpd
>>> <mailto:users-help [at] httpd**apache.org<users-help [at] httpd>
>>> >
>>>
>>>
>>>
>>>
>>> --
>>> *Ivan GOUIN**
>>> *
>>>
>>> ***Mob (Suisse**)* : +41 (0)79 94107 90
>>>
>>> *Mail* : gouin.ivan [at] gmail <mailto:gouin.ivan [at] gmail>
>>>
>>>
>>>
>>>
>>> --
>>> *Ivan GOUIN**
>>> *
>>>
>>> ***Mob (Suisse**)* : +41 (0)79 94107 90
>>>
>>> *Mail* : gouin.ivan [at] gmail <mailto:gouin.ivan [at] gmail>
>>>
>>
>> ------------------------------**------------------------------**---------
>> To unsubscribe, e-mail: users-unsubscribe [at] httpd**apache.org<users-unsubscribe [at] httpd>
>> For additional commands, e-mail: users-help [at] httpd
>>
>>
>
>
> --
> *Ivan GOUIN**
> *
>
> ***Mob (Suisse**)* : +41 (0)79 941 07 90
>
> *Mail* : gouin.ivan [at] gmail
>



--
*Ivan GOUIN**
*

***Mob (Suisse**)* : +41 (0)79 941 07 90

*Mail* : gouin.ivan [at] gmail


rainer.jung at kippdata

Aug 12, 2012, 4:11 AM

Post #9 of 10 (1398 views)
Permalink
Re: How to debug 70014 and 70007 errors [In reply to]

On 08.08.2012 16:20, ivan Gouin wrote:
> Hi,
>
> Here's more information about my issue:
>
> Here i will call
> user : the application who post the request.
> apache : the httpd server who receive request from the client and send
> them to tomcat
> tomcat: the web server tomcat, a Web Service application
>
> Versions
> user : Apache CXF client 2.2.9
> apache: httpd 2.2.17 (tried a 2.2.22 too)
> tomcat: 6.0.26 (jdk1.6.0_24)
>
> Here's the post request send by user ( * are for anonymise)
>
> POST /***/***/ws/v2?test HTTP/1.1
> Content-Type: text/xml; charset=UTF-8
> SOAPAction: ""
> Authorization: Basic Z3ZkMHRhb2FwcDpkbmVlc3cyYQ==
> Accept: */*
> User-Agent: Apache CXF 2.2.9
> Content-Length: 304
> Host: ***
> Connection: Keep-Alive
>
> <soap:Envelope
> xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/">************************</soap:Envelope>
>
> Start at 11:56:57
> Between 11:56:57.5357 and 11:56:58:4784: 4 request pass OK
>
> Here's the sequence after that : (Time is of tomcat seem too be a little
> shifted, user and apache are on the same host)
>
> 11:56:58.4817 user : POST request
> *11:56:58.459722tomcatTCP55150300 > 41323 [PSH, ACK] Seq=3187 Ack=3818
> Win=22400 Len=485 TSval=345704305 TSecr=749474400 (HTTP 200)*
> 11:56:58.491981apacheTCP55150300 > 41323 [PSH, ACK] Seq=3187 Ack=3818
> Win=22400 Len=485 TSval=345704305 TSecr=749474400 (HTTP 200)
> 11:56:58.492251userHTTP/XML594HTTP/1.1 200 OK

Did this packet contain the full response?

> *11:56:58.501457tomcatTCP6641323 > 50300 [ACK] Seq=3818 Ack=3672
> Win=15872 Len=0 TSval=749474449 TSecr=345704305*
> 11:56:58.531503apacheTCP6641323 > 50300 [ACK] Seq=3818 Ack=3672
> Win=15872 Len=0 TSval=749474449 TSecr=345704305
> 11:56:58.585937userTCP6045501 > 80 [ACK] Seq=2893 Ack=3948 Win=49640 Len=0

5 seconds pause

> *11:57:03.492499userTCP5480 > 45501 [FIN, ACK] Seq=3948 Ack=2893
> Win=16640 Len=0*

KeepAlive Timeout 5 seconds configured for Apache?

> 11:57:03.494663userTCP6045501 > 80 [ACK] Seq=2893 Ack=3949 Win=49640 Len=0
> 11:57:08.694657userTCP335[TCP segment of a reassembled PDU]
> 11:57:08.694703userTCP5480 > 45501 [RST] Seq=3949 Win=0 Len=0
> 11:57:08.694661userHTTP/XML358POST /*/*/ws/v2?test HTTP/1.1
> 11:57:08.694763userTCP5480 > 45501 [RST] Seq=3949 Win=0 Len=0
> *11:57:18.466178tomcatTCP6650300 > 41323 [FIN, ACK] Seq=3672 Ack=3818
> Win=22400 Len=0 TSval=345724311 TSecr=749474449*
> 11:57:18.498510apacheTCP6650300 > 41323 [FIN, ACK] Seq=3672 Ack=3818
> Win=22400 Len=0 TSval=345724311 TSecr=749474449
> *11:57:18.508720tomcatTCP6641323 > 50300 [ACK] Seq=3818 Ack=3673
> Win=15872 Len=0 TSval=749494456 TSecr=345724311*
> 11:57:18.538771apacheTCP6641323 > 50300 [ACK] Seq=3818 Ack=3673
> Win=15872 Len=0 TSval=749494456 TSecr=345724311
>
> What make me mad is why apache send a FIN/ACK closing the communication??
> Is there a time out somewhere?
> This seems to happen about 5 second after the last ACK
> Or 6 second the opening of the socket ( at 11:56:57.53)

I guess its the Keep Alive Timeout of 5 seconds configured for Apache.
Check configuration.

This should not produce a problem in itself. A client that observes a
closed connection when trying to send a follow on request should
transparently start a new connection.

Regards,

Rainer


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


gouin.ivan at gmail

Aug 13, 2012, 11:42 PM

Post #10 of 10 (1392 views)
Permalink
Re: How to debug 70014 and 70007 errors [In reply to]

Hi Rainer,

Keep Alive Timeout wasn't set on my config
But its default value of 5 seconds was the reason why the connection
closed.

In fact the root cause is the behavior of the CXF client who didn't take
care of the close announcement of this connection.

We're trying to fix this issue but setting the timeout higher solve is a
workaround for now.

Thank for your help.
Ivan


On 12 August 2012 13:11, Rainer Jung <rainer.jung [at] kippdata> wrote:

> On 08.08.2012 16:20, ivan Gouin wrote:
>
>> Hi,
>>
>> Here's more information about my issue:
>>
>> Here i will call
>> user : the application who post the request.
>> apache : the httpd server who receive request from the client and send
>> them to tomcat
>> tomcat: the web server tomcat, a Web Service application
>>
>> Versions
>> user : Apache CXF client 2.2.9
>> apache: httpd 2.2.17 (tried a 2.2.22 too)
>> tomcat: 6.0.26 (jdk1.6.0_24)
>>
>> Here's the post request send by user ( * are for anonymise)
>>
>> POST /***/***/ws/v2?test HTTP/1.1
>> Content-Type: text/xml; charset=UTF-8
>> SOAPAction: ""
>> Authorization: Basic Z3ZkMHRhb2FwcDpkbmVlc3cyYQ==
>> Accept: */*
>> User-Agent: Apache CXF 2.2.9
>> Content-Length: 304
>> Host: ***
>> Connection: Keep-Alive
>>
>> <soap:Envelope
>> xmlns:soap="http://schemas.**xmlsoap.org/soap/envelope/<http://schemas.xmlsoap.org/soap/envelope/>
>> ">**************************</soap:**Envelope>
>>
>> Start at 11:56:57
>> Between 11:56:57.5357 and 11:56:58:4784: 4 request pass OK
>>
>> Here's the sequence after that : (Time is of tomcat seem too be a little
>> shifted, user and apache are on the same host)
>>
>> 11:56:58.4817 user : POST request
>> *11:56:58.**459722tomcatTCP55150300 > 41323 [PSH, ACK] Seq=3187 Ack=3818
>> Win=22400 Len=485 TSval=345704305 TSecr=749474400 (HTTP 200)*
>> 11:56:58.**491981apacheTCP55150300 > 41323 [PSH, ACK] Seq=3187 Ack=3818
>>
>> Win=22400 Len=485 TSval=345704305 TSecr=749474400 (HTTP 200)
>> 11:56:58.492251userHTTP/**XML594HTTP/1.1 200 OK
>>
>
> Did this packet contain the full response?
>
> *11:56:58.**501457tomcatTCP6641323 > 50300 [ACK] Seq=3818 Ack=3672
>> Win=15872 Len=0 TSval=749474449 TSecr=345704305*
>> 11:56:58.**531503apacheTCP6641323 > 50300 [ACK] Seq=3818 Ack=3672
>> Win=15872 Len=0 TSval=749474449 TSecr=345704305
>> 11:56:58.585937userTCP6045501 > 80 [ACK] Seq=2893 Ack=3948 Win=49640 Len=0
>>
>
> 5 seconds pause
>
> *11:57:03.492499userTCP5480 > 45501 [FIN, ACK] Seq=3948 Ack=2893
>> Win=16640 Len=0*
>>
>
> KeepAlive Timeout 5 seconds configured for Apache?
>
> 11:57:03.494663userTCP6045501 > 80 [ACK] Seq=2893 Ack=3949 Win=49640 Len=0
>> 11:57:08.694657userTCP335[TCP segment of a reassembled PDU]
>> 11:57:08.694703userTCP5480 > 45501 [RST] Seq=3949 Win=0 Len=0
>>
>> 11:57:08.694661userHTTP/**XML358POST /*/*/ws/v2?test HTTP/1.1
>> 11:57:08.694763userTCP5480 > 45501 [RST] Seq=3949 Win=0 Len=0
>> *11:57:18.**466178tomcatTCP6650300 > 41323 [FIN, ACK] Seq=3672 Ack=3818
>> Win=22400 Len=0 TSval=345724311 TSecr=749474449*
>> 11:57:18.**498510apacheTCP6650300 > 41323 [FIN, ACK] Seq=3672 Ack=3818
>> Win=22400 Len=0 TSval=345724311 TSecr=749474449
>> *11:57:18.**508720tomcatTCP6641323 > 50300 [ACK] Seq=3818 Ack=3673
>> Win=15872 Len=0 TSval=749494456 TSecr=345724311*
>> 11:57:18.**538771apacheTCP6641323 > 50300 [ACK] Seq=3818 Ack=3673
>>
>> Win=15872 Len=0 TSval=749494456 TSecr=345724311
>>
>> What make me mad is why apache send a FIN/ACK closing the communication??
>> Is there a time out somewhere?
>> This seems to happen about 5 second after the last ACK
>> Or 6 second the opening of the socket ( at 11:56:57.53)
>>
>
> I guess its the Keep Alive Timeout of 5 seconds configured for Apache.
> Check configuration.
>
> This should not produce a problem in itself. A client that observes a
> closed connection when trying to send a follow on request should
> transparently start a new connection.
>
> Regards,
>
> Rainer
>
>
>
> ------------------------------**------------------------------**---------
> To unsubscribe, e-mail: users-unsubscribe [at] httpd**apache.org<users-unsubscribe [at] httpd>
> For additional commands, e-mail: users-help [at] httpd
>
>

Apache users RSS feed   Index | Next | Previous | View Threaded
 
 


Interested in having your list archived? Contact Gossamer Threads
 
  Web Applications & Managed Hosting Powered by Gossamer Threads Inc.