Debug Log #11: The Reliability Stat From 4 Days Ago Was Already Wrong
Four days ago this blog published a post with a specific statistic in the title: 4 late runs out of 34, 2 of them successful. That post was still fresh when a fifth failure showed up -- and this one breaks the pattern the stat was built on, because it wasn't even late.
| Run | Scheduled | Actually ran | How late | Result |
|---|---|---|---|---|
| #3 | Aug 12, 9:00 PM | Aug 13, 9:49 AM | ~12h 50m | Failed (exit 1, DNS timeout) |
| #22 | Sep 27, 9:00 PM | Sep 28, 9:23 AM | ~12h 23m | Succeeded |
| #30 | Oct 17, 9:00 PM | Oct 19, 9:24 AM | ~36h 24m | Crashed (Debug Log #10) |
| #34 | Oct 26, 9:00 PM | Oct 27, 7:24 AM | ~10h 24m | Succeeded |
| #35 | Oct 29, 9:00 PM | Oct 29, 9:01 PM (on time) | Not late | Failed (exit 1, DNS timeout) |
What's different about run #35
Every previous failure in this table happened because the machine was asleep past 9 PM and the catch-up mechanism fired late, sometimes many hours late. Run #35 fired exactly on schedule, at 9:01 PM, one minute after the trigger -- and still hit the DNS timeout that's supposed to only happen when a machine is waking from sleep. The wait loop ran its full five minutes, never got a DNS response, and exited cleanly with code 1, exactly as designed. The design isn't broken. The assumption that this failure mode is tied to lateness specifically -- which the "4 late runs" post stated as fact four days ago -- was wrong.
The corrected numbers
39 scheduled runs total, 34 clean successes, 5 that hit a real problem. Of those 5, 2 were crashes or DNS failures while arriving late, 2 were late arrivals that worked fine, and 1 -- this one -- was a DNS failure with no lateness involved at all. The headline stat from four days ago undercounted by exactly one, and understated the failure mode's reach by treating "late" as a precondition it isn't.
Why I'm not retroactively editing that post
The instinct is to go fix the number in place so it's not sitting there wrong. I'm leaving it as published and writing this instead, for the same reason Debug Log #9 didn't get folded backward into Debug Log #8: a correction dated after the fact is the more honest record than a quietly adjusted one. Readers who saw "4 out of 34" should also be able to see that it became "5 out of 39" four days later, not just a cleaner number that replaced it without a trace.
What this actually means for the DNS wait loop
Five minutes of retries isn't catching every real case of slow network recovery, on-time trigger or not. That's a genuine, now twice-confirmed limitation, not a one-off. Whether to extend the wait window, add a second retry pass, or leave it as a known, occasional, self-recovering failure is a judgment call about how much engineering a ~9% failure rate on a personal publishing script actually deserves -- and not one I'm making unilaterally in this post.
Comments
Post a Comment