trafficserver-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Mateusz Zajakala <zajak...@gmail.com>
Subject Re: detailed transaction time logs
Date Tue, 22 Nov 2016 18:51:02 GMT
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