Looking. Also cc'ing @mszabo as test author who surely knows better.

I'm not so familiar with the WANCache internals, but AIUI: because the value was set immediately before fetching, it is considered as "extremely new" (reflected in the "volatile hit" log line). In turn, this makes WANCache return an interim value for the key, which effectively corresponds to the stale value. I'm not sure how to prove or disprove this. If the theory is correct, increasing the fake time (say by 100 instead of just 1) should do it. (Besides, the argument to setMockTime is passed by reference, so we should not need a second call.)

Change #1139563 had a related patch set uploaded (by Máté Szabó; author: Máté Szabó):

[mediawiki/extensions/CampaignEvents@master] EventStoreTest: Increase simulated delay after purge

https://gerrit.wikimedia.org/r/1139563

@Daimona Thanks. There is quite a lot going on in WANObjectCache under the hood that makes it not entirely amenable for testing.

Judging by the referenced comment, the logic that kicks in here appears to have been introduced with the goal of reducing misses and regenerations in the ~11s for which a tombstone is expected to live, but it does not consider that the recently written "volatile" value might well have been the pre-purge value itself. I am also frankly unsure about how this interacts with the whole idea of the tombstone itself. If the tombstone exists to guard against replication lag for a reasonable time (~11s), then why return potentially stale values before it's expired?

I've submitted a PS that tries to mitigate this with some notes around other factors at play, namely that we need to mock time moving backwards here because simulating a future time will cause getWithSetCallback() to think it is dealing with excessive transaction lag, since getCacheSetOpts() will still return the real-life current timestamp that cannot be mocked.

Change #1139563 merged by jenkins-bot:

[mediawiki/extensions/CampaignEvents@master] EventStoreTest: Increase simulated delay after purge

https://gerrit.wikimedia.org/r/1139563

To try and answer my own question having thought about it a bit more, the behavior does make sense in that WANObjectCache doesn't really offer any staleness guarantees on returned values; checking that is up to the caller. The whole interim values + tombstones arrangement exists not to avoid returning stale values to callers but to ensure such stale values do not persist in the cache for a longer period.

In T392852#10774895, @mszabo wrote:

Judging by the referenced comment, the logic that kicks in here appears to have been introduced with the goal of reducing misses and regenerations in the ~11s for which a tombstone is expected to live, but it does not consider that the recently written "volatile" value might well have been the pre-purge value itself.

If I read that correctly, a value is only considered volatile if it's been written just a few milliseconds ago. I imagine in practice it would not very common to make a cache write and then, within milliseconds, purge it and access it again; outside of tests, that is. Maybe?

I've submitted a PS that tries to mitigate this with some notes around other factors at play, namely that we need to mock time moving backwards here because simulating a future time will cause getWithSetCallback() to think it is dealing with excessive transaction lag, since getCacheSetOpts() will still return the real-life current timestamp that cannot be mocked.

Thank you for looking deep into this and patching it! The fix looks fun too, reminds me of Christopher Nolan movies.