subscriber: lighter-weight timestamp recording #254
Comments
hawkw
added
C-subscriber
|
For what it's worth: As far as the conversion to There's likely a way, or ways, to compensate for this if conversion to an UTC-anchored time is required, and I'm happy to try and provide an honest description of what |
Hmm, I'm a bit bummed about this, as I would have kind of preferred to be able to do it without requiring an additional dependency on
In this case, we don't actually need a UTC-anchored timestamp at all; all these timestamps are only used to calculate durations. The only reason we send timestamps on the wire rather than durations is so that the console UI can continue to calculate durations across updates. It's possible what we really should be doing, rather than using protobuf's timestamp type in the wire format, is sending our own monotonic, non-UTC instant type instead...but I was lazy and didn't want to write that. |
|
I guess |
## Motivation Currently, if compiled in debug mode, the `console-subscriber` crate's `PollStats::end_poll` function will panic if a poll duration is negative (i.e. if the poll's end timestamp occurred before its start timestamp). Because the console currently uses non-monotonic `SystemTime`s rather than monotonic `Instant`s (due to serialization requirements), this means we are potentially succeptible to clock skew adjustments. If one occurs during a poll, and the system clock goes backwards, we may panic here. This isn't great! ## Solution This branch fixes the panic by removing the assertions, and changing `end_poll` to simply bail and print a warning rather than panicking when encountering a negative poll duration. This is a short-term solution; a better long-term solution would be to change `console-subscriber` to use monotonic `Instant`s rather than non-monotonic `SystemTime`s (as discussed [here][1] and [here][2]). Fixes #286 [1]:#254 [2]: #286 (comment)
…287) ## Motivation Currently, if compiled in debug mode, the `console-subscriber` crate's `PollStats::end_poll` function will panic if a poll duration is negative (i.e. if the poll's end timestamp occurred before its start timestamp). Because the console currently uses non-monotonic `SystemTime`s rather than monotonic `Instant`s (due to serialization requirements), this means we are potentially succeptible to clock skew adjustments. If one occurs during a poll, and the system clock goes backwards, we may panic here. This isn't great! ## Solution This branch fixes the panic by removing the assertions, and changing `end_poll` to simply bail and print a warning rather than panicking when encountering a negative poll duration. This is a short-term solution; a better long-term solution would be to change `console-subscriber` to use monotonic `Instant`s rather than non-monotonic `SystemTime`s (as discussed [here][1] and [here][2]). Fixes #286 [1]:#254 [2]: #286 (comment)
## Motivation Currently, the `console-subscriber` crate records all timestamps as `SystemTime`s. This is because they are eventually sent over the wire as protobuf `Timestamp`s, which can be constructed from a `SystemTime`. They cannot be constructed from `Instant`s, because `Instant` is opaque, and does not expose access to the underlying OS time. However, using `SystemTime` is not really correct for our use case. We only use timestamps for calculating durations; we only have to serialize them because some durations are calculated in the console UI rather than in-process. We *don't* need timestamps that are globally consistent with a shared timebase, but we *do* need monotonicity --- using `SystemTime` leaves us vulnerable to clock skew, if (for example), an NTP clock skew adjustment causes the system clock to run backwards far enough that a poll appears to end "before" it started (as in issue #286). If we were using monotonic `Instant`s, all polls should always have positive durations, but with `SystemTime`s, this isn't necessarily the case. Furthermore, `Instant::now()` may have less performance overhead than `SystemTime::now()`, at least on some platforms. ## Solution This branch changes `console-subscriber` to always take timestamps using `Instant::now()` rather than using `SystemTime::now()`, and store all timestamps as `Instant`s. In order to convert these `Instant`s into `SystemTime`s that can be sent over the wire, we construct a reference `TimeAnchor`, consisting of a paired `Instant` and `SystemTime` recorded at the same time when the `ConsoleLayer` is constructed. We can then construct "system times" that are monotonic, by calculating the duration between a given `Instant` and the anchor `Instant`, and adding that duration to the anchor `SystemTime`. These are not *real* system timestamps, as they will never run backwards if the system clock is adjusted; they are relative only to the base process start time as recorded by the anchor. However, they *are* monotonic, and all durations calculated from them will be reasonable. This is part of the change I proposed in #254. I'm not going to close that issue yet, though, as it also described potentially switching to use the `quanta` crate rather than `std::time::Instant` to reduce the overhead of recording monotonic timestamps. Fixes #286
## Motivation Currently, the `console-subscriber` crate records all timestamps as `SystemTime`s. This is because they are eventually sent over the wire as protobuf `Timestamp`s, which can be constructed from a `SystemTime`. They cannot be constructed from `Instant`s, because `Instant` is opaque, and does not expose access to the underlying OS time. However, using `SystemTime` is not really correct for our use case. We only use timestamps for calculating durations; we only have to serialize them because some durations are calculated in the console UI rather than in-process. We *don't* need timestamps that are globally consistent with a shared timebase, but we *do* need monotonicity --- using `SystemTime` leaves us vulnerable to clock skew, if (for example), an NTP clock skew adjustment causes the system clock to run backwards far enough that a poll appears to end "before" it started (as in issue #286). If we were using monotonic `Instant`s, all polls should always have positive durations, but with `SystemTime`s, this isn't necessarily the case. Furthermore, `Instant::now()` may have less performance overhead than `SystemTime::now()`, at least on some platforms. ## Solution This branch changes `console-subscriber` to always take timestamps using `Instant::now()` rather than using `SystemTime::now()`, and store all timestamps as `Instant`s. In order to convert these `Instant`s into `SystemTime`s that can be sent over the wire, we construct a reference `TimeAnchor`, consisting of a paired `Instant` and `SystemTime` recorded at the same time when the `ConsoleLayer` is constructed. We can then construct "system times" that are monotonic, by calculating the duration between a given `Instant` and the anchor `Instant`, and adding that duration to the anchor `SystemTime`. These are not *real* system timestamps, as they will never run backwards if the system clock is adjusted; they are relative only to the base process start time as recorded by the anchor. However, they *are* monotonic, and all durations calculated from them will be reasonable. This is part of the change I proposed in #254. I'm not going to close that issue yet, though, as it also described potentially switching to use the `quanta` crate rather than `std::time::Instant` to reduce the overhead of recording monotonic timestamps. Fixes #286
Currently,
console-subscriberrecords every timestamp by callingSystemTime::now(). This is not necessarily the most efficient way to record a timestamp; everySystemTime::now()call requires a system call.Also, perhaps more importantly, I don't think using system timestamps is really the most correct approach. The main reason the console records timestamps at all is to calculate durations. However, the system clock can go backwards; it's not guaranteed to be monotonic. This means that durations calculated using
SystemTimemight be incorrect. We should really be using monotonic time, such asInstants.I believe the main reason
console-subscriberdoesn't currently use monotonic timestamps is that it sends timestamps on the wire usingprost_types::Timestamp, which has aFrom<SystemTime>impl. SinceInstants are opaque, there's noFrom<Instant>implementation for protobuf timestamps.One solution might be to switch to recording timestamps using
Instants, but anchor them against a fixedSystemTime, so that they can be converted intoSystemTimes. The way we would do this is by recording a fixedSystemTimeandInstantpair when theConsoleLayeris created. Then, when we need to serialize anInstanttimestamp, we would take the duration elapsed between thatInstantand the "anchor" instant. Since the anchorInstantand anchorSystemTimerepresent (nearly) the same timestamp, we could then convert theInstanttimestamp into aSystemTimefor serialization, by adding the elapsed duration from the anchorInstantto the anchorSystemTime.Another option we might want to consider is using the
quantacrate by @tobz. This would offer a few advantages. In particular,quanta::Instantdoes provide anInto<prost_types::Timestamp>implementation. Additionally,quanta::Instants can be converted intou64s (unlike std's instants). This would allow them to be stored in atomics, which could be beneficial for #238. Finally,quantamay introduce less overhead comparedstd::time::Instant, at least on x86 platforms, where it usesrdtscThe text was updated successfully, but these errors were encountered: