fix(storage,di): invalidate the entity cache after commit; populate framework plumbing once (#450, #451)

CHANGELOG.md

@@ -11,6 +11,17 @@ follow [Semantic Versioning](https://semver.org). Ongoing work is collected unde
 
 ### Fixed
 
+- **Edits to an agent no longer fail for minutes after a busy save.** Under concurrent traffic — an
+  agent being updated while its traces were still arriving and the UI was open — the in-process entity
+  cache could refill with the *pre-save* version of a row and keep serving it for up to five minutes.
+  Every write attempted against that stale copy was rejected as a conflict, so ingestion retried and
+  saves failed for no visible reason. Cached entries are now dropped again once the save commits, so
+  the stale copy cannot outlive the write that replaced it.
+
+- **The proxy logs each upstream request once, not four times.** Every call your agents made through
+  the proxy emitted four identical sets of HTTP client log lines, quadrupling the volume on the
+  busiest path in the system and making proxy logs hard to read during an incident.
+
 - **Proxytrace is documented as source-available, consistently.** The Docker Hub overview still
   declared the product *Proprietary*, contradicting the Elastic License 2.0 relicense in 1.5.0 — the
   first licensing statement most evaluators read. It now states the ELv2 terms, the README carries a

Proxytrace.Common.Tests/AutofacExtensionsTests.cs

@@ -0,0 +1,70 @@
+using Autofac;
+using AwesomeAssertions;
+using Microsoft.Extensions.DependencyInjection;
+using Proxytrace.Common.DependencyInjection;
+
+namespace Proxytrace.Common.Tests;
+
+[TestClass]
+public sealed class AutofacExtensionsTests
+{
+    private interface IPlumbing;
+
+    private sealed class SharedPlumbing : IPlumbing;
+
+    private sealed class OtherPlumbing : IPlumbing;
+
+    [TestMethod]
+    public void RegisterServiceCollection_WhenTwoModulesRegisterTheSameImplementation_PopulatesItOnce()
+    {
+        // Framework extension methods share their plumbing through TryAddEnumerable, which dedupes
+        // only within one IServiceCollection. Every RegisterServiceCollection call builds a fresh
+        // one, so without this the container ends up with a copy per caller — which is how a single
+        // upstream request came to be logged once per module that had called AddHttpClient (#451).
+        var builder = new ContainerBuilder();
+        builder.RegisterServiceCollection(services =>
+            services.AddSingleton<IPlumbing, SharedPlumbing>());
+        builder.RegisterServiceCollection(services =>
+            services.AddSingleton<IPlumbing, SharedPlumbing>());
+
+        using var container = builder.Build();
+
+        container.Resolve<IEnumerable<IPlumbing>>().Should().ContainSingle()
+            .Which.Should().BeOfType<SharedPlumbing>();
+    }
+
+    [TestMethod]
+    public void RegisterServiceCollection_WithDistinctImplementations_KeepsEveryOne()
+    {
+        // Registering several implementations of one service is the whole point of IEnumerable<T>
+        // resolution — only an identical (service, implementation, lifetime) triple is a duplicate.
+        var builder = new ContainerBuilder();
+        builder.RegisterServiceCollection(services =>
+            services.AddSingleton<IPlumbing, SharedPlumbing>());
+        builder.RegisterServiceCollection(services =>
+            services.AddSingleton<IPlumbing, OtherPlumbing>());
+
+        using var container = builder.Build();
+
+        container.Resolve<IEnumerable<IPlumbing>>()
+            .Should().HaveCount(2)
+            .And.ContainItemsAssignableTo<IPlumbing>();
+    }
+
+    [TestMethod]
+    public void RegisterServiceCollection_WithInstanceRegistrations_LeavesThemAlone()
+    {
+        // Instance and factory descriptors are opaque — two of them are never provably the same
+        // registration, so they are populated exactly as written.
+        var first = new SharedPlumbing();
+        var second = new SharedPlumbing();
+
+        var builder = new ContainerBuilder();
+        builder.RegisterServiceCollection(services => services.AddSingleton<IPlumbing>(first));
+        builder.RegisterServiceCollection(services => services.AddSingleton<IPlumbing>(second));
+
+        using var container = builder.Build();
+
+        container.Resolve<IEnumerable<IPlumbing>>().Should().HaveCount(2);
+    }
+}

Proxytrace.Common/DependencyInjection/AutofacExtensions.cs

@@ -8,13 +8,63 @@ namespace Proxytrace.Common.DependencyInjection;
 
 public static class AutofacExtensions
 {
+    private const string PopulatedDescriptorsKey = "Proxytrace.ServiceCollection.PopulatedDescriptors";
+
     public static void RegisterServiceCollection(this ContainerBuilder builder, Action<IServiceCollection> config)
     {
         var services = new ServiceCollection();
         config(services);
+        DropAlreadyPopulated(builder, services);
         builder.Populate(services);
     }
-
+
+    /// <summary>
+    /// Removes descriptors that an earlier <see cref="RegisterServiceCollection"/> call already
+    /// populated into this container, so registering the same concrete implementation twice does not
+    /// leave two copies behind.
+    /// </summary>
+    /// <remarks>
+    /// Framework extension methods share their plumbing through <c>TryAdd</c>/<c>TryAddEnumerable</c>,
+    /// which dedupes only within *one* <see cref="IServiceCollection"/>. Every call here builds a
+    /// fresh collection, so each one re-adds that plumbing and <c>Populate</c> faithfully registers
+    /// all of it. Four modules calling <c>AddHttpClient</c> therefore put four
+    /// <c>IHttpMessageHandlerBuilderFilter</c>s in the container, and the logging handler each one
+    /// contributes wrapped every outgoing request — so a single upstream LLM call was logged four
+    /// times, on the hottest path in the system (#451).
+    ///
+    /// Only type-based registrations are compared: an identical (service, implementation, lifetime)
+    /// triple can never mean two *different* things, whereas instance- and factory-based descriptors
+    /// are opaque and are always populated as written. Genuine multi-registrations of one service
+    /// (the point of <c>IEnumerable&lt;T&gt;</c> resolution) use distinct implementation types and are
+    /// untouched.
+    /// </remarks>
+    private static void DropAlreadyPopulated(ContainerBuilder builder, IServiceCollection services)
+    {
+        if (!builder.Properties.TryGetValue(PopulatedDescriptorsKey, out object? stored)
+            || stored is not HashSet<(Type Service, Type Implementation, ServiceLifetime Lifetime)> populated)
+        {
+            populated = [];
+            builder.Properties[PopulatedDescriptorsKey] = populated;
+        }
+
+        for (int i = services.Count - 1; i >= 0; i--)
+        {
+            ServiceDescriptor descriptor = services[i];
+
+            // Keyed descriptors throw on the non-keyed accessors; they are rare and always explicit,
+            // so leave them alone rather than reaching for their keyed counterparts.
+            if (descriptor.IsKeyedService || descriptor.ImplementationType is not { } implementation)
+            {
+                continue;
+            }
+
+            if (!populated.Add((descriptor.ServiceType, implementation, descriptor.Lifetime)))
+            {
+                services.RemoveAt(i);
+            }
+        }
+    }
+
     public static IReadOnlyCollection<Type> GetImplementations(
         this Type type, 
         Assembly? assembly = null)

Proxytrace.Proxy.Tests/HttpClientRegistrationTests.cs

@@ -0,0 +1,58 @@
+using Autofac;
+using AwesomeAssertions;
+using Microsoft.Extensions.DependencyInjection;
+using Microsoft.Extensions.Http;
+using Proxytrace.Common.DependencyInjection;
+
+namespace Proxytrace.Proxy.Tests;
+
+/// <summary>
+/// Guards the registration shape behind #451: one upstream LLM call was emitting four identical sets
+/// of <c>System.Net.Http.HttpClient.openai.*</c> log lines — four handler instances logging one
+/// request, on the hottest path in the system. <c>AddHttpClient</c> shares its plumbing through
+/// <c>TryAddEnumerable</c>, which dedupes only within a single <see cref="IServiceCollection"/>; the
+/// API host composes four modules (Api, Application, Licensing, Proxy) that each call it on their own
+/// collection, so the container ended up with one logging filter per module.
+/// </summary>
+[TestClass]
+public sealed class HttpClientRegistrationTests
+{
+    [TestMethod]
+    public void RegisterServiceCollection_WithHttpClientsFromSeveralModules_RegistersOneLoggingFilter()
+    {
+        var builder = new ContainerBuilder();
+
+        // Stands in for the four modules that each register their own named clients.
+        builder.RegisterServiceCollection(services => services.AddHttpClient("openai"));
+        builder.RegisterServiceCollection(services => services.AddHttpClient("passthrough"));
+        builder.RegisterServiceCollection(services => services.AddHttpClient("license-server"));
+        builder.RegisterServiceCollection(services => services.AddHttpClient("self"));
+
+        using var container = builder.Build();
+
+        var filters = container.Resolve<IEnumerable<IHttpMessageHandlerBuilderFilter>>().ToList();
+
+        // One of each kind the framework ships (logging, metrics) — not one set per module. Every
+        // duplicate logging filter wraps the request in another logging handler.
+        filters.Should().OnlyHaveUniqueItems();
+        filters.Select(f => f.GetType()).Should().OnlyHaveUniqueItems();
+    }
+
+    [TestMethod]
+    public void RegisterServiceCollection_WithHttpClientsFromSeveralModules_KeepsEveryNamedClient()
+    {
+        // Deduplicating the shared plumbing must not touch the per-name configuration, which is what
+        // makes a named client actually usable — those are instance descriptors, not type ones.
+        var builder = new ContainerBuilder();
+        builder.RegisterServiceCollection(services =>
+            services.AddHttpClient("openai", client => client.Timeout = TimeSpan.FromMinutes(5)));
+        builder.RegisterServiceCollection(services =>
+            services.AddHttpClient("passthrough", client => client.Timeout = TimeSpan.FromMinutes(3)));
+
+        using var container = builder.Build();
+        var factory = container.Resolve<IHttpClientFactory>();
+
+        factory.CreateClient("openai").Timeout.Should().Be(TimeSpan.FromMinutes(5));
+        factory.CreateClient("passthrough").Timeout.Should().Be(TimeSpan.FromMinutes(3));
+    }
+}

Proxytrace.Storage.Tests/CachedRepositoryTests.cs

@@ -224,6 +224,51 @@ public async Task UpdateAsync_InvalidatesCacheUnconditionally()
         cache.TryGet(created.Id).Should().BeNull("the write must invalidate the cache entry");
     }
 
+    [TestMethod]
+    public async Task UpdateAsync_WhenAConcurrentReaderRepopulatesMidTransaction_TheEntryIsDroppedAfterCommit()
+    {
+        // The race behind #450: invalidation ran inside the still-open transaction, and CanUseCache
+        // suppresses the cache for the *writing* flow only (ambient.IsActive is AsyncLocal). Between
+        // that invalidation and the commit, a reader on another flow could miss the cache, read the
+        // pre-commit row and Set() it back — with nothing invalidating afterwards, the stale entity
+        // and its stale concurrency token were served until the 5-minute TTL expired, failing every
+        // write made against it in between.
+        IServiceProvider services = GetServices();
+        var repository = services.GetRequiredService<IRepository<IModel>>();
+        var generator = services.GetRequiredService<IDomainEntityGenerator<IModel>>();
+        var createExisting = services.GetRequiredService<IModel.CreateExisting>();
+        var cache = services.GetRequiredService<IEntityCache<IModel>>();
+        var transaction = services.GetRequiredService<ITransaction>();
+
+        IModel created = await generator.CreateAsync(CancellationToken);
+
+        await transaction.InvokeAsync(async () =>
+        {
+            await repository.UpdateAsync(createExisting("after-update", created), CancellationToken);
+
+            // Suppressing the ExecutionContext flow keeps the ambient transaction's AsyncLocal out of
+            // the spawned task, so that read sees CanUseCache as true and repopulates the cache —
+            // exactly what the racing reader does.
+            Task<IModel?> concurrentRead;
+            using (ExecutionContext.SuppressFlow())
+            {
+                // Started inside the suppression and awaited outside it: AsyncFlowControl must be
+                // disposed on the thread that created it, which an await in between cannot promise.
+                concurrentRead = Task.Run(() => repository.FindAsync(created.Id, CancellationToken));
+            }
+
+            await concurrentRead;
+
+            cache.TryGet(created.Id).Should().NotBeNull("the concurrent reader is expected to have repopulated the cache");
+        });
+
+        cache.TryGet(created.Id).Should().BeNull("committing must invalidate again, dropping whatever the reader cached");
+
+        IModel reloaded = await repository.FindAsync(created.Id, CancellationToken)
+                          ?? throw new InvalidOperationException("Expected the updated model to be readable.");
+        reloaded.Name.Should().Be("after-update");
+    }
+
     private sealed class FakeTimeProvider : TimeProvider
     {
         private DateTimeOffset now;

Proxytrace.Storage/Internal/AbstractRepository.cs

@@ -50,11 +50,40 @@ protected void Notify(Guid id, EntityChangeType change)
     }
 
     /// <summary>
-    /// Invalidate a single cached entity. Use after bypass writes that do not go through
-    /// the standard Add/Update path.
+    /// Invalidate a single cached entity — now, and again once the outermost transaction commits.
+    /// Use after any write, including bypass writes that do not go through the standard Add/Update
+    /// path.
     /// </summary>
-    protected void InvalidateCacheEntry(Guid id) 
-        => cache?.Invalidate(id);
+    /// <remarks>
+    /// Invalidating only inside the transaction leaves a window. <see cref="CanUseCache"/> suppresses
+    /// the cache for the *writing* flow only — <c>ambient.IsActive</c> is <c>AsyncLocal</c> — so
+    /// between the invalidation and the commit a concurrent reader on another flow can miss the
+    /// cache, read the still **pre-commit** row and <c>Set()</c> it back. Nothing invalidated again
+    /// afterwards, so that stale entity was served until the 5-minute TTL expired. It carries a stale
+    /// <c>UpdatedAt</c>, which is the optimistic-concurrency token, so every write made against it in
+    /// the meantime failed the pre-check in <see cref="UpdateCoreAsync"/> — turning a millisecond
+    /// race into minutes of failing writes on hot, cached, ingest-mutated entities like
+    /// <c>IAgent</c> (#450). Repeating the invalidation after the commit closes the window.
+    /// </remarks>
+    protected void InvalidateCacheEntry(Guid id)
+    {
+        cache?.Invalidate(id);
+
+        if (ambient.IsActive)
+            ambient.RegisterPostCommit(() => cache?.Invalidate(id));
+    }
+
+    /// <summary>
+    /// Drop the whole cache — now, and again once the outermost transaction commits, for the reason
+    /// described on <see cref="InvalidateCacheEntry"/>.
+    /// </summary>
+    protected void InvalidateCache()
+    {
+        cache?.InvalidateAll();
+
+        if (ambient.IsActive)
+            ambient.RegisterPostCommit(() => cache?.InvalidateAll());
+    }
 
     // The cache must never be read from or populated while an ambient transaction is active:
     // values read inside a transaction can reflect uncommitted writes, and populating from a
@@ -285,7 +314,7 @@ private async Task<TDomainEntity> AddCoreAsync(
         TStoredEntity stored = await mapper.Map(entity, cancellationToken);
         EntityEntry<TStoredEntity> entry = context.Set<TStoredEntity>().Add(stored);
         await context.SaveChangesAsync(cancellationToken);
-        cache?.Invalidate(entity.Id);
+        InvalidateCacheEntry(entity.Id);
         return await mapper.Map(entry.Entity, cancellationToken);
     }
 
@@ -332,7 +361,7 @@ await transaction.InvokeAsync(async () =>
 
         foreach (TDomainEntity entity in entities)
         {
-            cache?.Invalidate(entity.Id);
+            InvalidateCacheEntry(entity.Id);
             Notify(entity.Id, EntityChangeType.Added);
         }
     }
@@ -417,7 +446,7 @@ private async Task<TDomainEntity> UpdateCoreAsync(
         {
             throw new OptimisticConcurrencyException(entity.Id, typeof(TDomainEntity), ex);
         }
-        cache?.Invalidate(entity.Id);
+        InvalidateCacheEntry(entity.Id);
 
         return await this.GetAsync(entity.Id, cancellationToken);
     }
@@ -454,7 +483,7 @@ public virtual async Task<bool> RemoveAsync(Guid id, CancellationToken cancellat
                 // matches the version we loaded — treat it as "not removed by us" rather than throwing.
                 return false;
             }
-            cache?.Invalidate(id);
+            InvalidateCacheEntry(id);
             return true;
         });
 
@@ -474,7 +503,7 @@ public async Task RemoveAllAsync(CancellationToken cancellationToken = default)
             Guid[] ids = await set.AsNoTracking().Select(e => e.Id).ToArrayAsync(cancellationToken);
             set.RemoveRange(set);
             await context.SaveChangesAsync(cancellationToken);
-            cache?.InvalidateAll();
+            InvalidateCache();
             return ids;
         });
 

Proxytrace.Storage/Internal/Entities/Agent/AgentRepository.cs

@@ -169,10 +169,23 @@ private async Task<IAgent> PersistWithInitialVersionAsync(IAgent agent, Cancella
         });
 
         InvalidateCacheEntry(agentId);
-        versionCache?.InvalidateAll();
+        InvalidateVersionCache();
         return await this.GetAsync(agentId, cancellationToken);
     }
 
+    /// <summary>
+    /// Drops the agent-version cache now and again after the outermost transaction commits — the
+    /// window described on <see cref="AbstractRepository{TDomainEntity,TStoredEntity}.InvalidateCacheEntry"/>
+    /// applies to this second cache too when the write is nested in a larger logical unit.
+    /// </summary>
+    private void InvalidateVersionCache()
+    {
+        versionCache?.InvalidateAll();
+
+        if (ambient.IsActive)
+            ambient.RegisterPostCommit(() => versionCache?.InvalidateAll());
+    }
+
     private Task SetCurrentVersionIdAsync(Guid agentId, Guid versionId, CancellationToken cancellationToken)
         => transaction.InvokeAsync(async () =>
         {