The Error Logger That Cannot Log
A 22-character job name, a 20-character column, and an error handler that has thrown on every attempt since the day it shipped - plus the four parallel logging systems that still could not catch it.
Somewhere in the shift calculator is a code path reserved for the most alarming data condition it can detect — and that code path has failed, silently, on every single execution since the day it shipped. Not intermittently. Not under load. Every time, deterministically, for years. The failure was invisible precisely because the thing that failed was the error reporter itself. Part 8 ended by promising the estate's best bug, and I intend to deliver it in full, because I have never met a cleaner specimen of a whole genre: error-handling code is the least-executed, least-tested code in any system, and it fails at the exact moment it was built for.
The condition worth an alarm
During recomputation, the calculator occasionally derives a day whose total hours come out at twenty-four or more. That should be impossible — no shift spans a full day — so it almost always means corrupted inputs: a duplicate badge event, a sentinel that leaked into arithmetic, a logout attributed to the wrong day. The developers, to their credit, recognised this as a condition worth recording loudly. The code that handles it brims with intent — the comment above it reads, in the original, something close to // human error!!!!! — and it writes a special row to StatusSheet, the estate's log-of-record:
if (row.TotalHours >= TimeSpan.FromHours(24))
{
db.StatusSheets.Add(new StatusSheet
{
JobName = "Shift Calculator human", // count the characters
JobResult = "FailureHE",
Message = $"Impossible total for {row.EmployeeId} on {row.LogDate}",
RunTime = DateTime.Now
});
db.SaveChanges(); // this line always throws
}
Now the schema side. StatusSheet was created by the initial EF Core migration, and its JobName column was sized the way audit columns always are — generously enough for everything anyone had typed so far:
JobName = table.Column<string>(maxLength: 20, nullable: false)
"Shift Calculator human" is twenty-two characters. NVARCHAR(20) holds twenty. SQL Server does not quietly truncate an oversized insert; it rejects it — string or binary data would be truncated. So SaveChanges throws, the exception sails up into the calculator's one enclosing catch-everything block, and the run records a generic failure. The human-error telemetry has never been written. Not once. The error handler is the bug.
Why nobody noticed for years
Sit with the mechanics of the silence, because they generalise to every system you have ever operated.
First, the failure wore a disguise. The enclosing catch logged an error — the truncation exception — so the run didn't vanish; it just reported the wrong problem. Anyone reading the log saw a database write hiccup, not “our impossible-data detector fired and its report was destroyed in transit”. The original signal — which employee, which day, what value — was gone, replaced by an ORM stack trace.
Second, and this is the deeper one: the success condition of this code is the absence of a row, and the failure condition is also the absence of a row. If no ≥24-hour days occur, StatusSheet contains no FailureHE rows. If the logger is broken, StatusSheet contains no FailureHE rows. The two states are observationally identical from the outside, and nobody alarms on the continued non-appearance of a thing they hope never appears. Dead error paths are indistinguishable from healthy systems until the day you need them.
Third, nothing ever exercised the path before production data did. There are no tests in this estate — part 17 covers the pipelines that pretend otherwise — but I want to be precise about what kind of test was missing, because “write more tests” is cheap advice. A unit test of the happy path would never have caught this. What catches it is embarrassingly small: one test that executes the error branch against the real schema constraints, or even a compile-time constant for job names checked against the column width. The branch was written, reviewed, and shipped on the strength of reading it, and it reads perfectly.
Four logging systems, and the message still died
The bitter garnish is that this estate does not lack logging infrastructure. It has four systems, in parallel:
| Channel | Written by | Read by |
|---|---|---|
StatusSheet |
every batch job, by hand | operators, via SSMS |
ActionLog |
the web app's user-action audit | almost nobody |
Logs (Serilog MSSQL sink) |
the web app's structured logging | developers, occasionally |
| Application Insights | the web app's telemetry | developers, during incidents |
Four destinations, four schemas, four retention behaviours — and no policy anywhere saying which class of event belongs where. The web app writes to three of them; the batch jobs write only to StatusSheet, by hand, because none of the Serilog or App Insights wiring ever reached the Functions and console repos. So the estate's most operationally interesting events — sync failures, rerun outcomes, impossible data — flow exclusively through the one channel with NVARCHAR(20) name slots and no alerting, while the richly instrumented channels carry page views. Logging systems multiply when nobody trusts the last one enough to finish it, and each new channel makes the next incident's first question — where would that have been logged? — take longer to answer.
The rest of the ledger
The supporting cast of error-handling misdemeanours, in ascending severity:
catch (Exception ex) { throw ex; }— the estate's signature move, dozens of occurrences. It looks like a rethrow; it is actually a stack-trace guillotine, resetting the exception's origin to the catch block. Every diagnosis that followed one of these started from the wrong line. The fix is three keystrokes:throw;.- A failure taxonomy jammed into ten characters.
JobResultisNVARCHAR(10), and the calculator's branch-specific codes —FailureC,FailureCL,FailureCS,FailureM,FailureHE— are compressed to fit it. The suffixes encode which phase failed, which is genuinely valuable, in a scheme nobody documented and a column too narrow to be legible. The same disease as part 7'sModifiedBy: real semantics, smuggled encoding. ex.InnerException.InnerException.Message— a catch block that reaches two levels deep without null checks, because the exception that one developer saw that one time was doubly nested. Any differently shaped exception turns the handler itself into aNullReferenceExceptionfactory. Error handlers must be written for exceptions in general, not for the last exception you met.
The durable lesson costs one sentence: your error path is a feature, and it ships with the same bug rate as your features — but with none of the execution frequency that would surface those bugs. Anything that must work during a failure has to be exercised before one: run it in a test, fire it with synthetic bad data on a schedule, alert on its silence. The alternative is this article.
Next, the estate's chattiest inhabitant — the function that runs every five minutes, writes a heartbeat row each time with a typo in it, and exists to nag anyone who has been virtually swiped in for more than ten hours: nagging by timer.