Negative time skew adjustment error

[martinthomson]

Describe the bug
It appears as though some implementations use a different epoch than 1970-01-01. This manifests in a very large skew in reported times in logs. There is code to make an adjustment, but where the adjustment needs to be negative, a positive value is used instead, which doubles the skew instead.

(To be clear, this is likely just neqo, which sets an epoch at the time the program starts, due to its choice to rely on Rust's monotonic clock rather than its absolute one.)

To Reproduce
View any of the interop test qlogs from https://interop.seemann.io where neqo is the client.

Expected behavior
A negative value for the large skew.

Other

I note that you can't enter 0 as a value for the offset. I find this odd in the extreme.

[rmarx]

So, the major problem was that neqo is logging the reference_time in this format: 2020-08-16T20:53:56.582164977+00:00 while qvis was really expecting something like this 1597611236603323. Either we have a different interpretation of what a "unix timestamp" is, or neqo made a mistake there. If I manually replaced the time string in the client file with an equivalent number indicating microseconds since the epoch, it did work as expected. After all, the reference_time + relative_time setup is meant to allow users to set their own "epoch".

At this time, I have no intention of officially supporting the string-based format neqo currently uses (or similar) in qvis or in qlog in general. However, while we wait for neqo to update its errant ways ;), I have added a fallback to use JavaScript's Date.parse() if we detect such a string in a qlog trace. The downside is that Date.parse() only works at the millisecond resolution, so we have a tiny bit of data lost in the microsecond range, but that should be workable -for now-.

This fix (and the one for #29) is now live and loading the example files from #29 seems to work as expected now. At least mostly, because due to the heavy packet loss at the start, my automatic time-offset guesstimator misses the mark by a couple of milliseconds (it guesses 17, but 14 seems more correct). This is due to working from imperfect heuristics, but now that I have this example trace, I can add even more cleverness based on that in the future.

Finally, qvis can currently only deal with a minimum of 1ms latency, which is why I don't allow the offset to be 0. This can of course be updated down the line, but it's not a high priority atm. I hope this removes some extremeness from the oddity.

[martinthomson]

Thanks Robin. I think that I'll have to follow up with Lucas about his library and its serialization; hopefully we can fix that bug. I'm totally OK with this ignoring our garbage and defaulting to 0, it was the sign inversion in the offset that was that way.

(Not allowing 0 when you allow both -1 and 1 is strange. Maybe I don't understand what this tweak is supposed to do. I thought it was so that you can correct for relative clock skew on endpoints.)