Playwright Tests / test (push) Canceled after 0s
Retires Fuchs_intranet.debug_log() and every direct EXECUTE [dbo].[fds__admin_logdebug] call in favor of a single path: ILogger. A new SQL log sink (OCORE.MultiLogger.SqlLoggerProvider, gated by Fuchs:Logging:SqlSink:Enabled, default on) mirrors every _logger.LogWarning/-Error/ -Critical call into [dbo].[fds__debuglog] via a new fds__admin_logdebug_ext proc, at Warning+. - Program.cs registers the sink and RequestLogScopeMiddleware (request id/path/authenticated user, pushed after UseAuthentication) so every log line in a request — including ones written deep inside OCORE's SQL helpers — is attributed automatically. - FIS_SQLOptions, IntranetController.Do's catch-all, PdfPreviewAsync, and the banking-upload handlers now log once, with an explicit EventId preserving the exact CodeReference text the retired debug_log() calls used to write, so existing dashboards/queries over fds__debuglog keep working unchanged. - Fuchs_DataService/FdsMfr.cs's FdsSqlOptions had the identical double-write hazard (it's hosted in the same process per ADR 0010) — the original 2026-09-16 log review's mfr__getSchema/ fds__getUpdateableRequests deadlock rows came from exactly this class. Fixed the same way. - fds__debuglog gains LogLevel/Machine/Category/Account/AuthUser/IsDebug columns; the legacy fds__admin_logdebug proc is left in place unused, not dropped. - FdsDebug.DebugLog (Fuchs_DataService's other ~9 call sites) deliberately left on its direct DB-write path — no ILogger call sits alongside it there, so no duplication risk today. See ADR 0024 (supersedes 0023) and Docs/Concepts/error-logging-pipeline.md. New tests: ErrorLoggingTests (FIS_SQLOptions), FdsSqlOptionsTests, RequestLogScopeMiddlewareTests. 694/694 pass (the 4 PdfPipelineTests failures seen under full-suite parallel runs are a pre-existing, unrelated PdfSharp global-font-resolver test-isolation flake — they pass both individually and in most full-suite runs). Bumps the OCORE submodule to 3137b56 (SQL sink hardening: redaction matches short fragments as whole identifier segments, per-entry-tolerant serialization, lazy dataSerialized, opt-in SqlLoggerOptions.IncludeCategory, LogEntry.Category/AuthUser capture). Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
100 lines
5.9 KiB
Markdown
100 lines
5.9 KiB
Markdown
---
|
|
status: Active
|
|
lastUpdated: 2026-09-16
|
|
applyTo:
|
|
- "Fuchs/Program.cs"
|
|
- "Fuchs/Logging/**"
|
|
- "Fuchs/code/FuchsIntranet.cs"
|
|
- "Fuchs/Controllers/**"
|
|
- "Fuchs/Observability/FuchsTelemetry.cs"
|
|
relatedDecisions:
|
|
- "0003-structured-diagnostic-logging.md"
|
|
- "0003-interrupting-exceptions-notify-the-user.md"
|
|
- "0004-opentelemetry-observability.md"
|
|
- "0023-user-action-failures-persisted-to-db-log.md"
|
|
- "0024-multilogger-sql-log-sink.md"
|
|
---
|
|
|
|
# Error logging pipeline
|
|
|
|
## Summary
|
|
A `_logger.LogWarning`/`-Error`/`-Critical` call anywhere in the app — or in OCORE code called
|
|
from it — reaches three places automatically: the always-on file sink, a DB row in
|
|
`[dbo].[fds__debuglog]` (what support actually queries), and, for a user-initiated action that
|
|
threw unhandled, a SignalR toast to the user. One `ILogger` call is the single thing a call site
|
|
writes; nothing calls a stored procedure directly for attribution logging.
|
|
|
|
## How it works
|
|
|
|
### The two `ILoggerProvider`s
|
|
- **`FuchsLoggerProvider`** (`Fuchs/Logging/FuchsLoggerProvider.cs`, [0003](0003-structured-diagnostic-logging.md)):
|
|
every level ≥ Debug → `Debug.WriteLine` + a rolling-free text file (`logs/AppLog.txt` /
|
|
`logs/ErrorLog.txt`). Always on, no DB dependency.
|
|
- **`OCORE.MultiLogger.SqlLoggerProvider`** ([0024](0024-multilogger-sql-log-sink.md)): registered
|
|
in `Program.cs` via `builder.Logging.AddSqlLogger()`, gated by
|
|
`Fuchs:Logging:SqlSink:Enabled` (default on), filtered to `LogLevel.Warning`+. Writes via
|
|
`EXECUTE [dbo].[fds__admin_logdebug_ext]` into `[dbo].[fds__debuglog]` — the same table the
|
|
legacy, now-unused `fds__admin_logdebug` proc wrote to.
|
|
|
|
### Attribution: EventId, category, scope
|
|
- **`CodeReference`** (the row's short label) is `COALESCE(EventId.Name, ILogger category,
|
|
'MultiLogger')`, computed in the stored procedure. Give a log call an explicit `EventId` when
|
|
the call site should be individually greppable:
|
|
```csharp
|
|
_logger.LogError(new EventId(0, "SQL Error in getSQLDataSet"), ex, "SQL error in {Procedure}: ...", ...);
|
|
```
|
|
See `FIS_SQLOptions.OnError`, `IntranetController.Do`'s catch-all, `PdfPreviewAsync`, and the
|
|
`bam/up` (banking upload) handlers for the pattern — each preserves the exact string the old,
|
|
explicit `debug_log()` calls used, so existing saved queries over `CodeReference` still match.
|
|
- **`RequestLogScopeMiddleware`** (`Fuchs/Logging/RequestLogScopeMiddleware.cs`, registered after
|
|
`app.UseAuthentication()`) pushes `{requestId, path, authuser}` as an `ILogger` scope for the
|
|
whole request. Every log line written while handling it — including ones written deep inside
|
|
OCORE's SQL helpers — carries that automatically, without the call site doing anything.
|
|
`authuser` specifically lands in the dedicated `fds__debuglog.AuthUser` column (OCORE's
|
|
`MultiLogger_base.Log` picks the `"authuser"` scope key out into `LogEntry.AuthUser`); the rest
|
|
of the scope + any `{Placeholder}` args + an explicit `data:` object are merged into one redacted
|
|
JSON blob (`fds__debuglog.Data`).
|
|
- **No request/service-scoped logger available** (`new FIS_SQLOptions()` — ~15 call sites in
|
|
`Services/*.cs` construct it this way): `FIS_SQLOptions.OnError` falls back to the static
|
|
`OCORE.Logging.Logger` (set once in `Program.cs` to `app.Logger`), so those SQL errors are still
|
|
attributed, just under a less specific category.
|
|
|
|
### Placeholder naming
|
|
Always `{Foo}`, never `{@Foo}`. Plain `Microsoft.Extensions.Logging` (not Serilog) does not treat
|
|
`@` as a destructuring operator — it stays a literal leading character of the resulting property
|
|
name (`"@Foo"`), which is confusing in the serialized `Data` column.
|
|
|
|
### Redaction and cost
|
|
`OCORE.MultiLogger.LogRedaction.SerializeRedacted` masks property names matching known-sensitive
|
|
fragments/segments (`password`, `secret`, `token`, `pin`, `otp` as a whole identifier segment —
|
|
not substrings like `Mapping`/`HotPath`) at any nesting depth, degrades one unserializable context
|
|
entry to its `ToString()` instead of losing the whole payload, and tolerates self-referencing
|
|
graphs. `LogEntry.dataSerialized` is computed lazily — at most once, only if a sink actually reads
|
|
it — so a Warning+ call that no sink is currently listening for costs nothing extra to serialize.
|
|
|
|
### User-visible failure surface (unrelated to the DB write, [0023](0023-user-action-failures-persisted-to-db-log.md))
|
|
- `IntranetController.Do`'s catch-all publishes a SignalR toast (`IEventService.UserIssueAsync`)
|
|
for any unmodeled exception, for authenticated users only.
|
|
- A 500 response carries its message in the `x-ocms-desc` header (`ServerError(msg)` →
|
|
`EncodeResponseDescription`), which the frontend's default failure handler
|
|
(`$ocms.failure`/`oci_basic.js`) reads.
|
|
- PDF-preview endpoints go through the shared `PdfPreviewAsync` guard: logs, counts
|
|
`fuchs.pdf.previews{what,outcome}` (`success`/`gone`/`failure` — an expired-draft `410` is its
|
|
own `gone` outcome, not a render failure), toasts an authenticated caller, and returns a
|
|
message with the innermost exception text (omitted for the handful of preview endpoints
|
|
reachable without authentication — see `_allowedGet` in `IntranetController.cs`).
|
|
|
|
## Configuration
|
|
- `Fuchs:Logging:SqlSink:Enabled` (bool, default `true`) — off switch for the SQL sink without a
|
|
redeploy.
|
|
- SQL sink connects via `fuchs_fds_ConnectionString` (same connection as everything else), proc
|
|
`dbo.fds__admin_logdebug_ext`, `TruncateTextAt = 4000`.
|
|
|
|
## Extending this
|
|
- Adding a new sink (email/SMS on Critical, a rolling file replacing `FuchsLoggerProvider`) is a
|
|
registration in `Program.cs` — `OCORE.MultiLogger` already ships `EmailLoggerOptions`/
|
|
`SMSLoggerOptions`/`FileLoggerProvider`.
|
|
- A new place that needs DB attribution just calls `_logger.LogWarning`/`-Error` with an
|
|
`EventId` if it wants a specific `CodeReference` — never add a second, explicit stored-procedure
|
|
call next to it; that duplicates the row once the SQL sink picks the `ILogger` call up.
|