[JakeHuneau]

Fixes #517.

Problem

BaseMsgTrackingModule.handle writes each tracking event on a new thread of its own, so processing a message doesn't wait on the database. DbTrackingModule.persist is synchronized. So when one write is slow, the threads behind it queue on the lock and take it in no particular order.

Under load, a message's events can be written out of order and an earlier state can overwrite a later one. That's what #517 reports: a message that has received its MDN is left with the state from "sending started".

Change

• One writer per module: BaseMsgTrackingModule hands each event to a single-thread executor of its own. Writes stay off the processing thread and happen in the order the events were handled. The thread is a daemon, so it never keeps the JVM alive.
• Shutdown waits for queued writes: the tracking module is an ActiveModule, so the shutdown drain from Finish files being sent before shutting down, and report the ones cut off #625 already calls its awaitIdle with the shared deadline, after the pollers have finished their sends. awaitIdle now waits until the events queued so far are written, so a message sent just before shutdown keeps its tracking record. (Previously those writes were on independent threads that nothing waited for.)
• Stop and restart: DbTrackingModule.stop stops the writer, and start gives a restarted module a new one. An event handled after the writer has stopped is written directly instead of being dropped.

Your comment on #517 mentions moving tracking onto a queue in 5.0. This is a minimal version of that which fixes the ordering now, and it should fold into that work.

Tests

TrackingWriteOrderTest uses a recording tracker whose persist is synchronized like DbTrackingModule's:

• Order: 200 events, with the first write slow so the rest queue behind it. With the previous thread per event, all 200 were written but out of order, in 3 runs out of 3. They're now written in order. The test counts writes rather than calling awaitIdle, so it checks only the order.
• Handling an event doesn't wait for the write.
• awaitIdle waits for the events already handled, and gives up at its timeout.
• An event after the writer is stopped is written directly, not lost.
• A restarted module writes in the background again.
• session.drainWorkInProgress waits for queued tracking events.

Mutation checks: each of these changes fails at least one test:

• restoring thread-per-event
• awaitIdle not waiting
• dropping late events
• a restarted module keeping a stopped writer

Full suite: 253 tests pass.

[uhurusurfa]

Shouldn't this just call:

writer.shutdown();
writer.awaitTermination(timeoutMillis, TimeUnit.MILLISECONDS);

[JakeHuneau]

Agreed — changed to writer.shutdown(); writer.awaitTermination(...) in 0bafc65. I had used a marker so the writer stayed open, but handle() already writes an event directly once the writer has stopped, so events from receivers that are still running during shutdown are not lost either way. Added a test for that case.

[uhurusurfa]

🚀 Happy days