Core-dump-epidemiologie: een 18 jaar oude bug oplossen

De modellen en agents van OpenAI steunen steeds meer op schaalbare data-infrastructuur om tijdens inferentie relevante data te zoeken: wanneer de modellen over je vraag nadenken. Sommige van deze services zijn geschreven in C++, waarvan de low-level controle over het systeem ons helpt prestaties te maximaliseren en geheugengebruik te minimaliseren. Die efficiëntiewinst is belangrijk nu we opschalen, maar doordat C++ geen geheugenveiligheid biedt, kunnen bugs crashes veroorzaken door naar verkeerde of niet-bestaande geheugenadressen te schrijven.

Enkele maanden geleden zagen we crashes vanuit de Rockset-service, een op maat gemaakt onderdeel van onze ChatGPT‑data‑infrastructuur dat cruciaal is voor veel data-plug-ins en voor zoeken in gesprekken. Bij elk van deze crashes leek een normale C++-functie klaar te zijn en daarna terug te keren naar een ongeldig adres, waardoor de kernel het programma stopte omdat de instruction pointer niet langer naar code wees. Soms was de return-address-slot in het stackframe NULL. Soms leek het CPU-register voor de stack pointer zelf 8 bytes verkeerd te staan, alsof %rsp op de een of andere manier midden in normale uitvoering was verlaagd. In beide gevallen crashte het programma bij de return.

Dit zijn geen normale faalmodi voor applicatiecode. Een verdwaalde write die alleen op een opgeslagen return-adres belandt, is mogelijk, maar uiterst onwaarschijnlijk. Een bug die %rsp 8 bytes verkeerd uitlijnt zonder inline assembly, setcontext of longjmp (die we geen van alle gebruiken) is nog vreemder, omdat gecompileerde code dat register alleen direct aanpast in de proloog en epiloog van een functie. Voor elke hypothese die wij (of ChatGPT) konden bedenken, was sterk tegenbewijs, dus de bug leek onmogelijk.

Wat we voor één probleem hielden, bleken uiteindelijk twee losstaande bugs te zijn die toevallig tegelijk werden ontdekt. Ten eerste stille hardwarecorruptie op één Azure-host, waar de CPU simpelweg niet correct rekende. Ten tweede een 18 jaar oude race condition in GNU libunwind, een onopgemerkte bug in een veelgebruikte open-sourcebibliotheek.

Deze post vertelt hoe we ogenschijnlijk onverklaarbare crashes vonden en oplosten door als een epidemioloog te denken en een hoogwaardige dataset over de hele crashpopulatie te bouwen.

Laten we eerst dieper ingaan op Rockset. Het is een cloud-native datasysteem voor zoeken en realtime analytics dat we bij OpenAI voor veel interne toepassingen gebruiken, zoals sync-connectors (Rockset is in 2024 door OpenAI overgenomen). Streaming updates houden een actuele index van de kennisbank van een werkruimte bij, zodat ChatGPT relevante informatie kan zoeken bij het beantwoorden van vragen of uitvoeren van acties.

De uitvoeringslaag van Rockset is geschreven in C++. C++ geeft low-level toegang tot de CPU, wat goed is voor prestaties en efficiëntie, maar betekent dat applicatiebugs tot ongeldige geheugentoegang en segfaults kunnen leiden. Om die op te sporen gebruiken we folly’s fatal signal handler om bij een crash een stacktrace te loggen, en uploaden we de bijbehorende core dumps (een momentopname van de programmastaat tijdens de crash) naar Azure Blob Storage voor latere analyse. Alle queryverwerkende leaves van Rockset zijn gerepliceerd, waardoor een crash weinig impact heeft op clients. Toch staat elke segfault voor een bug die moet worden opgelost om onze betrouwbaarheids- en kwaliteitsdoelen te halen.

Onze eerste aanpak was deze cores als een klassiek debugprobleem te behandelen: een paar core dumps heel nauwkeurig bekijken, hypothesen vormen en ze één voor één uitsluiten.

De meeste crashes traden op in een methode genaamd DocumentTree::updateDocument. Bij deze crashes leek updateDocument een onbekende functie X te hebben aangeroepen, waarna de stack corrupt raakte terwijl X actief was en X vervolgens terugkeerde naar een adres dat geen uitvoerbare code was. In sommige gevallen leek het net gepopte frame van X geldig, behalve dat het opgeslagen return-adres NULL was. In andere gevallen leek de stack pointer zelf verkeerd, maar leek het volgende geldige frame nog steeds updateDocument te zijn.

We wisten niet wanneer de stack corrupt raakte, waardoor de zoekruimte enorm was. updateDocument is een grote methode waarin veel wordt geïnlinet, dus het aantal kandidaten voor X was overweldigend.

Was dit een bug in onze C++-code? Een compiler- of linkageprobleem? Een probleem in een van onze runtimebibliotheken? Een Linux-kernelbug rond signal delivery of context switching? Iets nog zeldzamers? Als dit een verdwaalde write was, waarom werd die dan niet gevangen door onze ASAN-stagingomgeving?

We probeerden onze applicatielogs te gebruiken om alle gevallen te vinden, maar stackcorruptiebugs zijn lastig uit alleen logs te classificeren omdat de gelogde stacktraces zelf corrupt zijn of ontbreken. We konden geen logquery maken zonder zowel fout-positieven als fout-negatieven. We inspecteerden handmatig meer cores en vonden extra voorbeelden, maar dat kostte te veel werk om een betrouwbare dataset op te leveren.

In deze fase van het onderzoek sloten we (ten onrechte) een hardwarebug uit, omdat we crashes in meerdere regio’s en op meerdere hardwaretypen zagen, en zochten we nog steeds alleen naar softwareoorzaken. Een paar dagen doken we extreem diep in één crash met verkeerd uitgelijnde %rsp, waarbij we de geschiedenis vóór de crash reconstrueerden uit stack- en registerinhoud. Dat leverde mogelijke aanwijzingen op, maar omdat we vasthielden aan onze eerste conclusie dat alle bugs dezelfde oorzaak hadden, kwamen we niet verder.

Voordat we bij het kantelpunt van ons onderzoek komen, is het belangrijk uit te leggen welke informatie we uit de corebestanden haalden.

Rockset wordt gecompileerd met -fno-omit-frame-pointer, zodat het actieve stackframe altijd via %rbp bereikbaar is en callers een gekoppelde lijst van frame pointers vormen.

Op Linux x86_64 reserveert de AMD64 System V ABI ook 128 bytes onder %rsp als de red zone. Die regio is beschikbaar voor userspace-code en, belangrijker, de kernel belooft hem bij het afleveren van een signaal niet te overschrijven, als onderdeel van het ABI-contract.

De red zone was centraal bij het debuggen van een crash na een return, omdat hij informatie van vóór de return bewaart. Wanneer een SIGSEGV wordt getriggerd, draait folly’s fatal signal handler op de stack van de crashende thread. Stackframes die niet meer actief zijn (omdat hun functie is teruggekeerd) worden door de signal handler overschreven, behalve de laatste 128 bytes. Daarom kunnen we dingen zeggen als: “Het net gepopte stackframe van X leek geldig, behalve een NULL return-adres.” De red zone bewaart delen van inactieve frames, of soms alleen het einde van één inactief frame.

We vonden één crash met verkeerd uitgelijnde stack waarbij alle betrokken functies heel klein waren. Daardoor zagen we dat %rsp tijdens de uitvoering van een relatief eenvoudige functie verkeerd uitgelijnd was geraakt, en dat daarna nog meer calls waren geslaagd. Het programma crashte pas toen de actieve functie uiteindelijk probeerde terug te keren. Geen van die codepaden gebruikte exceptions, inline assembly, setcontext of longjmp; als de stack pointer echt was veranderd zoals de core suggereerde, verklaarde geen plausibele bug in userspace-code het probleem.

Dat duwde ons richting de kernel.

Rockset gebruikt signalen agressiever dan de meeste programma’s. Query-uitvoering wordt opgesplitst in veel lichte taken die data uitwisselen. Dat is belangrijk om workloads met hoge QPS efficiënt te verwerken, maar maakt CPU-accounting per query lastig omdat werk voor veel query’s op dezelfde threadpool wordt gemultiplext.

Onze oplossing is wat we coarse_thread_cputime_clock noemen: een goedkope benadering van clock_gettime(CLOCK_THREAD_CPUTIME_ID, ...) die bij elke taakgrens kan worden gesampled. De timer_create-API kan periodieke signal delivery plannen op basis van meerdere definities van tijdsverloop, waaronder de opbouw van CPU-tijd. We plannen dat een signaal (SIGUSR2) elke paar milliseconden CPU-tijd wordt afgeleverd; de signal handler werkt dan een thread-lokale waarde bij. Hoewel veel taken de grove klok tijdens hun uitvoering niet zien vooruitgaan, levert de som van alle delta’s een onbevooroordeelde schatting op van de echte CPU-tijd voor een query.

Omdat we zo vaak signalen afleveren, leek een zeldzame kernelbug rond context switching of signal delivery plausibel. We besteedden tijd aan bugrapporten, kernelbroncode en de Azure-specifieke kernelpatches. We probeerden stresstests. We konden niets vinden dat ermee verband leek te houden.

Op dat moment besloten we afstand te nemen en een andere aanpak te proberen.

Er zijn grofweg twee manieren om zo’n probleem te debuggen.

De ene is handelen als een soort arts: focussen op één patiënt, veel tests doen en proberen één geval te diagnosticeren op basis van gedetailleerd bewijs.

De andere is meer denken als een epidemioloog: naar de hele populatie kijken en vragen of er patronen zijn die één geval niet kan laten zien. Begon de bug bij een specifieke release? Correleert hij met één hardware-SKU (het specifieke CPU- en servermodel), één regio of één kernelversie? Verbergen zich meerdere afzonderlijke clusters in wat één syndroom lijkt?

We hadden vooral in artsmodus gezeten. De cruciale omslag was het besluit dat we hoogwaardige populatiedata moesten verzamelen.

Onze eerdere pogingen om automatisch alle instanties van het probleem te vinden mislukten omdat we tekstzoekopdrachten op de logs probeerden te gebruiken. De core dumps zelf bevatten veel meer informatie, maar ze handmatig bekijken schaalde niet. We besloten te investeren in een pipeline die de core dumps automatisch kon analyseren.

We lieten ChatGPT een script schrijven dat een prefix van elk corebestand downloadde, de registers extraheerde, bekende fout-positieven met de logs wegfilterde en de crash automatisch labelde als return-to-null, misaligned-stack of other. Daarna draaiden we dat script parallel over elke productie-core dump van Rockset uit het voorgaande jaar.

Dit was het kantelpunt.

Zodra we een schone dataset hadden, werden correlaties meteen zichtbaar. Wat we als één vreemde bug behandelden, waren in werkelijkheid twee aparte crashpopulaties.

De return-to-null-cores waren verspreid over veel clusters en geografische regio’s. Hun frequentie was recent gestegen, maar er was geen scherpe startdatum en geen duidelijke infrastructuurgrens.

De misaligned-stack-crashes zagen er heel anders uit. Ze kwamen allemaal uit één regio, hadden een duidelijke startdatum en gebeurden nooit op knooppunten die al lang draaiden. Hoewel er meerdere Azure-VM’s (virtuele machines in de cloud) bij betrokken waren, leek het patroon op één fysieke machine met slechte hardware die problemen veroorzaakte voor elke VM die toevallig daarop terechtkwam.

Toen beseften we dat we twee bugs mentaal op één hoop hadden gegooid. Omdat we tegenvoorbeelden van beide bugs door elkaar haalden, konden we geen enkele samenhangende verklaring vinden.

Met een schone lijst van Kubernetes-knooppunten en timestamps konden we de crashes met verkeerd uitgelijnde stack terugleiden naar één fysieke host, die we eenvoudig konden denylisten.

We konden de registercorruptie op die host niet in een gecontroleerde omgeving reproduceren, zelfs niet na weken stresstesten. Maar zodra de problematische host buiten gebruik was gesteld, verdwenen de misaligned-stack-crashes.

De slechte host verwijderen is geen permanente oplossing, in de zin dat het een nieuw optreden van hetzelfde probleem niet voorkomt. We kunnen de software wel zo aanpassen dat een vergelijkbaar probleem, als het terugkomt, makkelijk wordt gedetecteerd en afgehandeld. We verbeterden onze fatal signal handler zodat die registerstatus opneemt, zodat we herhaling alleen uit de logs kunnen detecteren (geen core dump nodig). We wijzigden het control plane zodat VM’s meestal worden hergebruikt in plaats van gerecycled, wat bad-node-detectie op ons niveau van de infrastructuurstack veel eenvoudiger maakt. We werkten ook onze runbooks (en de mentale modellen van ons team) bij om deze mogelijkheid mee te nemen.

Met de bad-host-crashes apart gezet, waren de resterende return-to-null-cores veel makkelijker te doorgronden. Eerder hadden we exception unwinding uitgesloten omdat we dachten tegenvoorbeelden te hebben: crashes in codepaden waar beslist geen exceptions werden gebruikt. Maar die tegenvoorbeelden kwamen allemaal uit het cluster met hardwarecorruptie.

Toen we de resterende cores met dat in gedachten opnieuw bekeken, bleek die conclusie precies omgekeerd: alle crashes gebeurden tijdens exception unwinding.

Wanneer C++ een exception gooit, moet de runtime ontdekken welk catch block die moet ontvangen en welke destructors of cleanup handlers onderweg moeten draaien. De compiler emitteert deze metadata, maar de daadwerkelijke matching gebeurt dynamisch tijdens runtime.

Exception unwinding wordt niet uitgevoerd door de functie die throw aanroept, maar door helperfuncties die door de resulterende gecompileerde code worden aangeroepen. Die runtime-routines onderzoeken de stack, halen metadata op over de functies op de stack, zoeken dynamisch naar cleanup handlers en catch blocks, en dragen dan de controle over aan een van die locaties. De controle overdragen omvat het unwinden van alle tussenliggende stackframes (ook die van de helperfuncties).

Operationeel lijkt dit veel meer op een longjmp of een fiber switch dan op een normale call en return. Callee-save-registers moeten worden hersteld, net als de stackframeregisters %rbp en %rsp.

Onze binary linkt tegen twee bibliotheken met implementaties van de functies die C++ exception unwinding uitvoeren: libgcc en GNU libunwind. De definities van GNU libunwind waren de definities die de dynamic linker koos. Dat verraste ons; we hadden verwacht dat de libgcc-implementatie zou winnen vanwege regels voor symbol versioning, maar inspectie van draaiende binaries liet zien dat dit niet zo was.

Op dit punt veranderde onze werkhypothese, doordat we nog een aanname loslieten die we hadden gedaan toen we dachten dat er maar één bug was.

Misschien zagen we geen gewone functie die naar NULL terugkeerde. Misschien zagen we een unwind-overdracht: in feite een registerherstel in setcontext-stijl, waarbij de doel-instruction pointer NULL was geworden voordat de controle werd overgedragen. Met andere woorden: onjuiste data uit de unwindbibliotheek, niet een onjuiste return-address-slot op de stack.

Dat vernauwde het probleem drastisch. Of GNU libunwind berekende de verkeerde doelstaat, of het berekende de juiste staat en iets corrumpeerde die voordat hij kon worden toegepast.

We lazen de broncode van GNU libunwind en zagen dat die een ucontext_t op de stack synthetiseert, de gewenste registerstaat voor het frame van de cleanup handler invult en vervolgens een pointer naar die struct doorgeeft aan een interne assemblyroutine: _Ux86_64_setcontext.

Op dit punt hadden we alle stukjes.

De gesynthetiseerde ucontext_t leeft in een van de stackframes die tijdens de uitvoering van _Ux86_64_setcontext door die functie worden unwind. Las _Ux86_64_setcontext uit de struct nadat het %rsp had gewijzigd, op het moment dat de struct niet langer deel uitmaakte van de actieve stack? Dat zou hem kwetsbaar maken voor overschrijving door signal delivery, zoals onze frequente SIGUSR2.

Het antwoord was ja.

Hier zijn de laatste zes instructies van _Ux86_64_setcontext in de versie van GNU libunwind die wij gebruikten; ze bestaan vooral uit mov-instructies die uit geheugen naar een doelregister laden:

(%rdi wijst naar de op de stack gealloceerde ucontext_t, en de macro’s UC_MCONTEXT_* expanderen gewoon naar de vaste offset waarop een bepaald register is opgeslagen.)

De eerste instructie is het begin van het race window. Die werkt %rsp bij zodat het naar de nieuwe bodem van de actieve stack wijst. Zodra dit gebeurt, is de struct waar %rdi naar wijst geen deel meer van de actieve stack (of red zone), en is hij niet langer verboden terrein voor de kernel.

Meestal geeft dat geen problemen, maar als een signaal precies op het juiste (verkeerde?) moment aankomt, bouwt de kernel het signal frame op %rsp-128. Dat kan het geheugen overschrijven waar %rdi naar wijst.

Als dat gebeurt voordat de volgende instructie UC_MCONTEXT_GREGS_RIP(%rdi) leest, kan de herstelde instruction pointer corrupt raken. In onze crashes werd die NULL.

Dat is de bug.

Deze assembly verklaart ook een van de observaties die ons verwarden: waarom functie X een NULL had in de return-address-slot van het vorige stackframe.

setcontext was geschreven om alle registers te herstellen, inclusief %rdi, en kan dat register op het laatste moment van de controloverdracht dus niet gebruiken om UC_MCONTEXT_GREGS_RIP(%rdi) te lezen. In plaats daarvan leest het de waarde eerder, bewaart die op de stack, herstelt nog een paar registers en gebruikt dan retq om de opgeslagen waarde te lezen en de controle over te dragen.

Wat er in de cores uitzag als “een functie keerde terug naar NULL” was eigenlijk “de unwinder synthetiseerde een doel-return-adres op de stack, maar dat doel was corrupt geraakt voordat de overdracht klaar was.” We hadden aangenomen dat corruptie van de return-address-slot ter plekke moest gebeuren, omdat we geen plekken kenden waar (corrumpeerbare) data bewust naar de return-address-slot werd geschreven.

Wat deze bug absurd doet lijken, is hoe smal dit race window is. Bij dit soort race condition moet de externe gebeurtenis (het signaal) precies tussen twee stappen van een andere thread plaatsvinden. Hoe dichter die stappen bij elkaar liggen, hoe kleiner de kans dat de race condition optreedt.

In dit geval is het kwetsbare venster letterlijk één instructie breed! Een signaal moet worden afgeleverd nadat %rsp is gewijzigd, maar voordat de volgende instructie %rip laadt. Op een moderne superscalaire out-of-order CPU kunnen meerdere eenvoudige instructies als deze per cyclus draaien, dus het race window is ongeveer honderd picoseconden.

Toen we deze race vonden, dachten we eerst dat hij te zeldzaam moest zijn om het waargenomen crashpercentage te verklaren. We zagen over de fleet meer dan een dozijn return-to-null-crashes per dag. Kon een race van één instructie tijdens exception cleanup dat echt verklaren?

We grepen naar een Fermat-schatting. Als het kwetsbare venster in de orde van $10^{-10}$ seconden ligt en SIGUSR2 elke $10^{-2}$ seconden CPU-tijd arriveert, dan heeft elke exception cleanup handler of catch block grofweg $10^{-8}$ kans om de race te verliezen.

Rockset gebruikt exceptions als onderdeel van zijn interne backpressuremechanisme voor ingest. Eén overbelaste host kan in de orde van $10^{4}$ exceptions per seconde gooien. Dat impliceert dat de gemiddelde tijd tussen failures voor een host die backpressure gebruikt $10^{4}$ seconden is, oftewel één crash om de paar uur. Op fleetschaal is dat ruim genoeg om de waargenomen crashfrequentie te verklaren.

De GNU libunwind-bug is oud: meer dan 18 jaar, aanwezig in de eerste x86_64-versie die C++ exception unwinding ondersteunde.

Waarom dook hij dan nu op?

Het crashpercentage is grofweg evenredig met hoeveel exceptions worden gegooid en hoeveel signalen worden afgeleverd. Het hangt ook af van hoeveel stack de signal handler verbruikt.

Rockset is op alle drie assen ongebruikelijk. We gooien exceptions met hoge frequentie als onderdeel van normale overbelastingscontrole; door coarse_thread_cputime_clock leveren we SIGUSR2 ongewoon vaak af; en eerder dit jaar lieten we de SIGUSR2-handler meer stack gebruiken door een call naar timer_getoverrun toe te voegen, zodat we samengevoegde signalen konden meetellen.

Die laatste wijziging lijkt belangrijk te zijn geweest. Als de handler weinig genoeg stack gebruikt, bereikt en overschrijft hij het oude ucontext_t-geheugen mogelijk niet. Vóór die wijziging zien we deze crashes helemaal niet. Na de wijziging bleef het percentage laag totdat we de load opvoerden voor enkele use cases die het backpressuremechanisme zwaar belastten.

Anders gezegd: de libunwind-bug was er altijd al, maar het product van onze exceptionfrequentie, signaalfrequentie en stackgebruik van de handler had pas recent de drempel overschreden waarop hij operationeel zichtbaar werd.

Dit mechanisme verklaart ook het toeval dat zowel de hardwarebug als de libunwind-bug vooral binnen DocumentTree::updateDocument crashten. Crashes door libunwind waren sterk richting deze methode vertekend, omdat die altijd actief is op het punt waarop we een exception gooien om ingest-backpressure toe te passen. Hij werd ook sterk geselecteerd voor de crashes met verkeerd uitgelijnde %rsp, omdat het slechte hardwareknooppunt een SKU had die we gebruiken voor bulk-ingest en het grootste deel van zijn CPU-tijd in die methode doorbrengt.

Onze directe mitigatie was overstappen van GNU libunwind naar de unwinder van libgcc. Dat was op zichzelf een goede afweging: de implementatie van libgcc heeft geprofiteerd van veel werk om lock contention te verminderen, wat belangrijk is bij opschalen naar grote VM’s.

We hebben ook een op zichzelf staande reproducer en een fix⁠(opent in een nieuw venster) upstream naar GNU libunwind gestuurd, en gecontroleerd dat de andere unwinders geen vergelijkbaar probleem hebben.

Deze debugreis leerde ons veel over de details van dynamic linking, DWARF-unwindmetadata, Linux signal delivery, de System V ABI en de C++ exception-machinerie. Maar de belangrijkste les was eenvoudiger dan dat alles.

De belangrijkste stap was niet het slimme lezen van assembly of diepe kennis van de details. Het was het bouwen van een hoogwaardige dataset. Zonder die dataset voegden we twee verschillende fenomenen samen tot één verhaal en probeerden we ons uit de verwarring te redeneren. Toen we nauwkeurige en volledige populatiedata hadden, werd de structuur van het probleem duidelijk: de ene crashpopulatie hoorde bij een slechte host, de andere bij een race in libunwind. Toen de data beter werd, werd het debuggen makkelijker.

Voor infrastructuursystemen zoals Rockset doet dat er veel toe. Dit onderzoek versterkte onze inzet voor diepe instrumentatie, geautomatiseerd onderzoek en voortdurende verbetering van onze operationele tooling. Betrouwbaarheid gaat niet alleen om bugs oplossen nadat ze optreden; het gaat om het bouwen van de data, workflows en vaardigheden die onmogelijke problemen diagnosticeerbaar en oplosbaar maken.