[ADMINAPI-1327] [ADMINAPI-1479] fix: Enhance audit logging middleware to capture tenant information

Application/EdFi.Ods.AdminApi.Common/Infrastructure/Audit/AuditActionLoggingMiddleware.cs

@@ -3,6 +3,7 @@
 // The Ed-Fi Alliance licenses this file to you under the Apache License, Version 2.0.
 // See the LICENSE and NOTICES files in the project root for more information.
 
+using EdFi.Ods.AdminApi.Common.Infrastructure.MultiTenancy;
 using Microsoft.AspNetCore.Http;
 
 namespace EdFi.Ods.AdminApi.Common.Infrastructure.Audit;
@@ -22,7 +23,6 @@ public async Task InvokeAsync(HttpContext context)
             return;
         }
 
-        var clientId = context.User.FindFirst("client_id")?.Value;
         var sourceIpAddress = context.Connection.RemoteIpAddress?.ToString();
         var httpVerb = context.Request.Method;
         var httpUrl = context.Request.Path.Value;
@@ -33,16 +33,35 @@ public async Task InvokeAsync(HttpContext context)
         }
         catch
         {
+            // Authentication and tenant resolution both run downstream of this middleware,
+            // so context.User/context.Items are only populated by the time next() has run
+            // (or thrown) - never before. The tenant must be read from context.Items rather
+            // than the AsyncLocal-backed tenant context provider, since that provider's
+            // value reverts once TenantResolverMiddleware's own frame returns (see
+            // TenantResolverMiddleware.TenantConfigurationItemsKey).
             recorder.Record(
                 AuditEventType.Action,
-                clientId,
+                context.User.FindFirst("client_id")?.Value,
                 sourceIpAddress,
                 httpVerb,
                 httpUrl,
-                StatusCodes.Status500InternalServerError);
+                StatusCodes.Status500InternalServerError,
+                GetTenant(context));
             throw;
         }
 
-        recorder.Record(AuditEventType.Action, clientId, sourceIpAddress, httpVerb, httpUrl, context.Response.StatusCode);
+        recorder.Record(
+            AuditEventType.Action,
+            context.User.FindFirst("client_id")?.Value,
+            sourceIpAddress,
+            httpVerb,
+            httpUrl,
+            context.Response.StatusCode,
+            GetTenant(context));
     }
+
+    private static TenantConfiguration? GetTenant(HttpContext context) =>
+        context.Items.TryGetValue(TenantResolverMiddleware.TenantConfigurationItemsKey, out var tenant)
+            ? tenant as TenantConfiguration
+            : null;
 }

Application/EdFi.Ods.AdminApi.Common/Infrastructure/Audit/AuditEventRecorder.cs

@@ -29,7 +29,8 @@ public void Record(
         string? sourceIpAddress,
         string? httpVerb,
         string? httpUrl,
-        int? statusCode)
+        int? statusCode,
+        TenantConfiguration? tenant = null)
     {
         if (!settings.Value.Enabled)
         {
@@ -38,7 +39,11 @@ public void Record(
 
         try
         {
-            var tenant = tenantContextProvider.Get();
+            // The AsyncLocal-backed tenantContextProvider reverts for a caller once the
+            // middleware that called Set() (TenantResolverMiddleware) has returned, so a
+            // caller positioned outside it (AuditActionLoggingMiddleware, recording after
+            // next() completes) must resolve the tenant itself and pass it in explicitly.
+            tenant ??= tenantContextProvider.Get();
             var adminConnectionString = !string.IsNullOrEmpty(tenant?.AdminConnectionString)
                 ? tenant.AdminConnectionString
                 : configuration.GetConnectionStringByName("EdFi_Admin");

Application/EdFi.Ods.AdminApi.Common/Infrastructure/Audit/IAuditEventRecorder.cs

@@ -3,6 +3,8 @@
 // The Ed-Fi Alliance licenses this file to you under the Apache License, Version 2.0.
 // See the LICENSE and NOTICES files in the project root for more information.
 
+using EdFi.Ods.AdminApi.Common.Infrastructure.MultiTenancy;
+
 namespace EdFi.Ods.AdminApi.Common.Infrastructure.Audit;
 
 public interface IAuditEventRecorder
@@ -13,5 +15,6 @@ void Record(
         string? sourceIpAddress,
         string? httpVerb,
         string? httpUrl,
-        int? statusCode);
+        int? statusCode,
+        TenantConfiguration? tenant = null);
 }

Application/EdFi.Ods.AdminApi.Common/Infrastructure/MultiTenancy/TenantIdentificationMiddleware.cs

@@ -20,6 +20,14 @@ public partial class TenantResolverMiddleware(
     IOptions<AppSettings> options,
     IOptions<SwaggerSettings> swaggerOptions) : IMiddleware
 {
+    // AsyncLocal-backed context (tenantConfigurationContextProvider) reverts for a caller
+    // once this middleware's own InvokeAsync frame returns, so callers positioned outside
+    // it (e.g. AuditActionLoggingMiddleware, which must run outermost to see the final
+    // response status) cannot read it after calling next(). HttpContext.Items instead
+    // lives on the HttpContext instance itself, unaffected by that unwind, so it's mirrored
+    // here for any such caller.
+    public const string TenantConfigurationItemsKey = "TenantConfiguration";
+
     private readonly ITenantConfigurationProvider _tenantConfigurationProvider = tenantConfigurationProvider;
     private readonly IContextProvider<TenantConfiguration> _tenantConfigurationContextProvider = tenantConfigurationContextProvider;
     private readonly IOptions<AppSettings> _options = options;
@@ -47,6 +55,7 @@ public async Task InvokeAsync(HttpContext context, RequestDelegate next)
                     if (_tenantConfigurationProvider.Get().TryGetValue(tenantIdentifier!, out var tenantConfiguration))
                     {
                         _tenantConfigurationContextProvider.Set(tenantConfiguration);
+                        context.Items[TenantConfigurationItemsKey] = tenantConfiguration;
                     }
                     else
                     {
@@ -67,6 +76,7 @@ public async Task InvokeAsync(HttpContext context, RequestDelegate next)
                         _tenantConfigurationProvider.Get().TryGetValue(defaultTenant, out var tenantConfiguration))
                     {
                         _tenantConfigurationContextProvider.Set(tenantConfiguration);
+                        context.Items[TenantConfigurationItemsKey] = tenantConfiguration;
                     }
                     else
                     {

Application/EdFi.Ods.AdminApi/Program.cs

@@ -52,7 +52,12 @@
 
 AdminApiVersions.Initialize(app);
 
-//The ordering here is meaningful: Logging -> Routing -> Auth -> Endpoints
+//The ordering here is meaningful: Audit -> Logging -> Routing -> Auth -> Endpoints
+//AuditActionLoggingMiddleware must be outermost so it observes the final response status
+//code after RequestLoggingMiddleware/V3RequestErrorMiddleware has translated any exception
+//into its real HTTP status (they catch and never rethrow), rather than guessing 500 itself.
+app.UseMiddleware<AuditActionLoggingMiddleware>();
+
 if (adminApiMode == AdminApiMode.V3)
 {
     app.UseMiddleware<V3ErrorHandling.V3RequestErrorMiddleware>();
@@ -71,7 +76,6 @@
 app.UseAuthentication();
 app.UseRateLimiter();
 app.UseAuthorization();
-app.UseMiddleware<AuditActionLoggingMiddleware>();
 app.MapFeatureEndpoints();
 
 app.MapControllers();

docs/audit-logging.md

@@ -42,7 +42,7 @@ Three event types are recorded, corresponding to the `AuditEventType` enum
 |---|---|
 | `AuthenticationSuccess` | A client successfully obtains a token at `/connect/token` (OpenIddict's `ApplyTokenResponseContext`, handled by `SecurityExtensions.DefaultTokenResponseHandler` — recorded when the token response has no `Error`). |
 | `AuthenticationFailure` | (a) A token request at `/connect/token` fails (invalid client, invalid grant, invalid scope, etc. — same handler as above, recorded when the token response has an `Error`); or (b) any other request anywhere in the API is rejected with a 401 because the bearer token is missing, malformed, or expired (`JwtBearerEvents.OnChallenge` in `SecurityExtensions.cs`). |
-| `Action` | Every request whose HTTP method is `POST`, `PUT`, `PATCH`, or `DELETE`, regardless of outcome. `GET` requests are never logged as action events. Captured by `AuditActionLoggingMiddleware` (`Application/EdFi.Ods.AdminApi.Common/Infrastructure/Audit/AuditActionLoggingMiddleware.cs`), registered in the request pipeline in `Program.cs` (`app.UseMiddleware<AuditActionLoggingMiddleware>();`). |
+| `Action` | Every request whose HTTP method is `POST`, `PUT`, `PATCH`, or `DELETE`, regardless of outcome (2xx, 4xx — including 401/403 rejections — or 5xx). `GET` requests are never logged as action events. Captured by `AuditActionLoggingMiddleware` (`Application/EdFi.Ods.AdminApi.Common/Infrastructure/Audit/AuditActionLoggingMiddleware.cs`), registered as the **outermost** middleware in the request pipeline in `Program.cs` (`app.UseMiddleware<AuditActionLoggingMiddleware>();`, before `RequestLoggingMiddleware`/`V3RequestErrorMiddleware`, `UseAuthentication`, and `UseAuthorization`). |
 
 Note: `JwtBearerEvents.OnAuthenticationFailed` and `OnTokenValidated` also
 exist in `SecurityExtensions.cs` for logging/diagnostics, but only
@@ -66,7 +66,7 @@ entity in `Application/EdFi.Ods.AdminApi.Common/Infrastructure/Audit/AuditLog.cs
 | `SourceIpAddress` | `NVARCHAR(45)` | Yes | Populated for all three event types from `HttpContext.Connection.RemoteIpAddress`. |
 | `HttpVerb` | `NVARCHAR(10)` | Yes | Populated only for `Action` events (e.g. `POST`, `PUT`, `PATCH`, `DELETE`). Always `null` for both authentication event paths (`/connect/token` and the `OnChallenge` 401 path). |
 | `HttpUrl` | `NVARCHAR(2048)` | Yes | Populated only for `Action` events (the request path). Always `null` for authentication events. |
-| `StatusCode` | `INT` | Yes | Populated for `Action` events (the actual response status code, or `500` if the request pipeline threw an exception before a status code was set) and for the `OnChallenge` 401 path (always `401`). Always `null` for the `/connect/token` `ApplyTokenResponseContext` handler, since that handler runs before the final HTTP status is finalized. |
+| `StatusCode` | `INT` | Yes | Populated for `Action` events (the actual response status code — including 401/403/404/etc. produced by downstream error-handling middleware, or `500` as a last-resort fallback if an exception escapes the entire pipeline unhandled) and for the `OnChallenge` 401 path (always `401`). Always `null` for the `/connect/token` `ApplyTokenResponseContext` handler, since that handler runs before the final HTTP status is finalized. |
 
 Indexes exist on `Timestamp` and `ClientId` to support the most common
 lookups (recent events, and events for a given client).
@@ -130,6 +130,12 @@ the same per-tenant DbUp migration process used for the rest of the schema.
 current tenant context before enqueueing an event, so events are always
 written to the requesting tenant's own database.
 
+For `Action` events specifically, the tenant is *not* read from the
+`AsyncLocal`-backed tenant context provider that everything else in the app
+uses — see "Why `Action` events resolve tenant from `HttpContext.Items`,
+not the ambient tenant context" below for why, and how it's actually
+resolved.
+
 ## No HTTP exposure
 
 There is no controller, minimal API route, or other HTTP endpoint that
@@ -149,9 +155,75 @@ addressed in a future iteration:
 * Any admin UI, reporting dashboard, export tooling, or query API for
   browsing audit data.
 * Logging of read-only (`GET`) requests as action events.
-* Authorization-denied (403) mutation attempts. `AuditActionLoggingMiddleware`
-  is registered after `app.UseAuthorization()`, so requests that ASP.NET
-  Core's authorization middleware short-circuits with a 403 never reach it
-  and are not audited. Only 401 (authentication) rejections and mutation
-  attempts that complete the pipeline (2xx, 4xx other than 401/403, 5xx) are
-  currently captured. Capturing 403s is deferred to a future iteration.
+
+## Middleware ordering: why `AuditActionLoggingMiddleware` runs first
+
+`AuditActionLoggingMiddleware` is registered before `RequestLoggingMiddleware`
+(V2) / `V3RequestErrorMiddleware` (V3), and before `UseAuthentication` /
+`UseAuthorization`, so that it wraps the entire rest of the pipeline. This
+matters for two reasons:
+
+1. **Exception-driven status codes.** `RequestLoggingMiddleware` and
+   `V3RequestErrorMiddleware` catch exceptions (`ValidationException` → 400,
+   `INotFoundException` → 404, etc.) and translate them into the real HTTP
+   status without rethrowing. If the audit middleware sat *inside* that
+   translation layer (as it originally did, registered after
+   `UseAuthorization`), its own exception handler would run first and
+   hardcode `StatusCode = 500` for every exception — before the real status
+   was ever known — producing an audit row that didn't match what the client
+   actually received. Running outermost means `next()` only returns to the
+   audit middleware after the real status has been finalized, so the
+   recorded `StatusCode` always matches the response the client saw.
+2. **Authorization-denied (401/403) requests.** ASP.NET Core's authorization
+   middleware short-circuits a denied request (sets 401/403 and returns
+   without calling further into the pipeline) rather than throwing. With the
+   audit middleware outermost, that short-circuit still unwinds back through
+   it normally, so these denials are now captured as `Action` rows too —
+   previously they never reached the audit middleware at all.
+
+One consequence: `AuditActionLoggingMiddleware` reads the `client_id` claim
+from `context.User` *after* `next()` returns/throws, not before — since
+authentication now runs downstream of it (inside `next()`), `context.User`
+isn't populated yet at the point the middleware is entered.
+
+## Why `Action` events resolve tenant from `HttpContext.Items`, not the ambient tenant context
+
+The rest of the app resolves the current tenant via
+`IContextProvider<TenantConfiguration>`
+(`Application/EdFi.Ods.AdminApi.Common/Infrastructure/Context/ContextProvider.cs`),
+backed by `AsyncLocalContextStorage`
+(`Application/EdFi.Ods.AdminApi.Common/Infrastructure/Context/ContextStorage.cs`).
+`TenantResolverMiddleware` calls `Set()` on it, and every scoped service
+resolved further down the pipeline (as a descendant call) sees that value
+correctly — this is how `IUsersContext`/`ISecurityContext` pick the right
+per-tenant connection string today.
+
+`AuditActionLoggingMiddleware` cannot use the same mechanism for `Action`
+events, because of how it's positioned (see the "Middleware ordering"
+section above): it reads state only *after* `next()` has fully returned —
+i.e. after `TenantResolverMiddleware.InvokeAsync` itself has already
+returned. `AsyncLocal` values only flow *forward* into methods called from
+where they're set; once the setting method's own call frame returns, the
+value reverts for its caller. So by the time `AuditActionLoggingMiddleware`
+calls `recorder.Record(...)`, `tenantContextProvider.Get()` is back to
+whatever it was *before* `TenantResolverMiddleware` ran — `null` for a normal
+request — and `AuditEventRecorder` would silently fall back to the
+non-tenant-specific `EdFi_Admin` connection string. In multitenant mode that
+fallback isn't a valid connection string for the active tenant's DB engine,
+so every `Action` event write failed, retried twice, and fell back to the
+rate-limited text log — meaning **no `Action` rows were ever persisted**,
+while `AuthenticationSuccess`/`AuthenticationFailure` rows (recorded from
+inside the OpenIddict/JWT pipeline, still nested within
+`TenantResolverMiddleware`'s call frame) were unaffected.
+
+The fix: `TenantResolverMiddleware` also stores the resolved tenant in
+`context.Items[TenantResolverMiddleware.TenantConfigurationItemsKey]`.
+Unlike the `AsyncLocal` context, `HttpContext.Items` lives on the
+`HttpContext` instance itself — the same instance passed explicitly to every
+middleware in the chain — so it survives regardless of which call frames
+have returned. `AuditActionLoggingMiddleware` reads it from there and passes
+it explicitly into `IAuditEventRecorder.Record(..., tenant)`, which prefers
+the explicit value over the `AsyncLocal` lookup when one is supplied. The
+authentication-event call sites in `SecurityExtensions.cs` are unaffected —
+they still resolve tenant via the `AsyncLocal` provider, correctly, since
+they run as descendants of `TenantResolverMiddleware`, not after it returns.

docs/design/2026-07-28-audit-trail-logging.md

@@ -64,11 +64,41 @@ each project, following the existing 5-digit-sequence naming convention.
 ## Capture Points
 
 **Action events** (POST/PUT/PATCH/DELETE only — GETs excluded per scope):
-new lightweight middleware, registered alongside the existing
-`RequestLoggingMiddleware` (V2) / `V3RequestErrorMiddleware` (V3). It
-captures client_id (from the authenticated principal), timestamp, verb, URL,
-and source IP up front, then after `next()` completes, adds the response
-status code and enqueues the event.
+new lightweight middleware, registered as the **outermost** middleware in the
+pipeline — before `RequestLoggingMiddleware` (V2) / `V3RequestErrorMiddleware`
+(V3), and before `UseAuthentication`/`UseAuthorization`. It captures timestamp,
+verb, URL, and source IP up front; `client_id` and the response status code
+are both read only after `next()` returns or throws, since authentication and
+status-code finalization both happen downstream of this middleware.
+
+This ordering is deliberate, not incidental: `RequestLoggingMiddleware`/
+`V3RequestErrorMiddleware` catch exceptions and translate them into the real
+HTTP status (e.g. `ValidationException` → 400, `INotFoundException` → 404)
+without rethrowing. If the audit middleware sat inside that translation layer,
+its own exception handler would fire first and have to guess a status code
+before the real one was known. Sitting outermost means it always observes the
+final, already-translated status — including 401/403 authorization denials,
+which ASP.NET Core's authorization middleware short-circuits (sets the status
+and returns without calling further into the pipeline, rather than throwing).
+
+**Tenant resolution caveat from the same ordering change:** the rest of the
+app resolves the current tenant via an `AsyncLocal`-backed
+`IContextProvider<TenantConfiguration>`, set by `TenantResolverMiddleware`.
+`AsyncLocal` values only flow forward into methods called from where they're
+set — once `TenantResolverMiddleware.InvokeAsync` itself returns, the value
+reverts for its caller. Because the audit middleware now reads state only
+*after* `next()` has fully returned (i.e. after `TenantResolverMiddleware`
+has already returned), it cannot use that same lookup — doing so silently
+resolved to the non-tenant-specific default connection string in multitenant
+mode, which isn't a valid connection string for the active tenant's DB
+engine, and every `Action` write failed. Fix: `TenantResolverMiddleware` also
+stores the resolved tenant in `context.Items[...TenantConfigurationItemsKey]`
+— `HttpContext.Items` lives on the `HttpContext` instance itself, unaffected
+by which call frames have returned — and the audit middleware reads it from
+there instead, passing it explicitly into `IAuditEventRecorder.Record(...,
+tenant)`. The authentication-event hooks in `SecurityExtensions.cs` are
+unaffected, since they run as descendants of `TenantResolverMiddleware`
+(before it returns) and keep using the `AsyncLocal` lookup unchanged.
 
 **Authentication events**, hooked in the shared
 `Application/EdFi.Ods.AdminApi/Infrastructure/Security/SecurityExtensions.cs`: