Check event timestamp before passing anything to plugins

[Athanasius]

This has come out of the confusion I got with respect to fleetcarrier.space, the EDMC FCMS plugin, and the bot announcing my FC as having scheduled a jump 'now', when all that actually happened was I'd replayed some old Journals so as to trigger our codexentry code paths.

Absolver has kindly implemented a check in the FCMS plugin now:

def journal_entry(cmdr, is_beta, system, station, entry, state):
    if "timestamp" in entry:
        # Check that timestamp is recent enough
        dt = datetime.strptime(entry["timestamp"], "%Y-%m-%dT%H:%M:%SZ")
        if dt < datetime.utcnow() - timedelta(minutes=5):
            return

I am now wondering if we should just implement that same check (review the code for correctness of course) in plug.py.

If we do, then we'll also want a developer CL arg to not check, because I know I'll run into wanting EDMC to process old events, including passing them to plugins, both core and third party, at times. Heck, that's how this came to light.

I don't think we necessarily state that third-party plugins will definitely get all events for a 'new' journal (i.e. a newly detected file after startup-time one has been fully read), and we certainly do NOT support any user replaying journals through EDMC... so I'm inclined to not consider this an API change at all. Call it out in ChangeLog (subtly so as to not give the game away to all and sundry about how to get EDMC to process old Journals to some degree), but no need for a Major version bump.

• [ ] Ensure clock skew between local machine and Journal timestamps is accounted for. We already know the game uses server idea of time, not the local clock.

[kenneaal]

I object to this feature simply because I had to implement the check in the plugin, and if this gets added, it was all for naught!

(It's probably a good idea)

[Escalion]

LGTM

[VAKazakov]

that's neat idea as another failsafe. Abs, your code will be used in that so why not?

[Athanasius]

I object to this feature simply because I had to implement the check in the plugin, and if this gets added, it was all for naught!

(It's probably a good idea)

Hey, I had to help you get the code actually working! :P

[Athanasius]

This whole thing has a boot-strap problem when trying to detect/shout about an incorrect local clock.

1. The game client takes care to sync its internal idea of time with the game servers' idea of the current time. This is then used for the timstamps in Journal events. Thus there is always potentially some offset between naive local time and the Journal timestamps.
2. When we start up we read in the current latest journal file, which might, or might not, be from an already-running game. Even if it is then we have no idea how long ago the last entry in it occurred. Thus we can't use this scan to determine any offset between the local clock and the Journal events.
3. Playing on Windows we do have an attempt at detecting when the game is running. This assumes the game process sets a window title that starts with Elite - Dangerous. This is in monitor.py:EDLogs.game_running().
4. We would need to wait for the first new, definitely from the live game, event and always allow at least through. Note the time delta down and hope(?) it doesn't drift during this game+EDMC session.
5. Then perform the "is this an old event?" check whilst taking that delta into account.

An alternative would be to track inter-event deltas and if it's some amount more than the local time delta between last event and new one, assume someone's replaying a Journal. This may well be more reliable.

[Athanasius]

A more basic check would be "is the journal timestamp more than 24 hours different from local clock 'now'?". If someone is purposefully setting the wrong date on their machine then we don't support them.

[kenneaal]

The code above already compares against UTC time, so the server's time zone is accounted for. If the machine has done intentionally time skew, as you say there's nothing we can do about that. I don't think going as far as 24 hours is necessary, but perhaps a bit wider window than 5 minutes. (An hour, perhaps?)

[Athanasius]

The tricky part is that you can not only start with local clock skew, but have it skewing gradually more or less over time. This means you can't just note an initial delta somehow and then continue to use it.

Until I ensured the relevant Windows service was running on my own machine I was up to several minutes in less than a month.

Anyway, I'm inclined to use the loose +/- 24 hours check, as it's simple and shouldn't run into issues unless someone's being stupid about mis-setting their date (which at least used to be a trick to get around some time-based licensing issues).

[kenneaal]

I wasn't suggesting using a single delta? The FMCS plugin checks the timestamp for every message. And if someone's allowed for more than an hour of clock skew on your computer, it's probably intentional anyways.