Епидемиологија на core dump: поправка на 18-годишен баг

Моделите и агентите на OpenAI сè повеќе се потпираат на скалабилна податочна инфраструктура за да бараат релевантни податоци при инференција: кога моделите размислуваат за вашето прашање. Некои од овие услуги се напишани во C++, чија нискониво контрола врз системот ни овозможува да ги максимизираме перформансите и да ја минимизираме употребата на меморија. Тие придобивки во ефикасноста се важни додека се шириме, но недостигот на мемориска безбедност во C++ значи дека багови може да предизвикаат падови со запишување на погрешни или непостојни мемориски адреси.

Пред неколку месеци забележавме падови во услугата Rockset, посебно изграден дел од нашата податочна инфраструктура за ChatGPT, клучен за многу податочни приклучоци и за пребарување низ разговори. Во секој од овие падови, нормална C++ функција изгледаше како да завршува и потоа да се враќа на лажна адреса, па kernel го запираше програмот бидејќи покажувачот на инструкција веќе не покажуваше кон код. Понекогаш местото за повратна адреса во рамката на стекот беше NULL. Понекогаш самиот CPU-регистар за покажувачот на стек изгледаше поместен за 8 бајти, како %rsp некако да бил намален среде нормално извршување. Во двата случаи падот се случуваше при враќање.

Ова не се нормални начини на откажување за апликациски код. Залутано запишување што погодува само зачувана повратна адреса е можно, но крајно неверојатно. Баг што го поместува %rsp за 8 без inline assembly, setcontext или longjmp (не користиме ништо од тоа) е уште почуден, бидејќи компајлиран код го менува тој регистар директно само во прологот и епилогот на функцијата. Секоја хипотеза што нам или на ChatGPT ни падна на ум имаше силни докази против неа, па багот изгледаше невозможен.

Она што го сметавме за еден проблем на крај се покажа како два неповрзани бага, случајно откриени во исто време. Прво, тивко хардверско оштетување на еден Azure-хост, каде CPU едноставно не пресметуваше правилно. Второ, 18-годишна race condition во GNU libunwind, незабележан баг во широко користена open source библиотека.

Оваа објава е приказна за тоа како идентификувавме и поправивме навидум необјасниви падови размислувајќи како епидемиолог и градејќи квалитетен податочен сет за целата популација на падови.

Прво, да навлеземе подлабоко во Rockset. Тоа е cloud-native податочен систем за пребарување и аналитика во реално време што го користиме за многу внатрешни потреби во OpenAI, како sync-конектори (OpenAI го презеде Rockset во 2024). Стриминг-ажурирањата се користат за одржување ажуриран индекс на базата на знаење на работниот простор, за ChatGPT да може да бара релевантни информации кога одговара на прашања или извршува дејства.

Извршниот слој на Rockset е напишан во C++. Јазикот C++ дава нискониво пристап до CPU, што е добро за перформанси и ефикасност, но значи дека апликациски багови може да доведат до неважечки пристапи до меморија и segfault-и. За полесно следење го користиме fatal signal handler на folly за да запишеме stack trace при пад, а соодветните core dump-ови (снимка од состојбата на програмот при падот) ги качуваме во Azure blob storage за подоцнежна анализа. Сите листови за обработка на прашања во Rockset се реплицирани, што го минимизира влијанието на пад врз клиентот. Сепак, секој segfault одговара на баг што треба да се поправи за да ги исполниме нашите цели за доверливост и квалитет.

Нашиот почетен пристап беше да ги третираме овие core-ови како конвенционален проблем за дебагирање: детално да прегледаме неколку core dump-ови, да формираме хипотези и една по една да ги исклучуваме.

Повеќето падови се случија во метод наречен DocumentTree::updateDocument. Во тие падови изгледаше дека updateDocument повикал некоја непозната функција X, стекот се оштетил додека X била активна, а потоа X се вратила на адреса што не беше извршлив код. Во некои случаи штотуку отстранетата рамка на X изгледаше валидна, освен што зачуваната повратна адреса беше NULL. Во други случаи самиот покажувач на стек изгледаше погрешно, но следната валидна рамка сè уште се чинеше дека е updateDocument.

Не знаевме кога се оштетува стекот, што оставаше огромен простор за пребарување. updateDocument е голем метод со многу inlining, па бројот кандидати за X беше преголем.

Дали беше баг во нашиот C++ код? Проблем со компајлерот или поврзувањето? Проблем во некоја од нашите runtime библиотеки? Баг во Linux kernel околу испорака на сигнали или менување контекст? Нешто уште поретко? Ако ова беше залутано запишување, зошто нашата ASAN staging-средина не го фати?

Се обидовме со апликациските логови да ги идентификуваме сите појави на проблемот, но баговите со оштетување на стек тешко се класифицираат само од логови, бидејќи самите запишани stack trace-ови се оштетени или недостасуваат. Не успеавме да составиме log query без лажно позитивни и лажно негативни резултати. Рачно прегледавме уште core-ови и најдовме дополнителни примери, но тој процес бараше премногу труд за да ни даде доверлив податочен сет.

Во оваа фаза од истрагата (погрешно) исклучивме хардверски баг, бидејќи гледавме падови во повеќе региони и на повеќе типови хардвер, па сè уште баравме исклучиво софтверски причини. Неколку дена навлегувавме многу длабоко во еден пад со непорамнет %rsp, реконструирајќи ја историјата пред падот преку содржината на стекот и регистрите. Тоа даде можни траги, но бидејќи не се откажавме од почетниот заклучок дека сите багови имаат иста причина, не нè одглави.

Пред да дојдеме до пресвртницата во истрагата, важно е да објасниме какви информации извлекувавме од core-датотеките.

Rockset се компајлира со -fno-omit-frame-pointer, па активната рамка на стекот секогаш е достапна преку %rbp, а повикувачите формираат поврзана листа од покажувачи на рамки.

На Linux x86_64, AMD64 System V ABI резервира и 128 бајти под %rsp како red zone. Тој регион е достапен за userspace код и, важно, kernel ветува дека нема да го препише при испорака на сигнал, како дел од ABI-договорот.

Red zone беше клучна за дебагирање на пад по враќање, бидејќи зачувува дел од информациите од пред враќањето. Кога се активира SIGSEGV, fatal signal handler-от на folly работи на стекот на нишката што паѓа. Рамките на стек што веќе не се активни (бидејќи нивната функција се вратила) ќе бидат препишани од signal handler-от, освен последните 128 бајти. Затоа можеме да кажеме работи како „штотуку отстранетата рамка на X изгледаше валидна, освен NULL повратна адреса“. Red zone зачувува делови од неактивните рамки, или понекогаш само опашката на една неактивна рамка.

Најдовме еден пад со непорамнет стек во кој сите вклучени функции беа многу мали. Тоа ни овозможи да видиме дека %rsp се непорамнил при извршување на релативно едноставна функција и дека потоа уште повици успеале. Програмот падна дури кога активната функција конечно се обиде да се врати. Ниту една од тие патеки на код не користеше exceptions, inline assembly, setcontext или longjmp, па ако покажувачот на стек навистина се сменил како што сугерираше core-от, немаше веројатен баг во userspace код што го објаснуваше проблемот.

Тоа нè насочи кон kernel-от.

Rockset користи сигнали поагресивно од повеќето програми. Извршувањето на прашања е поделено на многу лесни задачи што разменуваат податоци. Ова е важно за ефикасно справување со high-QPS оптоварувања, но го отежнува мерењето CPU по прашање, бидејќи работата за многу прашања се мултиплексира врз истиот pool од нишки.

Нашето решение е нешто што го нарекуваме coarse_thread_cputime_clock, кое приближно го пресметува clock_gettime(CLOCK_THREAD_CPUTIME_ID, ...) доволно евтино за семплирање на секоја граница меѓу задачи. API-то timer_create може да се користи за закажување периодична испорака на сигнал според неколку поими за проток на време, вклучувајќи акумулирано CPU-време. Закажуваме сигнал (SIGUSR2) да се испорачува на секои неколку милисекунди CPU-време; тогаш signal handler-от ажурира вредност локална за нишката. Иако многу задачи не гледаат напредок на грубиот часовник додека се извршуваат, собирањето на сите делти дава непристрасна проценка на реалното CPU-време за едно прашање.

Бидејќи испорачуваме сигнали толку често, редок kernel-баг околу менување контекст или испорака на сигнали изгледаше веројатен. Поминавме време читајќи извештаи за багови, изворен код на kernel и kernel-закрпи специфични за Azure. Пробавме stress test-ови. Не успеавме да најдеме ништо што изгледаше поврзано.

Тогаш решивме да се повлечеме чекор назад и да пробаме друг пристап.

Постојат два широки начина да се дебагира ваков проблем.

Едниот е да се постапува како некаков доктор: да се фокусирате на еден пациент, да направите многу тестови и да се обидете да дијагностицирате еден случај од детални докази.

Другиот е повеќе како епидемиолог: да ја погледнете целата популација и да прашате дали има обрасци што еден случај не може да ги открие. Дали багот почнал со конкретно издание? Дали корелира со еден hardware SKU (конкретниот CPU и модел на сервер), еден регион или една верзија на kernel? Дали во она што изгледа како еден синдром се кријат повеќе одделни кластери?

Најчесто бевме во докторски режим. Клучната промена беше одлуката дека ни требаат квалитетни податоци за целата популација.

Нашите претходни обиди автоматски да ги најдеме сите инстанци на проблемот пропаднаа затоа што се обидувавме да користиме текстуални пребарувања низ логовите. Самите core dump-ови имаат многу повеќе информации, но рачното прегледување не се скалираше. Решивме да вложиме труд во pipeline што автоматски ќе ги анализира core dump-овите.

Му дадовме на ChatGPT да напише скрипта што преземаше префикс од секоја core-датотека, ги извлекуваше регистрите, ги филтрираше познатите лажно позитивни случаи преку логовите и автоматски го означуваше падот како return-to-null, misaligned-stack или друго. Потоа ја пуштивме таа скрипта паралелно врз секој продукциски Rockset core dump од претходната година.

Тоа беше пресвртницата.

Штом имавме чист податочен сет, корелациите веднаш се појавија. Она што го третиравме како еден чуден баг всушност беа две одделни популации на падови.

Return-to-null core-овите беа распрснати низ многу кластери и географски региони. Нивната зачестеност неодамна се зголемила, но немаше јасен датум на почеток ниту чиста инфраструктурна граница.

Падовите со непорамнет стек изгледаа сосема поинаку. Сите доаѓаа од еден регион, имаа јасен датум на почеток и никогаш не се случуваа на јазли што работеле долго време. Иако вклучуваа повеќе Azure VM-и (виртуелни машини хостирани во облак), образецот изгледаше како една физичка машина со лош хардвер да предизвикува проблеми за која било VM што ќе завршела на неа.

Тогаш сфативме дека ментално сме споиле два бага. Бидејќи мешавме контрапримери од двата бага, не можевме да најдеме едно кохерентно објаснување.

Со чист список на Kubernetes јазли и временски ознаки, успеавме да ги проследиме падовите со непорамнет стек до еден физички хост, кој лесно се стави на denylist.

Не успеавме да ја репродуцираме корупцијата на регистрите на тој хост во контролирана средина, дури ни по неколку недели stress testing. Но штом проблематичниот хост беше изваден од употреба, падовите со непорамнет стек исчезнаа.

Отстранувањето на лошиот хост не е трајно решение, во смисла дека не спречува нова појава на истиот проблем. Сепак, можеме да го смениме софтверот така што, ако сличен проблем се повтори, лесно да се открие и обработи. Го подобривме fatal signal handler-от да вклучува состојба на регистрите, за да можеме повторување да откриеме само од логовите (без потреба од core dump). Го сменивме control plane-от така што VM-ите обично се повторно користат наместо да се рециклираат, што многу го олеснува откривањето лош јазол на нашето ниво од инфраструктурниот стек. Ги ажуриравме и нашите runbook-ови (и менталните модели на тимот) за да ја вклучат оваа можност.

Со издвоени падови од лошиот хост, преостанатите return-to-null core-ови станаа многу полесни за разбирање. Претходно го исклучивме exception unwinding бидејќи мислевме дека имаме контрапримери: падови во патеки на код каде exceptions дефинитивно не се користеа. Но сите тие контрапримери беа од кластерот со хардверска корупција.

Кога повторно ги разгледавме преостанатите core-ови со тоа на ум, сфативме дека заклучокот бил сосема обратен: сите падови се случувале при exception unwinding.

Кога C++ фрла exception, runtime-от мора да открие кој catch-блок треба да го прими и кои деструктори или cleanup handler-и треба да се извршат по пат. Компајлерот ја емитува оваа metadata, но вистинското совпаѓање се случува динамички во runtime.

Exception unwinding всушност не го извршува функцијата што повикува throw, туку помошни функции повикани од добиениот компајлиран код. Тие runtime рутини го испитуваат стекот, земаат metadata за функциите најдени на стекот, динамички бараат cleanup handler-и и catch-блокови, а потоа ја пренесуваат контролата на една од тие локации. Преносот на контрола вклучува unwinding на сите посредни рамки на стек (вклучувајќи ги и оние на помошните функции).

Оперативно, ова е многу поблиску до longjmp или fiber switch отколку до нормален повик и враќање. Callee-save регистрите мора да се обноват, како и регистрите на рамката на стек %rbp и %rsp.

Нашиот binary се поврзува со две библиотеки што содржат имплементации на функциите за C++ exception unwinding: libgcc и GNU libunwind. Дефинициите од GNU libunwind беа избрани од dynamic linker-от. Тоа нè изненади; очекувавме имплементацијата на libgcc да победи поради правилата за versioning на симболи, но прегледот на активни binaries покажа дека не е така.

Во овој момент работната хипотеза ни се смени, бидејќи олабавивме уште една претпоставка што ја направивме кога мислевме дека има само еден баг.

Можеби не гледавме обична функција што се враќа на NULL. Можеби гледавме unwind transfer - практично обновување регистри во стил на setcontext - каде целниот покажувач на инструкција станал NULL пред да се пренесе контролата. Со други зборови, погрешни податоци од unwind библиотеката, а не погрешно место за повратна адреса на стекот.

Тоа драматично го стесни проблемот. Или GNU libunwind ја пресметуваше погрешната целна состојба, или ја пресметуваше правилната состојба, но нешто ја оштетуваше пред да се примени.

Го прочитавме изворниот код на GNU libunwind и најдовме дека синтетизира ucontext_t на стекот, ја пополнува саканата состојба на регистрите за рамката на cleanup handler-от, а потоа предава покажувач до таа структура на внатрешна assembly рутина: _Ux86_64_setcontext.

Во тој момент ги имавме сите парчиња.

Синтетизираниот ucontext_t живее во една од рамките на стек што ги unwound-ира _Ux86_64_setcontext за време на извршувањето на таа функција. Дали _Ux86_64_setcontext читаше од структурата откако го смени %rsp, кога структурата веќе не беше дел од активниот стек? Тоа би ја направило ранлива на препишување при испорака на сигнал, како нашиот чест SIGUSR2.

Одговорот беше да.

Еве ги последните шест инструкции на _Ux86_64_setcontext во верзијата на GNU libunwind што ја користевме, составени главно од mov инструкции што вчитуваат од меморија во целен регистар:

(%rdi покажува кон ucontext_t алоциран на стек, а макроата UC_MCONTEXT_* само се прошируваат во фиксниот offset каде е зачуван одреден регистар.)

Првата инструкција е почетокот на race-прозорецот. Таа го ажурира %rsp да покажува кон новото дно на активниот стек. Штом тоа се случи, структурата на која покажува %rdi веќе не е дел од активниот стек (или red zone) и веќе не е забранета за kernel-от.

Обично тоа не предизвикува проблеми, но ако сигнал пристигне во точно вистинскиот (погрешен?) момент, kernel-от ќе ја изгради рамката на сигналот на %rsp-128. Тоа може да ја препише меморијата на која покажува %rdi.

Ако тоа се случи пред следната инструкција да прочита UC_MCONTEXT_GREGS_RIP(%rdi), обновениот покажувач на инструкција може да се оштети. Во нашите падови, тој стануваше NULL.

Тоа е багот.

Овој assembly објаснува и едно од набљудувањата што нè збунуваше: зошто функцијата X имаше NULL во местото за повратна адреса на претходната рамка на стек.

setcontext е напишан да ги обнови сите регистри, вклучувајќи %rdi, па не може да го користи тој регистар за да прочита UC_MCONTEXT_GREGS_RIP(%rdi) во последниот момент на преносот на контрола. Наместо тоа, ја чита вредноста порано, ја зачувува на стекот, обновува уште неколку регистри, а потоа користи retq за да ја прочита зачуваната вредност и да ја пренесе контролата.

Она што во core-овите изгледаше како „функција се вратила на NULL“ всушност беше „unwinder-от синтетизирал целна повратна адреса на стекот, но таа цел била оштетена пред да заврши преносот“. Претпоставувавме дека оштетувањето на местото за повратна адреса мора да се случи на самото место, бидејќи не знаевме за места каде (оштетливи) податоци намерно се запишуваат таму.

Она што го прави овој баг апсурден е колку е тесен овој race-прозорец. Кај ваква race condition, надворешниот настан (сигналот) треба да се случи меѓу два чекора на друга нишка. Колку тие чекори се поблиску еден до друг, толку е помала веројатноста да се случи race condition.

Во овој случај ранливиот прозорец е буквално широк една инструкција! Сигналот мора да се испорача откако %rsp ќе се смени, но пред следната инструкција да го вчита %rip. Неколку едноставни инструкции како оваа може да се извршат по циклус на модерен superscalar out-of-order CPU, па race-прозорецот е приближно сто пикосекунди.

Кога ја најдовме оваа race состојба, првата реакција ни беше дека мора да е премногу ретка за да ја објасни забележаната стапка на падови. Гледавме повеќе од десетина return-to-null падови дневно низ fleet-от. Може ли race од една инструкција при чистење exceptions навистина да го објасни тоа?

Се свртевме кон Фермиева проценка. Ако ранливиот прозорец е од редот на $10^{-10}$ секунди, а SIGUSR2 пристигнува на секои $10^{-2}$ секунди CPU-време, тогаш секој handler за чистење exception или catch-блок има приближно $10^{-8}$ веројатност да ја изгуби race состојбата.

Rockset користи exceptions како дел од внатрешниот механизам за ingest backpressure. Еден преоптоварен хост може да фрла околу $10^{4}$ exceptions во секунда. Тоа значи дека средното време меѓу откажувања на хост што користи backpressure е $10^{4}$ секунди, односно еден пад на неколку часа. На ниво на fleet, тоа е повеќе од доволно за да ја објасни забележаната зачестеност на падови.

Багот во GNU libunwind е стар — повеќе од 18 години, присутен во првата верзија за x86_64 што поддржуваше C++ exception unwinding.

Па зошто се појави сега?

Стапката на падови е приближно пропорционална на тоа колку exceptions се фрлаат и колку сигнали се испорачуваат. Зависи и од тоа колку стек троши signal handler-от.

Rockset е необичен по сите три оски. Фрламе exceptions со висока стапка како дел од нормална контрола на преоптоварување; испорачуваме SIGUSR2 невообичаено често поради coarse_thread_cputime_clock; а порано годинава направивме handler-от за SIGUSR2 да користи повеќе стек со додавање повик до timer_getoverrun, за да ги евидентираме споените сигнали.

Се чини дека последната промена беше важна. Ако handler-от користи доволно малку стек, можеби нема да стигне до застарената ucontext_t меморија и да ја препише. Пред таа промена воопшто не ги забележувавме овие падови. По промената стапката остана ниска додека не го зголемивме оптоварувањето за некои случаи што го напрегнаа механизмот за backpressure.

Со други зборови, багот во libunwind отсекогаш бил таму, но производот од нашата стапка на exceptions, стапка на сигнали и употреба на стек од handler-от дури неодамна го премина прагот каде стана оперативно видлив.

Овој механизам ја објаснува и случајноста што и хардверскиот баг и багот во libunwind паѓаа главно во DocumentTree::updateDocument. Падовите од libunwind беа силно наклонети кон овој метод, бидејќи тој е секогаш активен кога фрламе exception за да примениме ingest backpressure. Тој беше силно застапен и кај падовите со непорамнет %rsp, бидејќи лошиот хардверски јазол беше од SKU што го користиме за bulk ingest, кој најголем дел од CPU-времето го троши во овој метод.

Нашето непосредно ублажување беше да преминеме од GNU libunwind на unwinder-от на libgcc. Тоа само по себе беше добра размена: имплементацијата на libgcc имаше корист од многу работа за намалување на lock contention, што е важно при скалирање на големи VM-и.

Исто така upstream-навме самостоен reproducer и поправка⁠(се отвора во нов прозорец) во GNU libunwind и проверивме дека другите unwinder-и немаат сличен проблем.

Ова патување низ дебагирањето нè научи многу за конкретните детали на динамичко поврзување, DWARF unwind metadata, испорака на Linux сигнали, System V ABI и механизмите за C++ exceptions. Но главната лекција беше поедноставна од сето тоа.

Најважниот чекор не беше умешното читање assembly или длабокото познавање на деталите. Беше градењето квалитетен податочен сет. Без тој податочен сет, мешавме две различни појави во една приказна и се обидувавме со расудување да излеземе од збунетоста. Штом добивме точни и целосни податоци за популацијата, структурата на проблемот стана очигледна: една популација на падови му припаѓаше на лош хост, а другата на race во libunwind. Кога податоците станаа подобри, дебагирањето стана полесно.

За инфраструктурни системи како Rockset, тоа е многу важно. Оваа истрага ја зацврсти нашата посветеност на длабока инструментација, автоматизирани истраги и континуирани подобрувања на оперативните алатки. Доверливоста не е само поправање багови откако ќе се случат — туку градење податоци, работни текови и вештини што невозможните проблеми ги претвораат во дијагностички и решливи.