Epidemiologija core dumpova: ispravka buga starog 18 godina

OpenAI-jevi modeli i agenti sve se više oslanjaju na skalabilnu podatkovnu infrastrukturu kako bi u vrijeme inferencije tražili relevantne podatke: dok modeli razmišljaju o vašem pitanju. Neki od tih servisa napisani su u C++-u, čija nam niskonivojska kontrola sistema omogućava maksimalne performanse i minimalnu potrošnju memorije. Te su prednosti važne dok se širimo, ali nedostatak memorijske sigurnosti u C++-u znači da bugovi mogu izazvati rušenja pisanjem na pogrešne ili nepostojeće memorijske adrese.

Prije nekoliko mjeseci primijetili smo rušenja unutar servisa Rockset, posebnog dijela naše podatkovne infrastrukture za ChatGPT, ključnog za mnoge podatkovne dodatke i pretraživanje razgovora. U svakom od tih rušenja izgledalo je da se obična C++ funkcija završi pa vrati na lažnu adresu, zbog čega kernel zaustavi program jer pokazivač instrukcije više ne pokazuje na kod. Ponekad je polje povratne adrese u stack okviru bilo NULL. Ponekad je i CPU registar pokazivača stacka izgledao pomjeren za 8 bajtova, kao da je %rsp nekako dekrementiran usred normalnog izvršavanja. U oba slučaja rušenje se desilo pri povratku.

To nisu uobičajeni načini otkaza aplikacijskog koda. Zalutali upis koji pogodi samo sačuvanu povratnu adresu moguć je, ali krajnje malo vjerovatan. Bug koji pomjeri %rsp za 8 bez inline assemblyja, setcontext ili longjmp (ništa od toga ne koristimo) još je čudniji, jer kompajlirani kod taj registar direktno podešava samo u prologu i epilogu funkcije. Protiv svake hipoteze koje smo se mi (ili ChatGPT) mogli sjetiti postojali su jaki dokazi, pa je bug djelovao nemoguće.

Ono što smo smatrali jednim problemom na kraju su se pokazala kao dva nepovezana buga, slučajno otkrivena u isto vrijeme. Prvo, tiho hardversko oštećenje na jednom Azure hostu, gdje CPU jednostavno nije ispravno računao. Drugo, 18 godina star race condition u GNU libunwindu, neprimijećen bug u široko korištenoj open source biblioteci.

Ovaj tekst govori kako smo prepoznali i ispravili naizgled neobjašnjiva rušenja razmišljajući kao epidemiolozi i gradeći kvalitetan skup podataka o cijeloj populaciji rušenja.

Prvo, zaronimo dublje u Rockset. To je cloud-native podatkovni sistem za pretragu i analitiku u stvarnom vremenu, koji u OpenAI-ju koristimo za mnoge interne namjene, poput sinhronizacijskih konektora (OpenAI je preuzeo Rockset 2024.). Streaming ažuriranja održavaju indeks baze znanja radnog prostora ažurnim, kako bi ChatGPT mogao pronaći relevantne informacije pri odgovaranju na pitanja ili izvođenju radnji.

Rocksetov izvršni sloj napisan je u C++-u. C++ omogućava niskonivojski pristup CPU-u, što je dobro za performanse i efikasnost, ali znači da aplikacijski bugovi mogu dovesti do nevažećih pristupa memoriji i segfaultova. Da bismo ih lakše pratili, koristimo follyjev fatal signal handler za bilježenje stack tracea pri rušenju, a pripadajuće core dumpove (snimak stanja programa u trenutku rušenja) šaljemo u Azure blob storage za kasniju analizu. Svi Rocksetovi listovi za obradu upita replicirani su, što smanjuje utjecaj rušenja na klijente. Ipak, svaki segfault odgovara bugu koji treba ispraviti da bismo ispunili ciljeve pouzdanosti i kvaliteta.

Naš početni pristup bio je tretirati te coreove kao klasičan problem debugiranja: detaljno pregledati nekoliko core dumpova, postaviti hipoteze i redom ih odbacivati.

Većina rušenja desila se u metodi DocumentTree::updateDocument. U tim rušenjima izgledalo je da je updateDocument pozvao neku nepoznatu funkciju X, stack se oštetio dok je X bila aktivna, a zatim se X vratila na adresu koja nije izvršni kod. U nekim slučajevima upravo skinuti okvir funkcije X izgledao je ispravno osim što mu je sačuvana povratna adresa bila NULL. U drugim slučajevima sam pokazivač stacka izgledao je pogrešno, ali je sljedeći važeći okvir i dalje izgledao kao updateDocument.

Nismo znali kada se stack oštećuje, što je ostavilo ogroman prostor za pretragu. updateDocument je velika metoda s mnogo inlininga, pa je broj kandidata za X bio prevelik.

Je li to bio bug u našem C++ kodu? Problem s kompajlerom ili linkovanjem? Problem u nekoj od naših runtime biblioteka? Bug u Linux kernelu oko isporuke signala ili prebacivanja konteksta? Nešto još rjeđe? Ako je to bio zalutali upis, zašto ga nije uhvatilo naše ASAN staging okruženje?

Pokušali smo koristiti aplikacijske logove da nađemo sve pojave problema, ali bugove s oštećenjem stacka teško je klasificirati samo iz logova jer su zabilježeni stack traceovi i sami oštećeni ili nedostaju. Nismo uspjeli napraviti log upit koji nije imao i lažno pozitivne i lažno negativne rezultate. Ručno smo pregledali još coreova i našli dodatne primjere, ali taj je proces bio previše zahtjevan da bi dao pouzdan skup podataka.

U toj fazi istrage (pogrešno) smo odbacili hardverski bug, jer smo vidjeli rušenja u više regija i na više tipova hardvera, pa smo i dalje tražili isključivo softverske uzroke. Nekoliko dana duboko smo analizirali jedno rušenje s pogrešno poravnatim %rsp, rekonstruirajući historiju prije rušenja iz sadržaja stacka i registara. To je dalo moguće tragove, ali pošto nismo odustali od početnog zaključka da svi bugovi imaju isti uzrok, nije nas odblokiralo.

Prije prekretnice u istrazi važno je objasniti kakve smo informacije izvlačili iz core datoteka.

Rockset se kompajlira s -fno-omit-frame-pointer, pa je aktivni stack okvir uvijek dostupan preko %rbp, a pozivaoci čine povezanu listu pokazivača okvira.

Na Linuxu x86_64, AMD64 System V ABI rezervira i 128 bajtova ispod %rsp kao crvenu zonu. Ta je oblast dostupna korisničkom kodu i, što je važno, kernel obećava da je neće prepisati pri isporuci signala, kao dio ABI ugovora.

Crvena zona bila je ključna za debugiranje rušenja nakon povratka, jer čuva dio informacija od prije povratka. Kada se okine SIGSEGV, follyjev fatal signal handler radi na stacku niti koja se ruši. Stack okviri koji više nisu aktivni (jer se njihova funkcija vratila) bit će prepisani signal handlerom, osim zadnjih 128 bajtova. Zato možemo reći stvari poput: “Upravo skinuti stack okvir funkcije X izgledao je ispravno, osim NULL povratne adrese.” Crvena zona čuva dio neaktivnih okvira, ili ponekad samo kraj jednog neaktivnog okvira.

Našli smo jedno rušenje s pogrešno poravnatim stackom u kojem su sve uključene funkcije bile vrlo male. To nam je omogućilo da vidimo da se %rsp pogrešno poravnao tokom izvršavanja relativno jednostavne funkcije i da su nakon toga drugi pozivi uspjeli. Program se srušio tek kada se aktivna funkcija konačno pokušala vratiti. Nijedan od tih puteva koda nije koristio izuzetke, inline assembly, setcontext ili longjmp, pa ako se pokazivač stacka zaista promijenio kako je core sugerirao, nijedan uvjerljiv bug u korisničkom kodu to nije objašnjavao.

To nas je usmjerilo prema kernelu.

Rockset koristi signale agresivnije od većine programa. Izvršavanje upita razbijeno je na mnogo lakih zadataka koji razmjenjuju podatke. To je važno za efikasno rukovanje opterećenjima s visokim QPS-om, ali otežava obračun CPU-a po upitu jer se rad za mnoge upite multipleksira na isti skup niti.

Naše rješenje zovemo coarse_thread_cputime_clock; ono dovoljno jeftino aproksimira clock_gettime(CLOCK_THREAD_CPUTIME_ID, ...) da možemo uzorkovati na svakoj granici zadatka. API timer_create može se koristiti za zakazivanje periodične isporuke signala prema više mjera protoka vremena, uključujući akumulaciju CPU vremena. Zakazujemo signal (SIGUSR2) svakih nekoliko milisekundi CPU vremena; tada signal handler ažurira vrijednost lokalnu za nit. Iako mnogi zadaci ne vide pomak grubog sata dok se izvršavaju, zbir svih delta daje nepristrasnu procjenu stvarnog CPU vremena za upit.

Pošto signale isporučujemo tako često, rijedak kernel bug oko prebacivanja konteksta ili isporuke signala djelovao je moguć. Proveli smo vrijeme čitajući izvještaje o bugovima, izvorni kod kernela i Azure-specifične kernel patcheve. Pokušali smo sa stres-testovima. Nismo našli ništa što je djelovalo povezano.

Tada smo odlučili napraviti korak unazad i pokušati drugačije.

Postoje dva široka načina za debugiranje ovakvog problema.

Jedan je ponašati se poput doktora: fokusirati se na jednog pacijenta, uraditi mnogo testova i pokušati dijagnosticirati pojedinačan slučaj iz detaljnih dokaza.

Drugi je više poput epidemiologa: posmatrati cijelu populaciju i pitati postoje li obrasci koje jedan slučaj ne može otkriti. Je li bug počeo s određenim izdanjem? Korelira li s jednim hardverskim SKU-om (konkretnim CPU-om i modelom servera), jednom regijom ili jednom verzijom kernela? Krije li se više odvojenih klastera unutar onoga što izgleda kao jedan sindrom?

Mi smo uglavnom bili u doktorskom režimu. Ključni pomak bio je zaključak da moramo prikupiti kvalitetne podatke o populaciji.

Naši raniji pokušaji da automatski nađemo sve primjerke problema propali su jer smo koristili tekstualne pretrage logova. Sami core dumpovi imaju mnogo više informacija, ali njihov ručni pregled nije se mogao skalirati. Odlučili smo uložiti trud u pipeline koji može automatski analizirati core dumpove.

ChatGPT nam je napisao skriptu koja je preuzimala prefiks svake core datoteke, izvlačila registre, filtrirala poznate lažno pozitivne slučajeve pomoću logova i automatski označavala rušenje kao return-to-null, misaligned-stack ili drugo. Zatim smo tu skriptu paralelno pokrenuli nad svakim produkcijskim Rockset core dumpom iz prethodne godine.

To je bila prekretnica.

Čim smo imali čist skup podataka, korelacije su se odmah pojavile. Ono što smo tretirali kao jedan čudan bug zapravo su bile dvije odvojene populacije rušenja.

Return-to-null coreovi bili su rasuti po mnogim klasterima i geografskim regijama. Njihova je učestalost nedavno porasla, ali nije bilo jasnog datuma početka ni čiste infrastrukturne granice.

Rušenja s pogrešno poravnatim stackom izgledala su potpuno drugačije. Sva su dolazila iz jedne regije, imala jasan datum početka i nikad se nisu desila na čvorovima koji su dugo radili. Iako su uključivala više Azure VM-ova (virtuelnih mašina u cloudu), obrazac je ličio na jednu fizičku mašinu s lošim hardverom koja pravi probleme svakom VM-u koji se zatekne na njoj.

Tada smo shvatili da smo u glavi spojili dva buga. Pošto smo miješali kontraprimjere iz oba buga, nismo mogli naći jedno koherentno objašnjenje.

S čistom listom Kubernetes čvorova i vremenskih oznaka mogli smo pratiti rušenja s pogrešno poravnatim stackom do jednog fizičkog hosta, koji je bilo lako staviti na denylistu.

Nismo uspjeli reproducirati oštećenje registara na tom hostu u kontroliranom okruženju, čak ni nakon više sedmica stres-testiranja. Međutim, čim je problematični host povučen iz upotrebe, rušenja s pogrešno poravnatim stackom nestala su.

Uklanjanje lošeg hosta nije trajno rješenje, u smislu da ne sprečava novu pojavu istog problema. Ipak, možemo promijeniti softver tako da se sličan problem, ako se ponovi, lako otkrije i obradi. Poboljšali smo fatal signal handler da uključuje stanje registara, kako bismo ponavljanje mogli otkriti samo iz logova (bez core dumpa). Promijenili smo control plane tako da se VM-ovi obično ponovo koriste umjesto recikliraju, što otkrivanje lošeg čvora čini mnogo lakšim na našem nivou infrastrukturnog steka. Ažurirali smo i runbookove (i mentalne modele tima) da uključe tu mogućnost.

Kad su rušenja lošeg hosta izdvojena, o preostalim return-to-null coreovima bilo je mnogo lakše razmišljati. Ranije smo odbacili exception unwinding jer smo mislili da imamo kontraprimjere: rušenja u putevima koda gdje se izuzeci sigurno nisu koristili. Ali svi ti kontraprimjeri bili su iz klastera hardverskog oštećenja.

Kad smo s tim na umu ponovo pregledali preostale coreove, otkrili smo da je zaključak bio potpuno obrnut: sva rušenja dešavala su se tokom exception unwindinga.

Kada C++ baci izuzetak, runtime mora otkriti koji catch blok ga treba primiti i koji destruktori ili handleri za čišćenje trebaju usput raditi. Kompajler emitira te metapodatke, ali se stvarno uparivanje dinamički dešava u runtimeu.

Exception unwinding zapravo ne izvodi funkcija koja poziva throw, nego pomoćne funkcije koje poziva nastali kompajlirani kod. Te runtime rutine pregledaju stack, dohvaćaju metapodatke o funkcijama na stacku, dinamički traže handlere za čišćenje i catch blokove, a zatim prenose kontrolu na jednu od tih lokacija. Prijenos kontrole uključuje unwinding svih međustack okvira (uključujući okvire pomoćnih funkcija).

Operativno, to je mnogo bliže longjmp-u ili prebacivanju fibera nego normalnom pozivu i povratku. Callee-save registri moraju se obnoviti, kao i registri stack okvira %rbp i %rsp.

Naš binarni fajl linkuje se s dvije biblioteke koje sadrže implementacije funkcija za C++ exception unwinding: libgcc i GNU libunwind. Dinamički linker izabrao je definicije iz GNU libunwinda. To nas je iznenadilo; očekivali smo da pobijedi libgcc implementacija zbog pravila verzioniranja simbola, ali pregled pokrenutih binarnih fajlova pokazao je suprotno.

U tom trenutku naša radna hipoteza se promijenila, jer smo popustili još jednu pretpostavku nastalu dok smo mislili da postoji samo jedan bug.

Možda nismo gledali običan povrat funkcije na NULL. Možda smo gledali unwind prijenos — praktično obnovu registara u stilu setcontext — gdje je odredišni pokazivač instrukcije postao NULL prije prijenosa kontrole. Drugim riječima, pogrešni podaci iz unwind biblioteke, a ne pogrešno polje povratne adrese na stacku.

To je dramatično suzilo problem. Ili je GNU libunwind računao pogrešno odredišno stanje, ili je računao ispravno stanje, ali ga je nešto oštetilo prije primjene.

Pročitali smo izvorni kod GNU libunwinda i našli da sintetizira ucontext_t na stacku, popunjava željeno stanje registara za okvir handlera za čišćenje, a zatim prosljeđuje pokazivač na tu strukturu internoj assembly rutini: _Ux86_64_setcontext.

U tom trenutku imali smo sve dijelove.

Sintetizirani ucontext_t živi u jednom od stack okvira koje _Ux86_64_setcontext unwinduje tokom izvršavanja te funkcije. Je li _Ux86_64_setcontext čitao iz strukture nakon što je promijenio %rsp, kada struktura više nije bila dio aktivnog stacka? To bi je učinilo ranjivom na prepisivanje pri isporuci signala, poput našeg čestog SIGUSR2.

Odgovor je bio da.

Ovo je posljednjih šest instrukcija _Ux86_64_setcontext u verziji GNU libunwinda koju smo koristili; uglavnom su to mov instrukcije koje učitavaju iz memorije u odredišni registar:

(%rdi pokazuje na ucontext_t alociran na stacku, a makroi UC_MCONTEXT_* samo se šire na fiksni offset na kojem je pohranjen određeni registar.)

Prva instrukcija je početak race prozora. Ona ažurira %rsp da pokazuje na novo dno aktivnog stacka. Čim se to desi, struktura na koju pokazuje %rdi više nije dio aktivnog stacka (ni crvene zone) i kernelu više nije zabranjena.

Obično to ne pravi probleme, ali ako signal stigne u tačno pravom (pogrešnom?) trenutku, kernel će izgraditi signalni okvir na %rsp-128. To može prepisati memoriju na koju pokazuje %rdi.

Ako se to desi prije nego što sljedeća instrukcija pročita UC_MCONTEXT_GREGS_RIP(%rdi), obnovljeni pokazivač instrukcije može biti oštećen. U našim rušenjima postao je NULL.

To je bug.

Ovaj assembly objašnjava i jedno opažanje koje nas je zbunilo: zašto je funkcija X imala NULL u polju povratne adrese prethodnog stack okvira.

setcontext je napisan da obnovi sve registre, uključujući %rdi, pa taj registar ne može koristiti za čitanje UC_MCONTEXT_GREGS_RIP(%rdi) u posljednjem trenutku prijenosa kontrole. Umjesto toga, vrijednost pročita ranije, spremi je na stack, obnovi još nekoliko registara, a zatim koristi retq da pročita sačuvanu vrijednost i prenese kontrolu.

Ono što je u coreovima izgledalo kao „funkcija se vratila na NULL” zapravo je bilo „unwinder je sintetizirao ciljnu povratnu adresu na stacku, ali je ta meta oštećena prije završetka prijenosa”. Pretpostavili smo da se polje povratne adrese mora oštetiti na licu mjesta, jer nismo znali za mjesta gdje se (oštetivi) podaci namjerno upisuju u to polje.

Ono zbog čega ovaj bug djeluje apsurdno jeste koliko je taj race prozor uzak. U ovakvom race conditionu vanjski događaj (signal) mora se desiti između dva koraka druge niti. Što su ti koraci bliži, manja je vjerovatnoća da će se race condition desiti.

U ovom slučaju ranjivi prozor doslovno je širok jednu instrukciju! Signal mora biti isporučen nakon što se %rsp promijeni, ali prije nego što sljedeća instrukcija učita %rip. Na modernom superskalarnom out-of-order CPU-u može se izvršiti više ovakvih jednostavnih instrukcija po ciklusu, pa je race prozor otprilike stotinu pikosekundi.

Kad smo našli ovaj race, prva reakcija bila je da mora biti prerijedak da objasni opaženu stopu rušenja. Vidjeli smo više od deset return-to-null rušenja dnevno širom flote. Može li race od jedne instrukcije tokom čišćenja izuzetaka zaista objasniti to?

Okrenuli smo se Fermijevoj procjeni. Ako je ranjivi prozor reda $10^{-10}$ sekundi, a SIGUSR2 stiže svakih $10^{-2}$ sekundi CPU vremena, onda svaki handler za čišćenje izuzetka ili catch blok ima oko $10^{-8}$ vjerovatnoće da izgubi utrku.

Rockset koristi izuzetke kao dio internog mehanizma povratnog pritiska pri unosu. Jedan preopterećen host može bacati oko $10^{4}$ izuzetaka u sekundi. To znači da je srednje vrijeme između otkaza hosta koji koristi povratni pritisak $10^{4}$ sekundi, odnosno jedno rušenje svakih nekoliko sati. Na nivou flote, to je više nego dovoljno da objasni opaženu učestalost rušenja.

GNU libunwind bug je star — više od 18 godina, prisutan u prvoj x86_64 verziji koja je podržavala C++ exception unwinding.

Zašto se onda pojavio tek sada?

Stopa rušenja približno je proporcionalna broju bačenih izuzetaka i isporučenih signala. Zavisi i od toga koliko stacka signal handler potroši.

Rockset je neobičan po sve tri ose. Izuzetke bacamo velikom stopom kao dio normalne kontrole preopterećenja; SIGUSR2 isporučujemo neobično često zbog coarse_thread_cputime_clock; a ranije ove godine povećali smo potrošnju stacka u SIGUSR2 handleru dodavanjem poziva timer_getoverrun, da bismo obračunali spojene signale.

Čini se da je ta posljednja promjena bila važna. Ako handler koristi dovoljno malo stacka, možda neće dosegnuti i prepisati zastarjelu ucontext_t memoriju. Prije te promjene uopće ne vidimo ova rušenja. Nakon promjene stopa je ostala niska dok nismo povećali opterećenje za neke namjene koje su opteretile mehanizam povratnog pritiska.

Drugim riječima, libunwind bug je uvijek bio tu, ali je proizvod naše stope izuzetaka, stope signala i potrošnje stacka u handleru tek nedavno prešao prag na kojem je postao operativno vidljiv.

Ovaj mehanizam objašnjava i slučajnost da su se i hardverski bug i libunwind bug rušili uglavnom unutar DocumentTree::updateDocument. Rušenja iz libunwinda bila su snažno pristrasna prema toj metodi, jer je uvijek aktivna u trenutku kada bacamo izuzetak da primijenimo povratni pritisak pri unosu. Bila je snažno odabrana i za rušenja s pogrešno poravnatim %rsp, jer je loš hardverski čvor bio SKU koji koristimo za masovni unos, gdje većina CPU vremena odlazi na tu metodu.

Naša neposredna mitigacija bila je prelazak s GNU libunwinda na libgccjev unwinder. To je i samo po sebi bila dobra razmjena: libgccjeva implementacija imala je mnogo rada na smanjenju nadmetanja za zaključavanja, što je važno pri skaliranju na velike VM-ove.

Također smo upstreamali samostalan reproducer i ispravku⁠(otvara se u novom prozoru) u GNU libunwind, te potvrdili da drugi unwinderi nemaju sličan problem.

Ovo debugiranje naučilo nas je mnogo o detaljima dinamičkog linkovanja, DWARF unwind metapodataka, isporuke signala u Linuxu, System V ABI-ja i C++ mehanizma izuzetaka. Ali glavna lekcija bila je jednostavnija od svega toga.

Najvažniji korak nije bilo domišljato čitanje assemblyja ni duboko poznavanje detalja. Bio je to izgraditi kvalitetan skup podataka. Bez tog skupa podataka miješali smo dva različita fenomena u jednu priču i pokušavali razmišljanjem izaći iz zbrke. Kad smo dobili tačne i potpune podatke o populaciji, struktura problema postala je očita: jedna populacija rušenja pripadala je lošem hostu, a druga raceu u libunwindu. Kad su podaci postali bolji, debugiranje je postalo lakše.

Za infrastrukturne sisteme poput Rockseta to je veoma važno. Ova istraga ojačala je našu posvećenost dubokoj instrumentaciji, automatiziranim istragama i stalnom unapređenju operativnih alata. Pouzdanost nije samo ispravljanje bugova nakon što se dese — radi se o izgradnji podataka, tokova rada i vještina koje nemoguće probleme pretvaraju u dijagnosticirane i rješive.