Start measuring Ping latency closer to sending request and remove Stopwatch instance by eduardobr · Pull Request #1714 · StackExchange/StackExchange.Redis (original) (raw)

As I understand it, a subtle but important difference here is in system clock changes. For example if a system clock is off and get corrected by an NTP sync (this happens pretty often), it'll introduce incorrect timings, since 2 absolute timestamps, as opposed to Stopwatch (which is relative) will not be relatively correct. It could show too much time or even negative time, when corrections occur.

As an example, let's say a command starts just after midnight:

[System time: 00:00:05.500] Command starts (`timingMessage.CreatedTimestamp` is set)
[System time: 00:00:06.000] NTP time corrects, it's actually [00:00:04] (clock drift was 2 seconds)
[System time: 00:00:05.000] Command finishes

...according to profiling, this command took -500ms, because that's that the diff in the 2 timestamps told us.

I agree on potential efficiency here, but I think we are trading correctness (no non-high performance counter systems), which is a hard sell when it comes to profiling. But maybe, the number of systems affected would be so low we're okay with that.

Thoughts? Suggestions?