[BUG] RemoveByTag is lost if it races a background factory (eager refresh)

[KristianJakubik]

Describe the bug

A cache entry created by a factory running in the background — e.g. during an eager refresh — is not correctly invalidated by tags.

There is a race condition when a tag invalidation happens while the factory is already executing and may have loaded its data from the database. The invalidation is silently lost and the entry keeps being served.

I believe the cause is that the entry's timestamp is assigned after the factory finishes,

FusionCache/src/ZiggyCreatures.FusionCache/FusionCache.cs

Line 509 in 2f2a434

var lateEntry = FusionCacheMemoryEntry<TValue>.CreateFromOptions(result, GetSerializedValueFromValue(operationId, key, result, options), null, ctx.Tags, options, false, ctx.LastModified?.UtcTicks, ctx.ETag);

An entry created by a standard foreground factory has its timestamp captured before the factory runs, so the same race resolves correctly there.

To Reproduce

using ZiggyCreatures.Caching.Fusion;

var cache = new FusionCache(new FusionCacheOptions
{
    DefaultEntryOptions = new FusionCacheEntryOptions
    {
        Duration = TimeSpan.FromSeconds(10),
        EagerRefreshThreshold = 0.1f,
    },
});

// We want to run tag invalidation when factory is already running
_ = RunTagInvalidationAfter(500);

// Prime the entry, then move into its eager-refresh window (10% of 10s = 1s).
await cache.GetOrSetAsync<string>("key", async (ctx, ct) =>
{
    Console.WriteLine("RUN: Factory is started for v1 value.");
    //Simulate loading data from database
    await Task.Delay(1000);
    Console.WriteLine("RUN: Factory is finnished. Return v1 value.");
    return "v1";
}, tags: ["tag"]);

// The cache item should be invalidated by tag
var cacheItem = await cache.TryGetAsync<string>("key");
Console.WriteLine("RUN: TryGet value: {0}.", cacheItem.HasValue ? cacheItem.Value : "empty");


Console.WriteLine("EXPECTED: The cache item is invalidated. {0}", cacheItem.HasValue ? "BUG: still cached" : "OK: invalidated");


await Task.Delay(1000);


Console.WriteLine("--------------------------------------------------------------------------------------------------------------------");

// Let's add the cache item again for eager loading
await cache.GetOrSetAsync<string>("key", (ctx, ct) =>
{
    Console.WriteLine("RUN: Factory is started and finnished. Return v1 value.");
    return Task.FromResult("v1");
}, tags: ["tag"]);

// Wait to trigger eager loading
await Task.Delay(2000);

var loadedValue = await cache.GetOrSetAsync<string>("key", async (ctx, ct) =>
{
    Console.WriteLine("RUN: Factory is started for v2 value.");
    await Task.Delay(1000);
    Console.WriteLine("RUN: Factory is finnished. Return v2 value.");
    return "v2";
}, tags: ["tag"]);

Console.WriteLine($"RUN: Loaded value from factory: {loadedValue}.");

_ = RunTagInvalidationAfter(500);

await Task.Delay(1500);

var eagerLoadedValue = await cache.TryGetAsync<string>("key");
Console.WriteLine($"RUN: TryGet eager loaded value: {eagerLoadedValue.Value}.");

Console.WriteLine("EXPECTED: The cache item with value: v2 is invalidated. {0}", eagerLoadedValue.HasValue ? "BUG: still cached" : "OK: invalidated");

Task RunTagInvalidationAfter(int delay)
{
    return Task.Run(async () =>
    {
        await Task.Delay(delay);
        Console.WriteLine("RUN: Remove by Tag");
        await cache.RemoveByTagAsync("tag");
    });
}

Expected behavior

An invalidation that overlaps a running factory should win, on the background path as well as the foreground one — so the entry should be timestamped when the factory starts, not when it completes.

Versions

I've encountered this issue on:

• FusionCache version : 2.6.0
• .NET 10

[CsKristof0316]

Hi, would like to contribute, I believe I managed to fix this on my fork by getting the current timestamp before the factory method gets executed and then assigning that timestamp as the logical expiration of the new entry after factory returns. Would this be an acceptable solution?

[jodydonetti]

Hi all, now that I'm back at having a life 😅 I'll take a better look at this.
Some time ago I made a change related to the factory execution timestamps, to cover a small edge case.
I think I'll need to reevaluate that change, the previous behavior and this possible change in the same context to get to a single, unified way to handle it.

Will update, meanwhile: thanks for opening this issue!