Tomcat Processing Timer Question

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
16 messages Options
Reply | Threaded
Open this post in threaded view
|

Tomcat Processing Timer Question

Eric Robinson
It is my understanding that the AccessLogValve %D field records the time from when the last byte of the client's request is received to when the last byte of the server's response is placed on the wire. Is that correct? If so, would TCP retransmissions impact the timer? If there are connectivity issues between the client and server, resulting in TCP retransmits, could that appear as higher response times in the localhost_access logs?

-Eric

Disclaimer : This email and any files transmitted with it are confidential and intended solely for intended recipients. If you are not the named addressee you should not disseminate, distribute, copy or alter this email. Any views or opinions presented in this email are solely those of the author and might not represent those of Physician Select Management. Warning: Although Physician Select Management has taken reasonable precautions to ensure no viruses are present in this email, the company cannot accept responsibility for any loss or damage arising from the use of this email or attachments.
Reply | Threaded
Open this post in threaded view
|

Re: Tomcat Processing Timer Question

markt
On 08/09/2020 18:46, Eric Robinson wrote:
> It is my understanding that the AccessLogValve %D field records the time from when the last byte of the client's request is received to when the last byte of the server's response is placed on the wire. Is that correct? If so, would TCP retransmissions impact the timer? If there are connectivity issues between the client and server, resulting in TCP retransmits, could that appear as higher response times in the localhost_access logs?

No. Tomcat has no visibility once the network stack has accepted the data.

Mark

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Tomcat Processing Timer Question

Christopher Schultz-2
In reply to this post by Eric Robinson
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Eric,

On 9/8/20 13:46, Eric Robinson wrote:
> It is my understanding that the AccessLogValve %D field records the
>  time from when the last byte of the client's request is received
> to when the last byte of the server's response is placed on the
> wire. Is that correct? If so, would TCP retransmissions impact the
> timer?

I'm not positive, but I believe Tomcat has zero visibility into that
level of detail.

> If there are connectivity issues between the client and server,
> resulting in TCP retransmits, could that appear as higher response
>  times in the localhost_access logs?

This would only happen if the re-transmissions were to cause network
buffering in the OS such that the stream writes (at the Java level) were
to block (and therefore "take time" instead of being essentially
instantaneous).

- -chris
-----BEGIN PGP SIGNATURE-----
Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/

iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl9XyvUACgkQHPApP6U8
pFi2PQ/9Er4fN490tP2Fq911WSX7+wQnnRwE9w5JWx36b++DtFAWxKJTpQGg0Dl2
pyP/1vVPB6ZHVPdVEUUvYPAzhDAVWJVrIdXUvcaMg2tKpb5zzERhdxpG2vEHQykb
YaRTPqu0QHNySjMyQ9yT3Q8YDSObvXAYnR+7f1aT1g9UOma63z4mKE11RuQloXGz
SqjiLzHjDQmehplDjTXTSwRxcjnJftCKG0Jwin4f8Kto6tJ/AJdTxaWmwXeSiRcn
QN8b586DpyS/k0hgkJ0bOWhbxVsy4aUhM+PeyjN4AXufzSjymY4hv4hpOO+37woT
SRj3rTd2LtS8h5v4VVSIFXTeL+kEwjo3iya/Komd4Z7Pu+qw91ZLy7LIrZfV4MHp
8me2jLobBiosIlXSAAxVjY3zOVlzqEOIjOL+t/Qwhn+CM/nDLfuhtwdfuu+KGpNs
/u18gauI4eb4MtoSETcvb5OaFHdkrmInCD3BXz9ZZRrnVCL9r9SLPN1yxENerdVq
RJrvJMItb5tLf0XcK7Wvm+lJIdArEkSCzZ3o3uDWbiRkN0hKU5R/Jndr/qfL12dj
/knGWyED0UGaY58TgOMAN6veMO991/PTL6to5Xr6RTivEQO+6YYS1zj1uGPc5p/n
gGnJ9b9VWeZBvlyDb7H9CxOvvkdJzMum6WaagIvmR5zi8ZZx3do=
=QoNs
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

RE: Tomcat Processing Timer Question

Eric Robinson
Hi Mark and Christopher,

For clarification, suppose a client sends and HTTP POST request which is bigger than the PMTU and has to be broken into multiple packets. It sounds like you're saying that the request is buffered by the network stack, and the stack does not send it up to tomcat until the full request is received. That would make sense if every HTTP request is encapsulated in its own separate TCP connection. Most of the time, that is not the case. A single connection is held open and used for multiple HTTP requests. The network stack has no understanding of anything above TCP, so it does not know when an HTTP request complete. It must therefore deliver whatever it has, and it would be up to tomcat to decide when the HTTP request is complete, wouldn't it?

If that is the case, tomcat could receive a partial HTTP request and would have to wait for the rest before processing it. So when does tomcat start its processing timer?


> -----Original Message-----
> From: Christopher Schultz <[hidden email]>
> Sent: Tuesday, September 8, 2020 1:19 PM
> To: [hidden email]
> Subject: Re: Tomcat Processing Timer Question
>
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
>
> Eric,
>
> On 9/8/20 13:46, Eric Robinson wrote:
> > It is my understanding that the AccessLogValve %D field records the
> > time from when the last byte of the client's request is received to
> > when the last byte of the server's response is placed on the wire. Is
> > that correct? If so, would TCP retransmissions impact the timer?
>
> I'm not positive, but I believe Tomcat has zero visibility into that level of
> detail.
>
> > If there are connectivity issues between the client and server,
> > resulting in TCP retransmits, could that appear as higher response
> > times in the localhost_access logs?
>
> This would only happen if the re-transmissions were to cause network
> buffering in the OS such that the stream writes (at the Java level) were to
> block (and therefore "take time" instead of being essentially instantaneous).
>
> - -chris
> -----BEGIN PGP SIGNATURE-----
> Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/
>
> iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl9XyvUACgkQHPApP
> 6U8
> pFi2PQ/9Er4fN490tP2Fq911WSX7+wQnnRwE9w5JWx36b++DtFAWxKJTpQGg
> 0Dl2
> pyP/1vVPB6ZHVPdVEUUvYPAzhDAVWJVrIdXUvcaMg2tKpb5zzERhdxpG2vEH
> Qykb
> YaRTPqu0QHNySjMyQ9yT3Q8YDSObvXAYnR+7f1aT1g9UOma63z4mKE11RuQl
> oXGz
> SqjiLzHjDQmehplDjTXTSwRxcjnJftCKG0Jwin4f8Kto6tJ/AJdTxaWmwXeSiRcn
> QN8b586DpyS/k0hgkJ0bOWhbxVsy4aUhM+PeyjN4AXufzSjymY4hv4hpOO+3
> 7woT
> SRj3rTd2LtS8h5v4VVSIFXTeL+kEwjo3iya/Komd4Z7Pu+qw91ZLy7LIrZfV4MHp
> 8me2jLobBiosIlXSAAxVjY3zOVlzqEOIjOL+t/Qwhn+CM/nDLfuhtwdfuu+KGpN
> s
> /u18gauI4eb4MtoSETcvb5OaFHdkrmInCD3BXz9ZZRrnVCL9r9SLPN1yxENerdV
> q
> RJrvJMItb5tLf0XcK7Wvm+lJIdArEkSCzZ3o3uDWbiRkN0hKU5R/Jndr/qfL12dj
> /knGWyED0UGaY58TgOMAN6veMO991/PTL6to5Xr6RTivEQO+6YYS1zj1uGPc5
> p/n
> gGnJ9b9VWeZBvlyDb7H9CxOvvkdJzMum6WaagIvmR5zi8ZZx3do=
> =QoNs
> -----END PGP SIGNATURE-----
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]

Disclaimer : This email and any files transmitted with it are confidential and intended solely for intended recipients. If you are not the named addressee you should not disseminate, distribute, copy or alter this email. Any views or opinions presented in this email are solely those of the author and might not represent those of Physician Select Management. Warning: Although Physician Select Management has taken reasonable precautions to ensure no viruses are present in this email, the company cannot accept responsibility for any loss or damage arising from the use of this email or attachments.

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Tomcat Processing Timer Question

markt
On 08/09/2020 21:19, Eric Robinson wrote:
> Hi Mark and Christopher,
>
> For clarification, suppose a client sends and HTTP POST request which
is bigger than the PMTU and has to be broken into multiple packets. It
sounds like you're saying that the request is buffered by the network
stack, and the stack does not send it up to tomcat until the full
request is received. That would make sense if every HTTP request is
encapsulated in its own separate TCP connection. Most of the time, that
is not the case. A single connection is held open and used for multiple
HTTP requests. The network stack has no understanding of anything above
TCP, so it does not know when an HTTP request complete. It must
therefore deliver whatever it has, and it would be up to tomcat to
decide when the HTTP request is complete, wouldn't it?
>
> If that is the case, tomcat could receive a partial HTTP request and
would have to wait for the rest before processing it. So when does
tomcat start its processing timer?

Tomcat starts the processing timer as soon as Tomcat processes the first
bytes of the request. In practice, this means the network stack has to
deliver the data to Tomcat, the Poller fires a read event, a thread is
allocated to process that read event, any TLS handshake has completed
and Tomcat has read the first real byte of the request.

If the request is split across multiple packets the timer starts when
Tomcat reads the first byte of the request from the first packet.

Tomcat stops the timer on a request after the last byte of the response
has been accepted by the network stack.

HTH,

Mark

>
>
>> -----Original Message-----
>> From: Christopher Schultz <[hidden email]>
>> Sent: Tuesday, September 8, 2020 1:19 PM
>> To: [hidden email]
>> Subject: Re: Tomcat Processing Timer Question
>>
> Eric,
>
> On 9/8/20 13:46, Eric Robinson wrote:
>>>> It is my understanding that the AccessLogValve %D field records the
>>>> time from when the last byte of the client's request is received to
>>>> when the last byte of the server's response is placed on the wire. Is
>>>> that correct? If so, would TCP retransmissions impact the timer?
>
> I'm not positive, but I believe Tomcat has zero visibility into that level of
> detail.
>
>>>> If there are connectivity issues between the client and server,
>>>> resulting in TCP retransmits, could that appear as higher response
>>>> times in the localhost_access logs?
>
> This would only happen if the re-transmissions were to cause network
> buffering in the OS such that the stream writes (at the Java level) were to
> block (and therefore "take time" instead of being essentially instantaneous).
>
> -chris
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [hidden email]
>> For additional commands, e-mail: [hidden email]
>
> Disclaimer : This email and any files transmitted with it are
confidential and intended solely for intended recipients. If you are not
the named addressee you should not disseminate, distribute, copy or
alter this email. Any views or opinions presented in this email are
solely those of the author and might not represent those of Physician
Select Management. Warning: Although Physician Select Management has
taken reasonable precautions to ensure no viruses are present in this
email, the company cannot accept responsibility for any loss or damage
arising from the use of this email or attachments.
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

RE: Tomcat Processing Timer Question

Eric Robinson
Hi Mark --

"If the request is split across multiple packets the timer starts when Tomcat reads the first byte of the request from the first packet.
Tomcat stops the timer on a request after the last byte of the response has been accepted by the network stack."

Now we're getting somewhere. If tomcat starts its timer when it reads the first byte of the client's request, and the request is split into multiple packets, doesn't it stand to reason that the timer would run longer when there are TCP retransmits?

--Eric

> -----Original Message-----
> From: Mark Thomas <[hidden email]>
> Sent: Tuesday, September 8, 2020 3:34 PM
> To: [hidden email]
> Subject: Re: Tomcat Processing Timer Question
>
> On 08/09/2020 21:19, Eric Robinson wrote:
> > Hi Mark and Christopher,
> >
> > For clarification, suppose a client sends and HTTP POST request which
> is bigger than the PMTU and has to be broken into multiple packets. It
> sounds like you're saying that the request is buffered by the network stack,
> and the stack does not send it up to tomcat until the full request is received.
> That would make sense if every HTTP request is encapsulated in its own
> separate TCP connection. Most of the time, that is not the case. A single
> connection is held open and used for multiple HTTP requests. The network
> stack has no understanding of anything above TCP, so it does not know when
> an HTTP request complete. It must therefore deliver whatever it has, and it
> would be up to tomcat to decide when the HTTP request is complete,
> wouldn't it?
> >
> > If that is the case, tomcat could receive a partial HTTP request and
> would have to wait for the rest before processing it. So when does tomcat
> start its processing timer?
>
> Tomcat starts the processing timer as soon as Tomcat processes the first
> bytes of the request. In practice, this means the network stack has to deliver
> the data to Tomcat, the Poller fires a read event, a thread is allocated to
> process that read event, any TLS handshake has completed and Tomcat has
> read the first real byte of the request.
>
> If the request is split across multiple packets the timer starts when Tomcat
> reads the first byte of the request from the first packet.
>
> Tomcat stops the timer on a request after the last byte of the response has
> been accepted by the network stack.
>
> HTH,
>
> Mark
>
> >
> >
> >> -----Original Message-----
> >> From: Christopher Schultz <[hidden email]>
> >> Sent: Tuesday, September 8, 2020 1:19 PM
> >> To: [hidden email]
> >> Subject: Re: Tomcat Processing Timer Question
> >>
> > Eric,
> >
> > On 9/8/20 13:46, Eric Robinson wrote:
> >>>> It is my understanding that the AccessLogValve %D field records the
> >>>> time from when the last byte of the client's request is received to
> >>>> when the last byte of the server's response is placed on the wire.
> >>>> Is that correct? If so, would TCP retransmissions impact the timer?
> >
> > I'm not positive, but I believe Tomcat has zero visibility into that
> > level of detail.
> >
> >>>> If there are connectivity issues between the client and server,
> >>>> resulting in TCP retransmits, could that appear as higher response
> >>>> times in the localhost_access logs?
> >
> > This would only happen if the re-transmissions were to cause network
> > buffering in the OS such that the stream writes (at the Java level)
> > were to block (and therefore "take time" instead of being essentially
> instantaneous).
> >
> > -chris
> >>
> >> ---------------------------------------------------------------------
> >> To unsubscribe, e-mail: [hidden email]
> >> For additional commands, e-mail: [hidden email]
> >
> > Disclaimer : This email and any files transmitted with it are
> confidential and intended solely for intended recipients. If you are not the
> named addressee you should not disseminate, distribute, copy or alter this
> email. Any views or opinions presented in this email are solely those of the
> author and might not represent those of Physician Select Management.
> Warning: Although Physician Select Management has taken reasonable
> precautions to ensure no viruses are present in this email, the company
> cannot accept responsibility for any loss or damage arising from the use of
> this email or attachments.
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: [hidden email]
> > For additional commands, e-mail: [hidden email]
> >
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]

Disclaimer : This email and any files transmitted with it are confidential and intended solely for intended recipients. If you are not the named addressee you should not disseminate, distribute, copy or alter this email. Any views or opinions presented in this email are solely those of the author and might not represent those of Physician Select Management. Warning: Although Physician Select Management has taken reasonable precautions to ensure no viruses are present in this email, the company cannot accept responsibility for any loss or damage arising from the use of this email or attachments.

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]
Reply | Threaded
Open this post in threaded view
|

Re: Tomcat Processing Timer Question

markt
On 08/09/2020 21:46, Eric Robinson wrote:
> Hi Mark --
>
> "If the request is split across multiple packets the timer starts when Tomcat reads the first byte of the request from the first packet.
> Tomcat stops the timer on a request after the last byte of the response has been accepted by the network stack."
>
> Now we're getting somewhere. If tomcat starts its timer when it reads the first byte of the client's request, and the request is split into multiple packets, doesn't it stand to reason that the timer would run longer when there are TCP retransmits?

For the request, it depends. If the retransmit is for part of the
request body and Tomcat hasn't read that far yet (or starting reading at
all) then it probably won't impact the processing time. If Tomcat is
performing a read and waiting for that packet then it will.

For the response, not unless the response is sfficiently big and the
retransmit sufficiently earlier in the response that the TCP buffers
fill and Tomcat is blocked from further writes.

Mark


>
> --Eric
>
>> -----Original Message-----
>> From: Mark Thomas <[hidden email]>
>> Sent: Tuesday, September 8, 2020 3:34 PM
>> To: [hidden email]
>> Subject: Re: Tomcat Processing Timer Question
>>
>> On 08/09/2020 21:19, Eric Robinson wrote:
>>> Hi Mark and Christopher,
>>>
>>> For clarification, suppose a client sends and HTTP POST request which
>> is bigger than the PMTU and has to be broken into multiple packets. It
>> sounds like you're saying that the request is buffered by the network stack,
>> and the stack does not send it up to tomcat until the full request is received.
>> That would make sense if every HTTP request is encapsulated in its own
>> separate TCP connection. Most of the time, that is not the case. A single
>> connection is held open and used for multiple HTTP requests. The network
>> stack has no understanding of anything above TCP, so it does not know when
>> an HTTP request complete. It must therefore deliver whatever it has, and it
>> would be up to tomcat to decide when the HTTP request is complete,
>> wouldn't it?
>>>
>>> If that is the case, tomcat could receive a partial HTTP request and
>> would have to wait for the rest before processing it. So when does tomcat
>> start its processing timer?
>>
>> Tomcat starts the processing timer as soon as Tomcat processes the first
>> bytes of the request. In practice, this means the network stack has to deliver
>> the data to Tomcat, the Poller fires a read event, a thread is allocated to
>> process that read event, any TLS handshake has completed and Tomcat has
>> read the first real byte of the request.
>>
>> If the request is split across multiple packets the timer starts when Tomcat
>> reads the first byte of the request from the first packet.
>>
>> Tomcat stops the timer on a request after the last byte of the response has
>> been accepted by the network stack.
>>
>> HTH,
>>
>> Mark
>>
>>>
>>>
>>>> -----Original Message-----
>>>> From: Christopher Schultz <[hidden email]>
>>>> Sent: Tuesday, September 8, 2020 1:19 PM
>>>> To: [hidden email]
>>>> Subject: Re: Tomcat Processing Timer Question
>>>>
>>> Eric,
>>>
>>> On 9/8/20 13:46, Eric Robinson wrote:
>>>>>> It is my understanding that the AccessLogValve %D field records the
>>>>>> time from when the last byte of the client's request is received to
>>>>>> when the last byte of the server's response is placed on the wire.
>>>>>> Is that correct? If so, would TCP retransmissions impact the timer?
>>>
>>> I'm not positive, but I believe Tomcat has zero visibility into that
>>> level of detail.
>>>
>>>>>> If there are connectivity issues between the client and server,
>>>>>> resulting in TCP retransmits, could that appear as higher response
>>>>>> times in the localhost_access logs?
>>>
>>> This would only happen if the re-transmissions were to cause network
>>> buffering in the OS such that the stream writes (at the Java level)
>>> were to block (and therefore "take time" instead of being essentially
>> instantaneous).
>>>
>>> -chris
>>>>
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: [hidden email]
>>>> For additional commands, e-mail: [hidden email]
>>>
>>> Disclaimer : This email and any files transmitted with it are
>> confidential and intended solely for intended recipients. If you are not the
>> named addressee you should not disseminate, distribute, copy or alter this
>> email. Any views or opinions presented in this email are solely those of the
>> author and might not represent those of Physician Select Management.
>> Warning: Although Physician Select Management has taken reasonable
>> precautions to ensure no viruses are present in this email, the company
>> cannot accept responsibility for any loss or damage arising from the use of
>> this email or attachments.
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: [hidden email]
>>> For additional commands, e-mail: [hidden email]
>>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [hidden email]
>> For additional commands, e-mail: [hidden email]
>
> Disclaimer : This email and any files transmitted with it are confidential and intended solely for intended recipients. If you are not the named addressee you should not disseminate, distribute, copy or alter this email. Any views or opinions presented in this email are solely those of the author and might not represent those of Physician Select Management. Warning: Although Physician Select Management has taken reasonable precautions to ensure no viruses are present in this email, the company cannot accept responsibility for any loss or damage arising from the use of this email or attachments.
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

RE: Tomcat Processing Timer Question

Eric Robinson
Mark --

Got it. So TCP retransmits can impact tomcat processing time under certain conditions, more likely due to issues with receiving requests from the client than sending responses.

-Eric

> -----Original Message-----
> From: Mark Thomas <[hidden email]>
> Sent: Tuesday, September 8, 2020 4:05 PM
> To: [hidden email]
> Subject: Re: Tomcat Processing Timer Question
>
> On 08/09/2020 21:46, Eric Robinson wrote:
> > Hi Mark --
> >
> > "If the request is split across multiple packets the timer starts when Tomcat
> reads the first byte of the request from the first packet.
> > Tomcat stops the timer on a request after the last byte of the response has
> been accepted by the network stack."
> >
> > Now we're getting somewhere. If tomcat starts its timer when it reads the
> first byte of the client's request, and the request is split into multiple packets,
> doesn't it stand to reason that the timer would run longer when there are
> TCP retransmits?
>
> For the request, it depends. If the retransmit is for part of the request body
> and Tomcat hasn't read that far yet (or starting reading at
> all) then it probably won't impact the processing time. If Tomcat is
> performing a read and waiting for that packet then it will.
>
> For the response, not unless the response is sfficiently big and the retransmit
> sufficiently earlier in the response that the TCP buffers fill and Tomcat is
> blocked from further writes.
>
> Mark
>
>
> >
> > --Eric
> >
> >> -----Original Message-----
> >> From: Mark Thomas <[hidden email]>
> >> Sent: Tuesday, September 8, 2020 3:34 PM
> >> To: [hidden email]
> >> Subject: Re: Tomcat Processing Timer Question
> >>
> >> On 08/09/2020 21:19, Eric Robinson wrote:
> >>> Hi Mark and Christopher,
> >>>
> >>> For clarification, suppose a client sends and HTTP POST request
> >>> which
> >> is bigger than the PMTU and has to be broken into multiple packets.
> >> It sounds like you're saying that the request is buffered by the
> >> network stack, and the stack does not send it up to tomcat until the full
> request is received.
> >> That would make sense if every HTTP request is encapsulated in its
> >> own separate TCP connection. Most of the time, that is not the case.
> >> A single connection is held open and used for multiple HTTP requests.
> >> The network stack has no understanding of anything above TCP, so it
> >> does not know when an HTTP request complete. It must therefore
> >> deliver whatever it has, and it would be up to tomcat to decide when
> >> the HTTP request is complete, wouldn't it?
> >>>
> >>> If that is the case, tomcat could receive a partial HTTP request and
> >> would have to wait for the rest before processing it. So when does
> >> tomcat start its processing timer?
> >>
> >> Tomcat starts the processing timer as soon as Tomcat processes the
> >> first bytes of the request. In practice, this means the network stack
> >> has to deliver the data to Tomcat, the Poller fires a read event, a
> >> thread is allocated to process that read event, any TLS handshake has
> >> completed and Tomcat has read the first real byte of the request.
> >>
> >> If the request is split across multiple packets the timer starts when
> >> Tomcat reads the first byte of the request from the first packet.
> >>
> >> Tomcat stops the timer on a request after the last byte of the
> >> response has been accepted by the network stack.
> >>
> >> HTH,
> >>
> >> Mark
> >>
> >>>
> >>>
> >>>> -----Original Message-----
> >>>> From: Christopher Schultz <[hidden email]>
> >>>> Sent: Tuesday, September 8, 2020 1:19 PM
> >>>> To: [hidden email]
> >>>> Subject: Re: Tomcat Processing Timer Question
> >>>>
> >>> Eric,
> >>>
> >>> On 9/8/20 13:46, Eric Robinson wrote:
> >>>>>> It is my understanding that the AccessLogValve %D field records
> >>>>>> the time from when the last byte of the client's request is
> >>>>>> received to when the last byte of the server's response is placed on
> the wire.
> >>>>>> Is that correct? If so, would TCP retransmissions impact the timer?
> >>>
> >>> I'm not positive, but I believe Tomcat has zero visibility into that
> >>> level of detail.
> >>>
> >>>>>> If there are connectivity issues between the client and server,
> >>>>>> resulting in TCP retransmits, could that appear as higher
> >>>>>> response times in the localhost_access logs?
> >>>
> >>> This would only happen if the re-transmissions were to cause network
> >>> buffering in the OS such that the stream writes (at the Java level)
> >>> were to block (and therefore "take time" instead of being
> >>> essentially
> >> instantaneous).
> >>>
> >>> -chris
> >>>>
> >>>> -------------------------------------------------------------------
> >>>> -- To unsubscribe, e-mail: [hidden email]
> >>>> For additional commands, e-mail: [hidden email]
> >>>
> >>> Disclaimer : This email and any files transmitted with it are
> >> confidential and intended solely for intended recipients. If you are
> >> not the named addressee you should not disseminate, distribute, copy
> >> or alter this email. Any views or opinions presented in this email
> >> are solely those of the author and might not represent those of Physician
> Select Management.
> >> Warning: Although Physician Select Management has taken reasonable
> >> precautions to ensure no viruses are present in this email, the
> >> company cannot accept responsibility for any loss or damage arising
> >> from the use of this email or attachments.
> >>>
> >>> --------------------------------------------------------------------
> >>> - To unsubscribe, e-mail: [hidden email]
> >>> For additional commands, e-mail: [hidden email]
> >>>
> >>
> >>
> >> ---------------------------------------------------------------------
> >> To unsubscribe, e-mail: [hidden email]
> >> For additional commands, e-mail: [hidden email]
> >
> > Disclaimer : This email and any files transmitted with it are confidential and
> intended solely for intended recipients. If you are not the named addressee
> you should not disseminate, distribute, copy or alter this email. Any views or
> opinions presented in this email are solely those of the author and might not
> represent those of Physician Select Management. Warning: Although
> Physician Select Management has taken reasonable precautions to ensure
> no viruses are present in this email, the company cannot accept responsibility
> for any loss or damage arising from the use of this email or attachments.
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: [hidden email]
> > For additional commands, e-mail: [hidden email]
> >
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]

Disclaimer : This email and any files transmitted with it are confidential and intended solely for intended recipients. If you are not the named addressee you should not disseminate, distribute, copy or alter this email. Any views or opinions presented in this email are solely those of the author and might not represent those of Physician Select Management. Warning: Although Physician Select Management has taken reasonable precautions to ensure no viruses are present in this email, the company cannot accept responsibility for any loss or damage arising from the use of this email or attachments.

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]
Reply | Threaded
Open this post in threaded view
|

Re: Tomcat Processing Timer Question

Christopher Schultz-2
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Eric,

On 9/8/20 17:29, Eric Robinson wrote:
> Got it. So TCP retransmits can impact tomcat processing time under
> certain conditions, more likely due to issues with receiving
> requests from the client than sending responses.
Well... buffering can happen either during the client-write phase or
the server-read phase or both.

Imagine a slow network like EDGE or something similar where the first
byte arrives at Tomcat's poller and it handed-off to the
request-processor (t=0 as far as Tomcat is concerned) and uploads a
large image over that EDGE connection. The OS won't allocate an
infinite input buffer, so at some point the Poller will get byte 0
when the client hasn't uploaded the complete request. It may still
take several seconds to upload all those bytes.

Imagine that the response is a transformed image so the response is
also large. The OS won't allocate an infinite output buffer, so at
some point the bytes will start streaming to the client (at a slow
rate). When the output buffer fills, your request-processing thread
will stall when calling ServletOutputStream.write() to write those
image bytes.

If your image transform is instantaneous, your access log will report
that the request took "a long time" relative to the amount of time
spent actually processing the request. Basically, you are just waiting
on I/O the entire time.

Are you have any specific problem you are trying to diagnose or fix?
Or are you just academically interested in what conditions might cause
"slow" request processing?

Hope that helps,
- -chris

>> -----Original Message----- From: Mark Thomas <[hidden email]>
>> Sent: Tuesday, September 8, 2020 4:05 PM To:
>> [hidden email] Subject: Re: Tomcat Processing Timer
>> Question
>>
>> On 08/09/2020 21:46, Eric Robinson wrote:
>>> Hi Mark --
>>>
>>> "If the request is split across multiple packets the timer
>>> starts when Tomcat
>> reads the first byte of the request from the first packet.
>>> Tomcat stops the timer on a request after the last byte of the
>>> response has
>> been accepted by the network stack."
>>>
>>> Now we're getting somewhere. If tomcat starts its timer when it
>>> reads the
>> first byte of the client's request, and the request is split into
>> multiple packets, doesn't it stand to reason that the timer would
>> run longer when there are TCP retransmits?
>>
>> For the request, it depends. If the retransmit is for part of the
>> request body and Tomcat hasn't read that far yet (or starting
>> reading at all) then it probably won't impact the processing
>> time. If Tomcat is performing a read and waiting for that packet
>> then it will.
>>
>> For the response, not unless the response is sfficiently big and
>> the retransmit sufficiently earlier in the response that the TCP
>> buffers fill and Tomcat is blocked from further writes.
>>
>> Mark
>>
>>
>>>
>>> --Eric
>>>
>>>> -----Original Message----- From: Mark Thomas
>>>> <[hidden email]> Sent: Tuesday, September 8, 2020 3:34 PM
>>>> To: [hidden email] Subject: Re: Tomcat Processing
>>>> Timer Question
>>>>
>>>> On 08/09/2020 21:19, Eric Robinson wrote:
>>>>> Hi Mark and Christopher,
>>>>>
>>>>> For clarification, suppose a client sends and HTTP POST
>>>>> request which
>>>> is bigger than the PMTU and has to be broken into multiple
>>>> packets. It sounds like you're saying that the request is
>>>> buffered by the network stack, and the stack does not send it
>>>> up to tomcat until the full
>> request is received.
>>>> That would make sense if every HTTP request is encapsulated
>>>> in its own separate TCP connection. Most of the time, that is
>>>> not the case. A single connection is held open and used for
>>>> multiple HTTP requests. The network stack has no
>>>> understanding of anything above TCP, so it does not know when
>>>> an HTTP request complete. It must therefore deliver whatever
>>>> it has, and it would be up to tomcat to decide when the HTTP
>>>> request is complete, wouldn't it?
>>>>>
>>>>> If that is the case, tomcat could receive a partial HTTP
>>>>> request and
>>>> would have to wait for the rest before processing it. So when
>>>> does tomcat start its processing timer?
>>>>
>>>> Tomcat starts the processing timer as soon as Tomcat
>>>> processes the first bytes of the request. In practice, this
>>>> means the network stack has to deliver the data to Tomcat,
>>>> the Poller fires a read event, a thread is allocated to
>>>> process that read event, any TLS handshake has completed and
>>>> Tomcat has read the first real byte of the request.
>>>>
>>>> If the request is split across multiple packets the timer
>>>> starts when Tomcat reads the first byte of the request from
>>>> the first packet.
>>>>
>>>> Tomcat stops the timer on a request after the last byte of
>>>> the response has been accepted by the network stack.
>>>>
>>>> HTH,
>>>>
>>>> Mark
>>>>
>>>>>
>>>>>
>>>>>> -----Original Message----- From: Christopher Schultz
>>>>>> <[hidden email]> Sent: Tuesday, September
>>>>>> 8, 2020 1:19 PM To: [hidden email] Subject: Re:
>>>>>> Tomcat Processing Timer Question
>>>>>>
>>>>> Eric,
>>>>>
>>>>> On 9/8/20 13:46, Eric Robinson wrote:
>>>>>>>> It is my understanding that the AccessLogValve %D
>>>>>>>> field records the time from when the last byte of the
>>>>>>>> client's request is received to when the last byte of
>>>>>>>> the server's response is placed on
>> the wire.
>>>>>>>> Is that correct? If so, would TCP retransmissions
>>>>>>>> impact the timer?
>>>>>
>>>>> I'm not positive, but I believe Tomcat has zero visibility
>>>>> into that level of detail.
>>>>>
>>>>>>>> If there are connectivity issues between the client
>>>>>>>> and server, resulting in TCP retransmits, could that
>>>>>>>> appear as higher response times in the
>>>>>>>> localhost_access logs?
>>>>>
>>>>> This would only happen if the re-transmissions were to
>>>>> cause network buffering in the OS such that the stream
>>>>> writes (at the Java level) were to block (and therefore
>>>>> "take time" instead of being essentially
>>>> instantaneous).
>>>>>
>>>>> -chris
>>>>>>
>>>>>> -----------------------------------------------------------------
- --
>>>>>>
>>>>>>
- -- To unsubscribe, e-mail: [hidden email]

>>>>>> For additional commands, e-mail:
>>>>>> [hidden email]
>>>>>
>>>>> Disclaimer : This email and any files transmitted with it
>>>>> are
>>>> confidential and intended solely for intended recipients. If
>>>> you are not the named addressee you should not disseminate,
>>>> distribute, copy or alter this email. Any views or opinions
>>>> presented in this email are solely those of the author and
>>>> might not represent those of Physician
>> Select Management.
>>>> Warning: Although Physician Select Management has taken
>>>> reasonable precautions to ensure no viruses are present in
>>>> this email, the company cannot accept responsibility for any
>>>> loss or damage arising from the use of this email or
>>>> attachments.
>>>>>
>>>>> ------------------------------------------------------------------
- --
>>>>>
>>>>>
- - To unsubscribe, e-mail: [hidden email]
>>>>> For additional commands, e-mail:
>>>>> [hidden email]
>>>>>
>>>>
>>>>
>>>> -------------------------------------------------------------------
- --
>>>>
>>>>
To unsubscribe, e-mail: [hidden email]

>>>> For additional commands, e-mail:
>>>> [hidden email]
>>>
>>> Disclaimer : This email and any files transmitted with it are
>>> confidential and
>> intended solely for intended recipients. If you are not the named
>> addressee you should not disseminate, distribute, copy or alter
>> this email. Any views or opinions presented in this email are
>> solely those of the author and might not represent those of
>> Physician Select Management. Warning: Although Physician Select
>> Management has taken reasonable precautions to ensure no viruses
>> are present in this email, the company cannot accept
>> responsibility for any loss or damage arising from the use of
>> this email or attachments.
>>>
>>> --------------------------------------------------------------------
- -
>>>
>>>
To unsubscribe, e-mail: [hidden email]
>>> For additional commands, e-mail: [hidden email]
>>>
>>
>>
>> ---------------------------------------------------------------------
>>
>>
To unsubscribe, e-mail: [hidden email]

>> For additional commands, e-mail: [hidden email]
>
> Disclaimer : This email and any files transmitted with it are
> confidential and intended solely for intended recipients. If you
> are not the named addressee you should not disseminate, distribute,
> copy or alter this email. Any views or opinions presented in this
> email are solely those of the author and might not represent those
> of Physician Select Management. Warning: Although Physician Select
> Management has taken reasonable precautions to ensure no viruses
> are present in this email, the company cannot accept responsibility
> for any loss or damage arising from the use of this email or
> attachments.
>
> ---------------------------------------------------------------------
>
>
To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>
-----BEGIN PGP SIGNATURE-----
Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/

iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl9YzWYACgkQHPApP6U8
pFgy9A//ZTrbPoaA1KLSikqNlxvs+ZXxonYWjDZ73vEvQLVj9P9NDV2/7IcUhe9k
xXZrJXBHQ36Hn4x15EDdJ4/puJQnvWY/+PdcYEHVKkExuUWorGKhb5Tst4hnpmC/
i0N3uOrzsePgxJeA22+mBSoSOVmw1dMCu9uWh3H6GmYVXjJKqe25lt0NO/+i7Pmp
hrcVusvnikDoBRjg74qKOPbCDfB1iaWBvhgVGfxhRu4OSne/DK0omxT1XtD0orCa
2B6ODVioMnyseliPTWARrzKV7kBV1SnbrAcqdbd4IwgluVwKmY4sa6vtdm8JLzXn
3HbMUyE1o6Z1QcVe0n6lHnlib+4bWxgkvY+4vPDMj3xgJJjhYxBbc9oNGhh51MNG
tTJpoBqY9Ro0NMQ0EiygnaZzu0ja9c47XBpBiDl4896Cub2kd3+n6uXPMtlk8YQ7
d63r2LS0y1OEFcgsAeIDXo0A3ehM3SFuWq/l6xDTVXctm2eCsNDfAXtwXGLPKxfq
H5oJMkwYkFdNok7YVbmBl4FEZpcQNzvEaSIljKpGm/MDbRKBeVEHXLjYTwpgGofu
gYC1bQWKUBKAQUIUc7Ys3SXYz7fFmFpYp9swACFNPvMz5yOYNJVaHaQ8BlIJ9ksT
AI9qx2ubIPhvIZoRO2nTDIx7eS9lY6DDArvW8XcOSgL4QW9vWrg=
=jdM/
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

RE: Tomcat Processing Timer Question

Eric Robinson
Hi Chris --

> Are you have any specific problem you are trying to diagnose or fix?
> Or are you just academically interested in what conditions might cause "slow"
> request processing?

A little of both. We've been running about 1500 instances of tomcat for the past 15 years. We're not tomcat experts by any means, but we're always looking to refine our understanding of tomcat performance. Like many people, we have custom scripts (ours are in python) that parse the jasper logs and produce a report that summarizes responsiveness and helps us isolate underperforming tomcat instances and JSP calls. Occasionally, we see evidence of chronic high latency in processing time when there is no indication of bottlenecks or problems in the servers themselves or the database back-ends. We theorize that client connectivity could be responsible.


> -----Original Message-----
> From: Christopher Schultz <[hidden email]>
> Sent: Wednesday, September 9, 2020 7:41 AM
> To: [hidden email]
> Subject: Re: Tomcat Processing Timer Question
>
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
>
> Eric,
>
> On 9/8/20 17:29, Eric Robinson wrote:
> > Got it. So TCP retransmits can impact tomcat processing time under
> > certain conditions, more likely due to issues with receiving requests
> > from the client than sending responses.
> Well... buffering can happen either during the client-write phase or the
> server-read phase or both.
>
> Imagine a slow network like EDGE or something similar where the first byte
> arrives at Tomcat's poller and it handed-off to the request-processor (t=0 as
> far as Tomcat is concerned) and uploads a large image over that EDGE
> connection. The OS won't allocate an infinite input buffer, so at some point
> the Poller will get byte 0 when the client hasn't uploaded the complete
> request. It may still take several seconds to upload all those bytes.
>
> Imagine that the response is a transformed image so the response is also
> large. The OS won't allocate an infinite output buffer, so at some point the
> bytes will start streaming to the client (at a slow rate). When the output
> buffer fills, your request-processing thread will stall when calling
> ServletOutputStream.write() to write those image bytes.
>
> If your image transform is instantaneous, your access log will report that the
> request took "a long time" relative to the amount of time spent actually
> processing the request. Basically, you are just waiting on I/O the entire time.
>
> Are you have any specific problem you are trying to diagnose or fix?
> Or are you just academically interested in what conditions might cause "slow"
> request processing?
>
> Hope that helps,
> - -chris
>
> >> -----Original Message----- From: Mark Thomas <[hidden email]>
> >> Sent: Tuesday, September 8, 2020 4:05 PM To:
> >> [hidden email] Subject: Re: Tomcat Processing Timer Question
> >>
> >> On 08/09/2020 21:46, Eric Robinson wrote:
> >>> Hi Mark --
> >>>
> >>> "If the request is split across multiple packets the timer starts
> >>> when Tomcat
> >> reads the first byte of the request from the first packet.
> >>> Tomcat stops the timer on a request after the last byte of the
> >>> response has
> >> been accepted by the network stack."
> >>>
> >>> Now we're getting somewhere. If tomcat starts its timer when it
> >>> reads the
> >> first byte of the client's request, and the request is split into
> >> multiple packets, doesn't it stand to reason that the timer would run
> >> longer when there are TCP retransmits?
> >>
> >> For the request, it depends. If the retransmit is for part of the
> >> request body and Tomcat hasn't read that far yet (or starting reading
> >> at all) then it probably won't impact the processing time. If Tomcat
> >> is performing a read and waiting for that packet then it will.
> >>
> >> For the response, not unless the response is sfficiently big and the
> >> retransmit sufficiently earlier in the response that the TCP buffers
> >> fill and Tomcat is blocked from further writes.
> >>
> >> Mark
> >>
> >>
> >>>
> >>> --Eric
> >>>
> >>>> -----Original Message----- From: Mark Thomas <[hidden email]>
> >>>> Sent: Tuesday, September 8, 2020 3:34 PM
> >>>> To: [hidden email] Subject: Re: Tomcat Processing Timer
> >>>> Question
> >>>>
> >>>> On 08/09/2020 21:19, Eric Robinson wrote:
> >>>>> Hi Mark and Christopher,
> >>>>>
> >>>>> For clarification, suppose a client sends and HTTP POST request
> >>>>> which
> >>>> is bigger than the PMTU and has to be broken into multiple packets.
> >>>> It sounds like you're saying that the request is buffered by the
> >>>> network stack, and the stack does not send it up to tomcat until
> >>>> the full
> >> request is received.
> >>>> That would make sense if every HTTP request is encapsulated in its
> >>>> own separate TCP connection. Most of the time, that is not the
> >>>> case. A single connection is held open and used for multiple HTTP
> >>>> requests. The network stack has no understanding of anything above
> >>>> TCP, so it does not know when an HTTP request complete. It must
> >>>> therefore deliver whatever it has, and it would be up to tomcat to
> >>>> decide when the HTTP request is complete, wouldn't it?
> >>>>>
> >>>>> If that is the case, tomcat could receive a partial HTTP request
> >>>>> and
> >>>> would have to wait for the rest before processing it. So when does
> >>>> tomcat start its processing timer?
> >>>>
> >>>> Tomcat starts the processing timer as soon as Tomcat processes the
> >>>> first bytes of the request. In practice, this means the network
> >>>> stack has to deliver the data to Tomcat, the Poller fires a read
> >>>> event, a thread is allocated to process that read event, any TLS
> >>>> handshake has completed and Tomcat has read the first real byte of
> >>>> the request.
> >>>>
> >>>> If the request is split across multiple packets the timer starts
> >>>> when Tomcat reads the first byte of the request from the first
> >>>> packet.
> >>>>
> >>>> Tomcat stops the timer on a request after the last byte of the
> >>>> response has been accepted by the network stack.
> >>>>
> >>>> HTH,
> >>>>
> >>>> Mark
> >>>>
> >>>>>
> >>>>>
> >>>>>> -----Original Message----- From: Christopher Schultz
> >>>>>> <[hidden email]> Sent: Tuesday, September 8, 2020
> >>>>>> 1:19 PM To: [hidden email] Subject: Re:
> >>>>>> Tomcat Processing Timer Question
> >>>>>>
> >>>>> Eric,
> >>>>>
> >>>>> On 9/8/20 13:46, Eric Robinson wrote:
> >>>>>>>> It is my understanding that the AccessLogValve %D field records
> >>>>>>>> the time from when the last byte of the client's request is
> >>>>>>>> received to when the last byte of the server's response is
> >>>>>>>> placed on
> >> the wire.
> >>>>>>>> Is that correct? If so, would TCP retransmissions impact the
> >>>>>>>> timer?
> >>>>>
> >>>>> I'm not positive, but I believe Tomcat has zero visibility into
> >>>>> that level of detail.
> >>>>>
> >>>>>>>> If there are connectivity issues between the client and server,
> >>>>>>>> resulting in TCP retransmits, could that appear as higher
> >>>>>>>> response times in the localhost_access logs?
> >>>>>
> >>>>> This would only happen if the re-transmissions were to cause
> >>>>> network buffering in the OS such that the stream writes (at the
> >>>>> Java level) were to block (and therefore "take time" instead of
> >>>>> being essentially
> >>>> instantaneous).
> >>>>>
> >>>>> -chris
> >>>>>>
> >>>>>> -----------------------------------------------------------------
> - --
> >>>>>>
> >>>>>>
> - -- To unsubscribe, e-mail: [hidden email]
> >>>>>> For additional commands, e-mail:
> >>>>>> [hidden email]
> >>>>>
> >>>>> Disclaimer : This email and any files transmitted with it are
> >>>> confidential and intended solely for intended recipients. If you
> >>>> are not the named addressee you should not disseminate, distribute,
> >>>> copy or alter this email. Any views or opinions presented in this
> >>>> email are solely those of the author and might not represent those
> >>>> of Physician
> >> Select Management.
> >>>> Warning: Although Physician Select Management has taken reasonable
> >>>> precautions to ensure no viruses are present in this email, the
> >>>> company cannot accept responsibility for any loss or damage arising
> >>>> from the use of this email or attachments.
> >>>>>
> >>>>> ------------------------------------------------------------------
> - --
> >>>>>
> >>>>>
> - - To unsubscribe, e-mail: [hidden email]
> >>>>> For additional commands, e-mail:
> >>>>> [hidden email]
> >>>>>
> >>>>
> >>>>
> >>>> -------------------------------------------------------------------
> - --
> >>>>
> >>>>
> To unsubscribe, e-mail: [hidden email]
> >>>> For additional commands, e-mail:
> >>>> [hidden email]
> >>>
> >>> Disclaimer : This email and any files transmitted with it are
> >>> confidential and
> >> intended solely for intended recipients. If you are not the named
> >> addressee you should not disseminate, distribute, copy or alter this
> >> email. Any views or opinions presented in this email are solely those
> >> of the author and might not represent those of Physician Select
> >> Management. Warning: Although Physician Select Management has taken
> >> reasonable precautions to ensure no viruses are present in this
> >> email, the company cannot accept responsibility for any loss or
> >> damage arising from the use of this email or attachments.
> >>>
> >>> --------------------------------------------------------------------
> - -
> >>>
> >>>
> To unsubscribe, e-mail: [hidden email]
> >>> For additional commands, e-mail: [hidden email]
> >>>
> >>
> >>
> >> ---------------------------------------------------------------------
> >>
> >>
> To unsubscribe, e-mail: [hidden email]
> >> For additional commands, e-mail: [hidden email]
> >
> > Disclaimer : This email and any files transmitted with it are
> > confidential and intended solely for intended recipients. If you are
> > not the named addressee you should not disseminate, distribute, copy
> > or alter this email. Any views or opinions presented in this email are
> > solely those of the author and might not represent those of Physician
> > Select Management. Warning: Although Physician Select Management has
> > taken reasonable precautions to ensure no viruses are present in this
> > email, the company cannot accept responsibility for any loss or damage
> > arising from the use of this email or attachments.
> >
> > ---------------------------------------------------------------------
> >
> >
> To unsubscribe, e-mail: [hidden email]
> > For additional commands, e-mail: [hidden email]
> >
> -----BEGIN PGP SIGNATURE-----
> Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/
>
> iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl9YzWYACgkQHPApP
> 6U8
> pFgy9A//ZTrbPoaA1KLSikqNlxvs+ZXxonYWjDZ73vEvQLVj9P9NDV2/7IcUhe9k
> xXZrJXBHQ36Hn4x15EDdJ4/puJQnvWY/+PdcYEHVKkExuUWorGKhb5Tst4hnp
> mC/
> i0N3uOrzsePgxJeA22+mBSoSOVmw1dMCu9uWh3H6GmYVXjJKqe25lt0NO/+i
> 7Pmp
> hrcVusvnikDoBRjg74qKOPbCDfB1iaWBvhgVGfxhRu4OSne/DK0omxT1XtD0or
> Ca
> 2B6ODVioMnyseliPTWARrzKV7kBV1SnbrAcqdbd4IwgluVwKmY4sa6vtdm8JLz
> Xn
> 3HbMUyE1o6Z1QcVe0n6lHnlib+4bWxgkvY+4vPDMj3xgJJjhYxBbc9oNGhh51M
> NG
> tTJpoBqY9Ro0NMQ0EiygnaZzu0ja9c47XBpBiDl4896Cub2kd3+n6uXPMtlk8YQ7
> d63r2LS0y1OEFcgsAeIDXo0A3ehM3SFuWq/l6xDTVXctm2eCsNDfAXtwXGLPK
> xfq
> H5oJMkwYkFdNok7YVbmBl4FEZpcQNzvEaSIljKpGm/MDbRKBeVEHXLjYTwpg
> Gofu
> gYC1bQWKUBKAQUIUc7Ys3SXYz7fFmFpYp9swACFNPvMz5yOYNJVaHaQ8BlIJ
> 9ksT
> AI9qx2ubIPhvIZoRO2nTDIx7eS9lY6DDArvW8XcOSgL4QW9vWrg=
> =jdM/
> -----END PGP SIGNATURE-----
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]

Disclaimer : This email and any files transmitted with it are confidential and intended solely for intended recipients. If you are not the named addressee you should not disseminate, distribute, copy or alter this email. Any views or opinions presented in this email are solely those of the author and might not represent those of Physician Select Management. Warning: Although Physician Select Management has taken reasonable precautions to ensure no viruses are present in this email, the company cannot accept responsibility for any loss or damage arising from the use of this email or attachments.

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]
Reply | Threaded
Open this post in threaded view
|

Re: Tomcat Processing Timer Question

Christopher Schultz-2
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Eric,

On 9/9/20 20:42, Eric Robinson wrote:
> Hi Chris --
>
>> Are you have any specific problem you are trying to diagnose or
>> fix? Or are you just academically interested in what conditions
>> might
cause "slow"

>> request processing?
>
> A little of both. We've been running about 1500 instances of
> tomcat for the past 15 years. We're not tomcat experts by any
> means, but we're always looking to refine our understanding of
> tomcat performance. Like many people, we have custom scripts (ours
> are in python) that parse the jasper logs and produce a report
> that summarizes responsiveness and helps us isolate underperforming
> tomcat instances and JSP calls. Occasionally, we see evidence of
> chronic high latency in processing time when there is no indication
> of bottlenecks or problems in the servers themselves or the
> database back-ends. We theorize that client connectivity could be
> responsible.
That is a reasonable conclusion.

You should also look at worker-thread availability. When you see these
"high latency" (which is usually a term reserved for I/O
characterization) events, do you have:

1. Available worker threads (from the executor thread pool)
2. Any other shared/limited resource (e.g. DB connection pool)

Also, are you seeing the otherwise unexpected slowness on each Tomcat
node, or are you seeing it at the load-balancer/multiplexer level?

- -chris

>> -----Original Message----- From: Christopher Schultz
>> <[hidden email]> Sent: Wednesday, September 9, 2020
>> 7:41 AM To: [hidden email] Subject: Re: Tomcat
>> Processing Timer Question
>>
> Eric,
>
> On 9/8/20 17:29, Eric Robinson wrote:
>>>> Got it. So TCP retransmits can impact tomcat processing time
>>>> under certain conditions, more likely due to issues with
>>>> receiving requests from the client than sending responses.
> Well... buffering can happen either during the client-write phase
> or the server-read phase or both.
>
> Imagine a slow network like EDGE or something similar where the
> first byte arrives at Tomcat's poller and it handed-off to the
> request-processor (t=0 as far as Tomcat is concerned) and uploads a
> large image over that EDGE connection. The OS won't allocate an
> infinite input buffer, so at some point the Poller will get byte 0
> when the client hasn't uploaded the complete request. It may still
> take several seconds to upload all those bytes.
>
> Imagine that the response is a transformed image so the response is
> also large. The OS won't allocate an infinite output buffer, so at
> some point the bytes will start streaming to the client (at a slow
> rate). When the output buffer fills, your request-processing thread
> will stall when calling ServletOutputStream.write() to write those
> image bytes.
>
> If your image transform is instantaneous, your access log will
> report that the request took "a long time" relative to the amount
> of time spent actually processing the request. Basically, you are
> just waiting on I/O the entire time.
>
> Are you have any specific problem you are trying to diagnose or
> fix? Or are you just academically interested in what conditions
> might cause "slow" request processing?
>
> Hope that helps, -chris
>
>>>>> -----Original Message----- From: Mark Thomas
>>>>> <[hidden email]> Sent: Tuesday, September 8, 2020 4:05 PM
>>>>> To: [hidden email] Subject: Re: Tomcat Processing
>>>>> Timer Question
>>>>>
>>>>> On 08/09/2020 21:46, Eric Robinson wrote:
>>>>>> Hi Mark --
>>>>>>
>>>>>> "If the request is split across multiple packets the
>>>>>> timer starts when Tomcat
>>>>> reads the first byte of the request from the first packet.
>>>>>> Tomcat stops the timer on a request after the last byte
>>>>>> of the response has
>>>>> been accepted by the network stack."
>>>>>>
>>>>>> Now we're getting somewhere. If tomcat starts its timer
>>>>>> when it reads the
>>>>> first byte of the client's request, and the request is
>>>>> split into multiple packets, doesn't it stand to reason
>>>>> that the timer would run longer when there are TCP
>>>>> retransmits?
>>>>>
>>>>> For the request, it depends. If the retransmit is for part
>>>>> of the request body and Tomcat hasn't read that far yet (or
>>>>> starting reading at all) then it probably won't impact the
>>>>> processing time. If Tomcat is performing a read and waiting
>>>>> for that packet then it will.
>>>>>
>>>>> For the response, not unless the response is sfficiently
>>>>> big and the retransmit sufficiently earlier in the response
>>>>> that the TCP buffers fill and Tomcat is blocked from
>>>>> further writes.
>>>>>
>>>>> Mark
>>>>>
>>>>>
>>>>>>
>>>>>> --Eric
>>>>>>
>>>>>>> -----Original Message----- From: Mark Thomas
>>>>>>> <[hidden email]> Sent: Tuesday, September 8, 2020
>>>>>>> 3:34 PM To: [hidden email] Subject: Re: Tomcat
>>>>>>> Processing Timer Question
>>>>>>>
>>>>>>> On 08/09/2020 21:19, Eric Robinson wrote:
>>>>>>>> Hi Mark and Christopher,
>>>>>>>>
>>>>>>>> For clarification, suppose a client sends and HTTP
>>>>>>>> POST request which
>>>>>>> is bigger than the PMTU and has to be broken into
>>>>>>> multiple packets. It sounds like you're saying that the
>>>>>>> request is buffered by the network stack, and the stack
>>>>>>> does not send it up to tomcat until the full
>>>>> request is received.
>>>>>>> That would make sense if every HTTP request is
>>>>>>> encapsulated in its own separate TCP connection. Most
>>>>>>> of the time, that is not the case. A single connection
>>>>>>> is held open and used for multiple HTTP requests. The
>>>>>>> network stack has no understanding of anything above
>>>>>>> TCP, so it does not know when an HTTP request complete.
>>>>>>> It must therefore deliver whatever it has, and it would
>>>>>>> be up to tomcat to decide when the HTTP request is
>>>>>>> complete, wouldn't it?
>>>>>>>>
>>>>>>>> If that is the case, tomcat could receive a partial
>>>>>>>> HTTP request and
>>>>>>> would have to wait for the rest before processing it.
>>>>>>> So when does tomcat start its processing timer?
>>>>>>>
>>>>>>> Tomcat starts the processing timer as soon as Tomcat
>>>>>>> processes the first bytes of the request. In practice,
>>>>>>> this means the network stack has to deliver the data to
>>>>>>> Tomcat, the Poller fires a read event, a thread is
>>>>>>> allocated to process that read event, any TLS handshake
>>>>>>> has completed and Tomcat has read the first real byte
>>>>>>> of the request.
>>>>>>>
>>>>>>> If the request is split across multiple packets the
>>>>>>> timer starts when Tomcat reads the first byte of the
>>>>>>> request from the first packet.
>>>>>>>
>>>>>>> Tomcat stops the timer on a request after the last byte
>>>>>>> of the response has been accepted by the network
>>>>>>> stack.
>>>>>>>
>>>>>>> HTH,
>>>>>>>
>>>>>>> Mark
>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>> -----Original Message----- From: Christopher
>>>>>>>>> Schultz <[hidden email]> Sent:
>>>>>>>>> Tuesday, September 8, 2020 1:19 PM To:
>>>>>>>>> [hidden email] Subject: Re: Tomcat
>>>>>>>>> Processing Timer Question
>>>>>>>>>
>>>>>>>> Eric,
>>>>>>>>
>>>>>>>> On 9/8/20 13:46, Eric Robinson wrote:
>>>>>>>>>>> It is my understanding that the AccessLogValve
>>>>>>>>>>> %D field records the time from when the last
>>>>>>>>>>> byte of the client's request is received to
>>>>>>>>>>> when the last byte of the server's response is
>>>>>>>>>>> placed on
>>>>> the wire.
>>>>>>>>>>> Is that correct? If so, would TCP
>>>>>>>>>>> retransmissions impact the timer?
>>>>>>>>
>>>>>>>> I'm not positive, but I believe Tomcat has zero
>>>>>>>> visibility into that level of detail.
>>>>>>>>
>>>>>>>>>>> If there are connectivity issues between the
>>>>>>>>>>> client and server, resulting in TCP
>>>>>>>>>>> retransmits, could that appear as higher
>>>>>>>>>>> response times in the localhost_access logs?
>>>>>>>>
>>>>>>>> This would only happen if the re-transmissions were
>>>>>>>> to cause network buffering in the OS such that the
>>>>>>>> stream writes (at the Java level) were to block (and
>>>>>>>> therefore "take time" instead of being essentially
>>>>>>> instantaneous).
>>>>>>>>
>>>>>>>> -chris
>>>>>>>>>
>>>>>>>>> --------------------------------------------------------------
- ---
>>
>>
>>>>>>>>>
- ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [hidden email] For
>> additional commands, e-mail: [hidden email]
>
> Disclaimer : This email and any files transmitted with it are
confidential and intended solely for intended recipients. If you are
not the named addressee you should not disseminate, distribute, copy
or alter this email. Any views or opinions presented in this email are
solely those of the author and might not represent those of Physician
Select Management. Warning: Although Physician Select Management has
taken reasonable precautions to ensure no viruses are present in this
email, the company cannot accept responsibility for any loss or damage
arising from the use of this email or attachments.
>
> ---------------------------------------------------------------------
>
>
To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>
-----BEGIN PGP SIGNATURE-----
Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/

iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl9aKOoACgkQHPApP6U8
pFjeSA/+K0/me8yZTGMcVfCvMrPLTlQENqXNGcTsF8ILgMpz3YVpmqSPjPGGg1W0
xdX8U5saN3T7dLqlLLxGUDoa+YYsIqzQnTYccxqIN4RdBtThem0QKZPrwgNYSSm8
ogzpSXhzG1/aQCMPs0RGFN8vdvCX7gAnqtYd5988b4RFgnMBfrA3Z87cc0kxcsJc
nr33L/aMpMf6HJIkX11TPTuQrF8TlplQx2y2RoNxRRdEslHNaxJyDsU03C237On8
7AjicqkRNxJuDbZOu6bCq2em1gi7u22syi50B2X5HRWNyK9PaVhST5ccx34Gref5
y84DUh8Gqaae7AGdj7aY1LeE+enKM3gIjsOaqNDk2X4Q+B05VOhxFwSAo79DNZY+
WX6liPTuO6y6tFW0UmtREnxm6turfzRGfTPUVzGEyAMqP9rBxPuxS7KS39VL7N7n
/44zHi30R1beJ8I0fFh5+PRKm9eZsbDniLA5as2oL4Vu2as6e1XmjK+GRn4Pb9U9
jdG+ySFsROeNFg2hkyAXpacLp0PyL1RuiUsACIy8vCTP7jRprrK3aAuV6d4W0pbq
+llMh3NVpVzkVGKc5Nc2ydRb5OstQajUmr21u1jH3ze6Rk+I3SmJ2TwWYq4UnpTI
z9NweMjRR/RzRsJKDGF7HtMMzva5ywNLiUdawNytE5mKT0buobs=
=67LH
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

RE: Tomcat Processing Timer Question

Eric Robinson
Chris --


> You should also look at worker-thread availability. When you see these "high
> latency" (which is usually a term reserved for I/O
> characterization) events, do you have:
>
> 1. Available worker threads (from the executor thread pool)
> 2. Any other shared/limited resource (e.g. DB connection pool)
>

Good thought. I should mention that the hosted application is canned, and is the same for all tomcat instances, with only minor variations in version between them. User workflow is also similar. Over the years we've developed a good feel for expected performance and resource utilization based on the user count per instance. So when one instance exhibits anomalous performance, we tend to go right to networking issues.

> Also, are you seeing the otherwise unexpected slowness on each Tomcat
> node, or are you seeing it at the load-balancer/multiplexer level?
>

We run multi-tenanted servers, with many instances of tomcat on each server. We've never seen issues at the load-balancer. Very occasionally, there might be a problem at the server level. When that happens, all instances on that server may become sluggish. What I'm talking about in this thread are cases where only one instance on a server is showing slowness in its jasper logs. Also, we typically do not see the same slowness when we test the application locally from the same network. I've had my eye on TCP retransmits as a possible culprit for a while, but I just didn't know for sure if my understanding of the tomcat processing timer is correct.

--Eric



> -----Original Message-----
> From: Christopher Schultz <[hidden email]>
> Sent: Thursday, September 10, 2020 8:24 AM
> To: [hidden email]
> Subject: Re: Tomcat Processing Timer Question
>
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
>
> Eric,
>
> On 9/9/20 20:42, Eric Robinson wrote:
> > Hi Chris --
> >
> >> Are you have any specific problem you are trying to diagnose or fix?
> >> Or are you just academically interested in what conditions might
> cause "slow"
> >> request processing?
> >
> > A little of both. We've been running about 1500 instances of tomcat
> > for the past 15 years. We're not tomcat experts by any means, but
> > we're always looking to refine our understanding of tomcat
> > performance. Like many people, we have custom scripts (ours are in
> > python) that parse the jasper logs and produce a report that
> > summarizes responsiveness and helps us isolate underperforming tomcat
> > instances and JSP calls. Occasionally, we see evidence of chronic high
> > latency in processing time when there is no indication of bottlenecks
> > or problems in the servers themselves or the database back-ends. We
> > theorize that client connectivity could be responsible.
> That is a reasonable conclusion.
>
> You should also look at worker-thread availability. When you see these "high
> latency" (which is usually a term reserved for I/O
> characterization) events, do you have:
>
> 1. Available worker threads (from the executor thread pool) 2. Any other
> shared/limited resource (e.g. DB connection pool)
>
> Also, are you seeing the otherwise unexpected slowness on each Tomcat
> node, or are you seeing it at the load-balancer/multiplexer level?
>
> - -chris
>
> >> -----Original Message----- From: Christopher Schultz
> >> <[hidden email]> Sent: Wednesday, September 9, 2020
> >> 7:41 AM To: [hidden email] Subject: Re: Tomcat Processing
> >> Timer Question
> >>
> > Eric,
> >
> > On 9/8/20 17:29, Eric Robinson wrote:
> >>>> Got it. So TCP retransmits can impact tomcat processing time under
> >>>> certain conditions, more likely due to issues with receiving
> >>>> requests from the client than sending responses.
> > Well... buffering can happen either during the client-write phase or
> > the server-read phase or both.
> >
> > Imagine a slow network like EDGE or something similar where the first
> > byte arrives at Tomcat's poller and it handed-off to the
> > request-processor (t=0 as far as Tomcat is concerned) and uploads a
> > large image over that EDGE connection. The OS won't allocate an
> > infinite input buffer, so at some point the Poller will get byte 0
> > when the client hasn't uploaded the complete request. It may still
> > take several seconds to upload all those bytes.
> >
> > Imagine that the response is a transformed image so the response is
> > also large. The OS won't allocate an infinite output buffer, so at
> > some point the bytes will start streaming to the client (at a slow
> > rate). When the output buffer fills, your request-processing thread
> > will stall when calling ServletOutputStream.write() to write those
> > image bytes.
> >
> > If your image transform is instantaneous, your access log will report
> > that the request took "a long time" relative to the amount of time
> > spent actually processing the request. Basically, you are just waiting
> > on I/O the entire time.
> >
> > Are you have any specific problem you are trying to diagnose or fix?
> > Or are you just academically interested in what conditions might cause
> > "slow" request processing?
> >
> > Hope that helps, -chris
> >
> >>>>> -----Original Message----- From: Mark Thomas <[hidden email]>
> >>>>> Sent: Tuesday, September 8, 2020 4:05 PM
> >>>>> To: [hidden email] Subject: Re: Tomcat Processing Timer
> >>>>> Question
> >>>>>
> >>>>> On 08/09/2020 21:46, Eric Robinson wrote:
> >>>>>> Hi Mark --
> >>>>>>
> >>>>>> "If the request is split across multiple packets the timer starts
> >>>>>> when Tomcat
> >>>>> reads the first byte of the request from the first packet.
> >>>>>> Tomcat stops the timer on a request after the last byte of the
> >>>>>> response has
> >>>>> been accepted by the network stack."
> >>>>>>
> >>>>>> Now we're getting somewhere. If tomcat starts its timer when it
> >>>>>> reads the
> >>>>> first byte of the client's request, and the request is split into
> >>>>> multiple packets, doesn't it stand to reason that the timer would
> >>>>> run longer when there are TCP retransmits?
> >>>>>
> >>>>> For the request, it depends. If the retransmit is for part of the
> >>>>> request body and Tomcat hasn't read that far yet (or starting
> >>>>> reading at all) then it probably won't impact the processing time.
> >>>>> If Tomcat is performing a read and waiting for that packet then it
> >>>>> will.
> >>>>>
> >>>>> For the response, not unless the response is sfficiently big and
> >>>>> the retransmit sufficiently earlier in the response that the TCP
> >>>>> buffers fill and Tomcat is blocked from further writes.
> >>>>>
> >>>>> Mark
> >>>>>
> >>>>>
> >>>>>>
> >>>>>> --Eric
> >>>>>>
> >>>>>>> -----Original Message----- From: Mark Thomas
> <[hidden email]>
> >>>>>>> Sent: Tuesday, September 8, 2020
> >>>>>>> 3:34 PM To: [hidden email] Subject: Re: Tomcat
> >>>>>>> Processing Timer Question
> >>>>>>>
> >>>>>>> On 08/09/2020 21:19, Eric Robinson wrote:
> >>>>>>>> Hi Mark and Christopher,
> >>>>>>>>
> >>>>>>>> For clarification, suppose a client sends and HTTP POST request
> >>>>>>>> which
> >>>>>>> is bigger than the PMTU and has to be broken into multiple
> >>>>>>> packets. It sounds like you're saying that the request is
> >>>>>>> buffered by the network stack, and the stack does not send it up
> >>>>>>> to tomcat until the full
> >>>>> request is received.
> >>>>>>> That would make sense if every HTTP request is encapsulated in
> >>>>>>> its own separate TCP connection. Most of the time, that is not
> >>>>>>> the case. A single connection is held open and used for multiple
> >>>>>>> HTTP requests. The network stack has no understanding of
> >>>>>>> anything above TCP, so it does not know when an HTTP request
> >>>>>>> complete.
> >>>>>>> It must therefore deliver whatever it has, and it would be up to
> >>>>>>> tomcat to decide when the HTTP request is complete, wouldn't it?
> >>>>>>>>
> >>>>>>>> If that is the case, tomcat could receive a partial HTTP
> >>>>>>>> request and
> >>>>>>> would have to wait for the rest before processing it.
> >>>>>>> So when does tomcat start its processing timer?
> >>>>>>>
> >>>>>>> Tomcat starts the processing timer as soon as Tomcat processes
> >>>>>>> the first bytes of the request. In practice, this means the
> >>>>>>> network stack has to deliver the data to Tomcat, the Poller
> >>>>>>> fires a read event, a thread is allocated to process that read
> >>>>>>> event, any TLS handshake has completed and Tomcat has read the
> >>>>>>> first real byte of the request.
> >>>>>>>
> >>>>>>> If the request is split across multiple packets the timer starts
> >>>>>>> when Tomcat reads the first byte of the request from the first
> >>>>>>> packet.
> >>>>>>>
> >>>>>>> Tomcat stops the timer on a request after the last byte of the
> >>>>>>> response has been accepted by the network stack.
> >>>>>>>
> >>>>>>> HTH,
> >>>>>>>
> >>>>>>> Mark
> >>>>>>>
> >>>>>>>>
> >>>>>>>>
> >>>>>>>>> -----Original Message----- From: Christopher Schultz
> >>>>>>>>> <[hidden email]> Sent:
> >>>>>>>>> Tuesday, September 8, 2020 1:19 PM To:
> >>>>>>>>> [hidden email] Subject: Re: Tomcat Processing Timer
> >>>>>>>>> Question
> >>>>>>>>>
> >>>>>>>> Eric,
> >>>>>>>>
> >>>>>>>> On 9/8/20 13:46, Eric Robinson wrote:
> >>>>>>>>>>> It is my understanding that the AccessLogValve %D field
> >>>>>>>>>>> records the time from when the last byte of the client's
> >>>>>>>>>>> request is received to when the last byte of the server's
> >>>>>>>>>>> response is placed on
> >>>>> the wire.
> >>>>>>>>>>> Is that correct? If so, would TCP retransmissions impact the
> >>>>>>>>>>> timer?
> >>>>>>>>
> >>>>>>>> I'm not positive, but I believe Tomcat has zero visibility into
> >>>>>>>> that level of detail.
> >>>>>>>>
> >>>>>>>>>>> If there are connectivity issues between the client and
> >>>>>>>>>>> server, resulting in TCP retransmits, could that appear as
> >>>>>>>>>>> higher response times in the localhost_access logs?
> >>>>>>>>
> >>>>>>>> This would only happen if the re-transmissions were to cause
> >>>>>>>> network buffering in the OS such that the stream writes (at the
> >>>>>>>> Java level) were to block (and therefore "take time" instead of
> >>>>>>>> being essentially
> >>>>>>> instantaneous).
> >>>>>>>>
> >>>>>>>> -chris
> >>>>>>>>>
> >>>>>>>>> --------------------------------------------------------------
> - ---
> >>
> >>
> >>>>>>>>>
> - ---------------------------------------------------------------------
> >> To unsubscribe, e-mail: [hidden email] For
> >> additional commands, e-mail: [hidden email]
> >
> > Disclaimer : This email and any files transmitted with it are
> confidential and intended solely for intended recipients. If you are not the
> named addressee you should not disseminate, distribute, copy or alter this
> email. Any views or opinions presented in this email are solely those of the
> author and might not represent those of Physician Select Management.
> Warning: Although Physician Select Management has taken reasonable
> precautions to ensure no viruses are present in this email, the company
> cannot accept responsibility for any loss or damage arising from the use of
> this email or attachments.
> >
> > ---------------------------------------------------------------------
> >
> >
> To unsubscribe, e-mail: [hidden email]
> > For additional commands, e-mail: [hidden email]
> >
> -----BEGIN PGP SIGNATURE-----
> Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/
>
> iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl9aKOoACgkQHPApP
> 6U8
> pFjeSA/+K0/me8yZTGMcVfCvMrPLTlQENqXNGcTsF8ILgMpz3YVpmqSPjPGG
> g1W0
> xdX8U5saN3T7dLqlLLxGUDoa+YYsIqzQnTYccxqIN4RdBtThem0QKZPrwgNYSS
> m8
> ogzpSXhzG1/aQCMPs0RGFN8vdvCX7gAnqtYd5988b4RFgnMBfrA3Z87cc0kxcsJ
> c
> nr33L/aMpMf6HJIkX11TPTuQrF8TlplQx2y2RoNxRRdEslHNaxJyDsU03C237On8
> 7AjicqkRNxJuDbZOu6bCq2em1gi7u22syi50B2X5HRWNyK9PaVhST5ccx34Gref
> 5
> y84DUh8Gqaae7AGdj7aY1LeE+enKM3gIjsOaqNDk2X4Q+B05VOhxFwSAo79D
> NZY+
> WX6liPTuO6y6tFW0UmtREnxm6turfzRGfTPUVzGEyAMqP9rBxPuxS7KS39VL7
> N7n
> /44zHi30R1beJ8I0fFh5+PRKm9eZsbDniLA5as2oL4Vu2as6e1XmjK+GRn4Pb9U9
> jdG+ySFsROeNFg2hkyAXpacLp0PyL1RuiUsACIy8vCTP7jRprrK3aAuV6d4W0pb
> q
> +llMh3NVpVzkVGKc5Nc2ydRb5OstQajUmr21u1jH3ze6Rk+I3SmJ2TwWYq4Un
> pTI
> z9NweMjRR/RzRsJKDGF7HtMMzva5ywNLiUdawNytE5mKT0buobs=
> =67LH
> -----END PGP SIGNATURE-----
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]

Disclaimer : This email and any files transmitted with it are confidential and intended solely for intended recipients. If you are not the named addressee you should not disseminate, distribute, copy or alter this email. Any views or opinions presented in this email are solely those of the author and might not represent those of Physician Select Management. Warning: Although Physician Select Management has taken reasonable precautions to ensure no viruses are present in this email, the company cannot accept responsibility for any loss or damage arising from the use of this email or attachments.

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]
Reply | Threaded
Open this post in threaded view
|

Re: Tomcat Processing Timer Question

Christopher Schultz-2
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Eric,

On 9/10/20 15:29, Eric Robinson wrote:

> Chris --
>
>
>> You should also look at worker-thread availability. When you see
>>  these "high latency" (which is usually a term reserved for I/O
>> characterization) events, do you have:>> 1. Available worker
>> threads (from the executor thread pool) 2. Any other
>> shared/limited resource (e.g. DB connection pool)
>>
>
> Good thought. I should mention that the hosted application is
> canned, and is the same for all tomcat instances, with only minor
> variations in version between them. User workflow is also similar.
> Over the years we've developed a good feel for expected
> performance and resource utilization based on the user count per
> instance. So when one instance exhibits anomalous performance, we
> tend to go right to networking issues.
>
>> Also, are you seeing the otherwise unexpected slowness on each
>> Tomcat node, or are you seeing it at the
>> load-balancer/multiplexer level?
>>
>
> We run multi-tenanted servers, with many instances of tomcat on
> each server. We've never seen issues at the load-balancer.

What I mean is, are you measuring the request at the Tomcat level, or at
the load-balancer level? If you are watching at the lb, then your lb
might pick a "busy" Tomcat and the request has to "wait in line" before
processing even begins. If you sample at the Tomcat level, you'll see no
discernible slowdown because the time "waiting in line" does not count.

> Very occasionally, there might be a problem at the server level.
> When that happens, all instances on that server may become
> sluggish. What I'm talking about in this thread are cases where
> only one instance on a server is showing slowness in its jasper
> logs. Also, we typically do not see the same slowness when we test
> the application locally from the same network. I've had my eye on
> TCP retransmits as a possible culprit for a while, but I just
> didn't know for sure if my understanding of the tomcat processing
> timer is correct.
I hope we've cleared that up for you, then.

You might also want to read about "buffer bloat" if you aren't already
familiar with that term.

- -chris
-----BEGIN PGP SIGNATURE-----
Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/

iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl9aiH4ACgkQHPApP6U8
pFiFfBAAvuUbRXK+iDDy7lLsw6eplMFrXXDbkxzwtSNafvdGlDWmcPWwdazZwhQ+
TJ0pzkUwf3/RBslu/oORJYelYKhpUJLodj0Y85ZtbuKBcU2JpKk1uueJ/aqnmVFK
9yep3ReYdggEXQ3JNb1VeI4ASdEhFWoFw8pc6DAcJZ4K2JaUtGKrtoWG8n+oEXos
kmthl9Dm9ge3edLimd7TPTx11iODi6pX3ddJ+uRh7qmvXZp4wVyX8W+hkKiOhUQM
hokUd8RruXQm6wut5m+JSO6eLHqkKUBiLspzlz1x/Y4cuaqAlC8Pl5y9NFTuLK3e
gFJeDmBUthN2y5h9KNKW5r+Gf9bKpuv1+kw7CIaNoFv2JxCGTmfL3VKM+Bp/rh7J
1SbshsTW6ffo5hKRNJUJKvxry3uUvzrss0AYe338tJ1QA+sHuXHsN8ZVtY3b+51O
HBOYf3pgIPsSd6zXkjaSRoOAhVc9G5sbJHx8ycQt+yAyVvXEUwrqeeRbsJeADk2s
reaizm9WvO2kHSqP93ANNYe1QJ+rw9b5og0uoCE8x9eO+czRHbJ7LFF6/rvX+6Pn
TIYB7AHyV8P3PHpHtBGIgaNfnvIYbqx/hzxJpLlpNEcS2zARfi1YCnuNtbiH0KU/
AKkBx5FnZvwclCA3qK2oqBnSEcBUFz2yobq4wAy//qwgL2gEFNc=
=mcpm
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: Tomcat Processing Timer Question

Eric Robinson
I'm not sure what you mean by measuring at the load balancer level. We're using the jasper logs and those only exist on the tomcat server itself. I must be misunderstanding your meaning.

Get Outlook for Android<https://aka.ms/ghei36>

________________________________
From: Christopher Schultz <[hidden email]>
Sent: Thursday, September 10, 2020 3:11:43 PM
To: [hidden email] <[hidden email]>
Subject: Re: Tomcat Processing Timer Question

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Eric,

On 9/10/20 15:29, Eric Robinson wrote:

> Chris --
>
>
>> You should also look at worker-thread availability. When you see
>>  these "high latency" (which is usually a term reserved for I/O
>> characterization) events, do you have:>> 1. Available worker
>> threads (from the executor thread pool) 2. Any other
>> shared/limited resource (e.g. DB connection pool)
>>
>
> Good thought. I should mention that the hosted application is
> canned, and is the same for all tomcat instances, with only minor
> variations in version between them. User workflow is also similar.
> Over the years we've developed a good feel for expected
> performance and resource utilization based on the user count per
> instance. So when one instance exhibits anomalous performance, we
> tend to go right to networking issues.
>
>> Also, are you seeing the otherwise unexpected slowness on each
>> Tomcat node, or are you seeing it at the
>> load-balancer/multiplexer level?
>>
>
> We run multi-tenanted servers, with many instances of tomcat on
> each server. We've never seen issues at the load-balancer.

What I mean is, are you measuring the request at the Tomcat level, or at
the load-balancer level? If you are watching at the lb, then your lb
might pick a "busy" Tomcat and the request has to "wait in line" before
processing even begins. If you sample at the Tomcat level, you'll see no
discernible slowdown because the time "waiting in line" does not count.

> Very occasionally, there might be a problem at the server level.
> When that happens, all instances on that server may become
> sluggish. What I'm talking about in this thread are cases where
> only one instance on a server is showing slowness in its jasper
> logs. Also, we typically do not see the same slowness when we test
> the application locally from the same network. I've had my eye on
> TCP retransmits as a possible culprit for a while, but I just
> didn't know for sure if my understanding of the tomcat processing
> timer is correct.
I hope we've cleared that up for you, then.

You might also want to read about "buffer bloat" if you aren't already
familiar with that term.

- -chris
-----BEGIN PGP SIGNATURE-----
Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/

iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl9aiH4ACgkQHPApP6U8
pFiFfBAAvuUbRXK+iDDy7lLsw6eplMFrXXDbkxzwtSNafvdGlDWmcPWwdazZwhQ+
TJ0pzkUwf3/RBslu/oORJYelYKhpUJLodj0Y85ZtbuKBcU2JpKk1uueJ/aqnmVFK
9yep3ReYdggEXQ3JNb1VeI4ASdEhFWoFw8pc6DAcJZ4K2JaUtGKrtoWG8n+oEXos
kmthl9Dm9ge3edLimd7TPTx11iODi6pX3ddJ+uRh7qmvXZp4wVyX8W+hkKiOhUQM
hokUd8RruXQm6wut5m+JSO6eLHqkKUBiLspzlz1x/Y4cuaqAlC8Pl5y9NFTuLK3e
gFJeDmBUthN2y5h9KNKW5r+Gf9bKpuv1+kw7CIaNoFv2JxCGTmfL3VKM+Bp/rh7J
1SbshsTW6ffo5hKRNJUJKvxry3uUvzrss0AYe338tJ1QA+sHuXHsN8ZVtY3b+51O
HBOYf3pgIPsSd6zXkjaSRoOAhVc9G5sbJHx8ycQt+yAyVvXEUwrqeeRbsJeADk2s
reaizm9WvO2kHSqP93ANNYe1QJ+rw9b5og0uoCE8x9eO+czRHbJ7LFF6/rvX+6Pn
TIYB7AHyV8P3PHpHtBGIgaNfnvIYbqx/hzxJpLlpNEcS2zARfi1YCnuNtbiH0KU/
AKkBx5FnZvwclCA3qK2oqBnSEcBUFz2yobq4wAy//qwgL2gEFNc=
=mcpm
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Disclaimer : This email and any files transmitted with it are confidential and intended solely for intended recipients. If you are not the named addressee you should not disseminate, distribute, copy or alter this email. Any views or opinions presented in this email are solely those of the author and might not represent those of Physician Select Management. Warning: Although Physician Select Management has taken reasonable precautions to ensure no viruses are present in this email, the company cannot accept responsibility for any loss or damage arising from the use of this email or attachments.
Reply | Threaded
Open this post in threaded view
|

Re: Tomcat Processing Timer Question

Martin Grigorov
Hi,

On Sat, Sep 12, 2020, 02:57 Eric Robinson <[hidden email]> wrote:

> I'm not sure what you mean by measuring at the load balancer level. We're
> using the jasper logs and those only exist on the tomcat server itself. I
> must be misunderstanding your meaning.
>

He meant to use the LB's logs for the same.
What software do you use for load balancing?


> Get Outlook for Android<https://aka.ms/ghei36>
>
> ________________________________
> From: Christopher Schultz <[hidden email]>
> Sent: Thursday, September 10, 2020 3:11:43 PM
> To: [hidden email] <[hidden email]>
> Subject: Re: Tomcat Processing Timer Question
>
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
>
> Eric,
>
> On 9/10/20 15:29, Eric Robinson wrote:
> > Chris --
> >
> >
> >> You should also look at worker-thread availability. When you see
> >>  these "high latency" (which is usually a term reserved for I/O
> >> characterization) events, do you have:>> 1. Available worker
> >> threads (from the executor thread pool) 2. Any other
> >> shared/limited resource (e.g. DB connection pool)
> >>
> >
> > Good thought. I should mention that the hosted application is
> > canned, and is the same for all tomcat instances, with only minor
> > variations in version between them. User workflow is also similar.
> > Over the years we've developed a good feel for expected
> > performance and resource utilization based on the user count per
> > instance. So when one instance exhibits anomalous performance, we
> > tend to go right to networking issues.
> >
> >> Also, are you seeing the otherwise unexpected slowness on each
> >> Tomcat node, or are you seeing it at the
> >> load-balancer/multiplexer level?
> >>
> >
> > We run multi-tenanted servers, with many instances of tomcat on
> > each server. We've never seen issues at the load-balancer.
>
> What I mean is, are you measuring the request at the Tomcat level, or at
> the load-balancer level? If you are watching at the lb, then your lb
> might pick a "busy" Tomcat and the request has to "wait in line" before
> processing even begins. If you sample at the Tomcat level, you'll see no
> discernible slowdown because the time "waiting in line" does not count.
>
> > Very occasionally, there might be a problem at the server level.
> > When that happens, all instances on that server may become
> > sluggish. What I'm talking about in this thread are cases where
> > only one instance on a server is showing slowness in its jasper
> > logs. Also, we typically do not see the same slowness when we test
> > the application locally from the same network. I've had my eye on
> > TCP retransmits as a possible culprit for a while, but I just
> > didn't know for sure if my understanding of the tomcat processing
> > timer is correct.
> I hope we've cleared that up for you, then.
>
> You might also want to read about "buffer bloat" if you aren't already
> familiar with that term.
>
> - -chris
> -----BEGIN PGP SIGNATURE-----
> Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/
>
> iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl9aiH4ACgkQHPApP6U8
> pFiFfBAAvuUbRXK+iDDy7lLsw6eplMFrXXDbkxzwtSNafvdGlDWmcPWwdazZwhQ+
> TJ0pzkUwf3/RBslu/oORJYelYKhpUJLodj0Y85ZtbuKBcU2JpKk1uueJ/aqnmVFK
> 9yep3ReYdggEXQ3JNb1VeI4ASdEhFWoFw8pc6DAcJZ4K2JaUtGKrtoWG8n+oEXos
> kmthl9Dm9ge3edLimd7TPTx11iODi6pX3ddJ+uRh7qmvXZp4wVyX8W+hkKiOhUQM
> hokUd8RruXQm6wut5m+JSO6eLHqkKUBiLspzlz1x/Y4cuaqAlC8Pl5y9NFTuLK3e
> gFJeDmBUthN2y5h9KNKW5r+Gf9bKpuv1+kw7CIaNoFv2JxCGTmfL3VKM+Bp/rh7J
> 1SbshsTW6ffo5hKRNJUJKvxry3uUvzrss0AYe338tJ1QA+sHuXHsN8ZVtY3b+51O
> HBOYf3pgIPsSd6zXkjaSRoOAhVc9G5sbJHx8ycQt+yAyVvXEUwrqeeRbsJeADk2s
> reaizm9WvO2kHSqP93ANNYe1QJ+rw9b5og0uoCE8x9eO+czRHbJ7LFF6/rvX+6Pn
> TIYB7AHyV8P3PHpHtBGIgaNfnvIYbqx/hzxJpLlpNEcS2zARfi1YCnuNtbiH0KU/
> AKkBx5FnZvwclCA3qK2oqBnSEcBUFz2yobq4wAy//qwgL2gEFNc=
> =mcpm
> -----END PGP SIGNATURE-----
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [hidden email]
> For additional commands, e-mail: [hidden email]
>
> Disclaimer : This email and any files transmitted with it are confidential
> and intended solely for intended recipients. If you are not the named
> addressee you should not disseminate, distribute, copy or alter this email.
> Any views or opinions presented in this email are solely those of the
> author and might not represent those of Physician Select Management.
> Warning: Although Physician Select Management has taken reasonable
> precautions to ensure no viruses are present in this email, the company
> cannot accept responsibility for any loss or damage arising from the use of
> this email or attachments.
>
Reply | Threaded
Open this post in threaded view
|

RE: Tomcat Processing Timer Question

Eric Robinson
We use LVS+ldirectord. It does not provide the kind of logs you're referring to.

> -----Original Message-----
> From: Martin Grigorov <[hidden email]>
> Sent: Saturday, September 12, 2020 12:03 AM
> To: Tomcat Users List <[hidden email]>
> Subject: Re: Tomcat Processing Timer Question
>
> Hi,
>
> On Sat, Sep 12, 2020, 02:57 Eric Robinson <[hidden email]>
> wrote:
>
> > I'm not sure what you mean by measuring at the load balancer level.
> > We're using the jasper logs and those only exist on the tomcat server
> > itself. I must be misunderstanding your meaning.
> >
>
> He meant to use the LB's logs for the same.
> What software do you use for load balancing?
>
>
> > Get Outlook for Android<https://aka.ms/ghei36>
> >
> > ________________________________
> > From: Christopher Schultz <[hidden email]>
> > Sent: Thursday, September 10, 2020 3:11:43 PM
> > To: [hidden email] <[hidden email]>
> > Subject: Re: Tomcat Processing Timer Question
> >
> > -----BEGIN PGP SIGNED MESSAGE-----
> > Hash: SHA256
> >
> > Eric,
> >
> > On 9/10/20 15:29, Eric Robinson wrote:
> > > Chris --
> > >
> > >
> > >> You should also look at worker-thread availability. When you see
> > >> these "high latency" (which is usually a term reserved for I/O
> > >> characterization) events, do you have:>> 1. Available worker
> > >> threads (from the executor thread pool) 2. Any other shared/limited
> > >> resource (e.g. DB connection pool)
> > >>
> > >
> > > Good thought. I should mention that the hosted application is
> > > canned, and is the same for all tomcat instances, with only minor
> > > variations in version between them. User workflow is also similar.
> > > Over the years we've developed a good feel for expected performance
> > > and resource utilization based on the user count per instance. So
> > > when one instance exhibits anomalous performance, we tend to go
> > > right to networking issues.
> > >
> > >> Also, are you seeing the otherwise unexpected slowness on each
> > >> Tomcat node, or are you seeing it at the load-balancer/multiplexer
> > >> level?
> > >>
> > >
> > > We run multi-tenanted servers, with many instances of tomcat on each
> > > server. We've never seen issues at the load-balancer.
> >
> > What I mean is, are you measuring the request at the Tomcat level, or
> > at the load-balancer level? If you are watching at the lb, then your
> > lb might pick a "busy" Tomcat and the request has to "wait in line"
> > before processing even begins. If you sample at the Tomcat level,
> > you'll see no discernible slowdown because the time "waiting in line" does
> not count.
> >
> > > Very occasionally, there might be a problem at the server level.
> > > When that happens, all instances on that server may become sluggish.
> > > What I'm talking about in this thread are cases where only one
> > > instance on a server is showing slowness in its jasper logs. Also,
> > > we typically do not see the same slowness when we test the
> > > application locally from the same network. I've had my eye on TCP
> > > retransmits as a possible culprit for a while, but I just didn't
> > > know for sure if my understanding of the tomcat processing timer is
> > > correct.
> > I hope we've cleared that up for you, then.
> >
> > You might also want to read about "buffer bloat" if you aren't already
> > familiar with that term.
> >
> > - -chris
> > -----BEGIN PGP SIGNATURE-----
> > Comment: Using GnuPG with Thunderbird - https://www.enigmail.net/
> >
> >
> iQIzBAEBCAAdFiEEMmKgYcQvxMe7tcJcHPApP6U8pFgFAl9aiH4ACgkQHPApP6
> U8
> >
> pFiFfBAAvuUbRXK+iDDy7lLsw6eplMFrXXDbkxzwtSNafvdGlDWmcPWwdazZw
> hQ+
> >
> TJ0pzkUwf3/RBslu/oORJYelYKhpUJLodj0Y85ZtbuKBcU2JpKk1uueJ/aqnmVFK
> >
> 9yep3ReYdggEXQ3JNb1VeI4ASdEhFWoFw8pc6DAcJZ4K2JaUtGKrtoWG8n+oE
> Xos
> >
> kmthl9Dm9ge3edLimd7TPTx11iODi6pX3ddJ+uRh7qmvXZp4wVyX8W+hkKiOh
> UQM
> >
> hokUd8RruXQm6wut5m+JSO6eLHqkKUBiLspzlz1x/Y4cuaqAlC8Pl5y9NFTuLK3
> e
> >
> gFJeDmBUthN2y5h9KNKW5r+Gf9bKpuv1+kw7CIaNoFv2JxCGTmfL3VKM+Bp/
> rh7J
> >
> 1SbshsTW6ffo5hKRNJUJKvxry3uUvzrss0AYe338tJ1QA+sHuXHsN8ZVtY3b+51
> O
> >
> HBOYf3pgIPsSd6zXkjaSRoOAhVc9G5sbJHx8ycQt+yAyVvXEUwrqeeRbsJeADk
> 2s
> >
> reaizm9WvO2kHSqP93ANNYe1QJ+rw9b5og0uoCE8x9eO+czRHbJ7LFF6/rvX+6
> Pn
> > TIYB7AHyV8P3PHpHtBGIgaNfnvIYbqx/hzxJpLlpNEcS2zARfi1YCnuNtbiH0KU/
> > AKkBx5FnZvwclCA3qK2oqBnSEcBUFz2yobq4wAy//qwgL2gEFNc=
> > =mcpm
> > -----END PGP SIGNATURE-----
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: [hidden email]
> > For additional commands, e-mail: [hidden email]
> >
> > Disclaimer : This email and any files transmitted with it are
> > confidential and intended solely for intended recipients. If you are
> > not the named addressee you should not disseminate, distribute, copy or
> alter this email.
> > Any views or opinions presented in this email are solely those of the
> > author and might not represent those of Physician Select Management.
> > Warning: Although Physician Select Management has taken reasonable
> > precautions to ensure no viruses are present in this email, the
> > company cannot accept responsibility for any loss or damage arising
> > from the use of this email or attachments.
> >
Disclaimer : This email and any files transmitted with it are confidential and intended solely for intended recipients. If you are not the named addressee you should not disseminate, distribute, copy or alter this email. Any views or opinions presented in this email are solely those of the author and might not represent those of Physician Select Management. Warning: Although Physician Select Management has taken reasonable precautions to ensure no viruses are present in this email, the company cannot accept responsibility for any loss or damage arising from the use of this email or attachments.

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]