Skip to content

[#4829] Do not decide gap recording from an event's message timestamp - #4835

Open
schananas wants to merge 5 commits into
mainfrom
bug/4829/gap-recording-not-decided-by-message-timestamp
Open

[#4829] Do not decide gap recording from an event's message timestamp#4835
schananas wants to merge 5 commits into
mainfrom
bug/4829/gap-recording-not-decided-by-message-timestamp

Conversation

@schananas

@schananas schananas commented Jul 29, 2026

Copy link
Copy Markdown
Contributor

Fixes #4829
Fixes #4834

What changed

Gap recording no longer consults an event's message timestamp. A global index is taken from a database sequence before the transaction commits, so a reader routinely sees index n+1 while n is a hole that fills later. The reader decided whether to remember that hole by comparing the visible event's own message timestamp against its wall clock, and recorded no gap when that event looked older than gapTimeout. A message timestamp is set in the handler, always before the commit, and the interval between the two is unbounded, so the shortcut could only ever fire too eagerly. Worse, the stale path called advanceTo(index, 0), which discards already-recorded gaps rather than merely declining new ones: token(102,{101}) plus row 105 yields {101,103,104} now and {} before.

Holes are always recorded now, bounded by maxGapOffset, which becomes the single give-up point. gapTimeout goes back to meaning the gap-cleaning knob its Javadoc always described.

terminate() no longer hangs (#4834). It blocked on an unbounded pollingThread.join(), so it wedged whenever the polling thread could not reach the top of the loop -- including simply being parked inside countEvents()'s JDBC call. The join now has a 5-second deadline and warns if the thread has not stopped; the loop also stops on its terminated flag rather than only on the interrupt.

maxGapOffset = 0 is rejected. It was accepted and silently restored the old behaviour.

Tests

AggregateBasedJpaEventStorageEngineIT#streamDeliversAnEventCommittedIntoAHoleUnderAnEventOlderThanTheGapTimeout is red on unmodified main (ConditionTimeoutException, the reader never returns the filled index) and green here. It runs on HSQLDB, no container. The hole is made by skipping the global-index sequence, which is what an uncommitted append leaves behind.

It replaces gapsForVeryOldEventsAreNotIncluded, which asserted the removed behaviour and tested nothing: its DELETE ... WHERE aggregateSequenceNumber < 0 matched NULL for tagless events, so it deleted no rows and streamed a contiguous store. Its own tokens.size() == 8 expectation after supposedly deleting 4 of 8 rows is the tell.

JpaPollingEventCoordinatorTest covers both terminate() paths; the blocked-poll case is 3 of 3 red with the join unbounded.

For the reviewer

No reader-only fix can be fully sound. From committed rows alone a hole is indistinguishable between abandoned and held by a slow transaction. maxGapOffset is a bounded mitigation, not a proof. A real proof needs the store's transaction state, on PostgreSQL the xmin low watermark, which is not expressible in portable JPQL.

This makes the surviving unsound comparison in withGapsCleaned more reachable, not less. At a 10% hole rate over 400 batches, main crosses gapCleaningThreshold (250) on 0 of 400 batches; this branch on 375 of 400, peaking at 940 gaps.

The real bound on Spring Boot is 60000, not 10000, because of the swapped defaults in #4799. That is an 88 KB token at 10000 gaps and 527 KB at 60000, written every batch, and a 60000-element IN list exceeds Oracle's ORA-01795 limit of 1000. Replay is affected too: every historical hole now becomes a gap.

Related: #2958 is a closed 4.9.1 production report of a processor wedged with gaps [[]] whose workaround admits "possibly losing processing of the gap events". Same code path.

A global index is taken from a database sequence before the transaction commits, so a reader
routinely sees index n+1 while n is a hole that fills later. The reader decided whether to remember
that hole by comparing the visible event's own message timestamp against its wall clock, and
recorded no gap when that event looked older than gapTimeout.

A message timestamp is set in the handler, always before the commit, and the interval between the
two is unbounded. Any slow store, contended lock or paused process therefore made the visible event
look old while the hole below it was minutes from committing, and nothing ever asked for that index
again. The error is one-sided, because the timestamp is always earlier than the commit, so the
shortcut only ever fired too eagerly.

Gap recording no longer consults any timestamp and always records the holes it discovers. The
first-token path is bounded by maxGapOffset too, so removing the shortcut cannot reintroduce the
unbounded gap list of #1241. maxGapOffset becomes the single give-up point, and gapTimeout goes back
to meaning the gap-cleaning knob its own Javadoc always described.

No reader-only fix can be fully sound: from committed rows alone a hole is indistinguishable
between abandoned and held by a slow transaction. maxGapOffset is a bounded mitigation, not a proof.
A sound answer needs the store's transaction state, which is not expressible in portable JPQL.

This also removes the cause of #2958.

Fixes #4829
…on the interrupt

The polling loop only ever read the terminated flag from inside its InterruptedException handler, so
the interrupt sent by terminate() had to survive in order to be seen at all. It does not have to:
the loop calls an arbitrary callback, and code reached from there consumes an interrupt without
rethrowing it. Once that happens the flag is set but never read again, the thread returns to its
poll interval, and terminate() waits on join() forever.

Checking the flag on every iteration makes the interrupt an accelerator rather than the condition.
Termination stays immediate when the interrupt does land in the sleep, and costs at most one more
poll when it does not.

Recording every gap rather than suppressing gaps for events that merely look old gives the callback
more to do, which turned this from a race that was rarely lost into a reliable hang in
AggregateBasedJpaEventStorageEngineIT.
@schananas
schananas requested a review from a team as a code owner July 29, 2026 17:21
@schananas schananas self-assigned this Jul 29, 2026
@schananas
schananas requested review from hjohn, jangalinski and zambrovski and removed request for a team July 29, 2026 17:21
@schananas
schananas marked this pull request as draft July 29, 2026 19:37
…hutdown

Checking the terminated flag on every iteration is only half of it. The flag is read at the top of
the loop, and a poll parked in the JDBC call underneath countEvents() never gets back there, because
an interrupt does not end a query already in flight. terminate() meanwhile waited on an unbounded
join(), so it inherited the deadline of whatever query it happened to catch. On this branch that
wedged AggregateBasedJpaEventStorageEngineIT once in four runs, with the polling thread holding 61 ms
of CPU across 876 seconds of wall clock.

terminate() now waits a bounded time and logs at warn if the thread is still running. Giving up
leaks nothing: the polling thread is a daemon, so the JVM does not wait for it, and the flag it has
already been handed means it will not call back into the component it was coordinating.

The loop re-reads that flag after the poll as well, before invoking the callback, so a termination
landing mid-poll does not deliver one more notification into a component that is shutting down.
…ill delivered

Unit tests on token advancement can no longer show this defect, because advance() no longer takes a
timestamp: there is nothing left for them to vary. The behaviour only exists end to end, where the
event that eventually fills the hole either reaches the reader or does not.

The new test builds that situation through the engine's own append path plus a skip of the global
index sequence, which is what an append that has taken its index but not committed leaves behind. The
event above the hole is stored with a timestamp an hour old, the reader crosses the hole, and only
then does the skipped index get its row. Against unmodified main the reader never comes back for it
and the test fails on its second assertion.

It replaces gapsForVeryOldEventsAreNotIncluded, which asserted the behaviour this branch removes and
never actually asserted it: the DELETE meant to punch the holes matched on aggregateSequenceNumber
< 0, which is NULL for events appended without tags, so no row was removed and the store it streamed
was contiguous.

withGapsCleaned still compares a stored timestamp against a wall clock, which is the same unsound
comparison the advance path just lost. Its Javadoc now says so, rather than leaving the next reader to
rediscover it.
… cost

assertPositive accepts 0, and a maxGapOffset of 0 restores exactly the behaviour this branch removes:
no gap is ever recorded, so an event whose transaction commits after a higher index became visible is
skipped for good. It is now rejected with a message that says why.

The Javadoc offered 10000 as the only figure to reason about, while the Spring Boot starter defaults
to 60000. A gap costs roughly nine bytes serialized, so the token rewritten on every batch measures
about 88 KB at 10000 outstanding gaps and about 527 KB at 60000, and every gap is also listed
individually in the IN clause of the next batch query, which passes Oracle's limit of 1000
expressions per list long before either figure.

gapCleaningThreshold gets the same treatment for what recording every hole makes of it. Simulating a
10% permanent-hole rate over 400 batches crosses the default threshold on 375 of them, against 0 of
400 on main, peaking at 940 outstanding gaps. Cleaning is therefore the normal path rather than the
exception, which makes the surviving timestamp comparison in withGapsCleaned more reachable, not
less. Replay is where that lands hardest: it starts below every hole the table has ever had, so it
pays for the gap-aware query and, once over the threshold, for a cleaning query that spans every gap
rather than a batch.
@schananas
schananas marked this pull request as ready for review July 29, 2026 23:34
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

1 participant