Jeg tog min Hetzner-maskine ned igen

Min Hetzner-maskine kørte rent i 22 dage. Så, omkring kl. 00:40 i nat, blev den tavs. Ingen alarmer, ingen SSH, ingen ping. Ingen mails fra Hetzner — de generer dig ikke, når kassen er levende nok til ikke at udløse deres hardware-watchdogs, men død nok til at intet svarer indefra.

En manuel hardware-reset fra Robot-panelet hentede den tilbage her til morgen — hurtigt, fordi vi allerede havde styr på BIOS-boot-rækkefølgen og GRUB efter et tidligere eventyr. Det interessante spørgsmål var ikke hvordan jeg fik den op igen. Det var hvad der egentlig slog den ihjel.

Sidste gang det her skete, måtte jeg bede Hetzner om at koble en konsol på, så jeg kunne se hvad maskinen lavede. Denne gang var en simpel reboot nok — og så graven i det bagefter.

Ingen OOM, ingen panic, ingen log

Første instinkt ved enhver Linux-død: journalctl -b -1. Hvis kernens OOM-killer havde fyret, ville der være umiskendelige spor — invoked oom-killer, Out of memory: Killed process, fejlede page-allokeringer.

Der var ingen.

Ingen kernel-panic. Ingen allokeringsfejl. Bare tre ensomme linjer fra systemd-journald om at den »under memory pressure, flushing caches« omkring 00:37, og så stoppede journald simpelthen med at skrive kl. 00:40:58. De allersidste linjer er kedelige Docker-health-check-timeouts — den slags der sker når noget er overbelastet, men stadig i live. Så intet.

Det er ikke OOM. Det er et hang.

Det sysstat fangede

Heldigvis havde sysstat stille samplet systemtilstanden hvert 10. minut i hele den 22-dages oppetid — én fil per dag under /var/log/sysstat/. Den rygende pistol lå i sa13:

To kolonner betyder noget.

%commit er forholdet mellem committed hukommelse og fysisk RAM plus swap. Committed hukommelse er det, processerne har bedt om — via mmap, malloc, brk — uanset om de faktisk har rørt det endnu. Linux defaulter til vm.overcommit_memory=0: »heuristisk« overcommit. Kernen uddeler gladeligt langt mere virtuel adresseplads end der fysisk findes, og vædder på, at de fleste processer aldrig bruger alt, hvad de reserverer. (Og det gør de som regel heller ikke. Java-heaps reserverer gigabytes, de aldrig rører. Node's V8 gør lignende tricks.)

Kl. 23:20 krydsede commit 100 %. Kl. 23:50 var den på 222 %. Kl. 00:40 var den på 498 % — næsten 678 GB committed mod 125 GB fysisk RAM og 4 GB swap.

Load average gik fra 2,28 til 5.369 på fyrre minutter. Det er tusindvis af tråde i kø, der venter på noget, de ikke engang kan dræbes ud af.

Hvad der faktisk skete

Jeg havde startet noget tungt arbejde i en devcontainer omkring 23:20 — en pks brain extract, der spawnede hundredevis af arbejdere (det er app-niveau-historien fra samme nat). Men det præcise hvad er ikke pointen. Mønstret er.

Workload'en committede enorme mængder hukommelse. Et stykke tid er det fint — committed hukommelse er ikke rigtig hukommelse, før den bliver rørt. Men efterhånden som arbejdet kørte, begyndte det at røre pages. Kernen måtte bakke de commits op med fysisk RAM. De frie pages svandt.

Og så swap. Hver eneste swap-slot var optaget af noget, kernen havde besluttet at evicte tidligere. Der var ingen fri swap at evicte flere pages ned i. Så kernen sad fast i swap-ind/swap-ud-dansen: læs en page tilbage fra swap, skriv en anden ud, igen og igen. Klassisk swap-thrashing.

Disk-I/O klatrede. Processer, der havde brug for hukommelse, blokerede på I/O. De gik i D-state — uafbrydelig søvn — og hobede sig op. Load average eksploderede. Kernens OOM-heuristik holdt mund, for set fra dens stol virkede reclaim: pages bevægede sig mellem RAM og swap. Det ligner succes, ikke fejl.

Til sidst var I/O-køen så dyb, at systemet ikke kunne komme videre med noget som helst. Inklusive at skrive journal-linjer. Inklusive at svare på ping. Inklusive SSH-dæmonens accept-loop.

Kassen var ikke løbet tør for hukommelse i OOM-forstand. Den var deadlocked på sin egen swap.

Læringen — og fiksen

Den faktiske fiks er uglamourøs: begræns hvor meget hukommelse hver container må bruge. Docker har understøttet det via cgroups i årevis; jeg havde bare ikke brugt det på en host, hvor jeg kører mange devcontainere.

Påført alle eksisterende containere, live, uden genstart:

for c in $(docker ps -aq); do
  docker update --memory=64g --memory-swap=64g "$c"
done

--memory-swap=64g (lig med --memory) slår swap helt fra for containeren — hvilket er det rigtige her, eftersom swap-thrashing var fejlmoden. Hvis en container prøver at overskride loftet, fyrer OOM-killeren mod processer inde i den containers cgroup alene. Host'en forbliver rask.

Det er den anden halvdel af spawn smalt-historien: app-laget skal ikke spilde tools det ikke bruger — men selv en velopdragen app skal host'en kunne overleve. Grænser per container er den forsikring.

sudo tee /usr/local/bin/docker-default-memcap.sh > /dev/null << 'EOF'
#!/bin/bash
CAP="${1:-64g}"
for cid in $(docker ps -aq 2>/dev/null); do
  lim=$(docker inspect -f '{{.HostConfig.Memory}}' "$cid" 2>/dev/null)
  if [ "$lim" = "0" ]; then
    name=$(docker inspect -f '{{.Name}}' "$cid" 2>/dev/null | sed 's|^/||')
    docker update --memory="$CAP" --memory-swap="$CAP" "$cid" > /dev/null 2>&1 \
      && logger -t docker-memcap "Applied $CAP cap to $name"
  fi
done
EOF
sudo chmod +x /usr/local/bin/docker-default-memcap.sh
(sudo crontab -l 2>/dev/null; echo "* * * * * /usr/local/bin/docker-default-memcap.sh 64g") | sudo crontab -

sudo tee /usr/local/bin/mem-monitor.sh > /dev/null << 'EOF'
#!/bin/bash
{
  echo "=== $(date -Iseconds) ==="
  free -h
  cat /proc/buddyinfo | grep -E "DMA32|Normal"
  ps -eo rss,user,comm --sort=-rss | head -11
  docker stats --no-stream --format '{{.Name}} {{.MemUsage}} ({{.MemPerc}})' | head -15
} >> /var/log/mem-monitor.log 2>&1
EOF
sudo chmod +x /usr/local/bin/mem-monitor.sh
(sudo crontab -l 2>/dev/null; echo "*/5 * * * * /usr/local/bin/mem-monitor.sh") | sudo crontab -

sudo tee /etc/sysctl.d/99-debug-hung.conf > /dev/null << 'EOF'
kernel.hung_task_timeout_secs = 120
kernel.hung_task_warnings = 10
kernel.softlockup_all_cpu_backtrace = 1
EOF
sudo sysctl -p /etc/sysctl.d/99-debug-hung.conf