Files
Fuchs_Intranet/Fuchs/Docs/Decisions/0023-user-action-failures-persisted-to-db-log.md
T
StefanandClaude Sonnet 5 bcf1f2dbb6
Playwright Tests / test (push) Canceled after 0s
feat: migrate DB error logging onto the generic OCORE MultiLogger SQL sink
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>
2026-09-16 17:20:06 +02:00

4.9 KiB

status, date, applyTo, supersededBy
status date applyTo supersededBy
Superseded 2026-09-16
Fuchs/Controllers/**
Fuchs/code/FuchsIntranet.cs
Fuchs/js/intranet/**
0024-multilogger-sql-log-sink.md

Superseded by 0024. The explicit Fuchs_intranet.debug_log / fds__admin_logdebug DB write this decision introduced was retired the same day, once 0024 made ILogger itself the single path to the DB log (fds__admin_logdebug_ext, same fds__debuglog table). Keeping both would have double-written every row. The frontend/x-ocms-desc/EncodeResponseDescription/preview-timeout decisions below are unaffected and still in force — only the DB write mechanism changed.

0023 — Failures of user actions are persisted to fds__admin_logdebug, with the SQL and a readable description

Context

Support diagnoses production problems from a query over the fds__admin_logdebug table (EXECUTE [dbo].[fds__admin_logdebug] via Fuchs_intranet.debug_log) — not from the web server's logs/ErrorLog.txt (0003), which is rarely reachable. Reviewing the 2026-09-16 production extract of that table showed three gaps:

  • Every "SQL Error in getSQLDataSet" row (twelve execution timeouts in one morning) had Data = NULL. FIS_SQLOptions.OnError logged its constructor context (the fn/id/code, usually null) instead of the data OCORE hands over (new { sql = … }), so nobody could tell which statement timed out.
  • Unhandled exceptions from IntranetController.Do went to ILogger only. A customer's failing "PDF-Vorschau" left no trace in the table at all.
  • The browser's generic failure alert reads its description from the x-ocms-desc response header, which the backend never set — so users always saw an empty "Der Server hat einen Fehler gemeldet:".

Decision

  • The DB log row must carry what is needed to attribute the failure. FIS_SQLOptions merges the OCORE payload (the SQL statement) with the caller context into the Data column ({ sql, context }). New OnError hooks must never drop the statement.
  • Every failure that interrupts a user action is written to fds__admin_logdebug too, in addition to ILogger and the notification required by 0003: the Do catch-all writes Unhandled exception in Do {fn}/{id} with route, user and the form field names (never values — they can carry tokens/PII); the PDF-preview endpoints go through a shared guard (IntranetController.PdfPreviewAsync) that logs PDF preview failed (endpoint) with ref/user/duration, counts fuchs.pdf.previews{outcome} (success/gone/failure — an expired-draft 410 from inside render() is its own gone outcome, not success, since it is not the render failure this guard exists to catch) and, for an authenticated caller, toasts the user.
  • A 500 carries its message in the x-ocms-desc header (ServerError(msg) → EncodeResponseDescription: percent-encoded ASCII, spaces as %20 because the client maps + to space before decodeURIComponent). Handlers that return a 500 should pass a user-readable German message; the frontend shows it verbatim.
  • Preview calls in the frontend never fail silently. They use a 120 s timeout ($inv.pdfPreviewTimeout), one shared error handler ($inv.pdfPreviewFailed) and a complete handler that unfreezes the editor and reports a timeout — postXT returns early on a timeout without calling error, so complete is the only place it is observable.

Consequences

  • Support can attribute a SQL timeout to its statement straight from the table; a failing preview is visible as one row with endpoint, reference id, user and duration.
  • debug_log is a synchronous DB round-trip and is only used on error paths; it must not be added to hot/success paths (see 0003 on the cost of DB logging).
  • x-ocms-desc is user-facing: messages must be German, short, and free of secrets. The innermost exception text is acceptable for an authenticated intranet user, but some preview endpoints (req/idoc, inv/rdoc, inv/rdocn, rem/idoc — see _allowedGet in IntranetController.cs) are reachable without authentication; PdfPreviewFailureMessage omits the exception detail for those callers and falls back to the generic message.

Alternatives considered

  • Enable FuchsLoggerProvider.DatabaseLoggingEnabled so every ILogger error lands in the DB. Rejected: it would write every LogError (including expected/handled ones and background-service noise) with a DB round-trip each, and the provider has no access to the request context (user, route) that makes a row actionable.
  • Return the message only in the JSON body. The generic client failure path never parses the body of a non-2xx response; the header is the existing contract in oci_basic.js.