Epidemiologija core dumpova: ispravak 18-godišnjeg buga

OpenAI-jevi modeli i agenti sve se više oslanjaju na skalabilnu podatkovnu infrastrukturu kako bi u vrijeme zaključivanja pronašli relevantne podatke: dok modeli razmišljaju o vašem pitanju. Neki od tih servisa napisani su u C++-u, čija nam niskorazinska kontrola sustava omogućuje maksimalne performanse i minimalnu potrošnju memorije. Te su prednosti učinkovitosti važne pri skaliranju, ali manjak 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 uočili 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 činilo se da je obična C++ funkcija završila pa se vratila na nevaljanu adresu, zbog čega je kernel zaustavio program jer pokazivač instrukcije više nije pokazivao na kod. Ponekad je mjesto za povratnu adresu u okviru stoga bilo NULL. Ponekad se činilo da je sam CPU registar pokazivača stoga pomaknut za 8 bajtova, kao da je %rsp nekako dekrementiran usred normalnog izvođenja. U oba slučaja rušenje se dogodilo pri povratku.

To nisu uobičajeni načini otkaza aplikacijskog koda. Zalutali zapis koji pogodi samo spremljenu povratnu adresu moguć je, ali krajnje nevjerojatan. Bug koji pogrešno poravna %rsp za 8 bez umetnutog assemblyja, poziva setcontext ili poziva longjmp (ništa od toga ne koristimo) još je čudniji jer prevedeni kod taj registar izravno podešava samo u prologu i epilogu funkcije. Za svaku hipotezu koje smo se mi (ili ChatGPT) mogli sjetiti postojali su jaki protuargumenti, pa se bug činio nemogućim.

Ono za što smo mislili da je jedan problem na kraju se pokazalo 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 stara utrka u izvršavanju (race condition) u GNU libunwindu, neprimijećen bug u široko korištenoj biblioteci otvorenog koda.

Ovaj tekst opisuje kako smo prepoznali i ispravili naizgled neobjašnjiva rušenja razmišljajući poput epidemiologa i izgradivši kvalitetan skup podataka o cijeloj populaciji rušenja.

Prvo, zaronimo dublje u Rockset. To je podatkovni sustav nativan za oblak, namijenjen pretraživanju i analitici u stvarnom vremenu, koji u OpenAI-ju koristimo za mnoge interne slučajeve, poput sinkronizacijskih konektora (OpenAI je preuzeo Rockset 2024.). Streaming ažuriranja održavaju ažuran indeks baze znanja radnog prostora kako bi ChatGPT mogao tražiti relevantne informacije pri odgovaranju na pitanja ili izvođenju radnji.

Rocksetov sloj za izvršavanje napisan je u C++-u. Jezik C++ daje niskorazinski pristup CPU-u, što je dobro za performanse i učinkovitost, ali znači da bugovi u aplikaciji mogu dovesti do nevaljanih pristupa memoriji i segfaultova. Da bismo ih lakše pratili, koristimo follyjev obrađivač fatalnih signala za zapis traga stoga pri rušenju te odgovarajuće core dumpove (snimku stanja programa u trenutku rušenja) prenosimo u Azure Blob Storage za kasniju analizu. Svi Rocksetovi leaf čvorovi za obradu upita replicirani su, što smanjuje utjecaj rušenja na klijente. Ipak, svaki segfault znači bug koji treba ispraviti kako bismo ispunili ciljeve pouzdanosti i kvalitete.

Isprva smo te core dumpove tretirali kao klasičan problem debugiranja: detaljno pregledati nekoliko core dumpova, oblikovati hipoteze i jednu po jednu ih odbacivati.

Većina rušenja dogodila se u metodi DocumentTree::updateDocument. U tim se rušenjima činilo da je updateDocument pozvao neku nepoznatu funkciju X, stog se oštetio dok je X bila aktivna, a zatim se X vratila na adresu koja nije bila izvršni kod. U nekim je slučajevima upravo uklonjeni okvir funkcije X izgledao valjano osim što mu je spremljena povratna adresa bila NULL. U drugim je slučajevima sam pokazivač stoga izgledao pogrešno, ali sljedeći valjani okvir i dalje se činio kao updateDocument.

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

Je li to bio bug u našem C++ kodu? Problem s kompajlerom ili povezivanjem? Problem u jednoj 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 zapis, zašto ga nije uhvatilo naše ASAN staging okruženje?

Pokušali smo upotrijebiti aplikacijske logove za pronalazak svih pojava problema, ali bugove s oštećenjem stoga teško je klasificirati samo iz logova jer su zabilježeni tragovi stoga i sami oštećeni ili nedostaju. Nismo uspjeli sastaviti upit nad logovima bez lažno pozitivnih i lažno negativnih rezultata. Ručno smo pregledali više core dumpova i našli dodatne primjere, ali taj je postupak bio previše zahtjevan da bi dao pouzdan skup podataka.

U toj fazi istrage (pogrešno) smo isključili 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 smo dana vrlo duboko analizirali jedno rušenje s pogrešno poravnatim %rsp-om, rekonstruirajući povijest prije rušenja iz sadržaja stoga i registara. To je dalo neke moguće tragove, ali kako nismo odustali od početnog zaključka da svi bugovi imaju isti uzrok, nije nas izvuklo iz zastoja.

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 okvir stoga uvijek dostupan kroz %rbp, a pozivatelji čine povezani popis pokazivača okvira.

Na Linuxu x86_64, AMD64 System V ABI također rezervira 128 bajtova ispod %rsp kao crvenu zonu. Ta je regija dostupna userspace kodu i, što je važno, kernel obećava da je neće pregaziti 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. Kad se okine SIGSEGV, follyjev obrađivač fatalnih signala izvodi se na stogu niti koja se ruši. Okvire stoga koji više nisu aktivni (jer se njihova funkcija vratila) prebrisat će obrađivač signala, osim zadnjih 128 bajtova. Zato možemo reći stvari poput „upravo uklonjeni okvir stoga funkcije X izgledao je valjano, osim NULL povratne adrese”. Crvena zona čuva dio neaktivnih okvira, ili ponekad samo kraj jednog neaktivnog okvira.

Pronašli smo jedno rušenje s pogrešno poravnatim stogom u kojem su sve uključene funkcije bile vrlo male. To nam je omogućilo vidjeti da je %rsp postao pogrešno poravnat tijekom izvođenja relativno jednostavne funkcije i da su nakon toga drugi pozivi uspjeli. Program se srušio tek kad se aktivna funkcija napokon pokušala vratiti. Nijedan od tih putova koda nije koristio iznimke, umetnuti assembly, poziv setcontext ni poziv longjmp, pa ako se pokazivač stoga doista promijenio kako je core sugerirao, nijedan uvjerljiv bug u userspace kodu nije objašnjavao problem.

To nas je usmjerilo prema kernelu.

Rockset koristi signale agresivnije od većine programa. Izvršavanje upita razlomljeno je na mnogo laganih zadataka koji razmjenjuju podatke. To je važno za učinkovitu obradu opterećenja 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 je rješenje nešto što zovemo coarse_thread_cputime_clock, što dovoljno jeftino aproksimira clock_gettime(CLOCK_THREAD_CPUTIME_ID, ...) da se uzorkuje na svakoj granici zadatka. API timer_create može se koristiti za zakazivanje periodične isporuke signala prema nekoliko poimanja proteka vremena, uključujući akumulaciju CPU vremena. Zakazujemo signal (SIGUSR2) za isporuku svakih nekoliko milisekundi CPU vremena, nakon čega obrađivač signala ažurira vrijednost lokalnu za nit. Iako mnogi zadaci ne vide pomak grubog sata dok se izvode, zbrajanje svih delta daje nepristranu procjenu stvarnog CPU vremena za upit.

Budući da signale isporučujemo tako često, rijedak bug u kernelu oko prebacivanja konteksta ili isporuke signala činio se mogućim. Proveli smo vrijeme čitajući izvješća o bugovima, izvorni kod kernela i Azureove zakrpe kernela. Pokušali smo sa stres-testovima. Nismo uspjeli pronaći ništa što bi se činilo povezanim.

Tad smo odlučili odmaknuti se i pokušati drukčiji pristup.

Postoje dva široka načina debugiranja ovakvog problema.

Jedan je ponašati se poput liječnika: usredotočiti se na jednog pacijenta, provesti mnogo testova i pokušati dijagnosticirati pojedinačni slučaj iz detaljnih dokaza.

Drugi je ponašati se više poput epidemiologa: pogledati 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 (određeni CPU i model poslužitelja), jednom regijom ili jednom verzijom kernela? Skriva li se više različitih klastera unutar nečega što izgleda kao jedan sindrom?

Uglavnom smo bili u liječničkom načinu rada. Ključna promjena bila je odluka da moramo prikupiti kvalitetne podatke o populaciji.

Naši raniji pokušaji automatskog pronalaženja svih instanci problema propali su jer smo pokušavali koristiti tekstualne pretrage logova. Sami core dumpovi imaju mnogo više informacija, ali ručno pregledavanje nije skaliralo. Odlučili smo uložiti trud u izgradnju pipelinea koji bi mogao automatski analizirati core dumpove.

Zamolili smo ChatGPT da napiše skriptu koja preuzima prefiks svake core datoteke, izdvaja registre, filtrira poznate lažno pozitivne slučajeve pomoću logova i automatski označava rušenje kao povratak na NULL, pogrešno poravnat stog ili drugo. Zatim smo tu skriptu paralelno pokrenuli nad svakim produkcijskim Rockset core dumpom iz prethodne godine.

To je bila prekretnica.

Kad 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.

Core dumpovi s povratkom na NULL bili su raspršeni po mnogim klasterima i geografskim regijama. Njihova se učestalost nedavno povećala, ali nije bilo jasnog početnog datuma ni čiste infrastrukturne granice.

Rušenja s pogrešno poravnatim stogom izgledala su posve drukčije. Sva su dolazila iz jedne regije, imala jasan početni datum i nikad se nisu događala na čvorovima koji su dugo radili. Iako su uključivala više Azure VM-ova (virtualnih strojeva hostanih u oblaku), obrazac je izgledao kao jedan fizički stroj s lošim hardverom koji stvara probleme bilo kojem VM-u koji se slučajno nađe na njemu.

Tad smo shvatili da smo u glavi spajali dva buga. Budući da smo miješali protuprimjere iz oba buga, nismo mogli pronaći jedno dosljedno objašnjenje.

S čistim popisom Kubernetes čvorova i vremenskih oznaka uspjeli smo rušenja s pogrešno poravnatim stogom povezati s jednim fizičkim hostom, koji je bilo lako dodati na denylist.

Nismo uspjeli reproducirati oštećenje registara na tom hostu u kontroliranom okruženju, čak ni nakon nekoliko tjedana stres-testiranja. No nakon što je problematični host izbačen iz upotrebe, rušenja s pogrešno poravnatim stogom nestala su.

Uklanjanje lošeg hosta nije trajno rješenje jer ne sprječava novu pojavu istog problema. Možemo, međutim, promijeniti softver tako da se sličan problem, ako se ponovi, lako otkrije i obradi. Poboljšali smo obrađivač fatalnih signala tako 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 ponovno koriste umjesto recikliraju, što na našoj razini infrastrukturnog sloja znatno olakšava otkrivanje loših čvorova. Ažurirali smo i runbookove (i mentalne modele tima) kako bi uključili tu mogućnost.

Kad smo izdvojili rušenja lošeg hosta, o preostalim core dumpovima s povratkom na NULL bilo je mnogo lakše razmišljati. Ranije smo isključili odmotavanje iznimki jer smo mislili da imamo protuprimjere: rušenja u putovima koda gdje se iznimke sigurno nisu koristile. No ti su protuprimjeri svi bili iz klastera hardverskog oštećenja.

Kad smo s tim na umu ponovno pregledali preostale core dumpove, shvatili smo da je zaključak bio potpuno obrnut: sva su se rušenja događala tijekom odmotavanja iznimki.

Kad C++ baci iznimku, runtime mora otkriti koji je catch blok treba primiti i koji se destruktori ili obrađivači čišćenja usput trebaju pokrenuti. Kompajler emitira te metapodatke, ali stvarno se uparivanje odvija dinamički u runtimeu.

Odmotavanje iznimke zapravo ne izvodi funkcija koja poziva throw, nego pomoćne funkcije koje poziva nastali prevedeni kod. Te runtime rutine pregledavaju stog, dohvaćaju metapodatke o funkcijama pronađenima na stogu, dinamički traže obrađivače čišćenja i catch blokove, a zatim prenose kontrolu na jedno od tih mjesta. Prijenos kontrole uključuje odmotavanje svih okvira stoga između tih točaka (uključujući okvire pomoćnih funkcija).

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

Naš se binarni program povezuje s dvije biblioteke koje sadrže implementacije funkcija za odmotavanje C++ iznimki: libgcc i GNU libunwind. Dinamički linker odabrao je definicije iz GNU libunwinda. To nas je iznenadilo; očekivali smo da će pobijediti implementacija libgcc-a zbog pravila verzioniranja simbola, ali pregled pokrenutih binarija pokazao je da nije tako.

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

Možda nismo gledali običan povratak funkcije na NULL. Možda smo gledali unwind prijenos – zapravo obnovu registara u stilu poziva setcontexta – pri kojem je odredišni pokazivač instrukcije postao NULL prije prijenosa kontrole. Drugim riječima, problem su bili pogrešni podaci iz unwind biblioteke, a ne pogrešno mjesto povratne adrese na stogu.

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

Pročitali smo izvorni kod GNU libunwinda i otkrili da sintetizira ucontext_t na stogu, popunjava željeno stanje registara za okvir obrađivača čišćenja, a zatim predaje pokazivač na tu strukturu internoj assembly rutini: _Ux86_64_setcontext.

U tom smo trenutku imali sve dijelove.

Sintetizirani ucontext_t živi u jednom od okvira stoga koje _Ux86_64_setcontext odmotava tijekom izvođenja te funkcije. Je li _Ux86_64_setcontext čitao iz strukture nakon što je promijenio %rsp, kad struktura više nije bila dio aktivnog stoga? To bi je učinilo ranjivom na prebrisivanje pri isporuci signala, primjerice našeg čestog signala SIGUSR2.

Odgovor je bio da.

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

(%rdi pokazuje na ucontext_t alociran na stogu, a makronaredbe UC_MCONTEXT_* samo se proširuju na fiksni pomak na kojem je pohranjen određeni registar.)

Prva instrukcija označava početak ranjivog prozora. Ona ažurira %rsp tako da pokazuje na novo dno aktivnog stoga. Čim se to dogodi, struktura na koju pokazuje %rdi više nije dio aktivnog stoga (ni crvene zone) i kernel više nije obvezan ne dirati je.

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

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

To je bug.

Ovaj assembly objašnjava i jedno opažanje koje nas je zbunjivalo: zašto je funkcija X imala NULL u mjestu za povratnu adresu prethodnog okvira stoga.

setcontext je napisan da obnovi sve registre, uključujući %rdi, pa ne može taj registar upotrijebiti za čitanje UC_MCONTEXT_GREGS_RIP(%rdi) u završnom trenutku prijenosa kontrole. Umjesto toga, vrijednost čita ranije, sprema je na stog, obnavlja još nekoliko registara, a zatim koristi retq da pročita spremljenu vrijednost i prenese kontrolu.

Ono što je u core dumpovima izgledalo kao „funkcija se vratila na NULL” zapravo je bilo „unwinder je sintetizirao ciljnu povratnu adresu na stogu, ali je taj cilj oštećen prije dovršetka prijenosa”. Pretpostavili smo da se oštećenje mjesta povratne adrese mora dogoditi na licu mjesta jer nismo znali za mjesta gdje se podaci koji se mogu oštetiti namjerno pišu u mjesto povratne adrese.

Ovaj bug djeluje apsurdno zbog toga koliko je uzak taj ranjivi prozor. U takvoj utrci u izvršavanju vanjski događaj (signal) mora se dogoditi između dva koraka koje izvodi druga nit. Što su ti koraci bliži jedan drugome, to je manja vjerojatnost da će doći do takve utrke.

U ovom je slučaju ranjivi prozor doslovno širok samo 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 nekoliko ovako jednostavnih instrukcija može se izvršiti po ciklusu, pa je taj ranjivi prozor otprilike stotinu pikosekundi.

Kad smo pronašli tu utrku u izvršavanju, prva nam je reakcija bila da mora biti prerijetka da objasni opaženu stopu rušenja. Vidjeli smo više od desetak rušenja s povratkom na NULL dnevno u cijeloj floti. Može li utrka u izvršavanju s prozorom od samo jedne instrukcije tijekom čišćenja iznimke doista to objasniti?

Okrenuli smo se Fermatovoj procjeni. Ako je ranjivi prozor reda veličine $10^{-10}$ sekundi, a SIGUSR2 stiže svakih $10^{-2}$ sekundi CPU vremena, tada svaki obrađivač čišćenja iznimke ili catch blok ima približno $10^{-8}$ vjerojatnosti da izgubi utrku.

Rockset koristi iznimke kao dio internog mehanizma ingest backpressurea. Jedan preopterećen host može baciti reda veličine $10^{4}$ iznimki u sekundi. To znači da je srednje vrijeme između otkaza hosta koji koristi backpressure $10^{4}$ sekundi, odnosno jedno rušenje svakih nekoliko sati. Na razini flote to je više nego dovoljno da objasni opaženu učestalost rušenja.

Bug u GNU libunwindu star je više od 18 godina i prisutan je u prvoj verziji x86_64 koja je podržavala odmotavanje C++ iznimki.

Zašto se onda pojavio sad?

Stopa rušenja približno je proporcionalna broju bačenih iznimki i broju isporučenih signala. Ovisi i o tome koliko stoga troši obrađivač signala.

Rockset je neuobičajen po sve tri osi. Bacamo iznimke velikom brzinom kao dio normalne kontrole preopterećenja; SIGUSR2 isporučujemo neuobičajeno često zbog coarse_thread_cputime_clock; a ranije ove godine povećali smo potrošnju stoga obrađivača SIGUSR2 dodavanjem poziva na timer_getoverrun, kako bismo mogli uračunati spojene signale.

Čini se da je ta posljednja promjena bila važna. Ako obrađivač koristi dovoljno malo stoga, možda neće dosegnuti i prebrisati zastarjelu memoriju ucontext_t. Prije te promjene ta rušenja uopće nismo opažali. Nakon promjene stopa je ostala niska dok nismo povećali opterećenje za neke slučajeve upotrebe koji su opteretili mehanizam backpressurea.

Drugim riječima, bug u libunwindu oduvijek je bio ondje, ali umnožak naše stope iznimki, stope signala i potrošnje stoga obrađivača tek je nedavno prešao prag na kojem postaje operativno vidljiv.

Taj mehanizam objašnjava i podudarnost da su se i hardverski bug i bug u libunwindu rušili uglavnom unutar DocumentTree::updateDocument. Rušenja iz libunwinda bila su snažno pristrana prema toj metodi jer je uvijek aktivna u trenutku kada bacamo iznimku radi primjene ingest backpressurea. Ta je metoda bila snažno zastupljena i kod rušenja zbog pogrešnog poravnanja %rsp-a jer je loš hardverski čvor bio SKU koji koristimo za masovni ingest, a većinu CPU vremena provodi u toj metodi.

Naša neposredna mitigacija bila je prijeći s GNU libunwinda na libgccov unwinder. To je i samo po sebi bila dobra zamjena: u libgccovu implementaciju uloženo je mnogo rada na smanjenju nadmetanja za lockove, što je važno pri skaliranju na velike VM-ove.

Poslali smo i samostalan reproducer te ispravak⁠(otvara se u novom prozoru) za GNU libunwind i provjerili da drugi unwinderi nemaju sličan problem.

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

Najvažniji korak nije bilo domišljato čitanje assemblyja ni duboko poznavanje detalja. Bila je to izgradnja kvalitetnog skupa podataka. Bez tog skupa podataka miješali smo dvije različite pojave u jednu priču i pokušavali se izvući iz zbrke samim zaključivanjem. Kad smo imali točne i potpune podatke o populaciji, struktura problema postala je očita: jedna populacija rušenja pripadala je lošem hostu, a druga utrci u izvršavanju u libunwindu. Kad su podaci postali bolji, debugiranje je postalo lakše.

Za infrastrukturne sustave poput Rockseta to je vrlo važno. Ova je istraga učvrstila našu predanost temeljitoj instrumentaciji, automatiziranim istragama i stalnom poboljšanju operativnih alata. Pouzdanost nije samo ispravljanje bugova nakon što se dogode – nego izgradnja podataka, procesa i vještina koji nemoguće probleme pretvaraju u probleme koje je moguće dijagnosticirati i riješiti.