[Bug][Backend][Observability] Serilog MinimumLevel is hardcoded to Debug in EventHandlerHostBuilder — EVERY appsettings log-level setting is dead config, and ~2.9M Debug events/day are shipped to Seq #594

New Issue

2026-07-14T21:12:24Z

spikerj commented

2026-07-14 21:12:24 +00:00

Filed by: QA Team

Summary

EventHandlerHostBuilder builds its Serilog LoggerConfiguration entirely in code and never binds it to IConfiguration. It hardcodes .MinimumLevel.Debug() and ships Debug all the way to Seq.

The consequence is that every log-level setting in every appsettings*.json in the solution is dead config. Operators can set whatever they like; it has no effect.

The code

SpikerSoft.EventHandlers.Infrastructure/Extensions/ServiceCollectionExtensions.cs:45

var loggerConfig = new LoggerConfiguration()
   .MinimumLevel.Debug()                       // <-- hardcoded, line 46
   .MinimumLevel.Override("Microsoft", LogEventLevel.Information)
   ...

and line 70, which forwards that Debug firehose to Seq:

loggerConfig.WriteTo.Seq(
    seqServerUrl,
    apiKey: envSpecificApiKey,
    restrictedToMinimumLevel: LogEventLevel.Debug);   // <-- line 73

ReadFrom.Configuration(...) / ReadFrom.Services(...) appear nowhere in the repository:

$ grep -rn "ReadFrom.Configuration\|ReadFrom.Services" --include=*.cs .
   (no matches)

Proof that operator intent is being silently discarded

SpikerSoft.EventHandlers.SecurityMonitor/appsettings.Production.json explicitly turns logging down for production:

"Logging": { "LogLevel": { "Default": "Warning", "Microsoft.AspNetCore": "Warning" } }

Someone deliberately asked for Warning in production. Here is what that service actually emits, live:

security-monitor    5,662 lines / 10 min   —  100% DBG/TRACE
system-remediation  5,764 lines / 10 min   —   99% DBG/TRACE

Zero INF/WRN/ERR lines in a 10-minute window from either. It is all debug.

This is not confined to the services that forgot a Serilog block. QuizGeneration's appsettings.Production.json correctly sets "MinimumLevel": "Information" — and it still emits Debug in production:

[21:00:15 DBG] [Production/QuizGeneration] ✅ [QuizGeneration] Exchange 'notifications' declared
[20:11:56 DBG] [Production/QuizGeneration] 🔌 [QuizGeneration] Connection attempt #1...

Note the Production/ in the enricher output. The config says Information. The code says Debug. The code wins, everywhere.

Blast radius

Measured across all spikersoft-* services on the swarm:

20,386 log lines / 10 min  ->  ~2.9 MILLION log events per day shipped to Seq

Overwhelmingly Debug-level, and the Seq sink is explicitly configured to accept it (restrictedToMinimumLevel: Debug).

Costs:

Seq ingestion + retention burn — ~2.9M events/day of mostly [TRACE] Starting activity creation for Remediation.disk, which is emitted roughly once per second.
Signal-to-noise. A real ERR is a needle in ~2.9M events/day of haystack. This directly undermines the value of Seq for incident response.
Serilog formats every message before the sink decides, so there is real CPU/alloc cost per event on 8 GB Jetsons.

Container disk is not at risk — I checked, and the json-file driver is correctly capped (max-size: 10m, max-file: 3). The cost lands on Seq and on signal quality, not on the node filesystems.

Fix

Bind Serilog to configuration so appsettings actually means something:

var loggerConfig = new LoggerConfiguration()
    .ReadFrom.Configuration(configuration)      // honor appsettings
    .Enrich.FromLogContext()
    ...

...and drop the hardcoded .MinimumLevel.Debug(), plus the restrictedToMinimumLevel: LogEventLevel.Debug on the Seq sink (let the sink inherit the configured minimum). Then set Serilog:MinimumLevel to Information in the base appsettings.json and leave Debug to appsettings.Development.json.

Worth auditing at the same time: 14 services ship an appsettings.Production.json with no Serilog block at all (BlogMediaProcessor, CalendarReminders, CodeExecution, Decompile, DockerMonitor, GameEvents, InfluxDashboard, KeycloakEvents, NodeAgent, Notifications, Ocr, SecurityMonitor, SystemRemediation, UploadCoordinator). Once the binding above is in place, those will silently inherit the base level — so the base needs to be correct.

#588 (open) — telemetry misregistration in this same file (ServiceCollectionExtensions.cs, the .AddService(serviceName, serviceVersion) positional-argument bug). Same file, same registration path; these two should almost certainly be fixed in one PR.
#558 (closed) — SERVER disk pressure. Not caused by this (log rotation is capped), but noting the link since it is the same neighbourhood. SERVER is currently at 87–88%, down from the 94% in that ticket.

**Filed by: QA Team** ## Summary `EventHandlerHostBuilder` builds its Serilog `LoggerConfiguration` **entirely in code** and **never binds it to `IConfiguration`**. It hardcodes `.MinimumLevel.Debug()` and ships Debug all the way to Seq. The consequence is that **every log-level setting in every `appsettings*.json` in the solution is dead config.** Operators can set whatever they like; it has no effect. ## The code `SpikerSoft.EventHandlers.Infrastructure/Extensions/ServiceCollectionExtensions.cs:45` ```csharp var loggerConfig = new LoggerConfiguration() .MinimumLevel.Debug() // <-- hardcoded, line 46 .MinimumLevel.Override("Microsoft", LogEventLevel.Information) ... ``` and line 70, which forwards that Debug firehose to Seq: ```csharp loggerConfig.WriteTo.Seq( seqServerUrl, apiKey: envSpecificApiKey, restrictedToMinimumLevel: LogEventLevel.Debug); // <-- line 73 ``` `ReadFrom.Configuration(...)` / `ReadFrom.Services(...)` appear **nowhere in the repository**: ``` $ grep -rn "ReadFrom.Configuration\|ReadFrom.Services" --include=*.cs . (no matches) ``` ## Proof that operator intent is being silently discarded `SpikerSoft.EventHandlers.SecurityMonitor/appsettings.Production.json` explicitly turns logging **down** for production: ```json "Logging": { "LogLevel": { "Default": "Warning", "Microsoft.AspNetCore": "Warning" } } ``` Someone deliberately asked for `Warning` in production. Here is what that service actually emits, live: ``` security-monitor 5,662 lines / 10 min — 100% DBG/TRACE system-remediation 5,764 lines / 10 min — 99% DBG/TRACE ``` Zero `INF`/`WRN`/`ERR` lines in a 10-minute window from either. It is *all* debug. This is not confined to the services that forgot a `Serilog` block. **QuizGeneration's `appsettings.Production.json` correctly sets `"MinimumLevel": "Information"`** — and it *still* emits Debug in production: ``` [21:00:15 DBG] [Production/QuizGeneration] ✅ [QuizGeneration] Exchange 'notifications' declared [20:11:56 DBG] [Production/QuizGeneration] 🔌 [QuizGeneration] Connection attempt #1... ``` Note the `Production/` in the enricher output. The config says Information. The code says Debug. **The code wins, everywhere.** ## Blast radius Measured across all `spikersoft-*` services on the swarm: ``` 20,386 log lines / 10 min -> ~2.9 MILLION log events per day shipped to Seq ``` Overwhelmingly Debug-level, and the Seq sink is explicitly configured to accept it (`restrictedToMinimumLevel: Debug`). Costs: - **Seq ingestion + retention burn** — ~2.9M events/day of mostly `[TRACE] Starting activity creation for Remediation.disk`, which is emitted roughly once per second. - **Signal-to-noise.** A real `ERR` is a needle in ~2.9M events/day of haystack. This directly undermines the value of Seq for incident response. - **Serilog formats every message before the sink decides**, so there is real CPU/alloc cost per event on 8 GB Jetsons. Container **disk** is not at risk — I checked, and the json-file driver is correctly capped (`max-size: 10m`, `max-file: 3`). The cost lands on Seq and on signal quality, not on the node filesystems. ## Fix Bind Serilog to configuration so appsettings actually means something: ```csharp var loggerConfig = new LoggerConfiguration() .ReadFrom.Configuration(configuration) // honor appsettings .Enrich.FromLogContext() ... ``` ...and drop the hardcoded `.MinimumLevel.Debug()`, plus the `restrictedToMinimumLevel: LogEventLevel.Debug` on the Seq sink (let the sink inherit the configured minimum). Then set `Serilog:MinimumLevel` to `Information` in the base `appsettings.json` and leave `Debug` to `appsettings.Development.json`. Worth auditing at the same time: **14 services ship an `appsettings.Production.json` with no `Serilog` block at all** (BlogMediaProcessor, CalendarReminders, CodeExecution, Decompile, DockerMonitor, GameEvents, InfluxDashboard, KeycloakEvents, NodeAgent, Notifications, Ocr, SecurityMonitor, SystemRemediation, UploadCoordinator). Once the binding above is in place, those will silently inherit the base level — so the base needs to be correct. ## Related - **#588** (open) — telemetry misregistration in **this same file** (`ServiceCollectionExtensions.cs`, the `.AddService(serviceName, serviceVersion)` positional-argument bug). Same file, same registration path; these two should almost certainly be fixed in one PR. - **#558** (closed) — SERVER disk pressure. Not caused by this (log rotation is capped), but noting the link since it is the same neighbourhood. SERVER is currently at 87–88%, down from the 94% in that ticket.

spikerj referenced this issue

2026-07-14 21:31:22 +00:00

[Bug][Backend][Observability] #575 was fixed in ONE publisher — BookController (5 publish sites) and 3 others still ship RabbitMQ messages with no traceparent, so user-initiated flows appear in Jaeger as disconnected orphan traces #597

spikerj referenced this issue

2026-07-14 23:01:09 +00:00

[Bug][Backend][CodeExecution] GitService stages files by absolute path — 2 unit tests fail on macOS (/var→/private/var symlink), and prod breaks if Git:RepositoryPath is ever a symlinked path #604

spikerj commented

2026-07-14 23:02:10 +00:00

PR up: spikersoft-backend #298 (not yet merged — leaving this open until it lands).

Confirmed the ticket's diagnosis and found it was understated in two ways:

Root mechanism. The hardcoded MinimumLevel.Debug() is only half of it — EventHandlerHostBuilder calls Host.UseSerilog(), which replaces the MEL ILoggerFactory. That's why the Logging:LogLevel blocks are bypassed: Serilog never reads them; it reads Serilog:MinimumLevel. The fix binds ReadFrom.Configuration last so a Serilog section wins, defaults to Information, and drops the Seq sink's restrictedToMinimumLevel: Debug.
The API has the same bug. SpikerSoft.Api/AddSerilogConfiguration is a near-verbatim duplicate with the identical hardcoded Debug + Seq pin, and the API's Logging:LogLevel:Default is Debug — so the largest service was firehosing too. Fixed both and locked them with mirrored tests so they can't drift.

Also honoured the operator intent the old code discarded: the 4 workers with a production Warning level (DockerMonitor, NodeAgent, SecurityMonitor, SystemRemediation) now get a real Serilog:MinimumLevel block. Development-only Debug values are deliberately not migrated (that would re-arm the firehose), and the 60 Logging:LogLevel blocks stay as-is (still live for the API's MEL providers) — converging the two keys is a follow-up.

Tests assert the effective level of the built logger (no-section → Information, not Debug — verified to fail if Debug is reintroduced; Warning quiets framework namespaces too; Debug re-enables; sinks survive config binding). Will close after #298 merges.

PR up: spikersoft-backend #298 (not yet merged — leaving this open until it lands). Confirmed the ticket's diagnosis and found it was understated in two ways: 1. **Root mechanism.** The hardcoded `MinimumLevel.Debug()` is only half of it — `EventHandlerHostBuilder` calls `Host.UseSerilog()`, which *replaces* the MEL `ILoggerFactory`. That's why the `Logging:LogLevel` blocks are bypassed: Serilog never reads them; it reads `Serilog:MinimumLevel`. The fix binds `ReadFrom.Configuration` last so a `Serilog` section wins, defaults to Information, and drops the Seq sink's `restrictedToMinimumLevel: Debug`. 2. **The API has the same bug.** `SpikerSoft.Api/AddSerilogConfiguration` is a near-verbatim duplicate with the identical hardcoded Debug + Seq pin, and the API's `Logging:LogLevel:Default` is `Debug` — so the largest service was firehosing too. Fixed both and locked them with mirrored tests so they can't drift. Also honoured the operator intent the old code discarded: the 4 workers with a production `Warning` level (DockerMonitor, NodeAgent, SecurityMonitor, SystemRemediation) now get a real `Serilog:MinimumLevel` block. Development-only `Debug` values are deliberately not migrated (that would re-arm the firehose), and the 60 `Logging:LogLevel` blocks stay as-is (still live for the API's MEL providers) — converging the two keys is a follow-up. Tests assert the effective level of the built logger (no-section → Information, not Debug — verified to fail if Debug is reintroduced; Warning quiets framework namespaces too; Debug re-enables; sinks survive config binding). Will close after #298 merges.

spikerj commented

2026-07-15 18:19:15 +00:00

Resolved and merged — closing.

Verified on current origin/master (be41048):

Fix commit 7977b57 + merge PR #298 (3fc5233) are in the tree. Both Serilog builders are corrected: AddEventHandlerSerilog (worker host) and its duplicate AddSerilogConfiguration (API) no longer hardcode MinimumLevel.Debug() — base default is now Information, ReadFrom.Configuration is applied last so an appsettings Serilog section overrides the code default, and the Seq sink's restrictedToMinimumLevel: Debug pin was dropped so it honours the pipeline minimum. The 4 Warning-in-prod workers (DockerMonitor, NodeAgent, SecurityMonitor, SystemRemediation) now carry matching Serilog:MinimumLevel blocks; Debug values were deliberately not migrated so the firehose is not re-armed.
Regression tests ran green locally on master (macOS/arm64):
- SpikerSoft.EventHandlers.Infrastructure.Tests → EventHandlerSerilogLevelBindingTests: 6 passed / 0 failed
- SpikerSoft.API.Tests → ApiSerilogLevelBindingTests: 3 passed / 0 failed
  These assert effective level on the built Logger (not merely "config was read"): no Serilog section → Information floor (the Debug-regression guard), config Warning → Information suppressed and Microsoft./System. quieted, config Debug → escape hatch re-enables Debug, and ReadFrom.Configuration does not wipe the code's Console sink when the section carries no WriteTo.

Unlike the deploy-gated tickets in this tracker (e.g. #582/#602/#596), this was a code/config-binding bug, so merged-to-master with passing tests is genuine resolution — no separate prod rollout to confirm.

Resolved and merged — closing. **Verified on current `origin/master`** (`be41048`): - Fix commit `7977b57` + merge PR #298 (`3fc5233`) are in the tree. Both Serilog builders are corrected: `AddEventHandlerSerilog` (worker host) and its duplicate `AddSerilogConfiguration` (API) no longer hardcode `MinimumLevel.Debug()` — base default is now `Information`, `ReadFrom.Configuration` is applied last so an appsettings `Serilog` section overrides the code default, and the Seq sink's `restrictedToMinimumLevel: Debug` pin was dropped so it honours the pipeline minimum. The 4 Warning-in-prod workers (DockerMonitor, NodeAgent, SecurityMonitor, SystemRemediation) now carry matching `Serilog:MinimumLevel` blocks; Debug values were deliberately not migrated so the firehose is not re-armed. - Regression tests ran green locally on master (macOS/arm64): - `SpikerSoft.EventHandlers.Infrastructure.Tests` → `EventHandlerSerilogLevelBindingTests`: **6 passed / 0 failed** - `SpikerSoft.API.Tests` → `ApiSerilogLevelBindingTests`: **3 passed / 0 failed** These assert effective level on the built `Logger` (not merely "config was read"): no `Serilog` section → Information floor (the Debug-regression guard), config `Warning` → Information suppressed and Microsoft.*/System.* quieted, config `Debug` → escape hatch re-enables Debug, and `ReadFrom.Configuration` does not wipe the code's Console sink when the section carries no `WriteTo`. Unlike the deploy-gated tickets in this tracker (e.g. #582/#602/#596), this was a code/config-binding bug, so merged-to-master with passing tests is genuine resolution — no separate prod rollout to confirm.

spikerj closed this issue

2026-07-15 18:19:18 +00:00

Sign in to join this conversation.

1 Participants

Notifications

Due Date

No due date set.

Dependencies

No dependencies set.

Reference: spikerj/spikersoft-issues#594