Diese Notiz ist noch nicht übersetzt — die englische Version wird angezeigt.

The kauditd Hold Queue Incident

This one took three rounds. Two of them produced fixes that looked like they worked, and neither of them was a fix. Writing it down mostly for the shape of the mistake, which is more portable than the specifics.

The mechanism underneath is in the neighbouring note — The Linux Audit Subsystem — and this story doesn't really parse without it. The one-line version: the kernel delivers audit records over two independent paths, unicast to a registered auditd and multicast to passive subscribers like journald, and the second does not substitute for the first.

The host

chiba: a headless Hetzner box running NixOS on kernel 6.18.45, btrfs root, impermanence (the root filesystem is wiped every boot). It runs the git forge, Matrix, mail and webmail.

Its intrusion detection uses five kernel audit watches — three tamper watches and two canary baits:

-w /root/.ssh                            -p wa -k chiba-tamper-ssh
-w /home/synapse/.ssh                    -p wa -k chiba-tamper-ssh
-w /persist/var/lib/sops-nix/key.txt     -p wa -k chiba-tamper-agekey
-w /root/.aws/credentials                -p r  -k chiba-canary-bait
-w /home/synapse/.aws/credentials        -p r  -k chiba-canary-bait

The actual bug, stated up front

In NixOS, security.audit.enable turns on only the kernel side and loads the rules. The daemon is a separate option: security.auditd.enable. It was never set. auditctl -s showed pid 0 — no registered consumer, the entire time.

The reason nobody looked there is a single sentence in this project's own design documentation, which read roughly:

systemd-journald-audit.socket is active, so audit records reach journald without the userspace auditd daemon.

That sentence is true. It was read as "therefore we don't need auditd", which is false. Journald subscribes over multicast; the kernel still wants a unicast consumer and treats its absence as a delivery failure. That one misreading cost three rounds of diagnosis.

Round 1 — the cold-boot burst (2026-08-21)

After a genuine cold start — the first in a while, since most deploys had been live switches rather than power cycles — every hardened systemd service loaded its seccomp-BPF filter at more or less the same moment. Each BPF program load is its own audit event. The burst blew straight through the then-current limit of 1024.

Symptoms: kauditd hold queue overflow, thousands of suppressed callbacks, kauditd pegged, and the network stack unresponsive for minutes. From outside it looked like a hard crash — no ping, no SSH. But journalctl -b -1 showed clean, orderly shutdowns. No panic.

Diagnosis: a simultaneous-start burst. Fix: raise backlogLimit, ending at 16384 (8192 having been patched live into grub.cfg from Hetzner rescue mode as the emergency measure).

Plausible. Also wrong.

Round 2 — it's not boot-specific (2026-08-22)

It came back: 216 overflow lines inside a single three-hour window, with no reboot in between.

Diagnosis this time: the BPF cascade isn't unique to boot. It fires on every PAM login session that spins up a fresh user@<uid>.service — systemd builds and tears down the whole per-user instance, cgroup-BPF programs included, per login, when the user has no lingering session to stay warm between connections.

Two accounts drove it:

  • synapse — every individual ssh chiba '<cmd>' is its own login/logout cycle. Automation that opens a fresh connection per command rather than multiplexing generates a lot of these.
  • forgejo — and this is the one that scales badly. Every git-over-SSH operation rides system sshd as that one shared system user. So every contributor pushing or pulling against the forge multiplies the same PAM churn, not just the operator.

Fix: users.users.<name>.linger = true for synapse, root and forgejo, keeping the per-user instances resident instead of cycling per connection.

Also plausible. Also wrong — though linger stayed, because it removed real churn and is correct on its own terms.

The instrumentation that was the bug it was measuring

Worth preserving for the sheer shape of it. The metric built in round 2, specifically to make this visible, was first implemented as a systemd.timer firing a Type=oneshot service every 30 seconds — which is to say, precisely the pattern that had just been diagnosed as the cause, running unconditionally and more often than the SSH traffic it was meant to observe.

It surfaced because paging continued after the linger deploy, and the overflow timestamps landed exactly on that service's start times. Rebuilt as a long-running process with a sleep loop.

Round 3 — the real one (2026-08-24)

It came back again. Linger active. backlogLimit at 16384.

The evidence

The counter shape is what cracked it:

  • node_audit_lost_total sat at exactly 0 for 50 hours after the 08-22 boot, then began climbing at 20:13:42 and never stopped. No reboot in between.
  • The audit event serial at onset was ~5580. At ~3 records per event that's ~16.7k records — crossing backlog_limit = 16384 right about there.
  • /proc/slabinfo showed skbuff_head_cache active = 17328 against that same limit of 16384. The held records were directly visible as pinned kernel memory.
  • After onset, lost grew by 18–19 per 10-minute check cycle, and one cycle generates ~17 audit records. Loss running 1:1 with every record produced.
  • backlog read 0 the entire time — because that's the main queue, which drains fine. The hold queue isn't in auditctl -s at all.
  • The host's only error-level logs in 24 hours: 137 lines, all 137 kauditd hold queue overflow. Otherwise completely healthy — zero failed units, disk 5%, RAM 2.7G of 15G, backups green, certificates valid.

The signature worth memorising

A counter that is exactly zero for hours, then climbs monotonically and never stops, describes a bucket filling up — not a burst.

A burst problem is jagged: spike, recover, spike, recover. This was flat, then a knee, then a straight line. That shape rules out "too much traffic at once" and points at "something that should be draining isn't."

Why both earlier fixes could never have held

They were time dials, not fixes.

  • Raising backlogLimit makes the bucket bigger (and pins more kernel memory). It moved onset from minutes after boot to ~50 hours after boot.
  • linger lowered the record rate. It moved onset the same way, for the same reason.

And every reboot reset the counter, which made both look like they had worked.

That's the transferable lesson: if a fix only moves the moment the problem returns, it isn't a fix.

The fix

security.auditd = {
  enable = true;
  settings.write_logs = false;
};

auditd registers as audit_pid on the unicast netlink socket. kauditd's send now succeeds, so audit_hold_queue drains instead of filling, the printk spam stops, and lost stands still.

backlogLimit stays at 16384. With a consumer present it guards only the main queue against genuine simultaneous-start bursts — which is what it was always meant to do.

auditd was also added to the central unit registry so its failure pages immediately. Otherwise its absence only announces itself ~2 days later as AuditRecordsLost, long after the cause.

On write_logs = no — a trade-off, not a trick

Deliberate for this host, and not a general recommendation. journald plus Vector is already chiba's evidence path, and /var/log lives in /persist, so a second on-disk copy of the same records would grow every backup while covering nothing that isn't already covered. Here, auditd is wanted purely as the queue consumer, not as a second store.

If you don't already have another durable log path, you want the real audit.log with rotation. (write_logs is a genuine auditd.conf(5) keyword, checked against the shipped man page for audit 4.2.1.)

Verification after deploy

Measured live, before → after:

  • auditctl -spid: 0 → 216431
  • skbuff_head_cache active: 17328 → 1147
  • lost: +18–19 per 10-minute cycle → frozen at 4802
  • overflow lines: continuous → 0
  • /var/log/audit: empty, as intended

Then a 14-minute window at 60-second sampling: lost flat across all 14 samples, backlog 0 throughout, skbuff_head_cache between 1147 and 1236 with no trend, zero overflow lines in every bucket — and 319 audit records delivered to journald in that same window, of which 0 were lost. Before the fix, lost had been growing 1:1 with every record. That's the closing proof. The Alertmanager alert cleared itself.

The correction that matters most

This project's own alert text claimed that during an overflow, tamper watches and canary reads had "NOT recorded".

That was wrong. The multicast hook runs before the failing unicast send — that's the if (skb_hook) line above the if (!sk) branch in kauditd_send_queue(). journald, and therefore the whole intrusion-detection pipeline, received every record throughout. Intrusion detection was never blind at any point.

What was lost was exclusively the copy destined for a daemon that wasn't there.

So: this was a monitoring and memory problem, not a security hole. Worth stating plainly, because the alert text made it sound like the latter for two days, and an alert that overstates its own blast radius is its own kind of bug — it was retracted at every site.

Where this actually stands

Budding. Closed, deployed, and verified against live measurement rather than reasoning. The three things worth carrying forward:

  1. Multicast subscribers don't satisfy a kernel that wants a unicast consumer — and "the records are showing up in the journal" is not evidence that they aren't being lost.
  2. auditctl -s doesn't show the hold queue, so backlog: 0 proves less than it looks like it proves.
  3. A fix that only moves the recurrence date isn't a fix — and a reboot that resets the counter will happily let you believe it was.