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 <[email protected]> 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 <[email protected]> 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 <[email protected]> wrote: >> > Sudheer, >> > >> > this is exactly what I was looking for. Many thanks! >> > >> > Mateusz >> > >> > On Mon, Nov 21, 2016 at 2:39 PM, Sudheer Vinukonda >> > <[email protected]> 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 <[email protected]> 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 >> > >> > >
