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 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); } /// 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)); }