the current poll must have started before it ended

[gwik]

I keep hitting the debug_assert:

thread 'tokio-runtime-worker' panicked at 'the current poll must have started before it ended; this is a `console-subscriber` bug!', /home/gwik/.cargo/registry/src/git.luolix.top-1ecc6299db9ec823/console-subscriber-0.1.2/src/stats.rs:449:13

After some investigations, it's simply the system clock going backward.

thread 'tokio-runtime-worker' panicked at 'the current poll must have started before it ended; this is a `console-subscriber` bug!
at      = SystemTime { tv_sec: 1645112066, tv_nsec: 136896974 }
started = SystemTime { tv_sec: 1645112066, tv_nsec: 136906896 }
result  = Err(SystemTimeError(9.922µs))

This is probably due to clock skew adjustements (I run a NTP daemon systemd-timesyncd).
I guess there is a reason to use SystemTime instead of Instant ?

[hawkw]

Yes, this is likely due to clock skew. Note that that assertion is only enabled in debug mode, in release mode, we will simply ignore any poll durations that are incorrect due to clock skew:

console/console-subscriber/src/stats.rs

Lines 449 to 451 in a2202f7

	let elapsed = last_poll_started.and_then(|started| at.duration_since(started).ok());
	debug_assert!(elapsed.is_some(), "the current poll must have started before it ended; this is a `console-subscriber` bug!");
	if let Some(elapsed) = elapsed {

A short-term solution for the panic would be to simply remove that assertion. We would then just ignore any polls that have negative durations, which is not ideal, but fixes the panic.

The longer-term solution is to transition the console to use monotonic time. Currently, we use SystemTimes rather than Instants because it's necessary to send timestamps on the wire, so we have to be able to access their actual values in order to serialize them. Instant is opaque, so it cannot easily be used for this. However, using SystemTime is not really correct either; these timestamps are only used for calculating durations, so it is much more important for them to be monotonic than to be globally comparable outside of the process. What we should probably do is switch to an approach where we take a single SystemTime timestamp and corresponding Instant when the process is started as an anchor, and record all actual timestamps using monotonic Instants. Then, we can calculate the elapsed time between the anchor Instant and the timestamp of a particular event, and add that duration to the anchored SystemTime. This allows us to generate a SystemTime that can be sent over the wire, but is monotonic and not effected by clock skew adjustments.

This is loosely related to the changes discussed in #254.