Late wakes near 400 microseconds, August 2026: we found where Linux had put the timer, not what made them late

What we set out to learn

Between 6 and 20 August 2026 the first unit (i7-12700, DeckLink Duo 2) ran one unbroken 339-hour soak, written up in its own entry. Its criteria were frozen on 5 August and allowed zero late engine frames. It had two, on 11 Aug at 03:25 UTC (567 µs) and 15 Aug at 08:50 UTC (570 µs), so it failed its own test.

Rytmi is Karhu TV's playout engine, in software, and Syke is its clock. Syke's clock thread wakes once per frame, every 20 ms at 50 frames per second. Each wake is a tick, and how far a tick lands from its scheduled instant is the clock phase. A late engine frame is a tick more than 500 µs late: a late wake, not a lost frame. An excursion is any tick far outside the ordinary range, which on this unit was a few hundred nanoseconds. Both times the card's output buffer absorbed the delay, and the card counted zero late frames on the SDI output. This entry follows our search for why the thread woke late, up to 18 Sep 2026, with per-run figures to 27 Sep 2026.

If you came for the kernel behaviour, it is in the traces section. In short: on Linux 6.8, take a thread on a CPU isolated with isolcpus and nohz_full, and leave kernel.timer_migration at its default of 1. An unpinned hrtimer that the thread arms for itself, such as the one behind a sleep, is then armed on the first housekeeping CPU, not on the thread's own, whenever it is due later than that CPU's next tick. Setting timer_migration=0 at runtime brought it back (on the second unit, an i7-14700: 497 of 500 expiries on the first housekeeping CPU before, none after, 8 Sep 2026). That settled where the timer lives. It did not, on our evidence, explain the late wakes.

The shape of it

Re-read after the run, the two late frames were the top of a population: 109 excursions of 380 µs or more. All were late, none early. 106 of the 109 fell within 380–450 µs, median 413. Several more fell just short of 380 µs. Below them lay a wide empty stretch: the ordinary tail stopped tens of microseconds up, and nothing else in the run's 339 hours landed in between. The distribution has two modes, not one long tail. The two late frames sat on a level of their own, 116 µs clear of the rest. The 109 came in 36 bursts of one to five, and every gap inside a burst was 112 or 113 s, or exactly twice that.

That beat is five slots of a lattice about 22.5 s long, and the lattice follows the content, not the wall clock. On five airings over nine days, one programme's events fell at the same point in it to within 0.2 s. One event fired on a programme's lattice before that programme had begun to air. Re-encoded copies, flown on the live channel in late August against predictions we froze beforehand, showed that the lattice keeps time with the content, not with the size of the file.

All 109 fell inside items handled one way on their way to the output. None fell inside items handled the other way, which filled just over half the airtime. We give no probability for that split. The events cluster in bursts and the bursts cluster in time, and we have not settled what the independent unit is. Load does not explain it. Minutes airing items of the first kind matched minutes of the second in CPU use, temperature, memory and ordinary clock phase.

The mechanism can be present and silent. 5 August was clean with the same programmes and binary. On 11 August the burst rate stepped from 0.41 to 3.81 a day within about five hours, with no change the operating system could see. With the engine stopped (24 Aug 2026), processing an event-bearing file in a separate process never reproduced the lattice, but that null could equally mean the machine was not in its armed state. We then ran trials on a bench alongside the live engine, each started within a second or two of a real excursion. The twelve that could be read, by 5 Sep 2026, favoured the engine's own handling of the item as a required ingredient without proving it, and the pass mark we judged them by was chosen after their rules were written down.

What it was not, and how we know

We rejected about twenty candidate causes, several of them our own. These are the ones a real-time Linux reader would suspect first.

SMI. A System Management Interrupt takes a CPU into firmware without the operating system seeing it. Intel CPUs count them in MSR 0x34. The counter read 374 on 21 Aug 2026, 350.30 hours into the campaign's boot, and 374 on 23 Jul 2026, 13.88 hours into another boot, so it did not advance while the machine ran. That rules out SMI but not microcode or management-engine stalls. A blocker arriving at random is ruled out without any counter. At random phase a small overhang is always at least as likely as a large one, so it would have put more events in the empty stretch below the cluster than there were in the whole cluster, and there were none. Nor could it land gap after gap on 112–113 s. The periodicity comes from the engine's side; anything below the operating system could only gate or amplify it.

The rest. We read TAI from the kernel, and NTP disciplines that clock. But none of the time daemon's frequency steps of 0.20 ppm or more fell on 11 Aug, which carried seven of the first nine events. The first burst, on 8 Aug, did coincide with its fastest slew, and no later burst did. We record that as a coincidence. TLB shootdowns (interrupts that flush a core's address translations) looked like a lead. Then a 1 Hz sampler of every interrupt counter on the clock's CPU, running from 12 Aug, found them all at baseline at the events. The machine is configured to keep its cores out of deep idle states, which rules out exit latency. We also ruled out temperature, memory use, any engine stall, and the periodic tamper-evidence seal our as-run log writes, which the events beat against rather than lock to. Our own large file copies leave marks too, all smaller than the cluster. On 25 Aug we wrote up one event as the mechanism; it was our nightly backup, started three seconds earlier. Clip junctions come about 25 s apart, so they are neither ruled in nor out.

What the kernel traces showed

On 4 Sep 2026, in an instrumented run that was not a soak, an ftrace ring buffer caught ten excursions. It recorded the clock thread's CPU, and a watcher froze it after each event. A tool that knows nothing about the engine recovered the lattice from the kernel's timestamps alone.

The buffers held 14 distinct genuine late wakes, all alike. Through each one the CPU's 1 kHz kernel tick kept to schedule within 14 µs, no task ran, and no interrupt, softirq or other timer fired there. The wake was traced in the idle task's context, the path for a wake queued from another CPU. The core was healthy and idle, and the late wake came from elsewhere. The thread's timer almost never expired on its own CPU: a handful of times in each buffer, against tens of thousands of wakes across them. Those buffers recorded none of the housekeeping CPUs. On 8 Sep a 10-second trace of every CPU on the second unit found the expiry before 497 of 500 wakes on the first housekeeping CPU.

The reason is ordinary Linux 6.8 behaviour, and it applies to any thread on a CPU isolated this way. The hrtimer behind a user-space sleep is unpinned. kernel.timer_migration defaults to 1, and the kernel documents it as an attempt “to migrate timers away from idle cpus to allow them to remain in low power states longer”. With it set, each hrtimer_start of an unpinned timer goes through switch_hrtimer_base and get_target_base to get_nohz_timer_target(). nohz_full has removed the isolated CPU from timer housekeeping. isolcpus has left it no scheduler domains, so the domain walk finds nothing. The fallback, housekeeping_any_cpu(), returns the first housekeeping CPU on a single-NUMA-node machine. hrtimer_check_target() keeps a timer local only if it expires before that CPU's earliest programmed event, so with a 1 kHz tick running there, any timer due more than a millisecond ahead is armed on the housekeeping CPU. The choice is made again at every hrtimer_start, so changing the sysctl needs no restart. We checked the chain line by line against the v6.8 source, and measured where it put the timer on the second unit. Our first reading, a round-robin across housekeeping CPUs, missed one branch; the data corrected it within the hour.

So the thread we had isolated was woken, once a frame, by a timer on another CPU. On the second unit we measured that CPU as the first housekeeping CPU, the kind that carries a machine's background work. On the first, the traces showed the wake arriving from off the core. It was not the only isolation setting we had configured and believed without checking. isolcpus had not kept device interrupts off that core. nohz_full had not stopped its tick, which fired 999.9 times a second on the first unit (12 Aug 2026) and 751 on the second (6 Sep 2026).

The change, and a test that could not fail

On 8 Sep 2026 we wrote down what the trace should show, then set kernel.timer_migration=0 on both units at runtime, without restarting the engine. Before, 497 of 500 expiries on the second unit were on the first housekeeping CPU; the first unit's only before-trace was the 4 Sep buffers. After, 500 of 500 were local on both units, each wake raised by the isolated CPU's own timer interrupt. The cost is one more timer interrupt per frame on a CPU that already takes a 1 kHz tick. The first unit's worst tick in the hour after was no worse than in the hour before. We made the setting persist across reboots, and added a post-boot check that fails unless it reads 0.

We withdrew the acceptance test we had registered, 75 hours clean on the first unit, before reading any data against it. That unit had already gone 50.5 hours without an excursion of 300 µs or more, or a late frame, before the change. At the rate the campaign had shown, a quiet stretch that long was already unlikely, so the unit was probably no longer in the state that produced events, and a quiet result was decided in advance.

On 9 Sep, rtla timerlat measured the timer interrupt on the second unit's first housekeeping CPU at a worst latency of 1.05 µs over 3,067 samples. We had been writing up the wake as late because its timer fired late there. That measurement, on the second unit and outside any event, removed our evidence for the step, so we withdrew it. It does not show the timer was on time. It cannot see a timer callback running late inside an interrupt that started punctually. The timer's placement stands. The claim that it was delayed there does not.

A positive control, a retracted p-value, and the one that stands

A quiet machine could not judge the change, so we built a positive control. It loads the first housekeeping CPU with a large file copy and compares the clock thread's worst wake with the timer migrated against the timer local. Its first runs, on 8 Sep on both units, were null, and we called that a refutation of “load on that CPU is the trigger”. On 18 Sep we downgraded it to untested. The copy had bypassed the page cache, so it caused no writeback or reclaim. The arms ran in sequence, nothing checked that the machine was settled, and the trip threshold sat above the events the test was built to catch. A null from an apparatus that cannot apply the treatment is not evidence of absence.

Run 4, on 14 Sep, gave 7 events to 0 at P = 0.0078, and we withheld it. The migrated arm always ran first and warmed the page cache for the other. The card also reported 3,324 dropped frames during the migrated arm against 19 during the local one, so the arms were not watching the same machine. And the run started thirteen minutes after a fault our own test had caused. An earlier run's teardown left its copy running, and that load cost three of the second unit's four outputs their card buffer. Four of our instruments missed it for 67 minutes.

On 16 Sep we rebuilt the test. Each arm evicts its load file from the page cache first, and rounds interleave with the leading arm alternating. The test refuses to start while any engine counter moves, and gives no p-value when the arms' backgrounds differ. Its first run, on 17 Sep, went 4 events to 0, too few to decide. For run 6 we wrote the prediction into our version-controlled record, which timestamps it: at least 7 events migrated, none local. It gave 8 to 0, and we headlined P = 0.0039, decided. An audit of our own work withdrew that the same day, about nine hours later. The eight events came from three of six rounds, so the round is the independent unit, and over rounds P is 0.125. Pre-registering a statistic does not make it valid.

Run 7 counted rounds, with a tie (neither arm producing an event) scoring nothing. Its rule and predicted outcome were committed at 17:31 UTC on 18 Sep: at least 7 non-tied rounds of 10, every one worse with the timer migrated. It closed at 18:41 UTC with 10 of 10, 28 events to 0, P ≈ 0.0010 on a sign test over rounds. On the second unit, under that load, keeping the timer local reduced the worst wake. It does not reproduce the campaign. 22 of the 28 events sit under 100 µs in a continuous tail, where the campaign left an empty stretch under a tight cluster. We had argued this load never reaches the campaign's band, and run 7's largest event, inside that band, ended that argument. Only the shapes of the two distributions still tell them apart.

The numbers

What it cost, and what we got wrong

None of it reached the SDI output. It cost time, and the accuracy of what we said. The count moved in public: nine through 12 Aug, 67 through 17 Aug, then 109. On nine events we said the 500 µs line sat inside the cluster and that the events clustered in long MXF items, and the full population broke both claims. Both late frames were on our instruments within minutes. A person noticed the first 27 hours later, and the second two days later. In late August, while the unit carried our experiments, we blamed a rise in the event rate on a schedule change, but the rise began more than eight hours before the change. The rest are told above, beside the results they distorted: a backup written up as the mechanism, a late wake written up as a late timer, a null from a test that could not apply its treatment, and a p-value computed over the wrong unit.

What it changed

From 8 Sep 2026 both units kept the clock thread's timer on its own CPU. That establishes where the timer lives. It does not establish what recurs every 22.5 seconds or so of content, what delayed the wake, or whether the timer's placement had anything to do with the campaign's events. The first unit's quiet began about 50 hours before the change, and an 89,932 ns tick came after it. A four-and-a-half-day quiet had also ended once before, from 28 Jul to 2 Aug. We changed the host and the engine on 8 and 9 Sep. The excursions' cause is not determined, so we credit neither change. On 14 Sep 2026 we parked the investigation rather than closing it, because it had never reached the SDI output, and left a tripwire on clock phase. Every event here predates the cards' first genlock, on 27 Sep 2026.