Core dump-epidemiologi: fikse en 18 år gammel feil

OpenAIs modeller og agenter er i økende grad avhengige av skalerbar datainfrastruktur for å søke etter relevante data under inferens: når modellene tenker gjennom spørsmålet ditt. Noen av disse tjenestene er skrevet i C++, der kontroll på lavt nivå over systemet lar oss maksimere ytelsen og minimere minnebruken. Disse effektivitetsgevinstene er viktige når vi skalerer, men C++ mangler minnesikkerhet, noe som betyr at feil kan føre til krasj ved å skrive til feil eller ikke-eksisterende minneadresser.

For noen måneder siden observerte vi krasj inne fra Rockset-tjenesten, en spesialtilpasset del av datainfrastrukturen vår for ChatGPT som er sentral for mange dataprogramtillegg og for søk i samtaler. I hvert av disse krasjene så det ut som om en vanlig C++-funksjon fullførte og deretter returnerte til en ugyldig adresse, slik at kjernen stoppet programmet fordi instruksjonspekeren ikke lenger pekte på kode. Noen ganger var returadressesporet i stack frame NULL. Noen ganger så det ut som CPU-registeret for stackpekeren selv var forskjøvet med 8 byte, som om %rsp på en eller annen måte var blitt dekrementert midt under normal kjøring. I begge tilfeller skjedde krasjet ved retur.

Dette er ikke normale feilmåter for applikasjonskode. En villfaren skriving som bare treffer en lagret returadresse er mulig, men ekstremt usannsynlig. En feil som feiljusterer %rsp med 8 uten å involvere inline-assembly, setcontext eller longjmp (ingen av dem bruker vi), er enda merkeligere, fordi kompilert kode bare justerer dette registeret direkte i funksjonens prolog og epilog. Alle hypotesene vi (eller ChatGPT) kunne komme på, hadde sterke bevis mot seg, så feilen virket umulig.

Det vi antok var ett problem, viste seg til slutt å være to urelaterte feil som tilfeldigvis ble oppdaget samtidig. Først stille maskinvarekorrupsjon på én Azure-vert, der CPU-en rett og slett ikke regnet riktig. Deretter en 18 år gammel race condition i GNU libunwind, en uoppdaget feil i et mye brukt åpen kildekode-bibliotek.

Dette innlegget er historien om hvordan vi identifiserte og fikset tilsynelatende uforklarlige krasj ved å tenke som en epidemiolog og bygge et datasett av høy kvalitet om hele krasjpopulasjonen.

La oss først gå dypere inn i Rockset. Det er et nettskybasert datasystem for søk og sanntidsanalyse som vi bruker til mange interne formål i OpenAI, for eksempel synkroniseringskoblinger (Rockset ble kjøpt opp av OpenAI i 2024). Strømmende oppdateringer brukes til å holde en oppdatert indeks over kunnskapsbasen til et arbeidsområde, slik at ChatGPT kan søke etter relevant informasjon når den svarer på spørsmål eller utfører handlinger.

Rocksets utførelseslag er skrevet i C++. C++-språket gir lavnivåtilgang til CPU-en, noe som er bra for ytelse og effektivitet, men det betyr at applikasjonsfeil kan føre til ugyldige minnetilganger og segfaults. For å spore opp slike feil bruker vi follys fatale signalhåndterer til å logge en stack trace når et krasj skjer, og vi laster opp de tilhørende core dumpene (et øyeblikksbilde av programmets tilstand da det krasjet) til Azure Blob Storage for senere analyse. Alle Rocksets blader for spørringsbehandling er replikert, noe som minimerer klientpåvirkningen av et krasj. Hver segfault tilsvarer likevel en feil som må fikses for at vi skal nå målene våre for pålitelighet og kvalitet.

Den første tilnærmingen vår var å behandle disse core dumpene som et vanlig feilsøkingsproblem: inspisere noen få core dumps svært nøye, danne hypoteser og utelukke dem én etter én.

De fleste krasjene skjedde i en metode kalt DocumentTree::updateDocument. I disse krasjene så det ut som om updateDocument hadde kalt en ukjent funksjon X, at stacken var blitt korrupt mens X var aktiv, og at X deretter hadde returnert til en adresse som ikke var kjørbar kode. I noen tilfeller så den nettopp poppede rammen til X gyldig ut, bortsett fra at den lagrede returadressen var NULL. I andre tilfeller så selve stackpekeren feil ut, men den neste gyldige rammen så fortsatt ut til å være updateDocument.

Vi visste ikke når stacken ble korrupt, noe som ga et enormt søkeområde. updateDocument er en stor metode med mye inlining, så antallet kandidater til X var overveldende.

Var dette en feil i C++-koden vår? Et kompilator- eller lenkeproblem? Et problem i et av runtime-bibliotekene våre? En feil i Linux-kjernen knyttet til signallevering eller kontekstbytte? Noe enda mer sjeldent? Hvis dette var en villfaren skriving, hvorfor ble den ikke fanget opp av ASAN-stagingmiljøet vårt?

Vi prøvde å bruke loggene våre på applikasjonsnivå til å identifisere alle forekomster av problemet, men stack-korrupsjonsfeil er vanskelige å klassifisere bare fra logger, fordi de loggede stack tracene selv er korrupte eller mangler. Vi klarte ikke å lage en loggspørring som ikke hadde både falske positiver og falske negativer. Vi inspiserte flere core dumps manuelt og fant noen flere eksempler, men prosessen var for arbeidskrevende til å gi oss et pålitelig datasett.

På dette stadiet i undersøkelsen utelukket vi (feilaktig) en maskinvarefeil, fordi vi så krasj i flere regioner og på flere maskinvaretyper, så vi lette fortsatt etter rene programvareårsaker. I noen dager gikk vi svært dypt inn i ett enkelt krasj med feiljustert %rsp, der vi rekonstruerte historikken før krasjet ved hjelp av innholdet i stacken og registrene. Det ga noen mulige spor, men fordi vi ikke slapp den opprinnelige konklusjonen om at alle feilene hadde samme årsak, kom vi ikke videre.

Før vi kommer til vendepunktet i undersøkelsen, er det viktig å forklare hva slags informasjon vi hentet ut fra core-filene.

Rockset kompileres med -fno-omit-frame-pointer, så den aktive stackrammen er alltid tilgjengelig via %rbp, og kallere danner en lenket liste med frame pointers.

På Linux x86_64 reserverer AMD64 System V ABI også 128 byte under %rsp som red zone. Dette området er tilgjengelig for userspace-kode, og viktigst: kjernen lover å ikke overskrive det når den leverer et signal, som en del av ABI-kontrakten.

Red zone var sentral i feilsøkingen vår av et krasj etter retur, fordi den bevarer noe informasjon fra før returen. Når et SIGSEGV utløses, kjører follys fatale signalhåndterer på stacken til tråden som krasjer. Stackrammer som ikke lenger er aktive (fordi funksjonen deres har returnert), blir overskrevet av signalhåndtereren, bortsett fra de siste 128 bytene. Derfor kan vi si ting som «X sin nettopp poppede stackramme så gyldig ut, bortsett fra en NULL-returadresse.» Red zone bevarer deler av de inaktive rammene, eller noen ganger bare halen av én inaktiv ramme.

Vi fant ett krasj med feiljustert stack der alle involverte funksjoner var svært små. Det gjorde at vi kunne se at %rsp var blitt feiljustert under kjøring av en relativt enkel funksjon, og at flere kall hadde lyktes etterpå. Programmet krasjet først da den aktive funksjonen til slutt prøvde å returnere. Ingen av disse kodebanene brukte unntak, inline-assembly, setcontext eller longjmp, så hvis stackpekeren virkelig endret seg slik core dumpen antydet, fantes det ingen plausibel feil i userspace-kode som forklarte problemet.

Det pekte oss mot kjernen.

Rockset bruker signaler mer aggressivt enn de fleste programmer. Spørringskjøring deles opp i mange lette oppgaver som utveksler data. Dette er viktig for å håndtere arbeidslaster med høy QPS effektivt, men det gjør CPU-regnskap per spørring vanskelig, siden arbeid for mange spørringer multiplekses på samme trådpool.

Løsningen vår er noe vi kaller coarse_thread_cputime_clock, som tilnærmer clock_gettime(CLOCK_THREAD_CPUTIME_ID, ...) billig nok til å sample ved hver oppgavegrense. API-et timer_create kan brukes til å planlegge periodisk signallevering basert på flere måter å måle tidens gang på, inkludert akkumulering av CPU-tid. Vi planlegger at et signal (SIGUSR2) skal leveres med noen få millisekunders mellomrom i CPU-tid, og da oppdaterer signalhåndtereren en trådlokal verdi. Selv om mange oppgaver ikke ser at den grove klokken går fremover mens de kjører, gir summen av alle deltaene et forventningsrett estimat av den faktiske CPU-tiden for en spørring.

Fordi vi leverer signaler så ofte, virket en sjelden kjernefeil knyttet til kontekstbytte eller signallevering plausibel. Vi brukte tid på å lese feilrapporter, kildekode for kjernen og Azure-spesifikke kjernepatcher. Vi prøvde stresstester. Vi klarte ikke å finne noe som virket relevant.

På det tidspunktet bestemte vi oss for å ta et skritt tilbake og prøve en annen tilnærming.

Det finnes to hovedmåter å feilsøke et problem som dette på.

Den ene er å opptre som en slags lege: fokusere på én pasient, kjøre mange tester og prøve å diagnostisere ett enkelt tilfelle ut fra detaljerte bevis.

Den andre er å opptre mer som en epidemiolog: se på hele populasjonen og spørre om det finnes mønstre som ett enkelt tilfelle ikke kan avsløre. Startet feilen i en bestemt release? Korrelerer den med én maskinvare-SKU (den konkrete CPU- og servermodellen), én region eller én kjerneversjon? Skjuler det seg flere distinkte klynger inni det som ser ut som ett syndrom?

Vi hadde stort sett vært i legemodus. Det avgjørende skiftet var å bestemme at vi måtte samle populasjonsdata av høy kvalitet.

De tidligere forsøkene våre på å finne alle forekomster av problemet automatisk mislyktes fordi vi prøvde å bruke tekstsøk i loggene. Core dumpene selv inneholder mye mer informasjon, men manuell gjennomgang av dem skalerte ikke. Vi bestemte oss for å legge inn innsatsen som trengtes for å bygge en pipeline som automatisk kunne analysere core dumpene.

Vi fikk ChatGPT til å skrive et skript som lastet ned et prefiks av hver core-fil, hentet ut registrene, filtrerte kjente falske positiver ved hjelp av loggene og automatisk merket krasjet som return-to-null, misaligned-stack eller annet. Deretter kjørte vi skriptet parallelt over alle Rockset-core dumps i produksjon fra året før.

Dette var vendepunktet.

Da vi hadde et rent datasett, dukket korrelasjonene opp umiddelbart. Det vi hadde behandlet som én merkelig feil, var egentlig to separate krasjpopulasjoner.

Return-to-null-core dumpene var spredt over mange klynger og geografiske regioner. Hyppigheten hadde økt i det siste, men det fantes ingen tydelig startdato og ingen klar infrastrukturgrense.

Krasjene med feiljustert stack så helt annerledes ut. Alle kom fra én region, hadde en tydelig startdato og skjedde aldri på noder som hadde kjørt lenge. Selv om de involverte flere Azure-VM-er (virtuelle maskiner i skyen), så mønsteret ut som én fysisk maskin med dårlig maskinvare som skapte problemer for den VM-en som tilfeldigvis havnet på den.

Det var øyeblikket da vi innså at vi mentalt hadde blandet sammen to feil. Fordi vi hadde blandet moteksempler fra begge feilene, klarte vi ikke å finne én sammenhengende forklaring.

Med en ryddig liste over Kubernetes-noder og tidsstempler kunne vi spore krasjene med feiljustert stack tilbake til én fysisk vert, som var enkel å blokkere.

Vi klarte ikke å reprodusere registerkorrupsjonen på den verten i et kontrollert miljø, selv etter flere uker med stresstesting. Da den problematiske verten ble tatt ut av drift, forsvant imidlertid krasjene med feiljustert stack.

Å fjerne den dårlige verten er ikke en permanent løsning, i den forstand at det ikke hindrer at samme problem oppstår på nytt. Vi kan imidlertid endre programvaren slik at et lignende problem lett oppdages og håndteres hvis det skjer igjen. Vi forbedret den fatale signalhåndtereren vår til å inkludere registertilstand, slik at vi kan oppdage tilbakefall bare fra loggene (ingen core dump nødvendig). Vi endret kontrollplanet slik at VM-er vanligvis gjenbrukes i stedet for å resirkuleres, noe som gjør det mye enklere å oppdage dårlige noder på vårt nivå i infrastrukturstakken. Vi oppdaterte også runbookene våre (og teamets mentale modeller) for å inkludere denne muligheten.

Da krasjene fra den dårlige verten var skilt ut, ble det mye enklere å resonnere om de gjenværende return-to-null-core dumpene. Tidligere hadde vi utelukket exception unwinding fordi vi trodde vi hadde moteksempler: krasj i kodebaner der unntak definitivt ikke ble brukt. Men disse moteksemplene kom alle fra klyngen med maskinvarekorrupsjon.

Da vi gikk gjennom de gjenværende core dumpene på nytt med dette i bakhodet, fant vi at konklusjonen var nøyaktig motsatt: krasjene skjedde alle under exception unwinding.

Når C++ kaster et unntak, må runtime finne ut hvilken catch-blokk som skal motta det, og hvilke destruktører eller oppryddingshåndterere som skal kjøres underveis. Kompilatoren genererer disse metadataene, men selve matchingen skjer dynamisk ved kjøring.

Exception unwinding utføres egentlig ikke av funksjonen som kaller throw, men av hjelpefunksjoner som kalles av den resulterende kompilerte koden. Disse runtime-rutinene undersøker stacken, henter metadata om funksjonene som finnes på stacken, leter dynamisk etter oppryddingshåndterere og catch-blokker, og overfører deretter kontrollen til ett av disse stedene. Å overføre kontroll innebærer å unwinde alle mellomliggende stackrammer (inkludert dem som tilhører hjelpefunksjonene).

Operasjonelt ligner dette mye mer på en longjmp eller et fiberbytte enn på et vanlig kall og retur. Callee-save-registre må gjenopprettes, i tillegg til stackrammeregistrene %rbp og %rsp.

Binærfilen vår lenker mot to biblioteker som inneholder implementasjoner av funksjonene som utfører C++ exception unwinding: libgcc og GNU libunwind. GNU libunwinds definisjoner var dem den dynamiske lenkeren valgte. Det overrasket oss; vi hadde ventet at libgcc-implementasjonen skulle vinne på grunn av reglene for symbolversjonering, men inspeksjon av kjørende binærfiler viste at det ikke var tilfelle.

På dette tidspunktet endret arbeidshypotesen vår seg, da vi slapp enda en antakelse vi hadde gjort da vi trodde det bare fantes én feil.

Kanskje vi ikke så en vanlig funksjon returnere til NULL. Kanskje vi så en unwind-overføring – i praksis en registergjenoppretting i setcontext-stil – der målinstruksjonspekeren var blitt NULL før kontrollen ble overført. Med andre ord feil data fra unwind-biblioteket, snarere enn et feil returadressspor på stacken.

Det snevret inn problemet dramatisk. Enten beregnet GNU libunwind feil måltilstand, eller så beregnet det riktig tilstand og noe korrumperte den før den kunne tas i bruk.

Vi leste kildekoden til GNU libunwind og fant at den syntetiserer en ucontext_t på stacken, fyller inn ønsket registertilstand for rammen til oppryddingshåndtereren og gir deretter en peker til denne structen til en intern assembly-rutine: _Ux86_64_setcontext.

På dette tidspunktet hadde vi alle brikkene.

Den syntetiserte ucontext_t ligger i en av stackrammene som unwindes av _Ux86_64_setcontext mens denne funksjonen kjører. Leste _Ux86_64_setcontext fra structen etter at den endret %rsp, på et tidspunkt da structen ikke lenger var en del av den aktive stacken? Det ville gjøre den sårbar for å bli overskrevet av en signallevering, for eksempel våre hyppige SIGUSR2.

Svaret var ja.

Her er de siste seks instruksjonene i _Ux86_64_setcontext i versjonen av GNU libunwind vi brukte, som hovedsakelig består av mov-instruksjoner som laster fra minne til et målregister:

(%rdi peker på den stack-allokerte ucontext_t, og makroene UC_MCONTEXT_* ekspanderer bare til den faste offseten der et bestemt register lagres.)

Den første instruksjonen er begynnelsen på race windowet. Den oppdaterer %rsp slik at den peker på den nye bunnen av den aktive stacken. Så snart dette skjer, er structen som %rdi peker på, ikke lenger en del av den aktive stacken (eller red zone), og den er ikke lenger forbudt område for kjernen.

Vanligvis skaper ikke dette problemer, men hvis et signal ankommer i akkurat riktig (feil?) øyeblikk, bygger kjernen signalrammen ved %rsp-128. Det kan overskrive minnet som %rdi peker på.

Hvis det skjer før neste instruksjon leser UC_MCONTEXT_GREGS_RIP(%rdi), kan den gjenopprettede instruksjonspekeren bli korrupt. I krasjene våre ble den NULL.

Det er feilen.

Denne assembly-koden forklarer også en av observasjonene som forvirret oss: hvorfor funksjon X hadde NULL i returadressesporet i den foregående stackrammen.

setcontext ble skrevet for å gjenopprette alle registre, inkludert %rdi, så den kan ikke bruke dette registeret til å lese UC_MCONTEXT_GREGS_RIP(%rdi) i kontrolloverføringens siste øyeblikk. I stedet leser den verdien tidligere, lagrer den på stacken, gjenoppretter noen flere registre og bruker deretter retq til å lese den lagrede verdien og overføre kontrollen.

Det som i core dumpene så ut som «en funksjon returnerte til NULL», var egentlig «unwinderen syntetiserte en målreturadresse på stacken, men dette målet var blitt korrupt før overføringen ble fullført». Vi hadde antatt at korrupsjon av returadressesporet måtte skje på stedet, fordi vi ikke kjente til noen steder der (korrumperbare) data med vilje ble skrevet til returadressesporet.

Det som får denne feilen til å virke absurd, er hvor smalt dette race windowet er. I denne typen race condition må den eksterne hendelsen (signalet) skje mellom to steg som tas av en annen tråd. Jo nærmere disse stegene ligger hverandre, desto mindre sannsynlig er det at race conditionen oppstår.

I dette tilfellet er det sårbare vinduet bokstavelig talt bare én instruksjon bredt! Et signal må leveres etter at %rsp er endret, men før neste instruksjon laster %rip. Flere enkle instruksjoner som dette kan kjøres per syklus på en moderne superskalær out-of-order-CPU, så race windowet er omtrent hundre pikosekunder.

Da vi fant denne racen, var den første reaksjonen vår at den måtte være for sjelden til å forklare den observerte krasjraten. Vi så mer enn et dusin return-to-null-krasj per dag på tvers av flåten. Kunne en race på én instruksjon under opprydding etter unntak virkelig forklare det?

Vi vendte oss til Fermat-estimering. Hvis det sårbare vinduet er i størrelsesorden $10^{-10}$ sekunder og SIGUSR2 ankommer hver $10^{-2}$ sekunder med CPU-tid, har hver oppryddingshåndterer eller catch-blokk for unntak omtrent $10^{-8}$ sannsynlighet for å tape racen.

Rockset bruker unntak som en del av sin interne mekanisme for ingest-backpressure. Én enkelt overbelastet vert kan kaste i størrelsesorden $10^{4}$ unntak per sekund. Det innebærer at gjennomsnittstiden mellom feil for en vert som bruker backpressure, er $10^{4}$ sekunder, eller ett krasj med noen timers mellomrom. På flåtenivå er det mer enn nok til å forklare den observerte krasjfrekvensen.

GNU libunwind-feilen er gammel – mer enn 18 år gammel, til stede i den første x86_64-versjonen som støttet C++ exception unwinding.

Så hvorfor dukket den opp nå?

Krasjraten er omtrent proporsjonal med hvor mange unntak som kastes, og hvor mange signaler som leveres. Den avhenger også av hvor mye stack signalhåndtereren bruker.

Rockset er uvanlig på alle tre aksene. Vi kaster unntak med høy frekvens som del av normal overbelastningskontroll; vi leverer SIGUSR2 uvanlig ofte på grunn av coarse_thread_cputime_clock; og tidligere i år fikk vi SIGUSR2-håndtereren til å bruke mer stack ved å legge til et kall til timer_getoverrun, slik at vi kunne ta høyde for sammenslåtte signaler.

Den siste endringen ser ut til å ha vært viktig. Hvis håndtereren bruker lite nok stack, kan det hende den ikke når og overskriver det gamle ucontext_t-minnet. Før den endringen observerer vi ikke disse krasjene i det hele tatt. Etter endringen forble raten lav til vi trappet opp last for noen bruksområder som presset backpressure-mekanismen.

Med andre ord har libunwind-feilen alltid vært der, men produktet av unntaksraten, signalraten og håndtererens stackbruk hadde først nylig krysset terskelen der den ble synlig operasjonelt.

Denne mekanismen forklarer også sammentreffet med at både maskinvarefeilen og libunwind-feilen stort sett krasjet inne i DocumentTree::updateDocument. Krasj fra libunwind var sterkt skjevt fordelt mot denne metoden, fordi den alltid er aktiv idet vi kaster et unntak for å bruke ingest-backpressure. Den var også sterkt overrepresentert i krasjene med feiljustert %rsp, fordi den dårlige maskinvare-noden var av en SKU vi bruker til bulk-ingest, som bruker mesteparten av CPU-tiden sin i den metoden.

Det umiddelbare avbøtende tiltaket vårt var å bytte fra GNU libunwind til libgccs unwinder. Det var en god avveining i seg selv: libgccs implementasjon har dratt nytte av mye arbeid for å redusere låsekonflikter, noe som er viktig ved skalering til store VM-er.

Vi oppstrømmet også en selvstendig reproduksjon og en fiks⁠(åpnes i et nytt vindu) til GNU libunwind, og bekreftet at de andre unwinderne ikke har et lignende problem.

Denne feilsøkingsreisen lærte oss mye om de konkrete detaljene i dynamisk lenking, DWARF-unwind-metadata, Linux-signallevering, System V ABI og C++-unntaksmekanismen. Men hovedlærdommen var enklere enn alt dette.

Det viktigste steget var ikke smart lesing av assembly eller dyp detaljkunnskap. Det var å bygge et datasett av høy kvalitet. Uten dette datasettet blandet vi to ulike fenomener inn i én historie og prøvde å resonnere oss ut av forvirringen. Da vi hadde nøyaktige og komplette populasjonsdata, ble problemets struktur åpenbar: én krasjpopulasjon tilhørte en dårlig vert, og den andre tilhørte en race i libunwind. Da dataene ble bedre, ble feilsøkingen enklere.

For infrastruktursystemer som Rockset betyr det mye. Denne undersøkelsen styrket forpliktelsen vår til dyp instrumentering, automatiserte undersøkelser og kontinuerlige forbedringer av de operative verktøyene våre. Pålitelighet handler ikke bare om å fikse feil etter at de oppstår – det handler om å bygge dataene, arbeidsflytene og ferdighetene som gjør umulige problemer diagnostiserbare og løsbare.