Re: NetLog viewer timestamps

[Eric Roman]

Thanks Albert! I will try to address the documentation issue separately (we are also planning a refresh of the viewer app in the coming months).

But in the meantime here is a quick summary:

Start Time: 

This is when the first event for the source was emitted - it appears at the very top, formatted in a human readable fashion.

st=TIME_SINCE_SOURCE

This appears on the left of each event. TIME_SINCE_SOURCE is the number of milliseconds since the first event of the source. The very first event is therefore always st=0. This is useful to eyeball how long things took relative to the source.

t=TIME_SINCE_CAPTURE

This appears on the left of each event, and means the number of milliseconds since the start of the log capture. It is helpful to measure elapsed time between any two events, since the frame of reference does not change between sources.

dt=ELAPSED_TIME_BEGIN_END

This appears tot he right of an event, and means the number of milliseconds between the "start" and "end" phase. Some events are categorized as the start of something, and have a corresponding end, which is used to pretty-print a hierarchal view and notate the dt=

The main caveat with time in NetLogs is to not rely too much on it mapping to a real point in time. In particular, NetLog captures use Chrome's base::TimeTicks as it cares more about measuring elapsed durations than current system time. The consequences of this are:

  * The absolute timestamp you see is estimated by taking the relative ticks since the start of the capture, and the system clock time at the start of the capture. So for instance if the system clock jumped forward by 1 hour partway through a log, that will not be reflected in how we display subsequent timestamps. 

  * Chrome's ticks implementation is inconsistent across platforms with regard to how time is measured during system sleep. If you put the computer to sleep/suspend partway through a capture, and then resume, you will get different results of time for Windows vs Unix. The difference is whether time ticks proceed during sleep (in which case elapsed times are skewed, but absolute timestamps are correct), or whether time is frozen in which case elapsed time is more reasonable, however absolute timestamps are now shifted.

On Fri, Aug 14, 2020 at 6:56 AM Albert Bihler <albert...@gmail.com> wrote:

Hi,

I am a little confused how to get the exact timestamp for events
in netlog-viewer. I have uploaded a screenshot to https://imgur.com/dFNrNb7

There is a start time that is human readable but I have no clue how to
interpret the "t=" and "st=" values.

All I found was some documentation here:
https://www.chromium.org/developers/design-documents/network-stack/netlog

Regading time is states:

"The time in milliseconds when the event occurred.

This is a time tick count and not a unix timestamp. However
it is easily convertible given the time tick offset (time
ticks are independent of system clock adjustments, guaranteeing
 that our timestamps don't go backwards)
..."

Well for me it isn't obvious how to convert the ticks to time and I am not
even sure whether the ticks refer to t= or st= in newlog-viewer. Could
somebody give me a hint?

Best regards,
Albert

--
You received this message because you are subscribed to the Google Groups "net-dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email to net-dev+u...@chromium.org.
To view this discussion on the web visit https://groups.google.com/a/chromium.org/d/msgid/net-dev/86d68d53-bcf1-4811-a0c9-49c91e66fdabn%40chromium.org.