Hello Karas,
Thank you for your reply.
I did not mention, but that was exactly my last test to understand those <ttms>
times being loged.
Not surprising, the obtained values from
<{TS_MILESTONE_UA_CLOSE-TS_MILESTONE_UA_BEGIN}msdms> are exactly the same as
<ttms>.
And so, I’m still puzzled… if no one noted that issue already… For sure its me
doing something wrong…
PS: I didn’t found any issue on github about it.
Thanks again
Nuno Baeta
From: Walt Karas <[email protected]>
Sent: 1 de junho de 2023 16:06
To: Nuno Jose Baeta <[email protected]>
Subject: Fwd: [E] How to log total server response time
CAUTION: This email was originated from outside NOS organization. Do not click
links or open attachments unless you recognize the sender and know the content
is safe.
---------- Forwarded message ---------
From: Walt Karas <[email protected]<mailto:[email protected]>>
Date: Mon, May 29, 2023 at 11:45 AM
Subject: Re: [E] How to log total server response time
To: <[email protected]<mailto:[email protected]>>
Maybe you want: %<{TS_MILESTONE_UA_CLOSE-TS_MILESTONE_UA_BEGIN}msdms>
See the note under:
https://docs.trafficserver.apache.org/admin-guide/logging/formatting.en.html#timestamps-and-durations
On Mon, May 29, 2023 at 9:42 AM Nuno Jose Baeta
<[email protected]<mailto:[email protected]>> wrote:
Hello,
We are using ATS v8.1 and would like to understand better how to log the total
time spent in a HTTP transaction (including the full body transfer time)
towards the client.
For that, we are using the field %<ttms>, for the Client-Proxy Connection time.
Looking at the ATS documentation, the meaning for <ttms> is:
“Time in milliseconds spent by Traffic Server processing the entire client
request. Measured from the time the connection between the client and Traffic
Server proxy was established until the last byte of the proxy response was
delivered to the client.”
At this moment, our logging.yaml for the access.log is the following:
format: '%<cqtd>:%<cqtt> "%<cqtx>" %<shn> %<shi> %<sssc> %<pfsc> %<stms>
%<ttms>'
Log example:
2023-05-29:14:20:41 "GET
http://trafficserver/media/stream_421342430.cmfv<https://urldefense.com/v3/__http:/trafficserver/media/stream_421342430.cmfv__;!!Op6eflyXZCqGR5I!GUMlpWKUbqXtSyyjQipM66jFsagWIGIiNLPqEquheCvVkbeYPqhdYlYml2Y0VHOwEmdAtq6iMYvYzEeyIHk$>
HTTP/1.1" origin2 0 200 FIN 18 19
But comparing to client browser network timings, we see times of hundreds of
milliseconds. For the above example, the total time was 506ms.
HTTP Timing breakdown:
Connection setup: 1.85
Request sent: 30.88
Wait response: 49.44
Content Download: 423.36
TOTAL: 505.53 ms
I cannot find any correlation.
Could you tell if it is possible to achieve this?
Thanks in advance.
Nuno Baeta
[email protected]<mailto:[email protected]>
