Nix schreef de helft van mijn debugger

Ik heb het gebruikt om talloze race-condities in Nix-builds te vinden, te reproduceren en op te lossen, maar het gaf me het gevoel dat ik een beetje gek werd. Wat is deze superkracht, en waarom gebruikt niemand anders het?

De tool is snel gegroeid en bevat nu een bronnenpaneel, stackframes, bladwijzers, een "Compare"-tabblad, veel meer gdb-ondersteuning, thread-lanes (die laten zien wie op elke stap de CPU in handen had) en "Check from here", wat helpt om de exacte stap te vinden waar een race-conditie optreedt.

Bij elke nieuwe functie ging ik ervan uit dat het een grote hoeveelheid programmeerwerk zou kosten, maar ik bleef tegen hetzelfde merken: het moeilijkste deel van elke functie was al gedaan, en Nix had het gedaan.

Een debugger heeft bijvoorbeeld de exacte inputs van het programma nodig, de debug-symbolen, de broncode, de bronnen van elke library eronder, en een manier voor iemand anders om dat allemaal op hun eigen machine te krijgen. Dat is precies wat een derivation is, en Nix maakt dat eenvoudig.

Twee kassiers, één rekening

Een klassiek, simpel voorbeeld van een race-conditie zijn twee threads die geld storten op één bankrekening. Elke storting leest het saldo, schrijft een regel naar het grootboek en slaat vervolgens het saldo plus de storting op. Als één kassier actie onderneemt tussen het lezen en opslaan van de andere, overschrijft deze het saldo met een verouderde waarde, waardoor de storting van de ander verloren gaat. 💥

static void deposit(int teller, long amount)
{
    long seen = balance;
    char line[64];
    int n = snprintf(line, sizeof line,
                    "teller %d: %ld + %ld\n",
                    teller, seen, amount);
    if (write(1, line, n) != n)
        return;
    balance = seen + amount;
}

Een kassier die draait tussen het lezen en opslaan van de ander, schrijft een verouderd saldo over de stortingen van de ander heen. [^1]

Voorbeeld van het proces:

Kassier 1	Saldo	Kassier 2
leest 150	150
	150	leest 150
slaat 200 op	200
	200	slaat 150 + 10 op
	160

De laatste storting van kassier 1 is verdwenen.

De VM van Rewind heeft één CPU, dus de eerste run slaagt ook. rewind check voert de build opnieuw uit onder verstoorde planningen (perturbed schedules), waarbij de guest-kernel op verschillende stappen wordt gevraagd opnieuw te plannen. Zo wordt de eerste fout herleid tot één specifieke stap:

$ rewind check --where github:fzakaria/rewindvm#bank
...
stap 3237 beslist het: een reschedule daar zorgt dat de run faalt
slagent: run 12feb5f832205a72, schedule 0
faalt: run c2f1cfac0c288f3e, schedule 1 over stappen 3237..3238
de twee zijn dezelfde run tot stap 3237
waar de threads waren:
3237   139/140   deposit (bank.c:24), op de CPU bij de beslissende stap
3250   139/141   deposit (bank.c:24), bij het eerste event dat verschilt

Het uitvoeren van deze controle op mijn laptop duurde 11 seconden. De twee runs zijn op dezelfde machine identiek, exit voor exit, tot stap 3237, waar alleen de falende run een reschedule krijgt.

Gratis extra één: de inputs

Het argument voor check is een derivation en kan een flake-referentie zijn. De schoonheid van Nix is dat het de inputs van een derivation kent, dus dat is alles wat we nodig hebben om ervoor te zorgen dat de run reproduceerbaar is. De inputs van de derivation zijn de broncode, de compiler, de libraries, de kernel en de configuratie van de VM.

rewind nix realiseert de inputs van de derivation, pakt de closure in een read-only erofs-image en boot de VM daarop.

De ID van de run is een hash van de inputs, vergelijkbaar met een store path. Met rewind show kan het commando dat de run opnieuw maakt, worden geprint:

$ rewind show 12feb5f8
rewind nix /nix/store/cr8rl40rjb9cmmcd9sxn9mpdrhvp53jj-bank-0.1.0.drv --epoch 1791331200 --clock branches --name bank-0.1.0  # 12feb5f832205a72

Wanneer de build slaagt, rapporteert de guest de NAR-hash van elke output. rewind nix controleert dit tegen de kopie op de host en tegen elke binary cache waar Nix substitutes van haalt, door alleen de .narinfo op te halen:

$ rewind nix github:fzakaria/rewindvm#bank
...
/nix/store/27a4q7w90jzp4wg5kaaajvb64zll6yqg-bank-0.1.0 dbf0df3de84b7a84  komt overeen met jouw store

Dit helpt ons valideren dat de build binnen de VM hetzelfde is als de build op mijn laptop, en dat de run van de VM reproduceerbaar is door Nix.

Gratis extra twee: elk symbool en elke bron

Het debuggen van code is veel eenvoudiger wanneer je naar de broncode kijkt. Een nieuw paneel in de Rewind-app, of rewind where in de terminal, toont de broncode van het programma op de huidige positie (playhead) en de stackframes die deze hebben aangeroepen.

De debugger moet weten waar de bronnen staan, en Nix geeft ons dat ook gratis.

nixpkgs bouwt pakketten met separateDebugInfo, en de debug-informatie wordt gecachet op cache.nixos.org als een debug-output. We kunnen debuginfod gebruiken om de debug-informatie en de bronnen op te halen via de build-ID. Hierdoor kunnen we de broncode van elke binary in de VM zien, inclusief die van de Linux-kernel! 😲

$ rewind where c2f1cfac 3250
proces 139 (bank), thread 141, bij stap 3250
#4 deposit (bank.c:24)
22  	int n = snprintf(line, sizeof line, "teller %d: %ld + %ld\n", teller, seen, amount);
23
>     24  	if (write(1, line, n) != n)
25  		return;
26  	balance = seen + amount;
aangeroepen door #5 teller (bank.c:34)
aangeroepen door #6 start_thread (pthread_create.c:454)

gdb, op een fork van elke stap

Soms is de broncode niet voldoende en moeten we de staat van het programma zien. rewind gdb opent gdb op een fork van de run op de positie van de playhead, inclusief elke thread van het proces. De debugger kan breakpoints en watchpoints instellen, en het geheugen, registers en variabelen inspecteren.

Bij stap 3249, vlak voordat kassier 2 de CPU terugkrijgt, kunnen we de variabele balance observeren en doorgaan tot deze verandert. Niets wat gdb doet verandert de opname; we kunnen terugspoelen naar dezelfde stap en opnieuw forken, of op elke andere stap forken, en gdb zal dezelfde staat zien.

Als gdb niet voldoende is, opent rewind shell --with nixpkgs#strace een shell in de VM op een bepaalde stap, met elk gewenst pakket uit nixpkgs op de PATH. Dit is simpelweg één extra closure verpakt in één extra image.

Twee runs vergelijken

Rewind maakt het zeer eenvoudig om twee runs te vergelijken. Het Compare-tabblad in de app, of rewind compare in de terminal, toont de laatste gedeelde gebeurtenissen van beide runs en de eerste gebeurtenis die verschilt.

Het Compare-tabblad zet de gebeurtenissen van beide runs naast elkaar vanaf het moment vlak voordat ze uiteengingen, waarbij de verschillen zijn gemarkeerd. Kassier 2 begint in de falende run vanaf 150 en in de succesvolle run vanaf 200.

Wie had de CPU?

De VM van Rewind heeft één CPU, dus op elk moment draait er precies één thread. Een race-conditie is een kwestie van volgorde: welke thread draaide wanneer.

De trace beantwoordt dat niet direct. Het registreert wat threads deden (een write, een open, een fork, een exit, een signaal), maar niet wie er draaide in de tussenpozen tussen die gebeurtenissen.

Rewind kan deze gaten opvullen zonder iets nieuws op te nemen. Elke run kan exact worden herhaald, dus het kan elk stuk van een run stap voor stap doorlopen en op elke stap aan de guest-kernel vragen welke thread op de CPU staat.

In de falende run wordt kassier 1 (Thread 140) onderbroken bij stap 3238, halverwege een storting: hij heeft het saldo gelezen maar nog niet opgeslagen. Kassier 2 (Thread 141) krijgt de CPU voor één enkele stap, 3239, lang genoeg om het saldo te lezen, en daarna krijgt kassier 1 de CPU terug en maakt hij het af. [^2]

Controleren vanaf hier (Check from here)

Het vinden van één slechte interleaving roept de volgende vraag op: hoe waarschijnlijk is dit? Is de succesvolle run de normale situatie, of had deze simpelweg geluk?

rewind check beantwoordt dit normaal gesproken door de hele derivation opnieuw te bouwen onder veel verschillende schema's. Met --run begint het proces in plaats daarvan bij een run die je al hebt, op elke gewenste stap. Het forkt de run daar één keer per schema; elke fork neemt vanaf die stap een andere volgorde van threads, en telt hoeveel runs anders eindigen. Alles vóór die stap blijft exact zoals het was.

We kunnen deze techniek toepassen op het bankvoorbeeld, beginnend vanaf de stap waar de twee runs uitegingen: 3221. Wanneer we vanaf daar 16 schema's draaien, verliezen ze alle 16 geld. [^3]

$ rewind check --run 12feb5f8 --schedule-from 3221 --schedules 16 --all --no-narrow
schedule   0: exited:0       4528 steps  dbf0df3de84b  run 12feb5f832205a72
schedule   1: exited:2       3313 steps    run f6eb462913dce489
schedule   2: exited:2       3328 steps    run 388cef73a9c545fa
schedule   3: exited:2       3312 steps    run 4d42012072d11537
...
schedule  16: exited:2       3314 steps    run 63f7817972a90273
16 van de 16 verstoorde schema's eindigden anders

Hetzelfde kan in de Rewind App via "Check from here" in het contextmenu van de playhead. Het forkt de run bij de playhead en voert elke fork uit onder een ander schema, waarbij geteld wordt hoeveel er anders eindigen.

Boekmerken

Met b kan de stap van de playhead worden voorzien van een boekmerk met een notitie. Boekmerken worden bewaard bij de run en reizen mee in de .rwd export. Wanneer ik de run aan iemand anders geef, opent diegene deze met mijn notities op de tijdlijn.

Andere voorbeelden om te proberen

Elk van deze is een derivation in de flake, met één bug en één fix:

• philosophers: de deadlock uit het vorige bericht.
• bank: de verloren update zoals hierboven beschreven.
• waiter: een SIGCHLD die arriveert tussen een vlagcontrole en een pauze, waardoor de parent slaapt tot de tien seconden timeout van make check hem doodt.
• config-reload: één proces herschrijft een configuratiebestand in place terwijl een ander het opnieuw leest. Op veel cores faalt dit bijna elke keer; op één CPU landen slechts sommige schema's de lezer tussen de truncate en de laatste write.

$ rewind check github:fzakaria/rewindvm#waiter

Nix is een superkracht

Het grootste deel van het zware werk van een debugger is al gedaan door Nix. Rewind voegt daar wat aan toe, maar de rest is er al: de inputs, de bronnen, de debug-symbolen en een manier voor iemand anders om dat allemaal op hun machine te krijgen.

Wanneer je begint met iets hermetisch zoals een Nix derivation, krijg je een debugger er praktisch gratis bij.

$ nix run github:fzakaria/rewindvm -- check github:fzakaria/rewindvm#bank

***

[^1]: Op mijn 16-core laptop verloor de bank geld in 396 van de 1.000 runs. Wanneer gepind op een enkele core met taskset, verloor hij in geen enkele van de 1.000 runs geld: één core alleen schakelt zelden threads in het midden van een storting, wat de reden is waarom Rewind de planning verstoort. [^2]: Dit is enigszins lastig te zien, aangek dan het event van Kassier 2 verborgen zit onder de oranje balk. [^3]: Schedule 0 is de run zelf, die slaagde. Elke andere regel is een fork die faalde: exited:2 betekent dat make check faalde omdat het saldo te laag was.