Skip to content

test(backend): stop re-stubbing DateProvider while a released-data stream is in flight - #7161

Draft
corneliusroemer-agent wants to merge 1 commit into
mainfrom
fix/dateprovider-mock-race
Draft

corneliusroemer-agent wants to merge 1 commit into
mainfrom
fix/dateprovider-mock-race

Conversation

@corneliusroemer-agent

@corneliusroemer-agent corneliusroemer-agent commented Aug 25, 2026

Copy link
Copy Markdown
Collaborator

This is Claude's attempt to fix a really weird/complicated flake. Not sure this is the way to go, but it might be right that we have a bug in how things are set up - I just suspect there's an easier way out here.

Details

GetReleasedDataEndpointWithDataUseTermsUrlTest fails intermittently in CI with Status expected:<200> but was:<500> in the test about expired restricted data use terms. Seen in run 32856832097; it was only diagnosable because that run archived the JUnit XML.

What actually happens

The test changed the current time by re-running every { dateProvider.getCurrentInstant() } answers { ... } in the middle of the test. MockK does that in two steps: recording the every { ... } block adds an entry to the mock's answer list, and the answers { ... } call then fills in what that entry should return. In between there is an entry that matches the call but has no answer yet, and anything calling the method in that window gets MockKException: no answer provided. Because the entry matches, relaxed = true never comes into play, which is why a relaxed mock did not protect against this.

Something else was calling the method at that moment. Two statements earlier the test reads an ETag off getReleasedData() without waiting for the response body. get-released-data is a streaming endpoint, so the body keeps running on a background thread after the test moves on — 8-9 ms in that CI run, long enough to overlap. It hit the empty answer entry while building the data use terms for a record.

That exception on its own is harmless: the controller catches errors during streaming and writes them into the response body, and this response was being thrown away anyway. The damage is indirect. The exception was thrown from inside the mock, which left MockK's call recorder — shared across threads — stuck in a logging mode. One millisecond later the test thread computed the ETag for the next request, called the same mock, got No other calls allowed in stdObjectAnswer instead of a date, and the request came back as a 500.

The change

Answers are installed once when the mock bean is created, and the tests now move time by writing to a @Volatile field that the answer reads. Nothing is stubbed after the Spring context is up, so the window with a matching-but-empty answer no longer exists at any point, on any thread. This is a stronger guarantee than making the test wait for the background work: waiting would only shrink a window that is microseconds wide.

relaxed = true is dropped. DateProvider has three methods and all three are stubbed, so strict mode now fails loudly if someone adds a fourth, rather than quietly returning a made-up value.

Separately, the streamed responses whose bodies these tests discard are now waited for. A stream still running when the next test starts also races the TRUNCATE that clears the tables between tests, which has no lock or statement timeout — a hazard worth closing even though it is not what broke this test.

Non-obvious things worth knowing

Faking getCurrentInstant() alone is enough to move the whole clock: getCurrentDateTime() and getCurrentDate() are answered with callOriginal(), and MockK intercepts the calls the real implementations make back into the mock. The test that asserts the ETag changes on the date alone is what proves this still works.

This flake needs a loaded machine. On its own the test class is far too fast to hit it — I ran the test 60 times in a row without a single failure, and measured why: with one record the background stream finishes in well under a millisecond, so it is long gone by the time the test re-stubs. Six full-suite runs did not reproduce it either. To show the mechanism I widened the gap between every and answers by 3 ms and had a background thread call the date provider: 2 failures in 20, with exactly the expected:<200> but was:<500> signature from CI, and none in 120 runs after this change. Six clean full-suite runs before and five after prove nothing on their own — the argument for the fix is that the failure mode is now structurally impossible, not that the tests went green.

Two things this is not, both ruled out from the stack traces: it is not a scheduled background job (the two that use the date provider have initial delays of one hour and fifteen minutes, so neither runs during a test), and it is not state leaking in from another test class (the trace names this class's own mock bean and its own request).

Nothing else in the test suite mocks DateProvider, so the same bug cannot be lurking elsewhere. The same shape — stubbing a mock while a request is still streaming — could apply to the keycloakAdapter stubbing in the sibling classes, but nothing on the released-data path calls it, so I left those alone.

🚀 Preview: Add preview label to enable

…ream is in flight

GetReleasedDataEndpointWithDataUseTermsUrlTest moved time by calling
`every { dateProvider.getCurrentInstant() } answers { ... }` mid-test. MockK
installs the matcher first and the answer second, so between the two there is a
matching stub whose answer is null. A matching stub means `relaxed = true` is
never consulted, so any other thread invoking the method in that window gets
`MockKException: no answer provided`. The other thread existed because the test
read an ETag off `getReleasedData()` without awaiting the response, leaving the
StreamingResponseBody running on the async executor.

Worse, that exception is thrown from inside the mock, which leaves MockK's
shared call recorder in SafeLoggingState. The next mock call on the test thread
then fails with "No other calls allowed in stdObjectAnswer", the request 500s,
and the test reports `expected:<200> but was:<500>`. Seen once in CI run
32856832097; reproduced locally 2/20 with the stubbing window widened by 3 ms,
0/100 after this change.

Answers are now installed once when the bean is created and tests only flip a
@volatile field, so no answerless stub ever exists. `relaxed` is dropped since
all three DateProvider methods are stubbed. The released-data responses whose
bodies these tests discard are now awaited too, so no stream is left running
into the next test's TRUNCATE.
@claude claude Bot added the backend related to the loculus backend component label Aug 25, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

backend related to the loculus backend component

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant