From d2f963a9cbac21019a52dbed38c7080816a98842 Mon Sep 17 00:00:00 2001 From: Sadeq Abu-Hattem Date: Sat, 14 Nov 2026 21:01:11 +0200 Subject: [PATCH 1/3] Let the engine build an entry without storing it, and report lost atomicity AuditRecorder.RecordAsync splits into Prepare, which applies the model's rules and formatting and returns the entry, and Counted, which meters it. The EF Core capture will use the two to add entries to the context being saved instead of going through the store. OnLostAtomicity(LostAtomicity.Report | Throw), IAuditObserver.AtomicityLost and the dotnetboost.auditing.atomicity.lost counter are what the capture reports through when another interceptor commits the transaction before the deferred Created entries are written. AtomicityLost is a default interface member, so existing observers still compile; LoggingAuditObserver logs it as an error. Co-Authored-By: Claude Opus 5.5 --- .../LoggingAuditObserver.cs | 11 ++++ src/DotNetBoost.Auditing.API/PublicApi.txt | 1 + .../AuditingOptions.cs | 8 +++ .../AuditingServiceCollectionExtensions.cs | 23 ++++++++ .../AuditingTelemetry.cs | 7 +++ .../Interfaces/Interfaces.cs | 17 ++++++ .../Models/LostAtomicity.cs | 23 ++++++++ src/DotNetBoost.Auditing.Core/PublicApi.txt | 9 +++ .../Services/AuditMetrics.cs | 7 +++ .../Services/AuditRecorder.cs | 55 +++++++++++++++++-- 10 files changed, 155 insertions(+), 6 deletions(-) create mode 100644 src/DotNetBoost.Auditing.Core/Models/LostAtomicity.cs diff --git a/src/DotNetBoost.Auditing.API/LoggingAuditObserver.cs b/src/DotNetBoost.Auditing.API/LoggingAuditObserver.cs index 29d92bf..46f3285 100644 --- a/src/DotNetBoost.Auditing.API/LoggingAuditObserver.cs +++ b/src/DotNetBoost.Auditing.API/LoggingAuditObserver.cs @@ -78,6 +78,17 @@ public void WriteSuppressed(AuditSuppression reason, string entityName, string e public void RecordedWithoutModelRules(string entityName, string entityId, AuditAction action) => LogNoModelRules(_logger, action, entityName, entityId); + /// + public void AtomicityLost(string correlationId, int entries) => + LogAtomicityLost(_logger, entries, correlationId); + + [LoggerMessage(EventId = 7107, Level = LogLevel.Error, + Message = "Wrote {Entries} Created entries outside the transaction of the change they describe " + + "(correlation {CorrelationId}): another SaveChanges interceptor committed it first. Open the " + + "transaction yourself around SaveChanges, or assign these entities' keys in code; see " + + "docs/limitations.md.")] + private static partial void LogAtomicityLost(ILogger logger, int entries, string correlationId); + [LoggerMessage(EventId = 7100, Level = LogLevel.Debug, Message = "Not recording a {Action} of '{EntityName}' ({EntityId}): recording is disabled.")] private static partial void LogRecordingDisabled(ILogger logger, AuditAction action, string entityName, string entityId); diff --git a/src/DotNetBoost.Auditing.API/PublicApi.txt b/src/DotNetBoost.Auditing.API/PublicApi.txt index 2079507..b4100b2 100644 --- a/src/DotNetBoost.Auditing.API/PublicApi.txt +++ b/src/DotNetBoost.Auditing.API/PublicApi.txt @@ -159,6 +159,7 @@ namespace DotNetBoost.Auditing.API public sealed class LoggingAuditObserver : DotNetBoost.Auditing.Core.Interfaces.IAuditObserver { public LoggingAuditObserver(Microsoft.Extensions.Logging.ILogger logger); + public void AtomicityLost(string correlationId, int entries); public void RecordedWithoutModelRules(string entityName, string entityId, DotNetBoost.Auditing.Core.Models.AuditAction action); public void WriteSuppressed(DotNetBoost.Auditing.Core.Models.AuditSuppression reason, string entityName, string entityId, DotNetBoost.Auditing.Core.Models.AuditAction action); } diff --git a/src/DotNetBoost.Auditing.Core/AuditingOptions.cs b/src/DotNetBoost.Auditing.Core/AuditingOptions.cs index 21c5e4c..41ec981 100644 --- a/src/DotNetBoost.Auditing.Core/AuditingOptions.cs +++ b/src/DotNetBoost.Auditing.Core/AuditingOptions.cs @@ -1,3 +1,4 @@ +using DotNetBoost.Auditing.Core.Models; using DotNetBoost.Auditing.Core.Metadata; namespace DotNetBoost.Auditing.Core; @@ -75,6 +76,13 @@ public sealed class AuditingOptions /// public bool RecordUpdatesWithoutBeforeImage { get; set; } = true; + /// + /// What the EF Core capture does when another interceptor commits the transaction a save ran in + /// before the capture has written its deferred Created entries. + /// by default. + /// + public LostAtomicity OnLostAtomicity { get; set; } = LostAtomicity.Report; + /// /// How long a recorded value may be before it is cut short and /// is set. Default 4000. diff --git a/src/DotNetBoost.Auditing.Core/AuditingServiceCollectionExtensions.cs b/src/DotNetBoost.Auditing.Core/AuditingServiceCollectionExtensions.cs index e5efdd1..9c6c19e 100644 --- a/src/DotNetBoost.Auditing.Core/AuditingServiceCollectionExtensions.cs +++ b/src/DotNetBoost.Auditing.Core/AuditingServiceCollectionExtensions.cs @@ -1,6 +1,7 @@ using DotNetBoost.Auditing.Core; using DotNetBoost.Auditing.Core.Interfaces; using DotNetBoost.Auditing.Core.Metadata; +using DotNetBoost.Auditing.Core.Models; using DotNetBoost.Auditing.Core.Services; using Microsoft.Extensions.DependencyInjection.Extensions; using System.Diagnostics.Metrics; @@ -286,6 +287,28 @@ public static AuditingBuilder WithoutCreatedAndDeletedValues(this AuditingBuilde return builder; } + /// + /// What the EF Core capture does when another SaveChanges interceptor commits the + /// transaction a save ran in before the capture has written its deferred Created + /// entries, so they can no longer be atomic with the change. + /// by default; is recommended in tests. + /// + /// The builder. + /// Report it, or fail the save. + /// The builder, for chaining. + /// is null. + /// is not defined. + public static AuditingBuilder OnLostAtomicity(this AuditingBuilder builder, LostAtomicity behaviour) + { + ArgumentNullException.ThrowIfNull(builder); + + if (!Enum.IsDefined(behaviour)) + throw new ArgumentOutOfRangeException(nameof(behaviour), behaviour, "Not a LostAtomicity value."); + + builder.Options.OnLostAtomicity = behaviour; + return builder; + } + /// /// Stops recording, leaving reads working. The kill switch, for an incident — the services /// stay resolvable and every write returns null. diff --git a/src/DotNetBoost.Auditing.Core/AuditingTelemetry.cs b/src/DotNetBoost.Auditing.Core/AuditingTelemetry.cs index 850e6bd..a16c868 100644 --- a/src/DotNetBoost.Auditing.Core/AuditingTelemetry.cs +++ b/src/DotNetBoost.Auditing.Core/AuditingTelemetry.cs @@ -66,6 +66,13 @@ public static class AuditingTelemetry /// public const string EntriesDeleted = "dotnetboost.auditing.entries.deleted"; + /// + /// Saves whose deferred Created entries were written outside the transaction of the + /// change, because another SaveChanges interceptor committed it first. Should stay at + /// zero; anything else is a composition to fix — see docs/limitations.md. + /// + public const string AtomicityLost = "dotnetboost.auditing.atomicity.lost"; + /// The entity's stored name — Product. /// /// Bounded by the application's model, which is what makes it safe to tag by. The entity's diff --git a/src/DotNetBoost.Auditing.Core/Interfaces/Interfaces.cs b/src/DotNetBoost.Auditing.Core/Interfaces/Interfaces.cs index 59694d2..0d5b04e 100644 --- a/src/DotNetBoost.Auditing.Core/Interfaces/Interfaces.cs +++ b/src/DotNetBoost.Auditing.Core/Interfaces/Interfaces.cs @@ -64,6 +64,23 @@ public interface IAuditObserver /// /// void RecordedWithoutModelRules(string entityName, string entityId, AuditAction action); + + /// + /// The EF Core capture wrote deferred Created entries + /// outside the transaction of the change they describe, because another interceptor + /// committed that transaction first. + /// + /// The save's correlation id, which every one of those entries carries. + /// How many entries were written outside the transaction. + /// + /// Raised only under ; + /// fails the save instead. A default implementation that does nothing, so an observer written + /// before this member existed still compiles. The fix is in docs/limitations.md: open the + /// transaction yourself around SaveChanges, or assign the keys in code. + /// + void AtomicityLost(string correlationId, int entries) + { + } } /// diff --git a/src/DotNetBoost.Auditing.Core/Models/LostAtomicity.cs b/src/DotNetBoost.Auditing.Core/Models/LostAtomicity.cs new file mode 100644 index 0000000..fb933a2 --- /dev/null +++ b/src/DotNetBoost.Auditing.Core/Models/LostAtomicity.cs @@ -0,0 +1,23 @@ +namespace DotNetBoost.Auditing.Core.Models; + +/// +/// What the EF Core capture does when the transaction a save ran in was committed by someone else +/// before the capture wrote its deferred Created entries — so those entries can no longer +/// be atomic with the change they describe. See docs/limitations.md. +/// +public enum LostAtomicity +{ + /// + /// Write the entries anyway, outside the transaction, and report it: to + /// and the + /// dotnetboost.auditing.atomicity.lost counter. The default, so an application that + /// composes interceptors this way does not start failing on upgrade. + /// + Report, + + /// + /// Fail the save. The change itself is already committed by then, so this does not undo it; + /// it makes the lost guarantee impossible to miss. Recommended in tests. + /// + Throw +} diff --git a/src/DotNetBoost.Auditing.Core/PublicApi.txt b/src/DotNetBoost.Auditing.Core/PublicApi.txt index a2f8ff8..2555639 100644 --- a/src/DotNetBoost.Auditing.Core/PublicApi.txt +++ b/src/DotNetBoost.Auditing.Core/PublicApi.txt @@ -19,6 +19,7 @@ namespace DotNetBoost.Auditing.Core public sealed class AuditingOptions { public AuditingOptions(); + public DotNetBoost.Auditing.Core.Models.LostAtomicity OnLostAtomicity { get; set; } public System.TimeSpan? Retention { get; set; } public bool Enabled { get; set; } public bool RecordCreatedValues { get; set; } @@ -34,6 +35,7 @@ namespace DotNetBoost.Auditing.Core } public static class AuditingTelemetry { + public const string AtomicityLost = "dotnetboost.auditing.atomicity.lost"; public const string EntriesDeleted = "dotnetboost.auditing.entries.deleted"; public const string EntriesRecorded = "dotnetboost.auditing.entries.recorded"; public const string MeterName = "DotNetBoost.Auditing"; @@ -117,6 +119,7 @@ namespace DotNetBoost.Auditing.Core.Interfaces { public abstract void RecordedWithoutModelRules(string entityName, string entityId, DotNetBoost.Auditing.Core.Models.AuditAction action); public abstract void WriteSuppressed(DotNetBoost.Auditing.Core.Models.AuditSuppression reason, string entityName, string entityId, DotNetBoost.Auditing.Core.Models.AuditAction action); + public virtual void AtomicityLost(string correlationId, int entries); } public interface IAuditStore { @@ -342,6 +345,11 @@ namespace DotNetBoost.Auditing.Core.Models public string? CorrelationId { get; init; } public string? Metadata { get; init; } } + public enum LostAtomicity : System.IComparable, System.IConvertible, System.IFormattable, System.ISpanFormattable, int + { + public const DotNetBoost.Auditing.Core.Models.LostAtomicity Report = 0; + public const DotNetBoost.Auditing.Core.Models.LostAtomicity Throw = 1; + } } namespace DotNetBoost.Auditing.Core.Services @@ -380,6 +388,7 @@ namespace Microsoft.Extensions.DependencyInjection public static DotNetBoost.Auditing.Core.AuditingBuilder DisableRecording(DotNetBoost.Auditing.Core.AuditingBuilder builder); public static DotNetBoost.Auditing.Core.AuditingBuilder IgnoreEntities(DotNetBoost.Auditing.Core.AuditingBuilder builder, System.Type[] entityTypes); public static DotNetBoost.Auditing.Core.AuditingBuilder IgnoreEntity(DotNetBoost.Auditing.Core.AuditingBuilder builder); + public static DotNetBoost.Auditing.Core.AuditingBuilder OnLostAtomicity(DotNetBoost.Auditing.Core.AuditingBuilder builder, DotNetBoost.Auditing.Core.Models.LostAtomicity behaviour); public static DotNetBoost.Auditing.Core.AuditingBuilder RequireOptIn(DotNetBoost.Auditing.Core.AuditingBuilder builder); public static DotNetBoost.Auditing.Core.AuditingBuilder UseActorAccessor(DotNetBoost.Auditing.Core.AuditingBuilder builder); public static DotNetBoost.Auditing.Core.AuditingBuilder UseCustomStore(DotNetBoost.Auditing.Core.AuditingBuilder builder, System.Func store); diff --git a/src/DotNetBoost.Auditing.Core/Services/AuditMetrics.cs b/src/DotNetBoost.Auditing.Core/Services/AuditMetrics.cs index a450068..d85a769 100644 --- a/src/DotNetBoost.Auditing.Core/Services/AuditMetrics.cs +++ b/src/DotNetBoost.Auditing.Core/Services/AuditMetrics.cs @@ -28,6 +28,7 @@ internal sealed class AuditMetrics : IDisposable private readonly Counter _recorded; private readonly Counter _suppressed; private readonly Counter _deleted; + private readonly Counter _atomicityLost; /// /// Creates the instruments on 's meter, or on one of its own. @@ -62,6 +63,9 @@ internal AuditMetrics(IMeterFactory? factory) _deleted = meter.CreateCounter( AuditingTelemetry.EntriesDeleted, "{entry}", "Audit entries deleted by a prune or an erasure."); + + _atomicityLost = meter.CreateCounter( + AuditingTelemetry.AtomicityLost, "{save}", "Saves whose deferred entries were written outside the change's transaction."); } /// One entry recorded. @@ -91,6 +95,9 @@ internal void Suppressed(AuditSuppression reason, string entityName, AuditAction }); } + /// One save whose deferred entries were written outside the change's transaction. + internal void AtomicityLost() => _atomicityLost.Add(1); + /// entries deleted by . internal void Deleted(int count, string operation) { diff --git a/src/DotNetBoost.Auditing.Core/Services/AuditRecorder.cs b/src/DotNetBoost.Auditing.Core/Services/AuditRecorder.cs index ff86e0a..283069d 100644 --- a/src/DotNetBoost.Auditing.Core/Services/AuditRecorder.cs +++ b/src/DotNetBoost.Auditing.Core/Services/AuditRecorder.cs @@ -101,6 +101,27 @@ internal void ReportSuppressed( /// Records one change, applying the model's rules and the engine's formatting. internal async Task RecordAsync(AuditWrite write, CancellationToken ct = default) + { + if (Prepare(write) is not { } entry) + return null; + + await _store.AppendAsync(entry, ct).ConfigureAwait(false); + Counted(entry); + + return entry; + } + + /// + /// Builds the entry for one change, applying the model's rules and the engine's formatting, or + /// returns null after reporting why it is not recorded. Nothing is stored. + /// + /// + /// Split from for the EF Core capture, which adds the entry to the + /// context being saved rather than to the store's context: those are different instances when + /// a scope holds more than one context. A caller that stores the entry itself calls + /// once it has. + /// + internal AuditEntry? Prepare(AuditWrite write) { ArgumentNullException.ThrowIfNull(write); @@ -176,14 +197,36 @@ internal void ReportSuppressed( entry.Changes.Add(change); } - await _store.AppendAsync(entry, ct).ConfigureAwait(false); + return entry; + } - // Counted here, which is "handed to the store" and not "committed" — the EF Core store only - // tracks an entry, and the caller's SaveChanges is what makes it durable. See - // AuditingTelemetry.EntriesRecorded. - _metrics.Recorded(entityName, write.Action); + /// + /// Counts an entry once it has been handed to storage, which is not "committed": the EF Core + /// store and capture only track an entry, and the caller's SaveChanges is what makes it + /// durable. See AuditingTelemetry.EntriesRecorded. + /// + internal void Counted(AuditEntry entry) => _metrics.Recorded(entry.EntityName, entry.Action); - return entry; + /// + /// Reports a save whose deferred entries are about to be written outside the change's + /// transaction, or throws under . + /// + /// The save's correlation id. + /// How many entries that concerns. + internal void AtomicityLost(string correlationId, int entries) + { + if (_options.OnLostAtomicity == LostAtomicity.Throw) + { + throw new InvalidOperationException( + "The transaction this save ran in was committed before DotNetBoost.Auditing wrote the " + + $"Created entries for {entries} entities with store-generated keys, so they cannot be atomic " + + "with the change any more. Another SaveChanges interceptor committed it from its own " + + "SavedChanges. Open the transaction yourself around SaveChanges, or assign these entities' " + + "keys in code. See docs/limitations.md, \"Sharing a DbContext with other SaveChanges interceptors\"."); + } + + _metrics.AtomicityLost(); + _observer.AtomicityLost(correlationId, entries); } /// From 76dd75ae5b92998da5d566cd00a9ca3b8abe8c12 Mon Sep 17 00:00:00 2001 From: Sadeq Abu-Hattem Date: Sat, 14 Nov 2026 21:01:11 +0200 Subject: [PATCH 2/3] Make the EF Core capture safe beside another SaveChanges interceptor The save lifecycle, ported from DotNetBoost.MultiLingual's design: - A save another interceptor issues from inside this one is nested: it joins the save in progress, and only the outermost save writes the deferred entries, commits or rolls back. Nested is decided by whether EF has accepted the outer save's changes; anything else starts over, rolling back what an abandoned or replayed save left open and detaching the entries it captured. - With another interceptor after it, the capture commits from EF's DbContext.SavedChanges event, once every interceptor has finished. - A transaction someone else committed early is reported, or fails the save under OnLostAtomicity(Throw). And the standalone fixes: SaveChangesCanceled rolls back; a concurrency conflict rolls back from EF's SaveChangesFailed event, since a ROLLBACK during the ThrowingConcurrencyException hook fails on PostgreSQL and SQL Server; an ambient TransactionScope is used rather than refused; a suppressed save is not captured; entries go to the context being saved, and a context without the audit tables is refused. The tracker is read once per save, and rollbacks on failure paths are best-effort so they cannot hide why the save failed. Tests: stand-ins for another library in TestSupport (a post-save writer, a replaying interceptor under a retrying strategy, and others), run in both registration orders and through SaveChanges and SaveChangesAsync, on SQLite in ProviderTests and on PostgreSQL and SQL Server in IntegrationTests. Co-Authored-By: Claude Opus 5.5 --- ...uditingSaveChangesInterceptor.Lifecycle.cs | 533 +++++++++++++++ .../AuditingSaveChangesInterceptor.cs | 282 ++++---- .../CompositionTests.cs | 446 +++++++++++++ .../EfCoreCompositionTests.cs | 259 ++++++++ .../EfCoreHarness.cs | 16 +- .../EfCoreSaveLifecycleTests.cs | 271 ++++++++ .../CompositionInterceptors.cs | 617 ++++++++++++++++++ .../DotNetBoost.Auditing.TestSupport.csproj | 2 + .../RecordingAuditObserver.cs | 6 + 9 files changed, 2281 insertions(+), 151 deletions(-) create mode 100644 src/DotNetBoost.Auditing.EntityFrameworkCore/AuditingSaveChangesInterceptor.Lifecycle.cs create mode 100644 tests/DotNetBoost.Auditing.IntegrationTests/CompositionTests.cs create mode 100644 tests/DotNetBoost.Auditing.ProviderTests/EfCoreCompositionTests.cs create mode 100644 tests/DotNetBoost.Auditing.ProviderTests/EfCoreSaveLifecycleTests.cs create mode 100644 tests/DotNetBoost.Auditing.TestSupport/CompositionInterceptors.cs diff --git a/src/DotNetBoost.Auditing.EntityFrameworkCore/AuditingSaveChangesInterceptor.Lifecycle.cs b/src/DotNetBoost.Auditing.EntityFrameworkCore/AuditingSaveChangesInterceptor.Lifecycle.cs new file mode 100644 index 0000000..b5f0076 --- /dev/null +++ b/src/DotNetBoost.Auditing.EntityFrameworkCore/AuditingSaveChangesInterceptor.Lifecycle.cs @@ -0,0 +1,533 @@ +using DotNetBoost.Auditing.Core.Models; +using Microsoft.EntityFrameworkCore; +using Microsoft.EntityFrameworkCore.ChangeTracking; +using Microsoft.EntityFrameworkCore.Diagnostics; +using Microsoft.EntityFrameworkCore.Infrastructure; +using Microsoft.EntityFrameworkCore.Storage; +using System.Data.Common; +using System.Diagnostics; +using System.Globalization; +using System.Runtime.CompilerServices; + +namespace DotNetBoost.Auditing.EntityFrameworkCore; + +// When a save starts, nests, ends and fails — what lets the capture share a context with another +// library's SaveChanges interceptor in either registration order. Ported from the same design in +// DotNetBoost.MultiLingual's save interceptor, not shared with it. +// +// The phases of one save: +// +// Saving outermost SavingChanges: start over from anything left behind, capture, open a +// transaction if creations are deferred and none is open. +// Nested a SavingChanges while a save of ours is in flight and EF has already accepted its +// changes (or while it awaits the event): depth++, capture into the same state. +// Saved outermost SavedChanges: write the deferred entries, then commit — or, when this +// interceptor owns the transaction and another SaveChanges interceptor follows it, +// leave it open for EF's DbContext.SavedChanges event. +// Awaiting event a save starting now is nested, not a new outermost one. +// Done the outer save's DbContext.SavedChanges event: write what nested saves deferred, +// commit, finish. +// Failed SaveChangesFailed, SaveChangesCanceled or ThrowingConcurrencyException: a nested +// save only unwinds its depth; the outermost rolls back and finishes. +internal sealed partial class AuditingSaveChangesInterceptor +{ + // Every entry this capture created, held weakly. An entry still Added when an outermost save + // starts belongs to a save that never completed — refused in SavingChanges, failed, or rolled + // back and put back by another interceptor's tracker snapshot — and would otherwise be written + // a second time beside the fresh capture's. + private readonly ConditionalWeakTable _created = new(); + + /// + /// Enters a save. Returns the state to capture into and that the caller may open a transaction + /// for, or null when there is nothing to do. + /// + private SaveState? Saving(DbContext context, InterceptionResult result) + { + var state = _states.GetOrCreateValue(context); + + // The interceptor's own deferred write. + if (state.IsRecording) + return null; + + if (result.HasResult) + { + // Another interceptor suppressed this save and accounts for it: nothing reaches the + // database through EF. Counted when it is nested, so its SavedChanges does not end the + // outer save early. + if (IsNested(state)) + state.Depth++; + + return null; + } + + if (IsNested(state)) + { + state.Depth++; + try + { + Capture(context, state, context.ChangeTracker.Entries().ToList()); + } + catch + { + state.Depth--; + throw; + } + + return state; + } + + // An outermost save. Whatever is left from an earlier one did not complete. + // + // The tracker is read once, here, and shared: every read of it runs EF's change detection + // over every tracked entity, and a save should pay for that once, not once per step. + var entries = context.ChangeTracker.Entries().ToList(); + StartOver(context, state, entries); + state.Depth = 1; + + try + { + foreach (var entry in entries) + { + if (entry.State is EntityState.Added or EntityState.Modified or EntityState.Deleted + && entry.Entity is not (AuditEntry or AuditPropertyChange)) + { + state.Changed.Add((entry, entry.State)); + } + } + + Capture(context, state, entries); + return state; + } + catch + { + StartOver(context, state, entries: null); + throw; + } + } + + /// + /// True when a save starting now is nested inside one of ours: that save is awaiting EF's + /// event, or it is in flight and EF has already saved and accepted its changes — the only moment + /// another interceptor can save from inside it. Anything else is a save that never completed + /// (EF raises nothing when an interceptor's SavingChanges throws), or one that another + /// interceptor is replaying from scratch, and the new save starts over. + /// + /// + /// An outer save that changed nothing EF tracks gives nothing to tell the two apart by, and is + /// treated as completed; it captured nothing, so starting over loses nothing. + /// + private static bool IsNested(SaveState state) => + state.CommitPending + || state.Depth > 0 + && state.Changed.Count > 0 + && state.Changed.TrueForAll(c => + c.Entry.State == (c.State == EntityState.Deleted ? EntityState.Detached : EntityState.Unchanged)); + + /// + /// Leaves a save that completed. Returns the state when it was the outermost, which does the + /// work, or null. + /// + private SaveState? Saved(DbContext context) + { + if (!_states.TryGetValue(context, out var state) || state.IsRecording) + return null; + + // Depth 0: a save this interceptor never entered — suppressed by another one. + if (state.Depth == 0 || --state.Depth > 0) + { + // EF raises the DbContext.SavedChanges event for a nested save too, before the outer + // save's; that one must not commit. + if (state.CommitPending && state.Depth > 0) + state.NestedSavesAwaitingEvent++; + + return null; + } + + return state; + } + + /// + /// Leaves the commit for EF's DbContext.SavedChanges event when this interceptor owns the + /// transaction and another SaveChanges interceptor follows it. Returns whether it did. + /// + /// + /// EF runs interceptors in the order they were added, and raises the event once every + /// SavedChanges has returned — or not at all when one throws, in which case every + /// interceptor sees SaveChangesFailed and this one rolls back. Committing here would put + /// the later interceptor's post-save work outside the transaction. The event is synchronous, so + /// that commit is one blocking round trip, paid only when another interceptor follows. + /// + private bool DeferCommit(DbContext context, SaveState state) + { + if (state.OwnedTransaction is null || !HasSaveInterceptorAfterThis(context)) + return false; + + state.CommitPending = true; + state.Depth = 1; + + if (!state.ListensToSavedChanges) + { + context.SavedChanges += OnSavedChanges; + state.ListensToSavedChanges = true; + } + + return true; + } + + /// Whether a SaveChanges interceptor was added to the context after this one. + private bool HasSaveInterceptorAfterThis(DbContext context) + { + var interceptors = context.GetService().FindExtension()?.Interceptors; + if (interceptors is null) + return false; + + var seenThis = false; + foreach (var interceptor in interceptors) + { + if (ReferenceEquals(interceptor, this)) + seenThis = true; + else if (seenThis && interceptor is ISaveChangesInterceptor) + return true; + } + + return false; + } + + /// EF's DbContext.SavedChanges event: every interceptor is done, so commit. + private void OnSavedChanges(object? sender, SavedChangesEventArgs e) + { + if (sender is not DbContext context + || !_states.TryGetValue(context, out var state) + || state.IsRecording + || !state.CommitPending) + { + return; + } + + if (state.NestedSavesAwaitingEvent > 0) + { + state.NestedSavesAwaitingEvent--; + return; + } + + try + { + // Creations a nested save added after the deferred pass ran. Synchronous, as the event is. + WriteDeferred(context, state); + state.OwnedTransaction?.Commit(); + Finish(context, state); + } + catch + { + RollbackQuietly(state); + Finish(context, state); + throw; + } + } + + /// Writes the deferred creations' entries, now that their keys exist. + private void WriteDeferred(DbContext context, SaveState state) + { + if (!BeginDeferredWrite(context, state)) + return; + + try + { + context.SaveChanges(); + } + finally + { + state.IsRecording = false; + } + } + + /// See . + private async Task WriteDeferredAsync(DbContext context, SaveState state, CancellationToken cancellationToken) + { + if (!BeginDeferredWrite(context, state)) + return; + + try + { + await context.SaveChangesAsync(cancellationToken).ConfigureAwait(false); + } + finally + { + state.IsRecording = false; + } + } + + /// + /// Records the deferred entries into the context and marks the save that will write them as + /// this interceptor's own. Returns false when there is nothing deferred. + /// + private bool BeginDeferredWrite(DbContext context, SaveState state) + { + if (state.Deferred.Count == 0) + return false; + + // Relied on a transaction someone else opened, and it is gone or replaced: they committed + // before this point, and these entries can no longer be atomic with the change. + if (state.ReliedOn is { } reliedOn && !ReferenceEquals(reliedOn, context.Database.CurrentTransaction)) + { + state.ReliedOn = null; + Recorder.AtomicityLost(state.CorrelationId, state.Deferred.Count); + } + + // This save raises SavingChanges and SavedChanges again, and the only thing pending is the + // trail itself. Without the flag it would record the deferred entries again, save again, + // and recurse until the stack ran out. + state.IsRecording = true; + try + { + RecordDeferred(context, state); + } + catch + { + state.IsRecording = false; + throw; + } + + // Cleared before the save, not after: nothing may re-run these, whatever happens next. + state.Deferred.Clear(); + return true; + } + + /// + /// Arranges the rollback for a concurrency conflict, which cannot happen in the hook that + /// reports it. + /// + /// + /// EF raises ThrowingConcurrencyException while it is still reading the batch's results. + /// The connection is busy, so a ROLLBACK sent then fails on PostgreSQL ("a command is + /// already in progress") and SQL Server ("an open DataReader"), and its error replaces the + /// concurrency exception. SQLite does not mind, which is how this hid. EF raises its + /// DbContext.SaveChangesFailed event once the reader is closed, just before it throws, + /// and the rollback happens there. + /// + private void RollBackAfterConflict(DbContext? context) + { + if (context is null + || !_states.TryGetValue(context, out var state) + || state.IsRecording + || state.ListensToSaveChangesFailed) + { + return; + } + + context.SaveChangesFailed += OnSaveChangesFailed; + state.ListensToSaveChangesFailed = true; + } + + /// EF's DbContext.SaveChangesFailed event, after a concurrency conflict. + private void OnSaveChangesFailed(object? sender, SaveChangesFailedEventArgs e) => Abort(sender as DbContext); + + /// Ends the save after a failure, a cancellation or a concurrency conflict. + private void Abort(DbContext? context) + { + if (LeaveFailed(context) is not { } state) + return; + + try + { + // Rolls back the change as well as its trail, which is the point of having opened it. + RollbackQuietly(state); + } + finally + { + Finish(context!, state); + } + } + + /// See . + private async Task AbortAsync(DbContext? context) + { + if (LeaveFailed(context) is not { } state) + return; + + try + { + await RollbackQuietlyAsync(state).ConfigureAwait(false); + } + finally + { + Finish(context!, state); + } + } + + /// + /// Leaves a save that failed. Returns the state when it was the outermost, which rolls back. A + /// nested save's failure is reported to whoever issued it, and the outer save goes on as that + /// caller decides. + /// + private SaveState? LeaveFailed(DbContext? context) + { + // A failure in the deferred save itself unwinds through SavedChanges, which rolls back. + if (context is null || !_states.TryGetValue(context, out var state) || state.IsRecording) + return null; + + if (state.Depth > 1) + { + state.Depth--; + return null; + } + + // Already finished: the failure is the outer save reporting what SavedChanges threw. + if (state.Depth == 0 && !state.CommitPending) + return null; + + return state; + } + + /// + /// Puts down whatever an earlier save left on this context: rolls back its transaction, and + /// detaches the entries it captured but never wrote. + /// + /// The context. + /// Its state. + /// + /// The tracker as the caller has just read it, or null to read it here — after a failed + /// capture, whose own entries the caller's list does not hold. + /// + private void StartOver(DbContext context, SaveState state, List? entries) + { + RollbackQuietly(state); + Finish(context, state); + + // A list, not the live tracker: detaching an entry changes what is being enumerated. + foreach (var entry in entries ?? context.ChangeTracker.Entries().ToList()) + { + if (entry.Entity is not AuditEntry audit + || entry.State != EntityState.Added + || !_created.TryGetValue(audit, out _)) + { + continue; + } + + // A copy: detaching a change takes it out of the entry's collection. + foreach (var change in audit.Changes.ToList()) + { + var changeEntry = context.Entry(change); + if (changeEntry.State == EntityState.Added) + changeEntry.State = EntityState.Detached; + } + + entry.State = EntityState.Detached; + } + } + + /// Remembers an entry this capture created, for . + private void Created(AuditEntry entry) => _created.AddOrUpdate(entry, entry); + + /// + /// Rolls back on a failure path, where the failure being reported is the one the caller needs. + /// + /// + /// Every caller is unwinding a save that already failed, inside EF's own failure handling or a + /// catch: an exception from the rollback would replace that failure, and the caller + /// would see "connection is broken" instead of why the save failed. Disposing the transaction, + /// which does next, rolls back whatever is left, and a server whose + /// connection is gone has rolled back already. + /// + private static void RollbackQuietly(SaveState state) + { + try + { + state.OwnedTransaction?.Rollback(); + } + catch (Exception exception) when (exception is DbException or InvalidOperationException) + { + // See remarks. + } + } + + /// See . + private static async Task RollbackQuietlyAsync(SaveState state) + { + if (state.OwnedTransaction is not { } transaction) + return; + + try + { + // Without the save's token: when the save was cancelled that token is already + // cancelled, and a rollback that refuses to run is how a transaction stays open. + await transaction.RollbackAsync(CancellationToken.None).ConfigureAwait(false); + } + catch (Exception exception) when (exception is DbException or InvalidOperationException) + { + // See RollbackQuietly. + } + } + + private void Finish(DbContext context, SaveState state) + { + state.OwnedTransaction?.Dispose(); + + if (state.ListensToSavedChanges) + context.SavedChanges -= OnSavedChanges; + + if (state.ListensToSaveChangesFailed) + context.SaveChangesFailed -= OnSaveChangesFailed; + + state.Reset(); + } + + /// What one save is holding, from its outermost SavingChanges to its end. + private sealed class SaveState + { + /// How many saves of this context are in flight, the outermost included. + public int Depth { get; set; } + + /// The entries the outermost save changes, and their state before it. + public List<(EntityEntry Entry, EntityState State)> Changed { get; } = []; + + /// Creations whose key arrives with the INSERT. + public List Deferred { get; } = []; + + /// The transaction this interceptor opened, or null when the caller had one. + public IDbContextTransaction? OwnedTransaction { get; set; } + + /// Someone else's transaction the deferred entries rely on. + public IDbContextTransaction? ReliedOn { get; set; } + + /// Whether the save now in flight is the interceptor's own deferred write. + public bool IsRecording { get; set; } + + /// Whether the commit waits for EF's DbContext.SavedChanges event. + public bool CommitPending { get; set; } + + /// Nested saves that completed while the commit waits, whose events come first. + public int NestedSavesAwaitingEvent { get; set; } + + /// Whether is subscribed to the context. + public bool ListensToSavedChanges { get; set; } + + /// Whether is subscribed, after a concurrency conflict. + public bool ListensToSaveChangesFailed { get; set; } + + /// + /// The id tying this save's entries together. Taken from the ambient activity when there is + /// one, so the trail joins the traces of the request that caused it, and otherwise minted + /// here — per save, not per entry. + /// + public string CorrelationId { get; private set; } = NewCorrelationId(); + + public void Reset() + { + Depth = 0; + Changed.Clear(); + Deferred.Clear(); + OwnedTransaction = null; + ReliedOn = null; + IsRecording = false; + CommitPending = false; + NestedSavesAwaitingEvent = 0; + ListensToSavedChanges = false; + ListensToSaveChangesFailed = false; + CorrelationId = NewCorrelationId(); + } + + private static string NewCorrelationId() => + Activity.Current?.Id ?? Guid.NewGuid().ToString("n", CultureInfo.InvariantCulture); + } +} diff --git a/src/DotNetBoost.Auditing.EntityFrameworkCore/AuditingSaveChangesInterceptor.cs b/src/DotNetBoost.Auditing.EntityFrameworkCore/AuditingSaveChangesInterceptor.cs index 793ef11..cb71c72 100644 --- a/src/DotNetBoost.Auditing.EntityFrameworkCore/AuditingSaveChangesInterceptor.cs +++ b/src/DotNetBoost.Auditing.EntityFrameworkCore/AuditingSaveChangesInterceptor.cs @@ -49,26 +49,32 @@ namespace DotNetBoost.Auditing.EntityFrameworkCore; /// Both disappear if the entity's key is assigned in code — a Guid set by the /// application, HiLo, a sequence — because then nothing is deferred. /// -/// State is per instance, so several contexts can share one -/// scope. Context pooling (AddDbContextPool) is not supported: pooled options are built once, +/// Inside an ambient TransactionScope it opens nothing: the deferred save enlists in +/// the scope like the primary one, and commits or rolls back with it. +/// +/// Beside another library's SaveChanges interceptor, in either order: a save the +/// other issues from inside this one is counted as nested, and when this interceptor owns the +/// transaction and another follows it, the commit waits for EF's DbContext.SavedChanges +/// event. See AuditingSaveChangesInterceptor.Lifecycle.cs. +/// +/// State is per instance, and every entry is added to the +/// context being saved, so several contexts can share one scope. Each must map the audit tables +/// (ApplyAuditing()). Context pooling (AddDbContextPool) is not supported: pooled options are built once, /// from the root provider, and cannot carry per-request services. /// /// The scope's provider; the engine is resolved lazily, on first save. -internal sealed class AuditingSaveChangesInterceptor(IServiceProvider services) : SaveChangesInterceptor +internal sealed partial class AuditingSaveChangesInterceptor(IServiceProvider services) : SaveChangesInterceptor { private readonly ConditionalWeakTable _states = new(); - // Resolved on first use, not injected: the recorder depends on the store, the store on the - // DbContext, and this interceptor is created while that DbContext is still being built. - private IAuditManager? _audit; - private IAuditManager Audit => _audit ??= services.GetRequiredService(); - private AuditingOptions? _options; private AuditingOptions Options => _options ??= services.GetRequiredService(); // The engine itself, not the public interface: this capture decides to skip an entity before - // the engine sees it, and the reason for that decision is the engine's to give. Resolved from - // the same scope as IAuditManager, so it is the same instance behind it. + // the engine sees it, and the reason for that decision is the engine's to give; and it stores + // entries in the context being saved, not through the store. Resolved on first use, not + // injected: the recorder depends on the store, the store on the DbContext, and this + // interceptor is created while that DbContext is still being built. private AuditRecorder? _recorder; private AuditRecorder Recorder => _recorder ??= services.GetRequiredService(); @@ -77,11 +83,9 @@ public override InterceptionResult SavingChanges(DbContextEventData eventDa { ArgumentNullException.ThrowIfNull(eventData); - if (eventData.Context is { } context && Begin(context) is { } state) + if (eventData.Context is { } context && Saving(context, result) is { } state) { - Capture(context, state); - - if (state.Deferred.Count > 0 && NeedsOwnTransaction(context)) + if (NeedsTransactionNow(context, state)) state.OwnedTransaction = context.Database.BeginTransaction(); } @@ -96,11 +100,9 @@ public override async ValueTask> SavingChangesAsync( { ArgumentNullException.ThrowIfNull(eventData); - if (eventData.Context is { } context && Begin(context) is { } state) + if (eventData.Context is { } context && Saving(context, result) is { } state) { - Capture(context, state); - - if (state.Deferred.Count > 0 && NeedsOwnTransaction(context)) + if (NeedsTransactionNow(context, state)) { state.OwnedTransaction = await context.Database .BeginTransactionAsync(cancellationToken) @@ -116,34 +118,24 @@ public override int SavedChanges(SaveChangesCompletedEventData eventData, int re { ArgumentNullException.ThrowIfNull(eventData); - // IsRecording means this completion belongs to the interceptor's OWN deferred save. Without - // this check that save's SavedChanges would record the deferred entries again, save again, - // and recurse until the stack ran out. - if (eventData.Context is not { } context - || !_states.TryGetValue(context, out var state) - || state.IsRecording) - { + if (eventData.Context is not { } context || Saved(context) is not { } state) return result; - } try { - if (state.Deferred.Count > 0) - { - state.IsRecording = true; - RecordDeferred(state); + WriteDeferred(context, state); - // Cleared before the save, not after: nothing may re-run these, whatever happens - // next. - state.Deferred.Clear(); - context.SaveChanges(); + if (!DeferCommit(context, state)) + { + state.OwnedTransaction?.Commit(); + Finish(context, state); } - - state.OwnedTransaction?.Commit(); } - finally + catch { + RollbackQuietly(state); Finish(context, state); + throw; } return result; @@ -157,33 +149,26 @@ public override async ValueTask SavedChangesAsync( { ArgumentNullException.ThrowIfNull(eventData); - // See SavedChanges: IsRecording means this is the interceptor's own deferred save completing, - // and running the deferred pass again would recurse without end. - if (eventData.Context is not { } context - || !_states.TryGetValue(context, out var state) - || state.IsRecording) - { + if (eventData.Context is not { } context || Saved(context) is not { } state) return result; - } try { - if (state.Deferred.Count > 0) + await WriteDeferredAsync(context, state, cancellationToken).ConfigureAwait(false); + + if (!DeferCommit(context, state)) { - // Guards the re-entry: this save raises SavingChanges and SavedChanges again, and - // the only thing pending is the trail itself. - state.IsRecording = true; - RecordDeferred(state); - state.Deferred.Clear(); - await context.SaveChangesAsync(cancellationToken).ConfigureAwait(false); - } + if (state.OwnedTransaction is { } transaction) + await transaction.CommitAsync(cancellationToken).ConfigureAwait(false); - if (state.OwnedTransaction is { } transaction) - await transaction.CommitAsync(cancellationToken).ConfigureAwait(false); + Finish(context, state); + } } - finally + catch { + await RollbackQuietlyAsync(state).ConfigureAwait(false); Finish(context, state); + throw; } return result; @@ -193,74 +178,84 @@ public override async ValueTask SavedChangesAsync( public override void SaveChangesFailed(DbContextErrorEventData eventData) { ArgumentNullException.ThrowIfNull(eventData); + Abort(eventData.Context); + } - if (eventData.Context is not { } context - || !_states.TryGetValue(context, out var state) - || state.IsRecording) - { - // A failure in the deferred save itself unwinds through SavedChanges, whose finally - // disposes the uncommitted transaction — rolling the change back with it. - return; - } + /// + public override Task SaveChangesFailedAsync( + DbContextErrorEventData eventData, + CancellationToken cancellationToken = default) + { + ArgumentNullException.ThrowIfNull(eventData); + return AbortAsync(eventData.Context); + } - try - { - // Rolls back the change as well as its trail, which is the point of having opened it. - state.OwnedTransaction?.Rollback(); - } - finally - { - Finish(context, state); - } + /// + /// EF reports a cancelled save here and not through SaveChangesFailed. + public override void SaveChangesCanceled(DbContextEventData eventData) + { + ArgumentNullException.ThrowIfNull(eventData); + Abort(eventData.Context); } /// - public override async Task SaveChangesFailedAsync( - DbContextErrorEventData eventData, + /// See . + public override Task SaveChangesCanceledAsync( + DbContextEventData eventData, CancellationToken cancellationToken = default) { ArgumentNullException.ThrowIfNull(eventData); + return AbortAsync(eventData.Context); + } + + /// + /// + /// EF reports a concurrency conflict here, just before it throws, and not through + /// SaveChangesFailed — unless an interceptor suppresses the exception, and then the save + /// goes on. Rolled back later, not here: see . + /// + public override InterceptionResult ThrowingConcurrencyException( + ConcurrencyExceptionEventData eventData, + InterceptionResult result) + { + ArgumentNullException.ThrowIfNull(eventData); - if (eventData.Context is not { } context - || !_states.TryGetValue(context, out var state) - || state.IsRecording) - { - return; - } + if (!result.IsSuppressed) + RollBackAfterConflict(eventData.Context); - try - { - if (state.OwnedTransaction is { } transaction) - await transaction.RollbackAsync(cancellationToken).ConfigureAwait(false); - } - finally - { - Finish(context, state); - } + return result; } - /// - /// The state for this save, or null when this save is the interceptor's own deferred - /// write and must not be captured again. - /// - private SaveState? Begin(DbContext context) + /// + /// See . + public override ValueTask ThrowingConcurrencyExceptionAsync( + ConcurrencyExceptionEventData eventData, + InterceptionResult result, + CancellationToken cancellationToken = default) { - if (_states.TryGetValue(context, out var existing)) - return existing.IsRecording ? null : existing; + ArgumentNullException.ThrowIfNull(eventData); + + if (!result.IsSuppressed) + RollBackAfterConflict(eventData.Context); - var state = new SaveState(); - _states.Add(context, state); - return state; + return ValueTask.FromResult(result); } - private void Finish(DbContext context, SaveState state) + /// + /// Whether to open a transaction now: this save has deferred creations, there is none of ours + /// yet, and none to rely on. When there is one to rely on, it is remembered, so that + /// SavedChanges can tell whether someone committed it early. + /// + private static bool NeedsTransactionNow(DbContext context, SaveState state) { - state.OwnedTransaction?.Dispose(); - state.OwnedTransaction = null; - state.IsRecording = false; - state.Deferred.Clear(); + if (state.Deferred.Count == 0 || state.OwnedTransaction is not null) + return false; - _states.Remove(context); + if (NeedsOwnTransaction(context)) + return true; + + state.ReliedOn ??= context.Database.CurrentTransaction; + return false; } /// @@ -271,9 +266,9 @@ private void Finish(DbContext context, SaveState state) /// The tracker is materialised to a list first. Recording adds entities to it, and enumerating /// a collection while adding to it is how a capture becomes a capture of itself. /// - private void Capture(DbContext context, SaveState state) + private void Capture(DbContext context, SaveState state, List entries) { - var entries = context.ChangeTracker.Entries().ToList(); + EnsureMapsAuditTables(context); foreach (var entry in entries) { @@ -344,11 +339,11 @@ private void Capture(DbContext context, SaveState state) continue; } - Record(write); + Record(context, write); } } - private void RecordDeferred(SaveState state) + private void RecordDeferred(DbContext context, SaveState state) { foreach (var (entry, write) in state.Deferred) { @@ -358,36 +353,43 @@ private void RecordDeferred(SaveState state) "cannot be recorded. Assign the key in code, or exclude the entity with [AuditIgnore] " + "or IgnoreEntity()."); - Record(write with { EntityId = entityId }); + Record(context, write with { EntityId = entityId }); } } /// /// Records through the engine, which applies the model's rules, formats the values and stamps - /// the actor, correlation and time. + /// the actor, correlation and time — and adds the entry to , the + /// context being saved. /// /// - /// Awaited by completion rather than with await, so the synchronous - /// SaveChanges path shares this code. With the EF Core store that is exact rather than - /// hopeful: appending only tracks the entity, so the task is already complete when it comes - /// back. A store that genuinely went to the database here would be refused rather than blocked - /// on. + /// Not through the store: the store holds the scope's registered context, and a second context + /// in the same scope (another instance, or another type) is a different one. Its entries would + /// then be tracked where this save cannot write them. /// - private void Record(AuditWrite write) + private void Record(DbContext context, AuditWrite write) { - var recording = Audit.RecordAsync(write); + if (Recorder.Prepare(write) is not { } entry) + return; - if (!recording.IsCompleted) - { - throw new InvalidOperationException( - "The audit store did not complete synchronously. The EF Core capture tracks entries on " + - "the context rather than writing them, so it cannot block on a store that goes to the " + - "database during Append. Register the EF Core store, or record explicitly through " + - "IAuditManager instead of through the interceptor."); - } + context.Set().Add(entry); + Created(entry); + Recorder.Counted(entry); + } - // Observes the result, so a failure surfaces here rather than as an unobserved exception. - recording.GetAwaiter().GetResult(); + /// + /// Refuses a context that captures changes but has nowhere to keep them, before it writes + /// anything. + /// + private static void EnsureMapsAuditTables(DbContext context) + { + if (context.Model.FindEntityType(typeof(AuditEntry)) is not null) + return; + + throw new InvalidOperationException( + $"{context.GetType().Name} captures its changes with UseAuditing(sp), but its model has no " + + "audit tables, and entries are kept in the context being saved. Call " + + "modelBuilder.ApplyAuditing() in its OnModelCreating, or remove UseAuditing(sp) from its options."); } /// @@ -395,32 +397,14 @@ private void Record(AuditWrite write) /// private static bool NeedsOwnTransaction(DbContext context) => context.Database.CurrentTransaction is null + // An ambient TransactionScope already makes the two saves atomic, and EF refuses to begin + // a transaction inside one. + && System.Transactions.Transaction.Current is null // A non-relational provider has none to open. && context.Database.IsRelational() // A retrying strategy refuses a transaction it did not start, because it could not replay // it. Documented on the class rather than worked around here. && !context.Database.CreateExecutionStrategy().RetriesOnFailure; - /// What one save is holding. Lives for the length of that save and no longer. - private sealed class SaveState - { - /// Creations whose key arrives with the INSERT. - public List Deferred { get; } = []; - - /// The transaction this interceptor opened, or null when the caller had one. - public IDbContextTransaction? OwnedTransaction { get; set; } - - /// Whether the save now in flight is the interceptor's own deferred write. - public bool IsRecording { get; set; } - - /// - /// The id tying this save's entries together. Taken from the ambient activity when there is - /// one, so the trail joins the traces of the request that caused it, and otherwise minted - /// here — per save, not per entry. - /// - public string CorrelationId { get; } = - Activity.Current?.Id ?? Guid.NewGuid().ToString("n", CultureInfo.InvariantCulture); - } - private readonly record struct Deferred(EntityEntry Entry, AuditWrite Write); } diff --git a/tests/DotNetBoost.Auditing.IntegrationTests/CompositionTests.cs b/tests/DotNetBoost.Auditing.IntegrationTests/CompositionTests.cs new file mode 100644 index 0000000..d31e633 --- /dev/null +++ b/tests/DotNetBoost.Auditing.IntegrationTests/CompositionTests.cs @@ -0,0 +1,446 @@ +using System.Globalization; +using System.Transactions; +using DotNetBoost.Auditing.Core.Interfaces; +using DotNetBoost.Auditing.Core.Models; +using DotNetBoost.Auditing.TestSupport; +using Microsoft.EntityFrameworkCore; +using Microsoft.EntityFrameworkCore.Diagnostics; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.DependencyInjection.Extensions; + +namespace DotNetBoost.Auditing.IntegrationTests; + +/// +/// The capture sharing a context with another library's SaveChanges interceptor, on real +/// transactional engines. The same cases as ProviderTests/EfCoreCompositionTests, where +/// SQLite's transactions are a file lock; here they are MVCC (PostgreSQL) and locking with real +/// isolation (SQL Server), which is where "rolled back with it" is worth proving. Each case runs +/// through SaveChanges and SaveChangesAsync. The standalone fixes from +/// ProviderTests/EfCoreSaveLifecycleTests run here too: cancellation and concurrency +/// conflicts are reported by each engine's driver in its own way. +/// +public abstract class CompositionSuite : IAsyncLifetime +{ + private const string OtherRow = "written by the other library"; + + private readonly List _providers = []; + private string _connectionString = null!; + + /// A connection string to this suite's database. + protected abstract Task DatabaseAsync(); + + /// + /// Points the options at the engine, with when + /// : it retries the test's own transient failure, which the engines' + /// built-in strategies would not. + /// + protected abstract void UseEngine(DbContextOptionsBuilder options, string connectionString, bool retrying); + + public async Task InitializeAsync() + { + _connectionString = await DatabaseAsync(); + + var (provider, _) = Build(null, auditingFirst: true); + using var scope = provider.CreateScope(); + var db = scope.ServiceProvider.GetRequiredService(); + + await db.Database.EnsureCreatedAsync(); + await db.Set().ExecuteDeleteAsync(); + await db.Set().ExecuteDeleteAsync(); + await db.Products.ExecuteDeleteAsync(); + } + + public async Task DisposeAsync() + { + foreach (var provider in _providers) + await provider.DisposeAsync(); + } + + private (ServiceProvider Provider, RecordingAuditObserver Observer) Build( + IInterceptor? other, + bool auditingFirst, + bool retrying = false, + LostAtomicity onLost = LostAtomicity.Report) + { + var observer = new RecordingAuditObserver(); + var services = new ServiceCollection(); + + services.AddDbContext((sp, o) => + { + UseEngine(o, _connectionString, retrying); + + if (other is not null && !auditingFirst) + o.AddInterceptors(other); + + o.UseAuditing(sp); + + if (other is not null && auditingFirst) + o.AddInterceptors(other); + }); + + services.AddAuditing() + .UseEntityFrameworkCore() + .DeclareEntity() + .OnLostAtomicity(onLost) + .Build(); + + services.Replace(ServiceDescriptor.Singleton(observer)); + + var provider = services.BuildServiceProvider(); + _providers.Add(provider); + return (provider, observer); + } + + private static async Task InScopeAsync(ServiceProvider provider, Func work) + { + using var scope = provider.CreateScope(); + await work(scope.ServiceProvider.GetRequiredService()); + } + + private async Task> ProductsAsync() + { + var (provider, _) = Build(null, auditingFirst: true); + using var scope = provider.CreateScope(); + return await scope.ServiceProvider.GetRequiredService().Products.AsNoTracking().ToListAsync(); + } + + private async Task> EntriesAsync() + { + var (provider, _) = Build(null, auditingFirst: true); + using var scope = provider.CreateScope(); + return await scope.ServiceProvider.GetRequiredService().Set().AsNoTracking().ToListAsync(); + } + + private static string Id(Product product) => product.Id.ToString(CultureInfo.InvariantCulture); + + private static PostSaveWriterInterceptor Writer(WriterCommit commit) => + new(() => new Product { Name = OtherRow }) { Commit = commit }; + + private async Task AssertEachCreationRecordedOnceAsync() + { + var products = await ProductsAsync(); + var created = (await EntriesAsync()).Where(e => e.Action == AuditAction.Created).Select(e => e.EntityId).Order(); + Assert.Equal(products.Select(Id).Order(), created); + } + + [Theory] + [InlineData(true, WriterCommit.InSavedChanges, false)] + [InlineData(true, WriterCommit.InSavedChanges, true)] + [InlineData(true, WriterCommit.OnSavedChangesEvent, false)] + [InlineData(true, WriterCommit.OnSavedChangesEvent, true)] + [InlineData(false, WriterCommit.OnSavedChangesEvent, false)] + [InlineData(false, WriterCommit.OnSavedChangesEvent, true)] + public async Task Both_creations_are_recorded_once_with_their_real_ids(bool auditingFirst, WriterCommit commit, bool sync) + { + var (provider, observer) = Build(Writer(commit), auditingFirst); + + await InScopeAsync(provider, async db => + { + db.Products.Add(new Product { Name = "Widget" }); + await db.SaveAsync(sync); + Assert.Null(db.Database.CurrentTransaction); + }); + + Assert.Equal(2, (await ProductsAsync()).Count); + await AssertEachCreationRecordedOnceAsync(); + Assert.Empty(observer.LostAtomicity); + } + + [Theory] + [InlineData(true, WriterCommit.InSavedChanges, false)] + [InlineData(true, WriterCommit.InSavedChanges, true)] + [InlineData(true, WriterCommit.OnSavedChangesEvent, false)] + [InlineData(true, WriterCommit.OnSavedChangesEvent, true)] + [InlineData(false, WriterCommit.InSavedChanges, false)] + [InlineData(false, WriterCommit.InSavedChanges, true)] + [InlineData(false, WriterCommit.OnSavedChangesEvent, false)] + [InlineData(false, WriterCommit.OnSavedChangesEvent, true)] + public async Task A_failed_write_in_the_other_library_rolls_back_everything(bool auditingFirst, WriterCommit commit, bool sync) + { + var writer = Writer(commit); + writer.FailWrite = true; + var (provider, _) = Build(writer, auditingFirst); + + await Assert.ThrowsAsync(() => InScopeAsync(provider, async db => + { + db.Products.Add(new Product { Name = "Widget" }); + await db.SaveAsync(sync); + })); + + Assert.Empty(await ProductsAsync()); + Assert.Empty(await EntriesAsync()); + } + + [Theory] + + [InlineData(false)] + + [InlineData(true)] + public async Task A_throw_from_a_later_SavedChanges_rolls_back_everything(bool sync) + { + var (provider, _) = Build(new ThrowAfterSaveInterceptor(), auditingFirst: true); + + await Assert.ThrowsAsync(() => InScopeAsync(provider, async db => + { + db.Products.Add(new Product { Name = "Widget" }); + await db.SaveAsync(sync); + })); + + Assert.Empty(await ProductsAsync()); + Assert.Empty(await EntriesAsync()); + } + + [Theory] + + [InlineData(false)] + + [InlineData(true)] + public async Task An_early_commit_by_the_other_library_fails_the_save_under_Throw(bool sync) + { + var (provider, _) = Build(Writer(WriterCommit.InSavedChanges), auditingFirst: false, onLost: LostAtomicity.Throw); + + var error = await Assert.ThrowsAsync(() => InScopeAsync(provider, async db => + { + db.Products.Add(new Product { Name = "Widget" }); + await db.SaveAsync(sync); + })); + + Assert.Contains("committed before", error.Message, StringComparison.Ordinal); + } + + [Theory] + [InlineData(true, 0, false)] + [InlineData(true, 0, true)] + [InlineData(false, 0, false)] + [InlineData(false, 0, true)] + [InlineData(true, 1, false)] + [InlineData(true, 1, true)] + [InlineData(false, 1, false)] + [InlineData(false, 1, true)] + public async Task A_replayed_save_records_each_change_once(bool auditingFirst, int failedAttempts, bool sync) + { + var replay = new ReplayingInterceptor(); + var (provider, _) = Build(replay, auditingFirst, retrying: true); + + await InScopeAsync(provider, async db => + { + db.Products.Add(new Product { Name = "Widget", Price = 1m }); + await db.SaveChangesAsync(); + }); + + replay.FailAttempts = failedAttempts; + await InScopeAsync(provider, async db => + { + (await db.Products.SingleAsync()).Price = 2m; + db.Products.Add(new Product { Name = "Gadget" }); + await db.SaveAsync(sync); + Assert.Null(db.Database.CurrentTransaction); + }); + + Assert.Single(await EntriesAsync(), e => e.Action == AuditAction.Updated); + await AssertEachCreationRecordedOnceAsync(); + } + + [Theory] + + [InlineData(false)] + + [InlineData(true)] + public async Task A_creation_inside_a_completed_TransactionScope_is_recorded(bool sync) + { + var (provider, _) = Build(null, auditingFirst: true); + + await InScopeAsync(provider, async db => + { + using var scope = new TransactionScope(TransactionScopeAsyncFlowOption.Enabled); + + // A store-generated key, so the creation is deferred. The interceptor must not open a + // transaction of its own inside the ambient one: EF refuses that. + db.Products.Add(new Product { Name = "Widget", Price = 1m }); + await db.SaveAsync(sync); + + scope.Complete(); + }); + + Assert.Single(await ProductsAsync()); + Assert.Single(await EntriesAsync(), e => e.Action == AuditAction.Created); + } + + [Theory] + + [InlineData(false)] + + [InlineData(true)] + public async Task Abandoning_a_TransactionScope_takes_the_trail_with_it(bool sync) + { + var (provider, _) = Build(null, auditingFirst: true); + + await InScopeAsync(provider, async db => + { + using var scope = new TransactionScope(TransactionScopeAsyncFlowOption.Enabled); + + db.Products.Add(new Product { Name = "Widget", Price = 1m }); + await db.SaveAsync(sync); + + // Disposed without Complete(): the scope rolls back, and the deferred entry with it. + }); + + Assert.Empty(await ProductsAsync()); + Assert.Empty(await EntriesAsync()); + } + + // ---- The standalone fixes, on a real engine -------------------------------------------- + + [Fact] + public async Task A_cancelled_save_leaves_no_transaction_open_and_a_retry_records_once() + { + var cancel = new CancellingInterceptor(); + var (provider, _) = Build(cancel, auditingFirst: true); + + await InScopeAsync(provider, async db => + { + db.Products.Add(new Product { Name = "Widget" }); + + using var request = new CancellationTokenSource(); + cancel.Cancel = request; + await Assert.ThrowsAnyAsync(() => db.SaveChangesAsync(request.Token)); + Assert.Null(db.Database.CurrentTransaction); + + cancel.Cancel = null; + await db.SaveChangesAsync(); + }); + + await AssertEachCreationRecordedOnceAsync(); + Assert.Single(await ProductsAsync()); + } + + [Theory] + [InlineData(false)] + [InlineData(true)] + public async Task A_save_refused_by_a_later_SavingChanges_hook_is_cleaned_up_by_the_next_save(bool sync) + { + var refuse = new RefusingInterceptor(); + var (provider, _) = Build(refuse, auditingFirst: true); + + await InScopeAsync(provider, async db => + { + db.Products.Add(new Product { Name = "Widget" }); + + await Assert.ThrowsAsync(() => db.SaveAsync(sync)); + + refuse.Active = false; + await db.SaveAsync(sync); + Assert.Null(db.Database.CurrentTransaction); + }); + + await AssertEachCreationRecordedOnceAsync(); + Assert.Single(await ProductsAsync()); + } + + [Theory] + [InlineData(false)] + [InlineData(true)] + public async Task A_concurrency_conflict_leaves_no_transaction_open(bool sync) + { + var (provider, _) = Build(null, auditingFirst: true); + + await InScopeAsync(provider, async db => + { + db.Products.Add(new Product { Name = "Gone", Price = 1m }); + await db.SaveChangesAsync(); + }); + + await InScopeAsync(provider, async db => + { + var gone = await db.Products.SingleAsync(); + + // Deleted behind this context's back, so updating it affects no row. + await InScopeAsync(provider, async other => + await other.Products.Where(p => p.Id == gone.Id).ExecuteDeleteAsync()); + + gone.Price = 2m; + db.Products.Add(new Product { Name = "Widget" }); + + await Assert.ThrowsAsync(() => db.SaveAsync(sync)); + Assert.Null(db.Database.CurrentTransaction); + }); + + // Neither the conflicting save's creation nor its entry. + Assert.Empty(await ProductsAsync()); + Assert.DoesNotContain(await EntriesAsync(), e => e.Action == AuditAction.Updated); + } + + [Theory] + [InlineData(false)] + [InlineData(true)] + public async Task A_suppressed_save_is_not_recorded_and_opens_no_transaction(bool sync) + { + var suppress = new SuppressingInterceptor(); + var (provider, _) = Build(suppress, auditingFirst: false); + + await InScopeAsync(provider, async db => + { + db.Products.Add(new Product { Name = "Widget" }); + + suppress.Active = true; + Assert.Equal(0, await db.SaveAsync(sync)); + Assert.Null(db.Database.CurrentTransaction); + Assert.Empty(db.ChangeTracker.Entries()); + }); + + Assert.Empty(await ProductsAsync()); + Assert.Empty(await EntriesAsync()); + } + + [Theory] + [InlineData(false)] + [InlineData(true)] + public async Task A_second_context_in_the_scope_writes_its_own_entries(bool sync) + { + var (provider, _) = Build(null, auditingFirst: true); + + using (var scope = provider.CreateScope()) + { + var registered = scope.ServiceProvider.GetRequiredService(); + await using var second = new AuditDbContext( + scope.ServiceProvider.GetRequiredService>()); + + second.Products.Add(new Product { Name = "Widget", Price = 1m }); + await second.SaveAsync(sync); + + (await second.Products.SingleAsync()).Price = 2m; + await second.SaveAsync(sync); + + Assert.Empty(registered.ChangeTracker.Entries()); + } + + await AssertEachCreationRecordedOnceAsync(); + Assert.Single(await EntriesAsync(), e => e.Action == AuditAction.Updated); + } +} + +[Collection("postgres")] +public sealed class PostgresCompositionTests(PostgresFixture fixture) : CompositionSuite +{ + protected override Task DatabaseAsync() => fixture.DatabaseAsync("audit_composition"); + + protected override void UseEngine(DbContextOptionsBuilder options, string connectionString, bool retrying) => + options.UseNpgsql(connectionString, b => + { + if (retrying) + b.ExecutionStrategy(d => new TestRetryingStrategy(d)); + }); +} + +[Collection("sqlserver")] +public sealed class SqlServerCompositionTests(SqlServerFixture fixture) : CompositionSuite +{ + protected override Task DatabaseAsync() => fixture.DatabaseAsync("audit_composition"); + + protected override void UseEngine(DbContextOptionsBuilder options, string connectionString, bool retrying) => + options.UseSqlServer(connectionString, b => + { + if (retrying) + b.ExecutionStrategy(d => new TestRetryingStrategy(d)); + }); +} diff --git a/tests/DotNetBoost.Auditing.ProviderTests/EfCoreCompositionTests.cs b/tests/DotNetBoost.Auditing.ProviderTests/EfCoreCompositionTests.cs new file mode 100644 index 0000000..148ecdd --- /dev/null +++ b/tests/DotNetBoost.Auditing.ProviderTests/EfCoreCompositionTests.cs @@ -0,0 +1,259 @@ +using System.Globalization; +using DotNetBoost.Auditing.Core; +using DotNetBoost.Auditing.Core.Models; +using DotNetBoost.Auditing.TestSupport; +using Microsoft.EntityFrameworkCore; +using Microsoft.EntityFrameworkCore.Diagnostics; +using Microsoft.Extensions.DependencyInjection; + +namespace DotNetBoost.Auditing.ProviderTests; + +/// +/// The capture sharing a context with another library's SaveChanges interceptor, registered +/// before it and after it. The stand-ins in TestSupport mimic what DotNetBoost.MultiLingual +/// does, without referencing it: a row written from SavedChanges through a nested save, a +/// transaction committed in SavedChanges or from EF's event, a save replayed under a +/// retrying strategy. Each case runs through SaveChanges and SaveChangesAsync: the +/// synchronous path has its own hooks, and the commit from EF's event is synchronous on both. +/// +public class EfCoreCompositionTests +{ + private const string OtherRow = "written by the other library"; + + private static EfCoreHarness Harness( + SaveChangesInterceptor other, + bool auditingFirst, + bool retrying = false, + Action? build = null, + Action? configure = null) => + new( + configure: configure, + build: build, + beforeAuditing: auditingFirst ? null : o => o.AddInterceptors(other), + afterAuditing: auditingFirst ? o => o.AddInterceptors(other) : null, + sqlite: retrying ? b => b.ExecutionStrategy(d => new TestRetryingStrategy(d)) : null); + + private static PostSaveWriterInterceptor Writer(WriterCommit commit) => + new(() => new Product { Name = OtherRow }) { Commit = commit }; + + private static async Task> ProductsAsync(EfCoreHarness harness) => + await harness.InScopeAsync(async (db, _) => await db.Products.AsNoTracking().OrderBy(p => p.Id).ToListAsync()); + + private static string Id(Product product) => product.Id.ToString(CultureInfo.InvariantCulture); + + // ---- A row written after the save ------------------------------------------------------ + + [Theory] + [InlineData(true, WriterCommit.InSavedChanges, false)] + [InlineData(true, WriterCommit.InSavedChanges, true)] + [InlineData(true, WriterCommit.OnSavedChangesEvent, false)] + [InlineData(true, WriterCommit.OnSavedChangesEvent, true)] + [InlineData(false, WriterCommit.OnSavedChangesEvent, false)] + [InlineData(false, WriterCommit.OnSavedChangesEvent, true)] + public async Task Both_creations_are_recorded_once_with_their_real_ids(bool auditingFirst, WriterCommit commit, bool sync) + { + using var harness = Harness(Writer(commit), auditingFirst); + + await harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Widget" }); + await db.SaveAsync(sync); + + Assert.Null(db.Database.CurrentTransaction); + }); + + // The other library's row is a creation with a store-generated key, written in a save + // nested inside this one. It is recorded like the entity, once, and the nested save is not + // mistaken for a second outermost one. + var products = await ProductsAsync(harness); + Assert.Equal(2, products.Count); + + var created = (await harness.EntriesAsync()).Where(e => e.Action == AuditAction.Created).Select(e => e.EntityId).Order().ToList(); + Assert.Equal(products.Select(Id).Order(), created); + } + + [Theory] + [InlineData(true, WriterCommit.InSavedChanges, false)] + [InlineData(true, WriterCommit.InSavedChanges, true)] + [InlineData(true, WriterCommit.OnSavedChangesEvent, false)] + [InlineData(true, WriterCommit.OnSavedChangesEvent, true)] + [InlineData(false, WriterCommit.InSavedChanges, false)] + [InlineData(false, WriterCommit.InSavedChanges, true)] + [InlineData(false, WriterCommit.OnSavedChangesEvent, false)] + [InlineData(false, WriterCommit.OnSavedChangesEvent, true)] + public async Task A_failed_write_in_the_other_library_rolls_back_everything(bool auditingFirst, WriterCommit commit, bool sync) + { + var writer = Writer(commit); + writer.FailWrite = true; + using var harness = Harness(writer, auditingFirst); + + await Assert.ThrowsAsync(() => harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Widget" }); + await db.SaveAsync(sync); + })); + + // With the capture registered first it owns the transaction, and the other library writes + // inside it after the capture's SavedChanges has returned. Committing there would leave the + // entity and its entry behind with the other library's row missing. + Assert.Empty(await ProductsAsync(harness)); + Assert.Empty(await harness.EntriesAsync()); + } + + [Theory] + + [InlineData(false)] + + [InlineData(true)] + public async Task A_throw_from_a_later_SavedChanges_rolls_back_everything(bool sync) + { + using var harness = Harness(new ThrowAfterSaveInterceptor(), auditingFirst: true); + + await Assert.ThrowsAsync(() => harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Widget" }); + await db.SaveAsync(sync); + + Assert.Null(db.Database.CurrentTransaction); + })); + + Assert.Empty(await ProductsAsync(harness)); + Assert.Empty(await harness.EntriesAsync()); + } + + // ---- A transaction committed before the capture wrote its entries ---------------------- + + [Theory] + + [InlineData(false)] + + [InlineData(true)] + public async Task An_early_commit_by_the_other_library_is_reported(bool sync) + { + // Registered first and committing in its own SavedChanges, the other library's transaction + // is gone by the time the capture writes the deferred entries. + using var harness = Harness(Writer(WriterCommit.InSavedChanges), auditingFirst: false); + + await harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Widget" }); + await db.SaveAsync(sync); + }); + + // Written anyway, as before, but no longer silently. + var (correlationId, entries) = Assert.Single(harness.Observer.LostAtomicity); + Assert.Equal(2, entries); + Assert.All(await harness.EntriesAsync(), e => Assert.Equal(correlationId, e.CorrelationId)); + } + + [Theory] + + [InlineData(false)] + + [InlineData(true)] + public async Task An_early_commit_by_the_other_library_fails_the_save_under_Throw(bool sync) + { + using var harness = Harness( + Writer(WriterCommit.InSavedChanges), + auditingFirst: false, + build: b => b.OnLostAtomicity(LostAtomicity.Throw)); + + var error = await Assert.ThrowsAsync(() => harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Widget" }); + await db.SaveAsync(sync); + })); + + Assert.Contains("committed before", error.Message, StringComparison.Ordinal); + Assert.Empty(harness.Observer.LostAtomicity); + } + + [Theory] + [InlineData(true, WriterCommit.InSavedChanges, false)] + [InlineData(true, WriterCommit.InSavedChanges, true)] + [InlineData(true, WriterCommit.OnSavedChangesEvent, false)] + [InlineData(true, WriterCommit.OnSavedChangesEvent, true)] + [InlineData(false, WriterCommit.OnSavedChangesEvent, false)] + [InlineData(false, WriterCommit.OnSavedChangesEvent, true)] + public async Task An_atomic_composition_reports_nothing(bool auditingFirst, WriterCommit commit, bool sync) + { + using var harness = Harness(Writer(commit), auditingFirst, build: b => b.OnLostAtomicity(LostAtomicity.Throw)); + + await harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Widget" }); + await db.SaveAsync(sync); + }); + + Assert.Empty(harness.Observer.LostAtomicity); + } + + // ---- A save replayed under a retrying strategy ----------------------------------------- + + [Theory] + [InlineData(true, false)] + [InlineData(true, true)] + [InlineData(false, false)] + [InlineData(false, true)] + public async Task A_replayed_save_records_each_change_once(bool auditingFirst, bool sync) + { + var replay = new ReplayingInterceptor(); + using var harness = Harness(replay, auditingFirst, retrying: true); + + await harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Widget", Price = 1m }); + await db.SaveChangesAsync(); + }); + + await harness.InScopeAsync(async (db, _) => + { + (await db.Products.SingleAsync()).Price = 2m; + db.Products.Add(new Product { Name = "Gadget" }); + await db.SaveAsync(sync); + + Assert.Null(db.Database.CurrentTransaction); + }); + + var entries = await harness.EntriesAsync(); + Assert.Single(entries, e => e.Action == AuditAction.Updated); + Assert.Equal( + (await ProductsAsync(harness)).Select(Id).Order(), + entries.Where(e => e.Action == AuditAction.Created).Select(e => e.EntityId).Order()); + } + + [Theory] + [InlineData(true, false)] + [InlineData(true, true)] + [InlineData(false, false)] + [InlineData(false, true)] + public async Task A_replay_retried_after_a_transient_failure_records_each_change_once(bool auditingFirst, bool sync) + { + var replay = new ReplayingInterceptor(); + using var harness = Harness(replay, auditingFirst, retrying: true); + + await harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Widget", Price = 1m }); + await db.SaveChangesAsync(); + }); + + replay.FailAttempts = 1; + await harness.InScopeAsync(async (db, _) => + { + // An update is recorded into the save while SavingChanges runs, so its entry is tracked + // before the replay starts — and the replay puts the tracker back before retrying. + (await db.Products.SingleAsync()).Price = 2m; + db.Products.Add(new Product { Name = "Gadget" }); + await db.SaveAsync(sync); + }); + + Assert.Equal(3, replay.Attempts); + + var entries = await harness.EntriesAsync(); + Assert.Single(entries, e => e.Action == AuditAction.Updated); + Assert.Equal( + (await ProductsAsync(harness)).Select(Id).Order(), + entries.Where(e => e.Action == AuditAction.Created).Select(e => e.EntityId).Order()); + } +} diff --git a/tests/DotNetBoost.Auditing.ProviderTests/EfCoreHarness.cs b/tests/DotNetBoost.Auditing.ProviderTests/EfCoreHarness.cs index 5a04981..9f62609 100644 --- a/tests/DotNetBoost.Auditing.ProviderTests/EfCoreHarness.cs +++ b/tests/DotNetBoost.Auditing.ProviderTests/EfCoreHarness.cs @@ -82,10 +82,16 @@ internal sealed class EfCoreHarness : IDisposable /// Applied to the options. /// Whether the context records itself through the interceptor. /// Applied to the builder after the declarations, just before Build(). + /// Applied to the options before UseAuditing: interceptors added here run first. + /// Applied to the options after UseAuditing: interceptors added here run after it. + /// Applied to the SQLite options, for an execution strategy. public EfCoreHarness( Action? configure = null, bool capture = true, - Action? build = null) + Action? build = null, + Action? beforeAuditing = null, + Action? afterAuditing = null, + Action? sqlite = null) { _connection = new SqliteConnection("DataSource=:memory:"); _connection.Open(); @@ -94,13 +100,16 @@ public EfCoreHarness( services.AddDbContext((sp, o) => { - o.UseSqlite(_connection); + o.UseSqlite(_connection, b => sqlite?.Invoke(b)); o.AddInterceptors(Saves); + beforeAuditing?.Invoke(o); // Without this line the tables exist and IAuditManager works, but nothing records // itself — which is what the "capture off" tests check. if (capture) o.UseAuditing(sp); + + afterAuditing?.Invoke(o); }); var builder = services.AddAuditing(o => configure?.Invoke(o)) @@ -124,6 +133,9 @@ public EfCoreHarness( public MutableActorAccessor Actors { get; } = new(); + /// The open connection every context in this harness shares. + public SqliteConnection Connection => _connection; + /// What the engine and the interceptor decided not to record. public RecordingAuditObserver Observer { get; } = new(); diff --git a/tests/DotNetBoost.Auditing.ProviderTests/EfCoreSaveLifecycleTests.cs b/tests/DotNetBoost.Auditing.ProviderTests/EfCoreSaveLifecycleTests.cs new file mode 100644 index 0000000..93cb7f2 --- /dev/null +++ b/tests/DotNetBoost.Auditing.ProviderTests/EfCoreSaveLifecycleTests.cs @@ -0,0 +1,271 @@ +using DotNetBoost.Auditing.Core.Models; +using DotNetBoost.Auditing.EntityFrameworkCore; +using DotNetBoost.Auditing.TestSupport; +using Microsoft.EntityFrameworkCore; +using Microsoft.Extensions.DependencyInjection; + +namespace DotNetBoost.Auditing.ProviderTests; + +/// +/// How the capture behaves when a save does not run the ordinary way: cancelled, refused, in +/// conflict, suppressed by another interceptor, or made by a context other than the one the store +/// was registered with. Each case runs through SaveChanges and SaveChangesAsync, +/// whose interceptor hooks are separate code. +/// +public class EfCoreSaveLifecycleTests +{ + // ---- A cancelled save (asynchronous only: a synchronous save takes no token) ----------- + + [Fact] + public async Task A_cancelled_save_leaves_no_transaction_open() + { + var cancel = new CancellingInterceptor(); + using var harness = new EfCoreHarness(afterAuditing: o => o.AddInterceptors(cancel)); + + await harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Widget" }); + + using var request = new CancellationTokenSource(); + cancel.Cancel = request; + await Assert.ThrowsAnyAsync(() => db.SaveChangesAsync(request.Token)); + + // The deferred creation made the interceptor open a transaction before the token was + // cancelled. EF reports a cancellation through SaveChangesCanceled, not + // SaveChangesFailed, so that is where it has to be rolled back. + Assert.Null(db.Database.CurrentTransaction); + }); + + await harness.InScopeAsync(async (db, _) => Assert.Empty(await db.Products.ToListAsync())); + } + + [Fact] + public async Task A_save_retried_after_a_cancellation_records_the_creation_once() + { + var cancel = new CancellingInterceptor(); + using var harness = new EfCoreHarness(afterAuditing: o => o.AddInterceptors(cancel)); + + await harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Widget" }); + + using var request = new CancellationTokenSource(); + cancel.Cancel = request; + await Assert.ThrowsAnyAsync(() => db.SaveChangesAsync(request.Token)); + + // Retrying a cancelled save is ordinary: nothing was written, and the entity is still + // Added. The cancelled attempt's state must not survive into this one. + cancel.Cancel = null; + await db.SaveChangesAsync(); + }); + + var entry = Assert.Single(await harness.EntriesAsync()); + Assert.Equal(AuditAction.Created, entry.Action); + await harness.InScopeAsync(async (db, _) => + Assert.Equal(entry.EntityId, (await db.Products.SingleAsync()).Id.ToString(System.Globalization.CultureInfo.InvariantCulture))); + } + + // ---- A save refused before it ran ------------------------------------------------------- + + [Theory] + [InlineData(false)] + [InlineData(true)] + public async Task A_save_refused_by_a_later_SavingChanges_hook_is_cleaned_up_by_the_next_save(bool sync) + { + // EF calls SavingChanges before the part of SaveChanges that reports failures, so nothing + // tells this interceptor that the save it opened a transaction for is over. The transaction + // stays open until the context saves again (or is disposed); that save must start over + // rather than join the abandoned one. + var refuse = new RefusingInterceptor(); + using var harness = new EfCoreHarness(afterAuditing: o => o.AddInterceptors(refuse)); + + await harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Widget" }); + + await Assert.ThrowsAsync(() => db.SaveAsync(sync)); + Assert.NotNull(db.Database.CurrentTransaction); + + refuse.Active = false; + await db.SaveAsync(sync); + + Assert.Null(db.Database.CurrentTransaction); + }); + + var product = await harness.InScopeAsync(async (db, _) => await db.Products.SingleAsync()); + var entry = Assert.Single(await harness.EntriesAsync()); + Assert.Equal(product.Id.ToString(System.Globalization.CultureInfo.InvariantCulture), entry.EntityId); + } + + // ---- A concurrency conflict ------------------------------------------------------------- + + [Theory] + [InlineData(false)] + [InlineData(true)] + public async Task A_concurrency_conflict_leaves_no_transaction_open(bool sync) + { + using var harness = new EfCoreHarness(); + + await harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Gone", Price = 1m }); + await db.SaveChangesAsync(); + }); + + await harness.InScopeAsync(async (db, _) => + { + var gone = await db.Products.SingleAsync(); + + // Deleted behind this context's back, so updating it affects no row. + await harness.InScopeAsync(async (other, _) => + await other.Products.Where(p => p.Id == gone.Id).ExecuteDeleteAsync()); + + gone.Price = 2m; + db.Products.Add(new Product { Name = "Widget" }); + + await Assert.ThrowsAsync(() => db.SaveAsync(sync)); + Assert.Null(db.Database.CurrentTransaction); + }); + } + + // An ambient TransactionScope is tested in IntegrationTests (CompositionTests): EF's SQLite + // provider refuses ambient transactions whether or not this library is involved. + + // ---- A save another interceptor suppressed --------------------------------------------- + + [Theory] + [InlineData(false)] + [InlineData(true)] + public async Task A_suppressed_creation_is_not_recorded_and_opens_no_transaction(bool sync) + { + var suppress = new SuppressingInterceptor(); + using var harness = new EfCoreHarness(beforeAuditing: o => o.AddInterceptors(suppress)); + + await harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Widget" }); + + suppress.Active = true; + Assert.Equal(0, await db.SaveAsync(sync)); + + // The interceptor that suppressed the save decided what happens to it. Auditing has + // nothing to record for a save that never reached the database. + Assert.Null(db.Database.CurrentTransaction); + Assert.Empty(db.ChangeTracker.Entries()); + }); + + Assert.Empty(await harness.EntriesAsync()); + await harness.InScopeAsync(async (db, _) => Assert.Empty(await db.Products.ToListAsync())); + } + + [Theory] + [InlineData(false)] + [InlineData(true)] + public async Task A_suppressed_update_leaves_no_entry_behind(bool sync) + { + var suppress = new SuppressingInterceptor(); + using var harness = new EfCoreHarness(beforeAuditing: o => o.AddInterceptors(suppress)); + + await harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Widget", Price = 1m }); + await db.SaveChangesAsync(); + }); + + await harness.InScopeAsync(async (db, _) => + { + (await db.Products.SingleAsync()).Price = 2m; + + suppress.Active = true; + await db.SaveAsync(sync); + + // Left tracked, the entry would be written by whatever this context saves next, + // describing a change that was never made. + Assert.Empty(db.ChangeTracker.Entries()); + }); + + Assert.DoesNotContain(await harness.EntriesAsync(), e => e.Action == AuditAction.Updated); + } + + // ---- A context other than the registered instance -------------------------------------- + + [Theory] + [InlineData(false)] + [InlineData(true)] + public async Task A_second_context_in_the_scope_writes_its_own_creation_entry(bool sync) + { + using var harness = new EfCoreHarness(); + + await harness.InScopeAsync(async (db, sp) => + { + // Same type, same options, same scope — but not the instance the DI container hands + // out, which is the one the store was bound to. + await using var second = new TestDbContext(sp.GetRequiredService>()); + + second.Products.Add(new Product { Name = "Widget" }); + await second.SaveAsync(sync); + + Assert.Empty(db.ChangeTracker.Entries()); + }); + + Assert.Single(await harness.EntriesAsync(), e => e.Action == AuditAction.Created); + } + + [Theory] + [InlineData(false)] + [InlineData(true)] + public async Task A_second_context_in_the_scope_writes_its_own_update_entry_in_its_own_save(bool sync) + { + using var harness = new EfCoreHarness(); + + await harness.InScopeAsync(async (db, _) => + { + db.Products.Add(new Product { Name = "Widget", Price = 1m }); + await db.SaveChangesAsync(); + }); + + await harness.InScopeAsync(async (db, sp) => + { + await using var second = new TestDbContext(sp.GetRequiredService>()); + + (await second.Products.SingleAsync()).Price = 2m; + await second.SaveAsync(sync); + + Assert.Empty(db.ChangeTracker.Entries()); + }); + + Assert.Single(await harness.EntriesAsync(), e => e.Action == AuditAction.Updated); + } + + [Theory] + [InlineData(false)] + [InlineData(true)] + public async Task A_context_without_the_audit_tables_is_refused_with_the_fix(bool sync) + { + using var harness = new EfCoreHarness(); + + var error = await Assert.ThrowsAsync(() => + harness.InScopeAsync(async (_, sp) => + { + var options = new DbContextOptionsBuilder().UseSqlite(harness.Connection); + options.UseAuditing(sp); + + await using var unmapped = new UnmappedDbContext(options.Options); + + unmapped.Products.Add(new Product { Name = "Widget", Price = 1m }); + await unmapped.SaveAsync(sync); + })); + + Assert.Contains(nameof(UnmappedDbContext), error.Message, StringComparison.Ordinal); + Assert.Contains("ApplyAuditing", error.Message, StringComparison.Ordinal); + + // Refused, not quietly recorded somewhere else. + Assert.Empty(await harness.EntriesAsync()); + } + + /// Maps the products table and nothing else: no ApplyAuditing(). + private sealed class UnmappedDbContext(DbContextOptions options) : DbContext(options) + { + public DbSet Products => Set(); + } +} diff --git a/tests/DotNetBoost.Auditing.TestSupport/CompositionInterceptors.cs b/tests/DotNetBoost.Auditing.TestSupport/CompositionInterceptors.cs new file mode 100644 index 0000000..f1090ef --- /dev/null +++ b/tests/DotNetBoost.Auditing.TestSupport/CompositionInterceptors.cs @@ -0,0 +1,617 @@ +using System.Runtime.CompilerServices; +using Microsoft.EntityFrameworkCore; +using Microsoft.EntityFrameworkCore.ChangeTracking; +using Microsoft.EntityFrameworkCore.Diagnostics; +using Microsoft.EntityFrameworkCore.Storage; + +namespace DotNetBoost.Auditing.TestSupport; + +// Stand-ins for another library's SaveChanges interceptor on the same context, without referencing +// one. Each mimics a behaviour DotNetBoost.MultiLingual has, because that is the composition these +// tests exist for; none of them is a copy of it. + +/// When commits the transaction it opened. +public enum WriterCommit +{ + /// In its own SavedChanges, before any interceptor registered after it has run. + InSavedChanges, + + /// From EF's DbContext.SavedChanges event, once every interceptor has finished. + OnSavedChangesEvent +} + +/// +/// Writes a row of its own after the save, through a nested SaveChanges issued from its +/// SavedChanges, the way a library storing data keyed on the entity's generated id must. +/// Opens a transaction in SavingChanges when there is none, and counts nested saves. Like +/// such a library, it has work only when the save changes an application entity: a save that only +/// writes audit entries gives it none. +/// +/// The row it writes; give it a store-generated key so the capture defers it. +public sealed class PostSaveWriterInterceptor(Func newRow) : SaveChangesInterceptor +{ + private readonly ConditionalWeakTable _states = new(); + + /// When it commits the transaction it opened. + public WriterCommit Commit { get; set; } = WriterCommit.OnSavedChangesEvent; + + /// Throw after writing its row and before committing, as a failed write would. + public bool FailWrite { get; set; } + + /// How many rows it has written, committed or not. + public int RowsWritten { get; private set; } + + /// + public override InterceptionResult SavingChanges(DbContextEventData eventData, InterceptionResult result) + { + if (!result.HasResult && eventData.Context is { } context) + Saving(context, s => s.Owned = context.Database.BeginTransaction()); + + return result; + } + + /// + public override async ValueTask> SavingChangesAsync( + DbContextEventData eventData, + InterceptionResult result, + CancellationToken cancellationToken = default) + { + if (!result.HasResult && eventData.Context is { } context && Saving(context, null)) + _states.GetOrCreateValue(context).Owned = await context.Database.BeginTransactionAsync(cancellationToken); + + return result; + } + + /// + public override int SavedChanges(SaveChangesCompletedEventData eventData, int result) + { + if (eventData.Context is { } context && Outermost(context) is { } state) + { + Write(context, state); + Complete(context, state); + } + + return result; + } + + /// + public override async ValueTask SavedChangesAsync( + SaveChangesCompletedEventData eventData, + int result, + CancellationToken cancellationToken = default) + { + if (eventData.Context is { } context && Outermost(context) is { } state) + { + await WriteAsync(context, state, cancellationToken); + Complete(context, state); + } + + return result; + } + + /// + public override void SaveChangesFailed(DbContextErrorEventData eventData) => Failed(eventData.Context); + + /// + public override Task SaveChangesFailedAsync(DbContextErrorEventData eventData, CancellationToken cancellationToken = default) + { + Failed(eventData.Context); + return Task.CompletedTask; + } + + /// + public override void SaveChangesCanceled(DbContextEventData eventData) => Failed(eventData.Context); + + /// + public override Task SaveChangesCanceledAsync(DbContextEventData eventData, CancellationToken cancellationToken = default) + { + Failed(eventData.Context); + return Task.CompletedTask; + } + + /// True when this starts an outermost save that should open a transaction. + private bool Saving(DbContext context, Action? open) + { + var state = _states.GetOrCreateValue(context); + if (state.Writing) + return false; + + if (state.Depth > 0 || state.Pending) + { + state.Depth++; + return false; + } + + state.Depth = 1; + state.HasWork = context.ChangeTracker.Entries().Any(e => + e.State is EntityState.Added or EntityState.Modified or EntityState.Deleted + && e.Entity is not (Core.Models.AuditEntry or Core.Models.AuditPropertyChange)); + + var needs = state.HasWork + && context.Database.CurrentTransaction is null + && System.Transactions.Transaction.Current is null; + if (needs) + open?.Invoke(state); + + return needs; + } + + private State? Outermost(DbContext context) + { + if (!_states.TryGetValue(context, out var state) || state.Writing || state.Depth == 0) + return null; + + if (--state.Depth > 0) + { + if (state.Pending) + state.NestedAwaitingEvent++; + + return null; + } + + return state; + } + + private void Write(DbContext context, State state) + { + if (!state.HasWork) + return; + + state.Writing = true; + try + { + context.Add(newRow()); + context.SaveChanges(); + RowsWritten++; + } + finally + { + state.Writing = false; + } + + ThrowIfFailing(); + } + + private async Task WriteAsync(DbContext context, State state, CancellationToken ct) + { + if (!state.HasWork) + return; + + state.Writing = true; + try + { + context.Add(newRow()); + await context.SaveChangesAsync(ct); + RowsWritten++; + } + finally + { + state.Writing = false; + } + + ThrowIfFailing(); + } + + private void ThrowIfFailing() + { + if (FailWrite) + throw new InvalidOperationException("The other library's write failed."); + } + + private void Complete(DbContext context, State state) + { + if (state.Owned is null || Commit == WriterCommit.InSavedChanges) + { + state.Owned?.Commit(); + Finish(context, state); + return; + } + + state.Pending = true; + state.Depth = 1; + if (!state.Listening) + { + context.SavedChanges += OnSavedChanges; + state.Listening = true; + } + } + + private void OnSavedChanges(object? sender, SavedChangesEventArgs e) + { + if (sender is not DbContext context || !_states.TryGetValue(context, out var state) || state.Writing || !state.Pending) + return; + + if (state.NestedAwaitingEvent > 0) + { + state.NestedAwaitingEvent--; + return; + } + + state.Owned?.Commit(); + Finish(context, state); + } + + private void Failed(DbContext? context) + { + if (context is null || !_states.TryGetValue(context, out var state) || state.Writing) + return; + + if (state.Depth > 1) + { + state.Depth--; + return; + } + + state.Owned?.Rollback(); + Finish(context, state); + } + + private void Finish(DbContext context, State state) + { + state.Owned?.Dispose(); + if (state.Listening) + context.SavedChanges -= OnSavedChanges; + + _states.Remove(context); + } + + private sealed class State + { + public int Depth { get; set; } + public IDbContextTransaction? Owned { get; set; } + public bool Writing { get; set; } + public bool HasWork { get; set; } + public bool Pending { get; set; } + public bool Listening { get; set; } + public int NestedAwaitingEvent { get; set; } + } +} + +/// +/// Under a retrying execution strategy with no caller transaction, suppresses the save and replays +/// it as one unit inside the strategy and a transaction of its own, putting the change tracker back +/// before each retry. +/// +public sealed class ReplayingInterceptor : SaveChangesInterceptor +{ + private readonly ConditionalWeakTable _replaying = new(); + + /// How many attempts fail after the save has run and before the commit. + public int FailAttempts { get; set; } + + /// How many attempts ran. + public int Attempts { get; private set; } + + /// + public override InterceptionResult SavingChanges(DbContextEventData eventData, InterceptionResult result) + { + if (!ShouldReplay(eventData.Context, result, out var context)) + return result; + + var snapshot = TrackerSnapshot.Take(context); + _replaying.Add(context, new object()); + try + { + var saved = context.Database.CreateExecutionStrategy().Execute( + context, + (_, c) => + { + Attempts++; + using var transaction = c.Database.BeginTransaction(); + try + { + var n = c.SaveChanges(); + if (FailAttempts > 0) + { + FailAttempts--; + throw new TransientTestException(); + } + + transaction.Commit(); + return n; + } + catch + { + transaction.Rollback(); + snapshot.Restore(c); + throw; + } + }, + verifySucceeded: null); + + return InterceptionResult.SuppressWithResult(saved); + } + finally + { + _replaying.Remove(context); + } + } + + private bool ShouldReplay(DbContext? candidate, InterceptionResult result, out DbContext context) + { + context = candidate!; + return !result.HasResult + && candidate is not null + && !_replaying.TryGetValue(candidate, out _) + && candidate.Database.CurrentTransaction is null + && candidate.Database.CreateExecutionStrategy().RetriesOnFailure; + } + + /// + public override async ValueTask> SavingChangesAsync( + DbContextEventData eventData, + InterceptionResult result, + CancellationToken cancellationToken = default) + { + if (!ShouldReplay(eventData.Context, result, out var context)) + return result; + + var snapshot = TrackerSnapshot.Take(context); + _replaying.Add(context, new object()); + try + { + var saved = await context.Database.CreateExecutionStrategy().ExecuteAsync( + context, + async (_, c, ct) => + { + Attempts++; + await using var transaction = await c.Database.BeginTransactionAsync(ct); + try + { + var n = await c.SaveChangesAsync(ct); + if (FailAttempts > 0) + { + FailAttempts--; + throw new TransientTestException(); + } + + await transaction.CommitAsync(ct); + return n; + } + catch + { + await transaction.RollbackAsync(CancellationToken.None); + snapshot.Restore(c); + throw; + } + }, + verifySucceeded: null, + cancellationToken); + + return InterceptionResult.SuppressWithResult(saved); + } + finally + { + _replaying.Remove(context); + } + } + + /// The change tracker as it stood before the save. + private sealed class TrackerSnapshot + { + private readonly HashSet _tracked; + private readonly List<(EntityEntry Entry, EntityState State, PropertyValues Current, PropertyValues? Original, HashSet Modified, string[] Temporary)> _changed; + + private TrackerSnapshot( + HashSet tracked, + List<(EntityEntry, EntityState, PropertyValues, PropertyValues?, HashSet, string[])> changed) + { + _tracked = tracked; + _changed = changed; + } + + public static TrackerSnapshot Take(DbContext context) + { + var tracked = new HashSet(ReferenceEqualityComparer.Instance); + var changed = new List<(EntityEntry, EntityState, PropertyValues, PropertyValues?, HashSet, string[])>(); + + foreach (var entry in context.ChangeTracker.Entries()) + { + tracked.Add(entry.Entity); + if (entry.State is EntityState.Added or EntityState.Modified or EntityState.Deleted) + { + changed.Add(( + entry, + entry.State, + entry.CurrentValues.Clone(), + entry.State == EntityState.Added ? null : entry.OriginalValues.Clone(), + entry.Properties.Where(p => p.IsModified).Select(p => p.Metadata.Name).ToHashSet(StringComparer.Ordinal), + entry.Properties.Where(p => p.IsTemporary).Select(p => p.Metadata.Name).ToArray())); + } + } + + return new TrackerSnapshot(tracked, changed); + } + + public void Restore(DbContext context) + { + // Rows the failed attempt started tracking were rolled back with it. + foreach (var entry in context.ChangeTracker.Entries().Where(e => !_tracked.Contains(e.Entity)).ToList()) + entry.State = EntityState.Detached; + + foreach (var (entry, state, current, original, modified, temporary) in _changed) + { + entry.State = state; + + // An added row's store-generated key goes back to the temporary value it had, so the + // retry inserts without an explicit key: SQL Server refuses one for an identity. + foreach (var name in temporary) + { + var key = entry.Property(name); + key.CurrentValue = current[name]; + key.IsTemporary = true; + } + + foreach (var property in entry.Properties) + { + if (!property.Metadata.IsPrimaryKey()) + property.CurrentValue = current[property.Metadata]; + + if (original is not null) + property.OriginalValue = original[property.Metadata]; + + if (state == EntityState.Modified) + property.IsModified = modified.Contains(property.Metadata.Name); + } + } + } + } +} + +/// The failure retries. +public sealed class TransientTestException() : Exception("A transient failure, forced by the test."); + +/// A retrying strategy for providers that have none of their own, such as SQLite. +/// EF's dependencies for the strategy. +public sealed class TestRetryingStrategy(ExecutionStrategyDependencies dependencies) + : ExecutionStrategy(dependencies, maxRetryCount: 3, maxRetryDelay: TimeSpan.FromMilliseconds(1)) +{ + /// + protected override bool ShouldRetryOn(Exception exception) => exception is TransientTestException; + + /// + protected override TimeSpan? GetNextDelay(Exception lastException) => + base.GetNextDelay(lastException) is null ? null : TimeSpan.Zero; +} + +/// +/// Throws from its SavedChanges for the outermost save only, after every interceptor before +/// it has finished. Nested saves — the capture's own deferred write among them — pass. +/// +public sealed class ThrowAfterSaveInterceptor : SaveChangesInterceptor +{ + private readonly ConditionalWeakTable> _depth = new(); + + /// + public override InterceptionResult SavingChanges(DbContextEventData eventData, InterceptionResult result) + { + Enter(eventData.Context); + return result; + } + + /// + public override ValueTask> SavingChangesAsync( + DbContextEventData eventData, + InterceptionResult result, + CancellationToken cancellationToken = default) + { + Enter(eventData.Context); + return ValueTask.FromResult(result); + } + + /// + public override int SavedChanges(SaveChangesCompletedEventData eventData, int result) => + Leave(eventData.Context) ? throw new InvalidOperationException("Refused after the save.") : result; + + /// + public override ValueTask SavedChangesAsync( + SaveChangesCompletedEventData eventData, + int result, + CancellationToken cancellationToken = default) => + Leave(eventData.Context) ? throw new InvalidOperationException("Refused after the save.") : ValueTask.FromResult(result); + + /// + public override void SaveChangesFailed(DbContextErrorEventData eventData) + { + if (eventData.Context is { } context) + _depth.Remove(context); + } + + /// + public override Task SaveChangesFailedAsync(DbContextErrorEventData eventData, CancellationToken cancellationToken = default) + { + SaveChangesFailed(eventData); + return Task.CompletedTask; + } + + private void Enter(DbContext? context) + { + if (context is not null) + _depth.GetOrCreateValue(context).Value++; + } + + private bool Leave(DbContext? context) => + context is not null && _depth.TryGetValue(context, out var depth) && depth.Value > 0 && --depth.Value == 0; +} + +/// +/// Cancels the caller's token once the save has started, the way a request abort reaches EF: +/// after every SavingChanges hook, while the batch runs. Asynchronous only: a synchronous +/// save takes no token. +/// +public sealed class CancellingInterceptor : SaveChangesInterceptor +{ + /// The source to cancel on the next save, or null to let it run. + public CancellationTokenSource? Cancel { get; set; } + + /// + public override ValueTask> SavingChangesAsync( + DbContextEventData eventData, + InterceptionResult result, + CancellationToken cancellationToken = default) + { + Cancel?.Cancel(); + return ValueTask.FromResult(result); + } +} + +/// Refuses every save from SavingChanges, as a validating interceptor would. +public sealed class RefusingInterceptor : SaveChangesInterceptor +{ + /// Whether it refuses. + public bool Active { get; set; } = true; + + /// + public override InterceptionResult SavingChanges(DbContextEventData eventData, InterceptionResult result) => + Active ? throw new InvalidOperationException("Refused by validation.") : result; + + /// + public override ValueTask> SavingChangesAsync( + DbContextEventData eventData, + InterceptionResult result, + CancellationToken cancellationToken = default) => + Active ? throw new InvalidOperationException("Refused by validation.") : ValueTask.FromResult(result); +} + +/// Suppresses the save, as an interceptor that writes the data some other way would. +public sealed class SuppressingInterceptor : SaveChangesInterceptor +{ + /// Whether it suppresses. + public bool Active { get; set; } + + /// + public override InterceptionResult SavingChanges(DbContextEventData eventData, InterceptionResult result) => + Active ? InterceptionResult.SuppressWithResult(0) : result; + + /// + public override ValueTask> SavingChangesAsync( + DbContextEventData eventData, + InterceptionResult result, + CancellationToken cancellationToken = default) => + ValueTask.FromResult(Active ? InterceptionResult.SuppressWithResult(0) : result); +} + +/// Saves through either of EF's paths, so one test covers both. +public static class SavePath +{ + /// + /// SaveChanges() when , else SaveChangesAsync(). The + /// synchronous path has its own interceptor hooks, and the capture implements each twice. + /// + public static Task SaveAsync(this DbContext context, bool sync) + { + ArgumentNullException.ThrowIfNull(context); + + if (!sync) + return context.SaveChangesAsync(); + + try + { + return Task.FromResult(context.SaveChanges()); + } + catch (Exception exception) + { + return Task.FromException(exception); + } + } +} diff --git a/tests/DotNetBoost.Auditing.TestSupport/DotNetBoost.Auditing.TestSupport.csproj b/tests/DotNetBoost.Auditing.TestSupport/DotNetBoost.Auditing.TestSupport.csproj index 1564cec..65a0730 100644 --- a/tests/DotNetBoost.Auditing.TestSupport/DotNetBoost.Auditing.TestSupport.csproj +++ b/tests/DotNetBoost.Auditing.TestSupport/DotNetBoost.Auditing.TestSupport.csproj @@ -19,5 +19,7 @@ to derive from, so it needs the attributes and assertions without being collected itself. --> + + diff --git a/tests/DotNetBoost.Auditing.TestSupport/RecordingAuditObserver.cs b/tests/DotNetBoost.Auditing.TestSupport/RecordingAuditObserver.cs index b652703..75c7d86 100644 --- a/tests/DotNetBoost.Auditing.TestSupport/RecordingAuditObserver.cs +++ b/tests/DotNetBoost.Auditing.TestSupport/RecordingAuditObserver.cs @@ -31,4 +31,10 @@ public void WriteSuppressed(AuditSuppression reason, string entityName, string e /// public void RecordedWithoutModelRules(string entityName, string entityId, AuditAction action) => WithoutModelRules.Add((entityName, entityId, action)); + + /// Every save reported as having lost its atomicity, in order. + public List<(string CorrelationId, int Entries)> LostAtomicity { get; } = []; + + /// + public void AtomicityLost(string correlationId, int entries) => LostAtomicity.Add((correlationId, entries)); } From 513082e4eca14fe09f3bac0287b8b3d0bd3c0c80 Mon Sep 17 00:00:00 2001 From: Sadeq Abu-Hattem Date: Sat, 14 Nov 2026 21:01:11 +0200 Subject: [PATCH 3/3] Document sharing a DbContext with other SaveChanges interceptors docs/limitations.md gains the section on what the capture does in each hook, which orders are safe, and what to do; and the notes on a throw from a later SavingChanges, suppressed saves, TransactionScope, and every audited context mapping the audit tables. The observability and configuration references cover OnLostAtomicity and the new counter, and the changelog lists preview.3's changes. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 61 +++++++++++++++++++ README.md | 3 +- docs/configuration-reference.md | 1 + docs/limitations.md | 102 ++++++++++++++++++++++++++++++++ docs/observability.md | 11 +++- 5 files changed, 176 insertions(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index d41dc96..1502c36 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,67 @@ This project follows [Semantic Versioning](https://semver.org/). ## [Unreleased] +Makes the EF Core capture safe beside another library's `SaveChanges` interceptor — such as +DotNetBoost.MultiLingual's — registered before it or after it, with or without a retrying strategy. 543 +tests on net8.0 and net10.0 needing nothing installed, plus 280 integration tests against +PostgreSQL, SQL Server and MongoDB in containers. + +### Added +- **`OnLostAtomicity(LostAtomicity.Report | Throw)`** on the builder, **`IAuditObserver.AtomicityLost`** + (a default member, so existing observers still compile) and the + **`dotnetboost.auditing.atomicity.lost`** counter. When an interceptor registered earlier commits + the transaction in its own `SavedChanges`, the deferred `Created` entries can no longer be atomic + with the change. That used to happen silently; it is now reported (the default — the + `LoggingAuditObserver` logs it as an error), or fails the save under `Throw`. + +### Changed +- **With another `SaveChanges` interceptor registered after it, the capture commits its own + transaction from EF's `DbContext.SavedChanges` event,** once every interceptor has finished, + instead of in its own `SavedChanges`. The later interceptor's post-save work is then inside the + transaction, and a failure in it rolls the entity and its entry back. The event is synchronous, so + that commit is one blocking round trip, even under `SaveChangesAsync`; with no interceptor after + it, the commit stays where it was. +- **The EF Core capture adds its entries to the context being saved, instead of through + `IAuditStore.AppendAsync`.** The store is bound to the scope's registered context, which is not + always the one saving (see the second-context fix below). Explicit `IAuditManager` calls still go + through the store. So a store wrapped or replaced to observe entries as they are recorded no + longer sees the capture's: count them with the `dotnetboost.auditing.entries.recorded` counter, + which still counts every one, or read them from the table. + +### Fixed +- **A save another interceptor issues from inside this one is nested, not a new save.** It joins + the save in progress; only the outermost save writes the deferred entries, commits or rolls back. + Before, the nested save's completion did all three and the outer save's found nothing left. +- **A save replayed by another interceptor is recorded once.** DotNetBoost.MultiLingual replays a + save under a retrying strategy; with the capture registered first, every change was recorded twice, + and again after each retry. Either registration order is now correct. +- **A rollback that fails while a save is already failing no longer hides why the save failed.** + The rollback is best-effort on those paths: disposing the transaction rolls back what is left, and + the caller sees the save's own exception. +- **A save abandoned when a later interceptor's `SavingChanges` throws is cleaned up by the next + save** on that context, which rolls back the transaction left open and records each change once. + EF reports nothing for such a save, so until the next save the transaction stays open. +- **A concurrency conflict now rolls back the capture's transaction.** EF reports it through + `ThrowingConcurrencyException`, not `SaveChangesFailed`, so the transaction stayed open. The + rollback waits for EF's `DbContext.SaveChangesFailed` event: EF raises the hook while it is still + reading the batch, and PostgreSQL and SQL Server refuse a `ROLLBACK` on a busy connection — whose + error would then replace `DbUpdateConcurrencyException`. +- **A cancelled save no longer leaves the interceptor's transaction open.** EF reports a + cancellation through `SaveChangesCanceled`, which the interceptor did not handle, so a save with + a deferred creation kept its transaction and its state on the context, and retrying the same + save recorded the creation twice. It now rolls back exactly as it does for `SaveChangesFailed`. +- **A creation inside a `TransactionScope` no longer throws.** The interceptor tried to open a + transaction of its own inside the ambient one, which EF refuses. It now opens none, and both + saves enlist in the scope. +- **A save another interceptor suppressed is no longer recorded.** With `SuppressWithResult`, the + interceptor still captured: an update left an entry tracked for the context's next save, and a + deferred creation threw because its key never arrived. +- **A second audited context in a scope now writes its own entries.** The capture recorded through + the store, which holds the scope's registered context, so entries for another instance (or + another type) were tracked on the wrong context and never written by the save they described. + Entries now go to the context being saved, and a context with `UseAuditing(sp)` but no audit + tables is refused with the fix in the message. + ### Security - **Aspire moved from 13.6.4 to 13.6.5**, for [GHSA-f7vh-h5g3-7jrh](https://github.com/advisories/GHSA-f7vh-h5g3-7jrh) (CVE-2026-120006), an diff --git a/README.md b/README.md index 801c7d5..48cf8a1 100644 --- a/README.md +++ b/README.md @@ -284,7 +284,8 @@ change and its trail land together or neither does. A creation with a store-gene exception — its id does not exist until the INSERT has run, so that entry needs a second save, and the interceptor opens a transaction around both when the caller has none. Assign keys in code and creations join the single-save path too; [limitations.md](docs/limitations.md) has the two cases -that cannot be made atomic. +that cannot be made atomic, and what changes when +[another library's interceptor shares the context](docs/limitations.md#sharing-a-dbcontext-with-other-savechanges-interceptors). **Dapper and MongoDB write when they are called** rather than joining a unit of work, so atomicity is yours to arrange: hand the first your transaction, or the second a session, and the guarantee is diff --git a/docs/configuration-reference.md b/docs/configuration-reference.md index 30d688b..ea4d1e3 100644 --- a/docs/configuration-reference.md +++ b/docs/configuration-reference.md @@ -28,6 +28,7 @@ reads the declared entities and refuses a configuration with no store. | `.RequireOptIn()` | Core | Record only entities marked `[Audited]` | | `.WithoutCreatedAndDeletedValues()` | Core | Record that a row appeared or went, without its values | | `.DisableRecording()` | Core | The kill switch. Reads still work; every record call returns `null` | +| `.OnLostAtomicity(LostAtomicity)` | Core | When another `SaveChanges` interceptor commits the transaction before the EF Core capture writes its deferred `Created` entries: `Report` (default — write them and report it) or `Throw` (fail the save; use it in tests) | | `.UseActorAccessor()` | Core | Replace how the actor is read. Registered **scoped** — an accessor worth having reads something per request | | `.UseEntityKeyAccessor()` | Core | Replace how entity keys are read. Both EF Core providers register one that reads the model instead | | `.UseObserver()` | Core | Be told what the engine decides **not** to record. Registered **singleton**; the default does nothing | diff --git a/docs/limitations.md b/docs/limitations.md index e1b2bce..52140b5 100644 --- a/docs/limitations.md +++ b/docs/limitations.md @@ -45,6 +45,100 @@ Both still record, rather than refusing. They are the holes in the headline guar Neither applies when nothing is deferred — see above. +An ambient `TransactionScope` is not one of them. Inside a scope the interceptor opens nothing: +both saves enlist in the scope and commit or roll back with it. (The provider has to support +ambient transactions; EF's SQLite provider does not.) + +## Sharing a DbContext with other SaveChanges interceptors + +Another library's interceptor on the same context (DotNetBoost.MultiLingual, say) changes one +thing: **who owns the transaction**. What this interceptor does at each step: + +| Step | What it does | +|---|---| +| `SavingChanges` | Captures. When there are deferred creations and no transaction is open (neither `Database.CurrentTransaction` nor an ambient `TransactionScope`), opens one. When one is open, remembers it | +| `SavedChanges` | Writes the deferred entries through the same context. That is a nested `SaveChanges`, which other interceptors see too. Then commits the transaction it opened, unless another `SaveChanges` interceptor is registered after it (next row) | +| EF's `DbContext.SavedChanges` event | Commits the transaction it opened, when another `SaveChanges` interceptor follows it. EF raises the event once every interceptor's `SavedChanges` has returned, so their post-save work is inside the transaction too | +| `SaveChangesFailed`, `SaveChangesCanceled`, `ThrowingConcurrencyException` | Rolls back the transaction it opened | + +A `SaveChanges` another interceptor issues from inside a save — from its `SavedChanges`, after EF +has accepted the changes — is recognised as **nested**: its work joins the save in progress, which +alone writes, commits or rolls back. An interceptor sharing the context should count nested saves +the same way, because the deferred write above is one. + +**Without a retrying strategy the order does not matter**: registered before or after +`UseAuditing(sp)`, another interceptor's work is inside the same transaction. With Auditing first, +the commit waits for EF's event — synchronous even under `SaveChangesAsync`, because the event is: +one blocking round trip, and only on a context where another `SaveChanges` interceptor follows this +one. + +**With a retrying strategy the order does not matter either.** DotNetBoost.MultiLingual, with a +retrying strategy and no caller transaction, suppresses the save and replays it inside the strategy +and a transaction of its own. This interceptor records the replay as the save, once per change, +inside that transaction, and again once per change if the strategy retries it. Registered before +MultiLingual, it captures the original save first and then throws that capture away when the replay +starts; registering MultiLingual first saves that work, and nothing else. + +**When another interceptor commits first.** An interceptor registered before this one that opens a +transaction in `SavingChanges` and commits it in its own `SavedChanges` leaves the deferred entries +nothing to be atomic with: by the time they are written, the transaction is gone. This interceptor +notices, and by default writes them anyway and reports it — to `IAuditObserver.AtomicityLost` and the +`dotnetboost.auditing.atomicity.lost` counter. `OnLostAtomicity(LostAtomicity.Throw)` fails the save +instead, which is what tests should use. Neither undoes the change: it is already committed. + +What to do when you share a context: + +| Your setup | Do this | +|---|---| +| Keys assigned in code (a `Guid`, HiLo, a sequence) | Nothing: no creation is deferred, so there is no second save and no transaction to share | +| No retrying strategy | Nothing, in either order. To make every save atomic regardless of what other interceptors do, open the transaction yourself (below) | +| A retrying strategy (`EnableRetryOnFailure`) | Nothing, in either order. Registering an interceptor that replays the save (MultiLingual) before `UseAuditing(sp)` saves a capture that would be thrown away | +| Another library's table with a composite key | Exclude it with `IgnoreEntity()`: composite keys are refused, so it would otherwise fail every save that writes it. MultiLingual's `Translation` is the case | + +The application-owned transaction, in the context. Override the synchronous `SaveChanges(bool)` +the same way if you call it: + +```csharp +public override async Task SaveChangesAsync(bool accept, CancellationToken ct = default) +{ + if (Database.CurrentTransaction is not null || Transaction.Current is not null) + return await base.SaveChangesAsync(accept, ct); + + await using var tx = await Database.BeginTransactionAsync(ct); + var result = await base.SaveChangesAsync(accept, ct); + await tx.CommitAsync(ct); + return result; +} +``` + +Under `EnableRetryOnFailure`, wrap the body in `Database.CreateExecutionStrategy().ExecuteAsync(...)`. +**Do not** use EF's usual `SaveChangesAsync(acceptAllChangesOnSuccess: false)` … `AcceptAllChanges()` +retry pattern here: this interceptor saves again from `SavedChanges`, before the changes are +accepted, so the second save would write them again — an added row inserted twice, a deleted one +failing as a concurrency conflict. It also hides the one signal this interceptor has for telling a +save nested inside one of its own from a save that never completed — whether EF has accepted the +outer save's changes — so another interceptor's nested save is taken for a new one, and the +transaction this interceptor opened is rolled back under it. + +## A throw from a later interceptor's `SavingChanges` is cleaned up by the next save + +When a creation is deferred, the interceptor opens its transaction in `SavingChanges`. EF calls the +`SavingChanges` hooks before the part of `SaveChanges` that reports failures, so if an interceptor +registered **after** `UseAuditing(sp)` throws from its own `SavingChanges`, no hook of this one runs +again for that save. The transaction stays open on the context **until the context saves again or +is disposed**. The next save recognises the abandoned one, rolls its transaction back, drops the +entries it captured, and starts over — so a retry records each change once. Measured, not inferred. + +A failure or a cancellation anywhere later in the save — the database refusing a row, a concurrency +conflict, the request being aborted — is reported, and rolled back at once. + +## A suppressed save is not recorded + +An interceptor that returns `InterceptionResult.SuppressWithResult(...)` from `SavingChanges` +skips EF's write and takes responsibility for the save. This one then records nothing for it, and +opens no transaction. An interceptor that suppresses a save and replays it through `SaveChanges` +— as DotNetBoost.MultiLingual does under a retrying strategy — is recorded through the replay. + ## `db.Update(entity)` has no before-image `Update(entity)` and `Entry(entity).State = Modified` on an entity the context never loaded give EF @@ -251,6 +345,14 @@ A history of changes is not a history of states. Rebuilding "the product as it w a change list is only correct if the trail is complete from creation, which it never is for a table that existed before the library was installed. SQL Server temporal tables do this properly. +## Every audited context maps the audit tables + +Entries are added to the context being saved, so a scope can hold several audited contexts — +another instance of the registered type, or another type — and each writes its own trail in its +own save. A context with `UseAuditing(sp)` whose model lacks the tables +(`modelBuilder.ApplyAuditing()`) is refused on its first save, before anything is written. Explicit +`IAuditManager` calls still go to the context registered with `UseEntityFrameworkCore()`. + ## Context pooling is not supported `AddDbContextPool` builds its options once, from the root provider, so they cannot carry the diff --git a/docs/observability.md b/docs/observability.md index 12f329c..153e9ca 100644 --- a/docs/observability.md +++ b/docs/observability.md @@ -55,8 +55,16 @@ are no attributes to read, so it reports what it knows. This is the only failure that cannot be undone, and one line at `Build()` prevents it: `DeclareEntitiesFrom(typeof(Product).Assembly)`. +One report is an **error**: **atomicity lost**. The EF Core interceptor wrote deferred `Created` +entries outside the transaction of the change they describe, because another `SaveChanges` +interceptor committed it first (see +[limitations.md](limitations.md#sharing-a-dbcontext-with-other-savechanges-interceptors)). It names +the save's correlation id, which those entries carry. Under `OnLostAtomicity(LostAtomicity.Throw)` +the save fails instead and nothing is reported. + For anything other than logging — a counter of your own, a health check, an alert — implement -`IAuditObserver` and register it with `.UseObserver()`. Two methods, and the interface says what +`IAuditObserver` and register it with `.UseObserver()`. Three methods — `AtomicityLost` has a +default that does nothing, so an observer written before it existed still compiles — and the interface says what an implementation may not do: **throw, or block.** Both are called on the recording path, synchronously, including from inside an EF Core `SaveChanges`, so an exception there fails the business write that was being audited. @@ -73,6 +81,7 @@ builder.Services.AddOpenTelemetry() | `dotnetboost.auditing.entries.recorded` | `{entry}` | `audit.entity`, `audit.action` | | `dotnetboost.auditing.writes.suppressed` | `{write}` | `audit.entity`, `audit.reason`, `audit.action` | | `dotnetboost.auditing.entries.deleted` | `{entry}` | `audit.operation` — `prune` or `erase` | +| `dotnetboost.auditing.atomicity.lost` | `{save}` | none. Should stay at zero; anything else is an interceptor composition to fix | **The first one is what you alert on, and it is the absence that matters.** "This entity recorded nothing for an hour" is the shape of every way a trail stops covering a table, and it is a question