Hoe Tailscale hielp bij het vinden de SQLite WAL-Reset bug

Inmiddels zijn we in de zomer en we zijn er zeker van dat we de bug hebben gevonden, dat we deze begrijpen — en belangrijker nog: dat we hem hebben opgelost.

We weten dat onze klanten verwachten dat Tailscale een betrouwbare service is, en gedurende enkele maanden zijn we niet aan die belofte nagekomen. Dat is verstorend en het spijt ons. We publiceren dit artikel om uit te leggen wat er misging, hoe we reageerden en hoe we uiteindelijk hebben geholpen bij het blootleggen van een langdurige bug in het hart van de SQLite-database.

De database-architectuur van Tailscale

Hoewel onze clients interactie hebben met ons control plane via één publiek eindpunt (controlplane.tailscale.com), is ons control plane intern opgesplitst in een reeks coördinatieservers (of "shards"). Elke tailnet bevindt zich op één moment op één interne shard, maar kan naadloos van de ene naar de andere migreren. Deze shards zijn een intern implementatiedetail; de gebruiker weet niet op welke shard hun tailnet staat en hoeft dat ook niet te weten.

Elke shard heeft een SQLite-database die alle informatie over de tailnets op die shard bevat. Eén enkel Go-proces heeft exclusieve toegang tot die database en bedient het control plane voor die tailnets. Dit single-writer ontwerp is precies hoe SQLite bedoeld is om gebruikt te worden.

We gebruiken SQLite als onze primaire database sinds 2022. We kozen hiervoor omdat het bekend, betrouwbaar en veelgebruikt is. SQLite is "saaie technologie" — in de goede zin van het woord. Veel bedrijven gebruiken SQLite in veel grotere implementaties zonder problemen, en we verwachtten hetzelfde zorgeloze gebruik.

In onze huidige back-up pipeline maken we elke paar minuten een volledige snapshot van de database en uploaden we het volledige SQLite-bestand naar een S3-bucket. We draaiden deze setup sinds begin 2023 zonder incidenten.

Dat veranderde in augustus vorig jaar, toen een datapijplijn die deze S3-back-ups uitleest, een fout rapporteerde in een van onze databases. We voerden het SQLite-commando PRAGMA integrity_check uit op de back-up en stelden vast dat deze inderdaad corrupt was. SQLite-corruptie is mogelijk, maar het is zeer ongebruikelijk en iets wat je bij normaal gebruik niet zou moeten tegenkomen. We herstelden de getroffen database en onderzochten de oorzaak, maar zonder resultaat.

Wanneer je op grote schaal opereert, kunnen zelfs zeldzame gebeurtenissen met enige frequentie voorkomen. Daarom hadden we ons niet moeten verbazen toen het opnieuw gebeurde — en opnieuw, en opnieuw. In totaal kampten we zes maanden lang met 19 afzonderlijke instanties van databasecorruptie voordat we de onderliggende bug uiteindelijk oplosten.

Wanneer men de term "databasecorruptie" hoort, is het natuurlijk om je zorgen te maken over dataverlies. Omdat ons control plane alleen configuratiegegevens verwerkt, bevatten deze databases metadata over je tailnet en apparaten, maar nooit je private encryptiesleutels of netwerkverkeer. Bij de eerste incidenten betekende het herstelproces dat een handvol onlangs toegevoegde apparaten of configuratiewijzigingen niet bewaard bleven, waardoor een kleine hoeveelheid metadata opnieuw moest worden ingevoerd.

Telkens wanneer er corruptie optrad, moesten we het control plane-proces op de shard stopzetten terwijl we de database herstelden of terugzetten. Dit was pijnlijk voor de tailnets op die shard, omdat hun volledige control plane verdween tijdens dat herstelvenster. In de beginfase duurde deze downtime meer dan een uur, maar we hebben het herstelproces bij opeenvolgende incidenten geleidelijk versneld.

Elk tailnet is een mesh-netwerk, waarbij apparaten peer-to-peer WireGuard®-verbindingen met elkaar maken. Wanneer een apparaat zich bij het tailnet voegt, moet het een lijst met andere apparaten opvragen bij het control plane voordat het nieuwe verbindingen kan tot stand brengen; als een apparaat dus online kwam tijdens de SQLite-downtime, kon het geen verbinding maken. Terwijl de database werd hersteld, bleven apparaten die al online waren met elkaar verbonden, maar konden ze geen wijzigingen in het netwerk waarnemen. Deze tailnets verloren ook tijdelijk toegang tot de webgebaseerde adminconsole en de Tailscale API.

Er is ook een bredere impact op het vertrouwen. We plaatsen een globaal incident op onze statuspagina, zelfs als slechts een klein aantal tailnets is getroffen. Veel mensen zagen een statuspagina-event voor een incident dat hen niet beïnvloedde. Sterker nog, de meeste shards en tailnets waren nooit betrokken bij een databasecorruptie-incident! Desondanks tast herhaaldelijke downtime het vertrouwen aan, of je nu direct bent getroffen of niet.

Vanaf de allereerste instantie van corruptie wisten we dat dit een ernstige bedreiging vormde voor onze betrouwbaarheid en we hebben veel engineeringtijd in het probleem gestoken — maar de oplossing was niet eenvoudig.

Op zoek naar de fout

Deze bug verzette zich tegen al onze eerste pogingen om hem te vinden.

We keken naar recente wijzigingen, maar er waren geen die relevant leken. Niemand had gewerkt aan onze low-level code die interactie heeft met SQLite, omdat deze jaren geleden was geschreven en tot dat moment geen problemen vertoonde. We hebben al die code met een fijnkam doorzocht om eerder gemiste bugs te vinden, maar we vonden niets dat de corruptie zou kunnen veroorzaken.

We zochten naar gemeenschappelijke factoren tussen de corruptie-incidenten, maar konden geen vinden. Het was niet gekoppeld aan één specifieke shard, klant, tailnet-functie, tijdstip of belastingsniveau. We hadden geen idee wat het gedrag triggerde.

Door dit gebrek aan betrouwbare triggers konden we de bug niet synthetisch reproduceren. In plaats daarvan moesten we vertrouwen op het implementeren van passieve, forensische telemetrie in onze live-omgeving om de corruptie "roodhandig" te betrappen. Het verzamelen van live-diagnostiek voor een databaseprobleem was het laatste wat we wilden doen, maar we hadden geen keuze.

Als extra complicatie trad de corruptie niet op volgens een vast schema. Soms zaten incidenten uren uit elkaar, andere keren weken. Dit maakte het moeilijk om progressie te voorspellen of verder werk te plannen, omdat we nooit zeker wisten wanneer we our volgende diagnostische dump zouden krijgen. Tussen oktober en december hadden we een periode van zes weken zonder corruptie-incidenten, voordat ze terugkeerden als een ongewenst kerstcadeau.

Omdat dit geen snelle of gemakkelijke fix zou zijn, hebben we contact opgenomen met de SQLite-ontwikkelaars voor een professioneel supportcontract. Dit was een uitstekende beslissing. Het gaf ons directe toegang tot hun diepe expertise en ervaring, en we hadden vele gedetailleerde technische gesprekken over onze architectuur en onze incidenten.

Samen met de SQLite core-ontwikkelaars brachten we verschillende theorieën in kaart over wat de corruptie kon veroorzaken — waaronder kapotte POSIX-locks bij close(), verkeerd beheer van geheugen dat eigendom is van SQLite, of het per ongeluk gebruiken van SQLite vanuit meerdere threads terwijl thread-safety was uitgeschakeld. Na elk incident verzamelden we meer data, voegden we meer diagnostiek toe en sloten we systematisch deze theorieën uit. We kwamen langzaam dichter bij de werkelijke bug.

De transacties die niet "blaften"

Terwijl we het grondprobleem onderzochten, moesten we nog steeds een live platform draaien. We namen agressieve stappen om herstel te automatiseren en downtime te minimaliseren:

• Het configureren van onze control plane shards om onmiddellijk hard te stoppen bij het detecteren van corruptie.
• Het implementeren van een geautomatiseerde back-up monitor die continu PRAGMA integrity_check uitvoerde op onze back-ups.
• Het verbeteren van onze runbooks en on-call training.

Deze inspanningen brachten onze responstijd terug naar minder dan een uur — en toen ontdekten we een onverwachte aanwijzing.

We wilden een manier om de service te herstellen die niet bestond uit het terugdraaien naar de laatste bekende goede back-up (wat veel dataverlies zou betekenen) of het repareren van de corrupt database (wat potentieel riskant was).

Om dit te doen, bouwden we een transaction logging pipeline. We streamden elke SQL-statement die de database wijzigde naar een apart logbestand. Omdat SQLite een single-writer database is met serialiseerbare transacties, was onze transactiegeschiedenis volledig lineair en deterministisch (dit zou niet gelden voor een multi-writer database zoals Postgres of MySQL). Het opnieuw afspelen van die transacties tegen de laatste bekende goede back-up zou de database moeten herstellen naar de meest recente staat, waarbij de corruptie veilig wordt omzeild.

Deze pijplijn werkte, maar deed vervolgens iets nog beters: hij gaf ons een aanwijzing.

In twee incidenten lukte het niet om onze transactielogs schoon af te spelen. Bij nadere inspectie ontdekten we dat data die was geschreven en gecommit door één transactie, onverklaarbaar onzichtbaar was voor latere transacties. Een schrijfactie was in het niets verdwenen zonder een foutmelding te geven. Dat zou onmogelijk moeten zijn!

De aanwijzingen in de WAL

Terwijl deze incidenten gaande waren, hadden de SQLite-ontwikkelaars een nieuw debuggingtool ontwikkeld. We hadden al een tijdje vermoed dat de bug ergens in het checkpoint-proces zat. Ze bouwden een tool om beter inzicht te krijgen in wat er gebeurde tijdens checkpoints.

Om te begrijpen wat deze tool vond, moeten we kort uitleggen hoe SQLite-checkpoints werken.

Een SQLite-database bestaat uit een reeks "pagina's", kleine blokken informatie. Wanneer je de database bijwerkt, moeten sommige van die pagina's worden vervangen door nieuwe pagina's met de bijgewerkte informatie.

Voor betere prestaties en grotere concurrency draaien we SQLite met Write-Ahead Logging (WAL). Dit betekent dat nieuwe pagina's niet direct naar het databasebestand worden geschreven, maar naar de "write-ahead log" of het "WAL-bestand".

Nieuwe pagina's kunnen niet oneindig naar het WAL-bestand worden geschreven; op een gegeven moment moeten ze worden teruggekopieerd naar het hoofd-databasebestand. Dit proces wordt "checkpointing" genoemd.

In de meeste implementaties beslist SQLite zelf wanneer er een checkpoint plaatsvindt, en is dit proces onzichtbaar voor de eindgebruiker en ontwikkelaar. In ons control plane nemen we handmatige controle over het checkpoint-proces, zodat we snelle en consistente back-ups kunnen maken. Deze niet-standaard aanpak leek verdacht terwijl we potentiële oorzaken uitsloten.

Eén aanwijzing was dat tijdens corruptie-incidenten onze metrics lieten zien dat SQLite rapporteerde meer pagina's uit het WAL-bestand te kopiëren dan er daadwerkelijk beschikbaar waren. Als er 10 pagina's in het WAL-bestand staan en er worden 20 pagina's naar de database gekopieerd, is er duidelijk iets mis.

Om te begrijpen wat er gebeurde tijdens deze foutieve checkpoints, maakten de SQLite-ontwikkelaars een nieuwe debuggingtool voor de virtual filesystem (VFS) laag.

SQLite is opgedeeld in verschillende lagen:

1. De bovenste laag is de parser en code generator, die SQL-statements omzet in interne datastructuren van SQLite.
2. Deze structuren worden doorgegeven aan de pager, die ze opsplitst in individuele pagina's om naar schijf te schrijven.
3. Het daadwerkelijke schrijven naar schijf wordt afgehandeld door de OS-interface, of het "virtual filesystem". Momenteel heeft SQLite twee mainstream VFS-implementaties: Unix en Windows.

Deze opzet stelt je in staat om verschillende lagen te vervangen door andere implementaties, of een bestaande laag te wrappen om meer informatie te verkrijgen. Om ons probleem te diagnosticeren, maakten de SQLite-ontwikkelaars een wrapper rond het virtual filesystem die extra tracing-informatie en logs schrijft over wijzigingen in de database. Deze wrapper heet de tmstmpvfs shim, en de broncode is beschikbaar in de publieke SQLite-repository.

We implementeerden de shim in onze live-omgeving en wachtten tot de volgende corruptie optrad. Gelukkig hoefden we niet lang te wachten.

De WAL-Reset bug

Na het volgende corruptie-incident stelden de extra logs van de nieuwe tmstmpvfs shim de SQLite-ontwikkelaars in staat om de bug te vinden en op te lossen: een zeldzame data race in de SQLite-broncode tussen een checkpoint en een schrijftransactie.

Specifiek gebeurt het volgende: als er op een specifiek moment tijdens een checkpoint een schrijfactie plaatsvindt, raakt het checkpoint-proces in de war. Het denkt dat sommige pagina's van de WAL naar het hoofd-databasebestand zijn gekopieerd, terwijl dat niet is gebeurd. Die pagina's worden nooit naar het databasebestand geschreven en die data gaat permanent verloren. Het databasebestand wordt corrupt, omdat andere pagina's die naar deze pagina's verwijzen — zoals een index — wel naar de database worden geschreven.

De SQLite-ontwikkelaars noemden dit de "WAL-Reset bug" en schatten dat deze minstens 16 jaar in SQLite aanwezig was. Hij kon zo lang bestaan omdat hij zeldzaam was — zo zeldzaam dat de ontwikkelaars code moesten toevoegen om hem bewust te triggeren in hun testomgevingen. Hun fix voegt een extra controle toe aan de checkpoint-functie die detecteert wanneer de WAL door een andere thread is gereset.

Ze bevestigden dat deze bug verantwoordelijk was voor al het vreemde gedrag dat we hadden gezien: de corruptie, de transactielogs die niet schoon konden worden toegepast en de inconsistente checkpoint-statistieken. Ze legden ook uit waarom wij vaker tegen deze bug aanliepen dan andere SQLite-gebruikers: we nemen handmatige controle over het checkpoint-proces en we checkpointen zeer agressief. Zelfs een bug die door een zeldzame conditie wordt getriggerd, zou ons uiteindelijk moeten raken.

Dit was een opwindend moment. Na maanden van verwarring en onzekerheid hadden we eindelijk een plausibele theorie voor de corruptie en een fix die we konden implementeren om het te voorkomen. De SQLite-ontwikkelaars brachten de fix uit als SQLite 3.52.0, en we bereidden ons voor om deze zo snel mogelijk uit te rollen.

Opgelost, met een vals alarm

We rolden SQLite 3.52.0 voorzichtig uit — eerst naar een paar canary shards en daarna naar de rest van het control plane.

Onze back-up monitor sprong prompt op rood en rapporteerde corruptie in 13 verschillende databases. Dit was uiterst alarmerend, maar we volgden onze herstelprocedures om alle vermeende corrupties te herstellen, waarna alles weer goed leek. Het bleek dat deze databases geen echte corruptie hadden geleden, maar last hadden van een tweede probleem in de versie van SQLite.

We deelden onze fouten met de SQLite-ontwikkelaars, wat een bug in SQLite aan het licht bracht gerelateerd aan stale expression indexes. Als je een index maakt op een berekende waarde en die berekening vervolgens verandert, bevat de index niet-overeenstemmende waarden, wat door PRAGMA integrity_check als corruptie wordt gerapporteerd.

In ons geval bewaarden we sommige timestamps met hoge precisie als tekst en zetten deze om naar een floating-point getal in een virtuele gegenereerde kolom. De SQLite 3.52.0 release die onze data race oploste, bevatte ook een optimalisatie die subtiel het afrondingsgedrag voor tekst-naar-floating-point conversies veranderde. Onze canary shards hadden geen timestamps die dit gewijzigde afrondingsgedrag triggerden, waardoor we dit in onze gefaseerde uitrol misten.

Omdat deze wijziging zorgde voor valse corruptie-waarschuwingen, trokken de SQLite-ontwikkelaars de 3.52.0 release in en publiceerden ze in plaats daarvan 3.51.3, die alleen de fix voor de WAL-Reset bug bevatte.

Wij hebben het probleem aan onze kant opgelost door de precisie van onze timestamps te verminderen naar gehele seconden; tekst-naar-integer conversies zijn ondubbelzinnig. Ondertussen voegden de SQLite-ontwikkelaars in 3.53.0 een automatische, zelfherstellende index-functie toe die het probleem van stale expression indexes voorkomt.

Tijd voor een feestje!

Nadat de fix was uitgerold over ons gehele control plane, waren we klaar om de overwinning te vieren, maar we bleven voorzichtig. De afwezigheid van corruptie-incidenten betekent niet automatisch dat alles is opgelost — we hadden immers al eens een misleidende periode van zes weken rust gehad.

We wilden positief bewijs dat deze data race actief voorkwam in onze productieomgeving. Nu we de oorzaak begrepen — een botsing tussen een schrijftransactie en een WAL-reset — hebben we onze SQLite-driver aangepast om een waarschuwing te loggen wanneer deze twee operaties overlappen. Als de waarschuwing afging maar de database niet corrupt raakte, wisten we dat de fix ons had gered van een potentieel incident.

We implementeerden de waarschuwing en wachtten. En we wachtten. En we wachtten. Naarmate de weken verstreken, begonnen we ons af te vragen waarom we niets zagen. Was de waarschuwing kapot? Was onze theorie fout? Lurkte de echte bug nog steeds in het donker?

Twee maanden later ging het alarm waar we op wachtten eindelijk af.

Deze melding bewees dat de precieze condities voor de WAL-Reset bug inderdaad voorkomen in onze productieomgeving, wat betekent dat dit de waarschijnlijke dader was voor onze zes maanden van onstabiele uptime. Sinds die vreemd vreugdevolle melding zijn we (op het moment van schrijven) al vier maanden zonder database-incidenten gedraaid. Eindelijk konden we een zucht van verlichting slaan.

Afwijken van het gebaande pad

Niemand wilde dat we zes maanden besteden aan het zoeken naar bugs in SQLite. Dit was een immens frustrerende ervaring voor zowel onze klanten als ons personeel, en we zijn allemaal blij dat we deze instabiliteit achter ons kunnen laten.

Dit onderzoek is een nuttige herinnering: het op een niet-standaard manier gebruiken van "saaie technologie" brengt risico's met zich mee. De gangbare paden en standaardconfiguraties zijn ongelooflijk goed getest en betrouwbaar. De meeste mensen gebruiken SQLite in een standaardconfiguratie en komen nooit met dit soort problemen in aanraking. Alles wat we deden was een publieke, gedocumenteerde en ondersteunde configuratie — maar door handmatige controle over het checkpoint-proces te nemen en op ons eigen agressieve tempo te draaien, weken we af van het gebaande operationele pad.

Het oplossen van deze incidenten was een enorme, cross-functionele inspanning waarbij tientallen mensen betrokken waren — waaronder de engineering- en supportteams van Tailscale en de core maintainers van SQLite. Dankzij hen is de impact van deze incidenten niet veel erger geweest.

We weten dat herhaaldelijke downtime het vertrouwen schaadt, ongeacht hoeveel mensen erdoor worden getroffen, en we zijn onze klanten dankbaar voor hun geduld en steun terwijl we dit opspoorden.

Hoe frustrerend deze periode ook was, we staan er nu sterker in dan voorheen. De langdurige bug in SQLite is gepatcht en we hebben tientallen andere incidentele problemen opgelost die we tijdens het zoeken ontdekten. We hebben de open-source SQLite VFS shim gefinancierd die hielp om de race condition bijna onmiddellijk te isoleren, wat zal helpen bij het opsporen van soortgelijke bugs in de toekomst. Tot slot hebben we onze database back-up en herstelprocessen verfijnd en deze meer dan een dozijn keer live getest.

Hopelijk komt er geen ander database-incident zoals dit meer voor — maar als dat toch gebeurt, staan we klaar.