Archive ·
Fourteen days of SDI playout, 61 million frames produced: the August 2026 soak, including the part that failed
Between 6 and 20 August 2026 the first unit ran one unbroken 339-hour playout with no late frames on the SDI output, and still failed the criterion we had frozen before it started, because twice the engine's clock thread woke more than half a millisecond late.
Written once, on the date above. Corrections are added at the end as dated addenda, and nothing above them is changed silently.
What we set out to learn, and what we froze before we started
A soak test runs a system without a break for long enough that rare faults get a chance to show. Ours ran on the first unit (our second was built after this run), a Linux machine with an Intel i7-12700 and a Blackmagic DeckLink Duo 2, putting out 1080p50 over SDI, where a frame lasts 20 milliseconds, from a looping test schedule of mixed sources: 25p and 50p material in MPEG-2, DNxHD and H.264 among them. The engine is Rytmi, our software playout engine; Syke, its clock, keeps time to TAI, International Atomic Time. The card was free-running at the time, with no house sync reference; it was first genlocked on 27 September 2026 (that entry). This was a development bench running a test schedule, not a production fleet.
After a shorter pre-registered null test (35.8 hours, adjudicated on 30 July 2026, no late engine frames), we froze a criterion for the fortnight on 5 August 2026, before the run began. Its own rule: “These numbers do not move after the run starts. If the run fails, it failed.” All three parts had to hold.
C1: the clock thread never wakes late — never once more than half a millisecond after the instant it was scheduled for. The criterion called this “delivered output”, which overstated it: the counter measures late wakes inside the engine, before anything reaches the card.
C2: ordinary behaviour does not degrade. Clock phase is how far a tick lands from its intended instant. The 99th percentile (p99) of each second's worst tick, sampled once a minute, must stay at or below 1,500 ns; across the calibration runs it never left the range 952 to 1,091 ns.
C3: no excursion comes near a frame. The worst tick must stay at or below 2 ms, a tenth of a frame. The calibration runs' worst ticks left an empty elevenfold gap that no bound could be fitted to, so this one was anchored to a physical quantity.
Of the calibration runs, eighteen were long enough to judge, and all passed but one: a real fault on 4 August, with 2 late frames and a 23.45 ms excursion. A review before freezing found that the adjudicator, the script that applies the criterion to the logs, skipped short runs, which would have let two runs carrying late frames escape. A criterion whose primary gate can be escaped by restarting is not a criterion, so C1 and C3 were set to judge any run of two samples or more.
A readiness audit then found that the engine was the Linux kernel's preferred out-of-memory victim: it had inherited an OOM score adjustment of +200, a 6.4 GB handicap on a 31.8 GB machine with no swap. That explained 4 August, which the criterion had put down to decoder underruns: one of the engine's own decoder threads had invoked the out-of-memory killer, which killed 30.8 GB of development tooling in the same second. The underruns were the symptom. We protected the engine and added 8 GB of swap. It also found that our test harness, which built the schedule before each engine start, would have left the channel black for the fortnight over one unreadable media file that the engine itself would have skipped. Refusing to start is not automatically the safe choice. We rebooted with someone at the machine to prove it comes back, and all 17 pre-flight checks passed.
What happened
The engine came up at 19:53:26 UTC on 6 August 2026, and the campaign's official start was recorded about four and a half minutes later. That gap caused the first failure, and it was ours. On 8 August, looking into a 425 µs phase peak overnight, we found the adjudicator had printed “INSUFFICIENT — no runs in range” for 39 hours: it kept only runs that began after the recorded start, so it had discarded the campaign's only run. The bug was aligned against success: fourteen clean days would have ended with no verdict, and a restart would have “fixed” it. The same fact had made our public campaign total over-count by 13,500 frames a day earlier, and we had fixed that without sweeping for others. We fixed the adjudicator that day, in tooling only; judged properly, the run passed at that point. The 425 µs peak itself later proved to be the first of the excursions described below.
At 03:25:19 UTC on 11 August, about 103.5 hours in, the clock thread woke 566,716 ns late. C1 failed, and could not be undone: the counter clears only on a restart, which would itself have ended the run. Our public panel, built from the engine's own counters every fifteen minutes, showed it by 03:33, unattended. The adjudicator's FAIL sat unread for about 27 hours, until a peak was noticed by eye at 06:40 UTC on 12 August. That day we published the failure on this site's main page, mid-run, and relabelled the run from a pass/fail test to a specimen: the verdict was banked, and a restart would have destroyed the only live example of the fault.
At 08:50:13 UTC on 15 August, about 205 hours in, a second late wake came in at 569,759 ns, the run's worst tick. We did not notice it for two days; until 17 August every internal document said “late 1”. Both fell in quiet stretches: no commit landed on 9, 10 or 11 August, and none from the afternoon of 13 August to the afternoon of 17 August. But the box was not left alone for the fortnight: development, builds and site publishing ran on it, eighteen commits on 12 August alone. The adjudicator prints CONFOUNDED when build artefacts are written during the campaign, as a flag for a human to attribute rather than an automatic void, and it found three. Builds were pinned away from the clock's processor cores, and neither late second coincides with one.
We stopped the engine deliberately at 23:16:43 UTC on 20 August, about 3.3 hours after the fourteen-day mark, and proved the shutdown clean from the log rather than from an exit code: the queue feeding the as-run log, our hash-chained compliance record of what the engine played out, drained its last 711 records, and the final record is a block seal, the chain's own checkpoint. Verdict: FAIL (CONFOUNDED). C1 failed on 2 late wakes. C2 passed at 1,055 ns against 1,500, on the once-a-minute sampling it specifies (the every-second p99 below reads 1,059). C3 passed at 569,759 ns against 2,000,000.
The numbers
One run, 6–20 August 2026. Where our main page's evidence table carries a figure, it is the same figure here.
| Measurement | Value | When and how |
|---|---|---|
| Continuous engine run | 339 h | 2026-08-06T19:53:26Z to 2026-08-20T23:16:43Z, stopped deliberately. Three independent derivations agree to within twenty seconds: systemd (339.3881 h), the engine's frame counter (339.3825 h), the 1 Hz diagnostic line (339.3861 h). Rounded down. |
| Frames produced | 61,088,850 | The engine's frame counter, 14 s before the stop. Produced, not put on the wire: 214 were shed to drift compensation, by design. |
| Late SDI frames | 0 | Reported by the card itself, not by us: frames that reached the SDI output late. The card's own denominator, not the 61,088,850 produced, 214 of which never reached it. |
| Frames dropped by the card, after start-up | 0 | The card counted 4 at start-up, as it had at the start of earlier runs, and none after, so we do not publish an unqualified “0 dropped”. |
| Late engine frames (C1) | 2 | Twice the clock thread woke more than half a millisecond late: 11 Aug 03:25 UTC (567 µs) and 15 Aug 08:50 UTC (570 µs). The criterion allowed zero. |
| Frames shed to drift compensation | 214 | The card's crystal ran slow against TAI, between −2.2 and −4.2 parts per million, tracking case temperature, so the engine produced marginally faster than the card consumed and discarded the surplus before the card saw it. |
| Seconds at exactly 50 frames | 1,221,791 | Every second, none missing: in all 1,221,790 intervals the frame counter advanced by exactly 50 and the timecode by one second, across 14 midnights. The engine's counter, not a wire measurement. The clock reported LOCK throughout: its own phase lock to TAI, not genlock. |
| Clip junctions, frame-exact | 7,439 | Every clip change visible in the as-run log, checked against the engine's tick grid: exactly one source frame from outgoing to incoming, worst deviation 79 ns, no gaps, no overlaps — in the video; the audio across them was not checked. Not counted: the 48.6 s restart gap at the very start, between the previous run's last frame and this run's first. Not visible to the as-run log, so not covered: 782 same-file transitions, being 391 returns to the top of the schedule and 391 duplicate airings from a known defect in which the first item of a looping region airs twice per loop. |
| Clock phase, per-second worst tick | median 197 ns | Across all 1,221,791 seconds: median 197 ns, p90 735, p99 1,059, p99.9 1,219, p99.99 39,780, worst 569,759, which is 2.85 % of a frame. Above p99.99, nothing in this run landed between about 50 µs and 355 µs; the excursions above that gap are a second population, not the tail of the first. |
| Compliance records dropped | 0 | Of 47,518,115 as-run records. The writer's queue may drop a record rather than stall the clock thread, and writes an exception into the chain when it does, so a drop would have left its own evidence. The log keeps one record per source frame (a 25p item logs 25 a second), which is why it holds fewer records than the engine produced frames. |
| Stalls in the output cadence | 0 | The engine's own count, across the whole run. |
| Engine memory, peak | 264 MB | 243 MB at the stop; no leak over 339 h. |
| Frame underruns, after start-up priming | — | The counter read 71, all of it decoder priming within the first eight seconds, and did not move again across 20,363 samples. As of 28 September 2026 our main page keeps the value withdrawn, because later runs grew: the same unit's following run by 33 on 21 August 2026, while we ran our own work on the machine alongside it, and one of the second unit's four channels by 3, unexplained, on 24 September 2026. |
What went wrong
The run failed its own test. A late wake means that on one tick of the fifty in a second, the clock thread woke late. The frame was still built and the card's output buffer absorbed the delay: under 3 % of one frame, about 0.35 % of the 160 ms (8 frames) that buffer held when we measured it over 30 hours to 1 August 2026. Nothing reached the SDI output late, missing or out of order; the frame counter advanced exactly 50 across each event, and the clock was back in its ordinary range within the following second. It is an internal timing miss, not a dropped frame, and none of that changes the verdict. A criterion you only quote when it passes is not a criterion.
Nothing watched the adjudicator, three times. A wrong INSUFFICIENT stood for 39 hours and the FAIL sat unread for 27. The panel published both late wakes within minutes, as it was built to, and nobody saw the second one there for two days. The automation held and the attention did not.
Our public panel was wrong in places while the run went on, and each error was corrected when found. It called frames produced “delivered”, mixed per-run with campaign-summed figures, and said clip junctions were “ruled out by measurement” when they were neither ruled out nor in. On 17 August it said SOAK OFF for about 2.5 hours while the engine ran perfectly, because a GitHub incident was failing its data fetch; on 19 August its longest-run record still read 39 hours, 308 hours into this run.
This run's audio was not measured, and the software carried an audio defect. For sixty days from a change we made on 18 July 2026, until its fix on 16 September 2026, the engine fed the card audio at the wrong rate after any clip change where the source frame rate changed but the audio channel count and sample rate did not. Recorded on the wire on 16 September 2026, the worst case put 5.2 % silence, in short scattered gaps, into programme audio that had none. What it did to this run's audio was not measured, so every frame and junction figure here is a video figure.
It did not end with the campaign. On the binary deployed on 21 August a third late wake, 571,634 ns, came on 22 August, and more followed, the worst tick reaching 904,629 ns, 4.5 % of a frame, in the run that ended 4 September. Every run from 19 August to 5 September 2026 exceeded 944–3,091 ns, the typical band for a run's worst tick before then. None of those runs was a soak: they carried probes, experiments on the live channel and our own load, so their counters measure our work as much as the engine, and we do not publish them as results. The three runs of 6–9 September peaked at 326,072, 1,217 and 89,932 ns, and every run on the first unit from 9 to 27 September 2026 stayed at or below 4,043 ns, including runs of 176 and 195 hours. We changed the host and the engine on 8 and 9 September; with the cause undetermined, we credit neither change.
What it changed
From 8 August 2026 the adjudicator selected runs by whether they overlap the campaign and labelled a run that straddles the recorded start, with a regression test that fails if the old rule returns; the fix was swept across every tool that reads that start time. On 12 August 2026 a watcher went onto the box, touching nothing in the engine and checking every 10 minutes for underrun growth, card drops, output-cadence stalls, a low card buffer and phase above 5 ms. It reports and never acts: stopping a playout channel on a threshold is a self-inflicted outage while the card's buffer is absorbing the condition. As of 28 September 2026, and since 8 September, a late engine wake trips an alarm with no start-up allowance and pushes it to an engineer's phone, worst case about 15 minutes after the event; before 8 September a box could page once, ever. The push path was proven end to end on 27 September 2026, by a reference-loss alarm during the first genlock rather than by a late wake.
And the failure became an investigation. After the stop we re-read the fortnight from eight independent directions. The two late wakes are the largest of 109 excursions of 380 µs or more that the instruments had recorded all along; the half-millisecond counter only saw the two that crossed it. All 109 are late, never early. 106 sit in a 380–450 µs band, median 413, and the two late wakes stand 116 µs clear of the rest, with nothing in between. They came in 36 bursts of one to five, and every gap inside a burst is 112 or 113 s, or exactly twice that: 73 gaps, no other value. They are the same size in working hours and in the small hours. Ruled out, each by a measurement that could have said otherwise: the NTP daemon's steering of the kernel's TAI clock, the as-run block seal, thermal effects, and any engine stall or restart. Clip junctions, about every 25 s on this schedule, are neither ruled out nor in. By 21 August 2026 around twenty candidate causes had been tested and rejected, several of them ours. The cause is not determined; the investigation has its own entry.
Written on 28 September 2026 from the record: the phase criterion frozen on 5 August 2026, the campaign close-out of 20 August 2026, and investigation records RET-129 (the adjudicator) and RET-130 (the excursions).
Addendum ·
This entry calls the as-run log “our hash-chained compliance record of what the engine played out”, and its facts table counts 7,439 frame-exact clip junctions from that log. Both claim more than the log can bear. The log records each frame as the engine hands it on towards the card, stamped with the engine’s clock tick, not what left the SDI output; and a frame the engine then discards to absorb the card’s drift keeps its entry. The engine discarded 214 frames that way in this run. So the junction count is exact on the log’s own tick grid, and it is not a measurement of the output. We had known of this fault in the log since July 2026 and did not check this entry’s wording against it; we found it on 29 Sep 2026 while writing what the as-run log proves, which gives the detail.