trafficserver-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Sudheer Vinukonda <sudheervinuko...@yahoo.com>
Subject Re: detailed transaction time logs
Date Tue, 22 Nov 2016 19:52:37 GMT
ATS by default supports connection pools on the Origin side (meaning, idle (persistent) connections
are reused for subsequent requests). This may be the reason why you probably see the server
header read done in no time.

For tuning the transfer time, if you are not already using it, you may enable chunked encoding
(HTTP/1.1+). Also, is your origin physically outside the ATS box or are you running it on
the same host? There are some tcp socket settings you can tune in ats records config (e.g
so_linger, nagle etc).

- Sudheer

> On Nov 22, 2016, at 10:51 AM, Mateusz Zajakala <zajakala@gmail.com> wrote:
> 
> Thanks,
> 
> it seems that for problematic transactions all time is spent between "server_read_header_done"
(almost always at 0.000) and "server_close" (even 5.000 and more). My guess is that I need
to look into low-level network performance (drivers/tcp bottlenecks), because all time is
spent transfering HTTP data?
> 
> One thing is not clear though, how is it possible that "server_read_header_done" is always
at 0 and it is AFTER http response headers are already parsed? This could mean that connection
to origin is fast and only transfering the actual content (file) takes time, but my origin
(httpd 2.4.6) reports that it took max 1 microsecond to serve the file (all files are served
from RAM).
> 
> Any ideas where I should look to find what takes so much time on those occastional slow
requests?
> 
> Thanks a lot!
> Mat
> 
> 
> 
> 
>> On Mon, Nov 21, 2016 at 5:41 PM, Miles Libbey <mlibbey@apache.org> wrote:
>> In ATS 6+ you use custom logging to log Milestone data about
>> transactions ("{Milestone field name}ms" and {Milestone field
>> name1-Milestone field name2}msdms). Milestones are here:
>> https://docs.trafficserver.apache.org/en/latest/developer-guide/api/functions/TSHttpTxnMilestoneGet.en.html#c.TSHttpTxnMilestoneGet
>> So, I think Origin time to first byte would be
>> %<{TS_MILESTONE_SERVER_FIRST_READ-TS_MILESTONE_SERVER_FIRST_CONNECT}msdms>
>> 
>> miles
>> 
>> On Mon, Nov 21, 2016 at 5:58 AM, Mateusz Zajakala <zajakala@gmail.com> wrote:
>> > Sudheer,
>> >
>> > this is exactly what I was looking for. Many thanks!
>> >
>> > Mateusz
>> >
>> > On Mon, Nov 21, 2016 at 2:39 PM, Sudheer Vinukonda
>> > <sudheervinukonda@yahoo.com> wrote:
>> >>
>> >> You may try turning on slow logs that record more detailed individual
>> >> milestones (time taken for each internal state during the transaction
>> >> lifecycle) for transactions that take longer than a specified duration.
>> >>
>> >>
>> >> https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.config.en.html#proxy-config-http-slow-log-threshold
>> >>
>> >> - Sudheer
>> >>
>> >> On Nov 21, 2016, at 3:19 AM, Mateusz Zajakala <zajakala@gmail.com>
wrote:
>> >>
>> >> Hi,
>> >>
>> >> I'm trying to debug a reverse proxy which occasionally takes longer than
>> >> usual time to serve a client. I can see in the logs e.g. that the request
>> >> took 10 times the usual amount of time for similar file, however I can't
say
>> >> whether it was caused by the origin side or client side (i.e. was the issue
>> >> when retrieving content from origin or serving it to client).
>> >>
>> >> Is there any way to get more detailed logs for response time? I'm looking
>> >> at 'ttms' value, is there any log to indicate "origin connection time",
>> >> "time between sending request to origin and finishing reading response",
>> >> "time between starting and finishing serving response to client" etc. That
>> >> would help with optimizing...
>> >>
>> >> If there is nothing in the logs, maybe there is some useful statistic I
>> >> should look into?
>> >>
>> >> Thanks
>> >> Mateusz
>> >
>> >
> 

Mime
View raw message