Core dump’i epidemioloogia: 18 aasta vanuse vea parandus

OpenAI mudelid ja agendid toetuvad üha enam skaleeritavale andmetaristule, et leida järeldamise ajal – kui mudelid teie küsimuse üle mõtlevad – asjakohaseid andmeid. Osa neist teenustest on kirjutatud C++-is, mille madalatasemeline kontroll süsteemi üle võimaldab maksimeerida jõudlust ja vähendada mälukasutust. Need tõhususe eelised on skaleerimisel olulised, kuid C++ mäluturbe puudumine tähendab, et vead võivad valele või olematule mäluaadressile kirjutades kokkujooksmisi põhjustada.

Mõni kuu tagasi nägime krahhe Rockseti teenuses – see on ChatGPT andmetaristu erilahendus, mis on tähtis paljude andmepluginate ja vestlustest otsimise jaoks. Igas krahhis näis tavaline C++ funktsioon lõppevat ja naasvat vigasele aadressile, mistõttu kernel peatas programmi, sest käsuosuti ei osutanud enam koodile. Mõnikord oli pinu kaadri tagastusaadressi pesa NULL. Mõnikord näis CPU pinuosuti register ise olevat 8 baiti nihkes, justkui oleks %rsp tavalise täitmise keskel kuidagi vähendatud. Mõlemal juhul toimus krahh naasmisel.

Need pole rakenduskoodi tavalised tõrkerežiimid. Hulkuv kirjutus, mis tabab ainult salvestatud tagastusaadressi, on võimalik, kuid äärmiselt ebatõenäoline. Viga, mis viib %rsp 8 baidi võrra paigast ilma inline-assembleri, setcontexti või longjmpita (me ei kasuta neist ühtegi), on veel kummalisem, sest kompileeritud kood muudab seda registrit otse ainult funktsiooni proloogis ja epiloogis. Igal hüpoteesil, mille peale meie (või ChatGPT) tulime, oli tugev vastutõend, seega tundus viga võimatu.

See, mida pidasime üheks probleemiks, osutus lõpuks kaheks seosetuks veaks, mis avastati juhuslikult samal ajal. Esiteks vaikne riistvararike ühes Azure’i hostis, kus CPU lihtsalt ei arvutanud õigesti. Teiseks 18 aasta vanune võidujooksu tingimus GNU libunwindis – märkamata jäänud viga laialt kasutatud avatud lähtekoodiga teegis.

See lugu räägib, kuidas tuvastasime ja parandasime näiliselt seletamatud krahhid, mõeldes epidemioloogina ning luues kvaliteetse andmestiku kogu krahhide populatsiooni kohta.

Kõigepealt vaatame Rockseti lähemalt. See on pilvepõhine andmesüsteem otsinguks ja reaalaja-analüütikaks, mida kasutame OpenAI-s paljudel sisemistel juhtudel, näiteks sünkroonimiskonnektorites (OpenAI omandas Rockseti 2024. aastal). Voogedastatud uuendustega hoitakse tööjaama teadmistebaasi indeks ajakohane, et ChatGPT saaks küsimustele vastates või toiminguid tehes asjakohast teavet otsida.

Rockseti täitmiskiht on kirjutatud C++-is. C++ annab madalatasemelise ligipääsu CPU-le, mis aitab jõudlust ja tõhusust, kuid tähendab, et rakenduse vead võivad viia vigaste mälupöörduste ja segfault’ideni. Nende leidmiseks kasutame folly fataalse signaali käsitlejat, mis logib krahhi korral pinujälje, ja laadime vastavad core dump’id (programmi oleku hetktõmmised krahhi ajal) hilisemaks analüüsiks Azure’i blob-salvestusse. Kõik Rockseti päringutöötluse lehed on replikeeritud, mis vähendab krahhi mõju kliendile. Iga segfault vastab siiski veale, mis tuleb meie töökindluse ja kvaliteedieesmärkide täitmiseks parandada.

Alguses käsitlesime neid core’e tavapärase silumisprobleemina: uurisime mõnda core dump’i väga põhjalikult, püstitasime hüpoteese ja välistasime neid ükshaaval.

Enamik krahhe toimus meetodis nimega DocumentTree::updateDocument. Neis krahhides näis, et updateDocument oli kutsunud tundmatu funktsiooni X, pinu riknes X-i töö ajal ja X naasis aadressile, mis polnud täidetav kood. Mõnel juhul paistis X-i äsja eemaldatud kaader kehtiv, välja arvatud see, et salvestatud tagastusaadress oli NULL. Muudel juhtudel näis pinuosuti ise vale, kuid järgmine kehtiv kaader paistis endiselt olevat updateDocument.

Me ei teadnud, millal pinu riknes, mis jättis tohutu otsinguruumi. updateDocument on suur meetod, mida inline’itakse palju, nii et X-i kandidaate oli üle jõu palju.

Kas see oli viga meie C++ koodis? Kompilaatori või linkimise probleem? Probleem mõnes käitusaja teegis? Linuxi kerneli viga signaalide edastuses või kontekstivahetuses? Midagi veel haruldasemat? Kui see oli hulkuv kirjutus, miks meie ASAN-i staging-keskkond seda ei tabanud?

Püüdsime probleemi kõiki esinemisi tuvastada rakendusetaseme logidega, kuid pinurikke vigu on ainult logide põhjal raske liigitada, sest logitud pinujäljed on ise rikutud või puuduvad. Me ei suutnud koostada logipäringut, milles poleks olnud nii valepositiivseid kui ka valenegatiivseid tulemusi. Uurisime käsitsi veel core’e ja leidsime lisanäiteid, kuid see oli liiga töömahukas, et anda usaldusväärne andmestik.

Selles uurimisjärgus välistasime (ekslikult) riistvaravea, sest nägime krahhe mitmes regioonis ja mitut tüüpi riistvaral, seega otsisime endiselt ainult tarkvaralisi põhjuseid. Mõne päeva süvenesime ühte valesti joondatud %rsp krahhi, taastades krahhieelse ajaloo pinu ja registrite sisu järgi. See andis võimalikke vihjeid, kuid kuna me ei loobunud algsest järeldusest, et kõigil vigadel on sama põhjus, ei aidanud see meid edasi.

Enne uurimise pöördepunkti on oluline selgitada, millist infot me core-failidest välja võtsime.

Rockset kompileeritakse võtmega -fno-omit-frame-pointer, seega on aktiivne pinukaader alati %rbp kaudu leitav ja kutsujad moodustavad kaadriviitade ahelloendi.

Linuxi x86_64-l reserveerib AMD64 System V ABI ka 128 baiti %rsp all punase tsoonina. See ala on kasutajaruumi koodile saadaval ja ABI lepingu osana lubab kernel signaali edastamisel seda mitte rikkuda.

Punane tsoon oli naasmisjärgse krahhi silumisel keskne, sest see säilitab osa infost naasmiseelsest ajast. Kui käivitub SIGSEGV, jookseb folly fataalse signaali käsitleja krahhiva lõime pinul. Pinukaadrid, mis pole enam aktiivsed (sest nende funktsioon on naasnud), kirjutab signaalikäsitleja üle, välja arvatud viimased 128 baiti. Seepärast saame öelda näiteks: „X-i äsja eemaldatud pinukaader paistis kehtiv, välja arvatud NULL tagastusaadress.“ Punane tsoon säilitab osa mitteaktiivsetest kaadritest või vahel ainult ühe kaadri lõpu.

Leidsime ühe valesti joondatud pinu krahhi, kus kõik seotud funktsioonid olid väga väikesed. See võimaldas näha, et %rsp läks paigast suhteliselt lihtsa funktsiooni täitmise ajal ja et pärast seda õnnestusid veel mõned kutsed. Programm jooksis kokku alles siis, kui aktiivne funktsioon lõpuks naasta üritas. Ükski neist kooditeedest ei kasutanud erindeid, inline-assemblerit, setcontexti ega longjmpi, seega kui pinuosuti muutus tõesti nii, nagu core näitas, ei selgitanud seda ükski usutav kasutajaruumi koodiviga.

See suunas meid kerneli poole.

Rockset kasutab signaale agressiivsemalt kui enamik programme. Päringu täitmine jagatakse paljudeks kergeteks ülesanneteks, mis vahetavad andmeid. See on oluline suure QPS-iga koormuste tõhusaks käsitlemiseks, kuid muudab päringupõhise CPU arvestuse kohmakaks, sest paljude päringute töö multipleksitakse samasse lõimepuuli.

Meie lahendus on coarse_thread_cputime_clock, mis lähendab clock_gettime(CLOCK_THREAD_CPUTIME_ID, ...) piisavalt odavalt, et proovida igal ülesandepiiril. API-t timer_create saab kasutada perioodilise signaali ajastamiseks mitme ajakulu mõiste järgi, sh kogunenud CPU aja põhjal. Ajastame signaali (SIGUSR2) edastamise iga mõne millisekundi CPU aja järel; siis uuendab signaalikäsitleja lõimekohalikku väärtust. Kuigi paljude ülesannete täitmise ajal jäme kell ei edene, annab kõigi deltade summa päringu tegeliku CPU aja nihketa hinnangu.

Kuna edastame signaale nii sageli, tundus haruldane kerneli viga kontekstivahetuses või signaaliedastuses usutav. Lugesime veateateid, kerneli lähtekoodi ja Azure’i-spetsiifilisi kerneliparandusi. Proovisime koormusteste. Me ei leidnud midagi, mis oleks seotuna tundunud.

Siis otsustasime sammu tagasi astuda ja proovida teist lähenemist.

Sellise probleemi silumiseks on kaks üldist viisi.

Üks on tegutseda nagu arst: keskenduda ühele patsiendile, teha palju teste ja proovida üksikjuhtu detailsete tõendite põhjal diagnoosida.

Teine on tegutseda rohkem epidemioloogina: vaadata kogu populatsiooni ja küsida, kas leidub mustreid, mida üksikjuht ei näita. Kas viga algas kindla väljalaskega? Kas see korreleerub ühe riistvara SKU-ga (konkreetne CPU ja serverimudel), ühe regiooni või ühe kerneli versiooniga? Kas näiliselt ühe sündroomi sees peitub mitu eraldi klastrit?

Olime enamasti olnud arsti režiimis. Murrang oli otsus koguda kvaliteetseid populatsiooniandmeid.

Varasemad katsed probleemi kõiki juhtumeid automaatselt leida nurjusid, sest püüdsime kasutada logides tekstiotsinguid. Core dump’ides endis on palju rohkem infot, kuid nende käsitsi läbivaatamine ei skaleerunud. Otsustasime panustada töövoo loomisse, mis suudaks core dump’e automaatselt analüüsida.

Lasime ChatGPT‑l kirjutada skripti, mis laadis alla iga core-faili prefiksi, eraldas registrid, filtreeris logide abil tuntud valepositiivid ja sildistas krahhi automaatselt kui return-to-null, valesti joondatud pinu või muu. Seejärel jooksutasime skripti paralleelselt üle kõigi eelmise aasta tootmiskeskkonna Rockseti core dump’ide.

See oli pöördepunkt.

Kui meil oli puhas andmestik, ilmusid korrelatsioonid kohe. See, mida olime pidanud üheks veidraks veaks, oli tegelikult kaks eraldi krahhipopulatsiooni.

Return-to-null core’id olid hajutatud paljudesse klastritesse ja geograafilistesse regioonidesse. Nende sagedus oli hiljuti kasvanud, kuid selget alguskuupäeva ega puhast taristupiiri polnud.

Valesti joondatud pinu krahhid nägid täiesti teistsugused välja. Need kõik tulid ühest regioonist, neil oli selge alguskuupäev ja neid ei juhtunud kunagi kaua töötanud sõlmpunktides. Kuigi need hõlmasid mitut Azure’i VM-i (pilves majutatud virtuaalmasinat), näis muster viitavat ühele vigase riistvaraga füüsilisele masinale, mis põhjustas probleeme sellele sattunud VM-ile.

Sel hetkel mõistsime, et olime kaks viga mõttes kokku sulatanud. Kuna segasime mõlema vea vastunäiteid, ei leidnud me ühtset sidusat seletust.

Puhas Kubernetes’i sõlmpunktide ja ajatemplite loend võimaldas meil viia valesti joondatud pinu krahhid ühe füüsilise hostini, mille sai hõlpsasti keeluloendisse panna.

Me ei suutnud selle hosti registririkkumist kontrollitud keskkonnas taasesitada isegi pärast mitmenädalast koormustestimist. Kui probleemne host kasutusest eemaldati, kadusid valesti joondatud pinu krahhid.

Vigase hosti eemaldamine pole püsilahendus selles mõttes, et see ei takista sama probleemi uut esinemist. Saame aga muuta tarkvara nii, et sarnase probleemi kordumisel oleks seda lihtne tuvastada ja käsitleda. Täiustasime fataalse signaali käsitlejat nii, et see sisaldaks registriseisu ja võimaldaks kordumist tuvastada ainult logidest (core dump’i pole vaja). Muutsime juhtimistasandit nii, et VM-e tavaliselt taaskasutatakse, mitte ei looda uuesti; see teeb vigase sõlmpunkti tuvastamise meie taristukihi tasemel palju lihtsamaks. Uuendasime ka oma runbook’e (ja tiimi mõttemudeleid), et see võimalus oleks neis olemas.

Kui vigase hosti krahhid olid eraldatud, muutusid ülejäänud return-to-null mälutõmmised palju arusaadavamaks. Varem olime erindite lahtikerimise välistanud, sest arvasime, et meil on vastunäited: krahhid kooditeedel, kus erindeid kindlasti ei kasutatud. Kuid need vastunäited pärinesid kõik riistvararikke klastrist.

Kui vaatasime ülejäänud mälutõmmised seda arvestades uuesti, selgus, et järeldus oli täpselt vastupidine: kõik krahhid toimusid erindite lahtikerimise ajal.

Kui C++ viskab erindi, peab runtime välja selgitama, milline catch-plokk selle vastu võtab ning millised destruktorid või koristuskäsitlejad teel käivitada. Kompilaator väljastab need metaandmed, kuid tegelik sobitamine toimub dünaamiliselt käitusajal.

Erindi lahtikerimist ei tee tegelikult throw’d käivitav funktsioon, vaid abifunktsioonid, mida kutsub sellest tekkinud kompileeritud kood. Need käitusaja rutiinid uurivad pinu, hangivad metaandmeid pinult leitud funktsioonide kohta, otsivad dünaamiliselt koristuskäsitlejaid ja catch-plokke ning annavad juhtimise ühte neist kohtadest. Juhtimise üleandmine hõlmab kõigi vahepealsete pinukaadrite lahtikerimist (sh abifunktsioonide omi).

Töö mõttes sarnaneb see palju rohkem longjmpi või fiber’i vahetusega kui tavalise kutse ja naasmisega. Taastada tuleb callee-save registrid ning pinukaadri registrid %rbp ja %rsp.

Meie binaar lingib kahe teegiga, mis sisaldavad C++ erindite lahtikerimise funktsioonide teostusi: libgcc ja GNU libunwind. Dünaamiline linker valis GNU libunwindi definitsioonid. See üllatas meid; ootasime, et sümboliversioonide reeglite tõttu võidab libgcc teostus, kuid töötavate binaaride uurimine näitas, et nii polnud.

Sel hetkel muutus meie tööhüpotees, kui lõdvendasime veel üht eeldust, mille olime teinud siis, kui arvasime, et vigu on ainult üks.

Võib-olla ei näinud me tavalise funktsiooni naasmist NULL-i. Võib-olla nägime unwind-ülekannet – sisuliselt setcontexti-laadset registrite taastamist –, kus sihtkäsuosuti oli enne juhtimise üleandmist muutunud NULL-iks. Teisisõnu vale data unwind-teegist, mitte vale tagastusaadressi pesa pinul.

See kitsendas probleemi järsult. Kas GNU libunwind arvutas vale sihtoleku või arvutas õige oleku ja miski rikkus selle enne rakendamist.

Lugesime GNU libunwindi lähtekoodi ja leidsime, et see sünteesib pinule ucontext_t, täidab koristuskäsitleja kaadri jaoks soovitud registriseisu ja annab selle struktuuri viida sisemisele assemblerirutiinile: _Ux86_64_setcontext.

Sel hetkel olid meil kõik tükid olemas.

Sünteesitud ucontext_t elab ühes pinukaadris, mille _Ux86_64_setcontext selle funktsiooni täitmise ajal lahti kerib. Kas _Ux86_64_setcontext luges struktuuri pärast %rsp muutmist, kui struktuur polnud enam aktiivse pinu osa? See teeks selle haavatavaks signaali edastuse, näiteks meie sagedase SIGUSR2, põhjustatud ülekirjutamisele.

Vastus oli jah.

Siin on GNU libunwindi kasutatud versiooni _Ux86_64_setcontexti viimased kuus käsku, peamiselt mov-käsud, mis laadivad mälust sihtregistrisse:

(%rdi osutab pinule eraldatud ucontext_t-le ja makrod UC_MCONTEXT_* laienevad lihtsalt fikseeritud nihkeks, kus konkreetne register on salvestatud.)

Esimene käsk on võidujooksu akna algus. See uuendab %rsp, et see osutaks aktiivse pinu uuele alumisele otsale. Kohe pärast seda pole struktuur, millele %rdi osutab, enam aktiivse pinu (ega punase tsooni) osa ja pole kerneli jaoks enam puutumatu.

Tavaliselt see probleeme ei tekita, kuid kui signaal saabub täpselt õigel (või valel?) hetkel, ehitab kernel signaalikaadri aadressile %rsp-128. See võib üle kirjutada mälu, millele %rdi osutab.

Kui see juhtub enne, kui järgmine käsk loeb UC_MCONTEXT_GREGS_RIP(%rdi), võib taastatud käsuosuti rikneda. Meie krahhides muutus see NULL-iks.

See ongi viga.

See assembler selgitab ka üht tähelepanekut, mis meid segadusse ajas: miks funktsioonil X oli eelmise pinukaadri tagastusaadressi pesas NULL.

setcontext kirjutati taastama kõiki registreid, sh %rdi, seega ei saa ta juhtimise ülekande viimasel hetkel kasutada seda registrit UC_MCONTEXT_GREGS_RIP(%rdi) lugemiseks. Selle asemel loeb ta väärtuse varem, salvestab selle pinule, taastab veel mõned registrid ja kasutab siis retq-d salvestatud väärtuse lugemiseks ning juhtimise üleandmiseks.

See, mis core’ides paistis kui „funktsioon naasis NULL-i“, oli tegelikult „unwinder sünteesis pinule siht-tagastusaadressi, kuid siht riknes enne ülekande lõppu“. Eeldasime, et tagastusaadressi pesa rikutakse kohapeal, sest me ei teadnud kohti, kus (rikutavaid) andmeid tagastusaadressi pessa meelega kirjutatakse.

Selle vea teeb absurdseks võidujooksu akna kitsus. Sellises võidujooksu tingimuses peab väline sündmus (signaal) juhtuma kahe sammu vahel, mida teeb teine lõim. Mida lähemal need sammud teineteisele on, seda ebatõenäolisem on võidujooksu tingimus.

Sel juhul on haavatav aken sõna otseses mõttes ühe käsu laiune! Signaal peab saabuma pärast seda, kui %rsp on muudetud, kuid enne kui järgmine käsk laadib %rip. Moodsal superskalaarsel out-of-order CPU-l saab tsükli kohta täita mitu sellist lihtsat käsku, seega on võidujooksu aken umbes sada pikosekundit.

Kui selle võidujooksu leidsime, oli esimene reaktsioon, et see peab olema liiga haruldane, et nähtud krahhimäära selgitada. Nägime kogu pargis üle tosina return-to-null krahhi päevas. Kas ühe käsu võidujooks erindite koristamisel võiks seda tõesti seletada?

Pöördusime Fermat’ hinnangu poole. Kui haavatav aken on suurusjärgus $10^{-10}$ sekundit ja SIGUSR2 saabub iga $10^{-2}$ CPU-sekundi järel, siis on igal erindi koristuskäsitlejal või catch-plokil umbes $10^{-8}$ tõenäosus võidujooks kaotada.

Rockset kasutab erindeid oma sisemise sissevõtu vastusurve mehhanismi osana. Üks ülekoormatud host võib visata suurusjärgus $10^{4}$ erindit sekundis. See tähendab, et vastusurvet kasutava hosti keskmine riketevaheline aeg on $10^{4}$ sekundit ehk üks krahh iga mõne tunni tagant. Kogu pargi mastaabis on sellest nähtud krahhisageduse selgitamiseks enam kui küllalt.

GNU libunwindi viga on vana – üle 18 aasta vana, olemas juba esimeses x86_64 versioonis, mis toetas C++ erindite lahtikerimist.

Miks see siis alles nüüd välja tuli?

Krahhimäär on ligikaudu võrdeline sellega, kui palju erindeid visatakse ja kui palju signaale edastatakse. See sõltub ka sellest, kui palju pinu signaalikäsitleja tarbib.

Rockset on kõigil kolmel teljel ebatavaline. Visakame tavalise ülekoormuse ohje osana erindeid suure sagedusega; edastame SIGUSR2 signaale coarse_thread_cputime_clocki tõttu harukordselt sageli; ja selle aasta alguses panime SIGUSR2 käsitleja rohkem pinu kasutama, lisades kutse timer_getoverrunile, et arvestada liidetud signaale.

Viimane muudatus näib olevat olnud oluline. Kui käsitleja kasutab piisavalt vähe pinu, ei pruugi see jõuda aegunud ucontext_t mäluni ega seda üle kirjutada. Enne seda muudatust me neid krahhe üldse ei täheldanud. Pärast muudatust püsis määr madal, kuni suurendasime koormust mõnel kasutusjuhul, mis pingestas vastusurve mehhanismi.

Teisisõnu oli libunwindi viga kogu aeg olemas, kuid meie erindimäära, signaalimäära ja käsitleja pinukasutuse korrutis ületas alles hiljuti läve, kus see töös nähtavaks sai.

See mehhanism selgitab ka kokkusattumust, et nii riistvaraviga kui ka libunwindi viga jooksid enamasti kokku DocumentTree::updateDocumenti sees. libunwindi krahhid kaldusid tugevalt selle meetodi poole, sest see on alati aktiivne hetkel, mil viskame erindi sissevõtu vastusurve rakendamiseks. %rsp valesti joondamise krahhide puhul valis seda samuti tugevalt see, et vigane riistvara sõlmpunkt oli SKU, mida kasutame masssissevõtuks ja mis veedab suurema osa CPU ajast selles meetodis.

Meie vahetu leevendus oli minna GNU libunwindilt üle libgcc unwinderile. See oli ka eraldi hea kompromiss: libgcc teostus on saanud palju parandusi lukukonkurentsi vähendamiseks, mis on suurtele VM-idele skaleerides oluline.

Saadtsime GNU libunwindi ülesvoolu ka iseseisva reprodutseerija ja paranduse⁠(avaneb uues aknas) ning kontrollisime, et teistel unwinderitel sarnast probleemi pole.

See silumisteekond õpetas meile palju dünaamilise linkimise, DWARF-i unwind-metaandmete, Linuxi signaaliedastuse, System V ABI ja C++ erindimehhanismi üksikasjadest. Kuid põhiõppetund oli sellest kõigest lihtsam.

Kõige olulisem samm polnud nutikas assembleri lugemine ega detailide sügav tundmine. See oli kvaliteetse andmestiku loomine. Ilma selle andmestikuta segasime kaks eri nähtust üheks looks ja püüdsime end segadusest välja mõelda. Kui meil olid täpsed ja täielikud populatsiooniandmed, sai probleemi struktuur ilmselgeks: üks krahhipopulatsioon kuulus vigasele hostile, teine libunwindi võidujooksule. Kui andmed paranesid, muutus silumine lihtsamaks.

Selliste taristusüsteemide nagu Rockset puhul on see väga tähtis. See uurimine kinnitas meie pühendumust sügavale instrumenteerimisele, automatiseeritud uurimistele ja tööriistade pidevale parandamisele. Töökindlus ei tähenda ainult vigade parandamist pärast nende ilmnemist – see tähendab andmete, töövoogude ja oskuste loomist, mis muudavad võimatud probleemid diagnoositavaks ja lahendatavaks.