Recras storing op 9 december 2019

Leestijd: 10 minuten

Op maandag 9 december om 15:58 kreeg Recras te maken met een crash. Wat we toen nog niet wisten was dat dit wel eens de grootste storing in de historie van Recras kon worden, waarbij we 4 uur offline waren met als overmaat van ramp ook nog eens 13 uur aan dataverlies. Een bijzonder slecht scenario dat we niet hadden zien aankomen. Juist het altijd online zijn hebben we altijd en bijzonder hoog op onze agenda.

In dit verslag kun je lezen wat er is gebeurd — maar ook zeker zo belangrijk — wat we ervan geleerd hebben en welke maatregelen we al hebben genomen, nog zullen nemen en welke maatregelen onze gebruikers kunnen nemen om dit nooit weer te laten plaatsvinden.

Hoe de verloren data terug beredeneerd kan worden kun je hier lezen.

Zo werkt Recras

Om het probleem te kunnen begrijpen is het eerst belangrijk om te weten hoe Recras werkt. In het voorjaar van 2019 zijn we overgestapt naar een nieuwe databasestructuur. We zijn overgestapt naar de omgeving van Kubernetes in combinatie met Galera. Hieronder probeer ik uit te leggen wat dit inhoudt:

De servers

Recras draait synchroon op 2 servers. Naarmate Recras groter wordt kunnen we in de toekomst eenvoudig opschalen naar meerdere servers. Wat dat betreft zijn we technisch klaar om 10 keer zo groot te worden.
Iedereen die iets wijzigt of toevoegt aan Recras werkt op een van deze servers.
Een load balancer verdeelt alle werkzaamheden evenredig over beide servers. Daarmee werken alle gebruikers continu afwisselend op beide servers.
Het synchroon opereren van de servers wordt geregeld via Galera.
Galera werkt met een meerderheid (3 instanties verdeeld over 3 locaties), in de situatie van Recras is dit opgedeeld in 2 datanodes en 1 arbiter, de meerderheid bepaalt de algehele status.
Galera werkt met een principe dat alle nodes een wijziging moeten goedkeuren alvorens deze wordt toegepast, dit zorgt ervoor dat de databases synchroon blijven.
Het geheel hangt in een cluster van Kubernetes; dat zorgt ervoor dat Recras in principe 24/7 bereikbaar is. Een kwaliteit van Kubernetes is dat processen automatisch worden herstart als er iets mis gaat, de taak van Kubernetes is om processen aan de praat te houden.
Als er een server crasht dan neemt de andere server Recras over. Ook onderhoud kan hierdoor bijna altijd zonder downtime plaatsvinden, want we werken dan even met zijn allen op 1 server.

Backup protocol (voordat de crash plaatsvond)

Iedere nacht wordt er een versleutelde backup gemaakt van heel Recras.
Iedere 10 minuten worden er logs gemaakt van alle wijzigingen die de afgelopen 10 minuten hebben plaatsgevonden, dit zijn de zogenaamde binlogs (binaire logboeken).
In geval van een crash kunnen de backups worden teruggezet en daar kunnen dan de binlogs aan toe worden gevoegd.

Partner Osso

Het serverbeheer wordt geregeld door onze partner Osso uit Groningen. Dat is een bedrijf dat is gespecialiseerd in serverbeheer in combinatie met Kubernetes en Galera. Het mooie is dat ze ook een kantoor hebben in de Mediacentrale, het gebouw waar Recras ook is gevestigd. We kunnen dus altijd even snel overleggen.

De aanloop naar de storing toe

Op 9 december liepen er al een aantal keren wat zaken niet helemaal goed. Hieronder het verslag in tijden van de dag.

11:46 Osso meldt dat 1 server vreemde errors geeft op 1 van de database-instanties. De programmeurs van Recras onderzoeken of er een deploy stuk loopt. Dat is nieuwe code die aan Recras wordt toegevoegd (het moment dat Recrasleden in beeld krijgen dat er een update is geweest). Maar er is niets geks te zien.

14:15 Osso meldt dat er weer problemen optreden en er weer een database-instantie is gecrashed.

15:58 Recras vliegt eruit, alle alarmbellen gaan af. Beide galera datanodes zijn gecrashed. De mensen van Osso proberen de database-instanties te herstarten maar deze crashen direct weer.

16:15 We trekken de conclusie dat er data-corruptie is opgetreden op beide database-instanties, er wordt nog geprobeerd met een aantal andere oplossingen de boel weer aan de praat te krijgen, dit lukt niet.

16:23 Tot overmaat van ramp blijken de binlogs gedurende de dag te zijn opgeruimd doordat beide database-instanties al een keer waren gecrashed en de data van de collega-galera-node hadden gekregen. De data van vandaag is daarmee verloren gegaan. We proberen nog een aantal manieren in de hoop het dataverlies van de dag te vermijden.

17:04 We concluderen dat het onvermijdelijk is om de backup van de afgelopen nacht 01:19 terug te zetten en dat alle data van vandaag verloren is gegaan. Dat wordt een slecht-nieuws-mededeling aan alle Recrasleden.

17:14 De backups die Recras kan terugzetten zijn versleuteld; dat betekent dat al zou iemand deze backup in handen krijgen dat die de data niet kan lezen. Het decrypten duurt langer dan gehoopt, zo’n 2 minuten per Recras. Dat is balen maar we kunnen niet anders dan wachten.

18:51 De decryptie is klaar en alles kan weer worden teruggezet. Het goed installeren neemt nog flink wat tijd in beslag.

19:40 Recras draait weer op 1 database-instantie. Het wordt spannend om morgen weer helemaal live te gaan.

Hoe kon het zo mis gaan?

Door een bug in MariaDB (onze database-oplossing) ontstond er corruptie toen een nieuwe functionaliteit in gebruik werd genomen.
Door deze situatie konden bepaalde queries (opdrachten voor de database) niet worden uitgevoerd. Deze queries werden echter wel in gang gezet en daardoor crashte de database op 1 server. Deze werd vervolgens automatisch weer herstart.
Door deze situatie was Recras nog wel online op de andere server omdat Recras op 2 fysiek verschillende locaties draait.
Na het crashen wordt de server/database automatisch weer herstart en komt terug in de poule met servers.
De arbiter en de server die online waren gebleven hebben samen tweederde gewicht als het gaat om te bepalen welke data de juiste data is.
Omdat de server die uitviel achter liep qua data krijgt die de missende data terug van de andere server.
Omdat de consistentie van de data niet zeker was is de gehele dataset vervangen. Met deze handeling zijn ook de binlogs verdwenen, die op dezelfde server bewaard werden.
Geen problemen nog want de andere server beschikte ook nog over de binlogs.
Echter een paar uur later gebeurde precies het omgekeerde: de server die zich aan het begin van de dag goed hield begon nu tegen problemen aan te lopen.
Na verloop van tijd werd ook die server herstart en werden daar de binlogs verwijderd.

Communicatie

Zodra Recas eruit ligt staat de telefoon op kantoor roodgloeiend, want alle gebruikers krijgen een scherm dat ze het noodnummer moeten bellen. Vaak weten wij het al voor die tijd en de meeste problemen kunnen zelfs opgelost worden voordat een gebruiker hier weet van heeft. Hier heeft Osso allemaal automatische meldingen voor ingebouwd.

We zetten het noodnummer in zo’n situatie over op de melding dat we weten dat Recras eruit ligt en dat we er hard aan werken. Dat zorgt ervoor dat we met zijn allen gefocust kunnen blijven werken aan het probleem.

Via recras.com/status informeren we dan onze gebruikers. Hieronder de tijdlijn van deze meldingen.

16:04 Eerste melding via statusupdates dat we eruit liggen

16:04 Voicemail wordt omgezet en Twitterbericht eruit

16:20 Update dat het aan de database ligt

16:26 Update proberen dataverlies te voorkomen

17:05 Waarschijnlijk slecht nieuws, data van vandaag verloren

17:48 Herstellen van data gaat lang duren

18:06 Een mail eruit aan onze leden

19:43 Recras is weer online

20:06 Laatste update

23:00 Pagina op website gelanceerd: Zie hier

23:00 Telefoonplan weer teruggezet

Het is erg belangrijk voor ons om de impact van het probleem goed te beschrijven zodat alle leden weten wat er is gebeurd en wat ze er aan kunnen doen om nog te proberen na te gaan welke offertes ze de afgelopen dag hebben verstuurd. Op die manier weet iedereen wat te doen en dat voorkomt over het algemeen vele telefoontjes die allemaal hetzelfde zijn.

Dinsdag 10 december

De meesten van ons hebben niet echt fijn geslapen en al vroeg bevinden we ons weer op kantoor. Vandaag is het zaak om goed te communiceren naar alle leden en het zou mooi zijn als alle leden aan het einde van de dag hun Recras-werkzaamheden weer hebben hersteld.

Achter de schermen wordt hard gewerkt aan het repareren van de database-omgeving, want we werken nog steeds op 1 database-instantie en we willen weer opschalen naar onze Galera-omgeving met 2 database-instanties. Zodra we dat doen gaat het helaas weer mis. Er blijkt toch nog een fout in de database te zitten die we gisteren nog niet hadden gevonden. Gelukkig hadden we voordat we dat gingen doen een snapshot gemaakt, dat is een momentopname waar we altijd naar terug kunnen, zodat we niet weer terug hoeven naar de backup van afgelopen nacht. Toch is er weer een half uur aan data verloren gegaan.

Eerst wordt nog eens uitvoerig onderzocht wat er gisteren allemaal is geüpdate en op welke tijdstippen.

Updates op Maandag 9 december

09:37 “nieuwe online boeken / contactformulier” standaard aan voor nieuwe
leden

09:49 refactoring mbt boekprocessen

09:53 tag “boeking productpresentatie”

10:32 boeking bewerken verbeteren

14:14 boekingsregels slepen

15:18 bedrijf in dagplanning

Gezien het tijdstip van de servermeldingen van 14:15 besluiten we om de wijziging met betrekking tot boekingsregels verslepen ongedaan te maken. Ook dit proces hebben we perfect op orde. Echter dit helpt helaas ook niet. Steeds als we denken het opgelost te hebben zit er toch nog weer iets nieuws in de weg. Het gaat de hele ochtend zo door.

Er wordt door de techneuten besloten de complete indexering opnieuw op te bouwen, zodat alle verwijzingen kloppen.

Ondertussen blijven we communiceren via onze status-updatepagina dat er nog hard wordt gewerkt en dat we onze leden afraden om met Recras te werken. We prijzen onszelf gelukkig dat het december is en dat het niet een zaterdag in juni is, waarop alle Recrasleden op volle toeren hun bedrijven aan het runnen zijn.

Langzaam komt er licht aan de horizon en zijn de techneuten er redelijk zeker van dat het euvel moet zijn opgelost. Rond 13:00 draait Recras weer stabiel op 1 server. Maar we willen weer terug naar onze standaardsituatie waarbij we draaien op 2 servers. In overleg met Osso wordt besloten eerst weer een snapshot te maken (daardoor ligt Recras er weer een minuut uit) maar als het mis dreigt te gaan bij het opschalen naar 2 servers dan kunnen we in ieder geval weer terug naar de situatie van een minuut geleden en verliezen we niet opnieuw data. Het is bizar hoe je je grenzen aanpast. Normaal gesproken is een minuut offline onacceptabel voor ons, maar om erger te voorkomen leek ons dit absoluut de beste keus en vinden we het een goed idee.

De tweede server wordt er weer bij geplaatst en alles lijkt stabiel. Wat een enorme opluchting. De communicatieafdeling krijgt groen licht om de boodschap te verkondigen dat er weer in Recras gewerkt kan worden en dat alles stabiel lijkt.

Gingen er ook nog dingen goed?

Uiteraard gaan er nooit alleen maar dingen fout, wat ons betreft ging er ook best veel goed. We zijn blij dat we voor dergelijke situaties goede protocollen hebben waar we op terug kunnen vallen en dat we snel en adequaat kunnen handelen. Hieronder een aantal punten waar wij tevreden over waren.

Communicatie en samenwerking met onze partner Osso ging goed.
De nachtelijke backups die we hebben gemaakt konden worden uitgepakt en opnieuw geïnstalleerd.
Het crisisteam was in een paar minuten paraat en nam adequate beslissingen.
Communicatie richting de Recrasgebruikers verliep goed.
We vinden het bijna hartverwarmend hoeveel begrip de meeste Recrasleden hadden voor de vervelende situatie waarin we ons bevonden en sommigen staken ons een hart onder de riem. In de vorm van mailtjes en berichtjes, en we kregen zelfs bier per post.

Spoedoverleg – wat kan Recras op de achtergrond verbeteren

Nadat we weer in de lucht zijn volgt er een spoedoverleg tussen Recras en Osso.

Hier worden direct oplossingen besproken die snel geïmplementeerd kunnen worden. De volgende punten zijn hierbij het belangrijkst:

Hoe heeft het kunnen gebeuren dat de logboeken/binlogs verdwenen en hoe kunnen we dat voorkomen?
Waarom duurde het decrypten van de backup zo lang, is hier geen snellere oplossing voor?

Kortom als we nog eens een soortgelijke situatie hebben willen we zo min mogelijk dataverlies en zo snel mogelijk weer online.

De volgende afspraken worden gemaakt.

Uitgevoerde kortetermijnmaatregelen

De binlogs/logboeken zullen iedere 10 minuten veilig worden gesteld.
Naast de bestaande ge-encrypte backup wordt er een extra nachtelijke backup gedraaid, die wordt opgeslagen op de server waar ook Recras op draait.
Deze extra backup kan worden ingezet voor een snelle recovery op 1 node. Daar kunnen vervolgens door een replay te doen van de de binlogs, de data weer aangevuld worden. Dit proces zou snel, misschien wel in een kwartier, klaar moeten zijn. Dit gaan we in het nieuwe jaar echter nog testen.

We zijn blij met onze partner Osso, alle punten die zijn besproken zijn inmiddels (een dag na de crash) ook uitgevoerd.

Verdere opvolging

Testomgeving gelijk trekken met productieomgeving, zodat de configuratie en versies overeenkomen met productie. Dit vergroot de kans dat gelijksoortige databasebugs al in het ontwikkelingsproces aan het licht komen. Recras doet hierdoor ook meer ervaring op met de Galera-mechanismen.
Jaarlijks testen van de recovery procedure. Waarin herstel getest wordt en bijgesteld kan worden naar de dan geldende eisen en inzichten. (bijvoorbeeld hersteltijd)
Encryptiemethode aanpassen met oog op sneller herstel.
Meenemen ervaring in verbeterproces van zowel Osso als Recras.

Factuur-PDF’s nog teruggehaald

Aangemaakte PDF’s 9 december konden nog worden teruggehaald, omdat de PDF’s op een andere locatie werden opgeslagen. De factuur PDF’s zijn gemaild naar de betreffende Recrasleden.

Nog een aanbeveling voor Recras m.b.t. opslag van PDF’s

Zorgen dat in de bestandsnaam van PDF’s datum-tijd wordt opgeslagen. Dan kan de PDF niet worden overschreven op het moment dat hetzelfde bestand op een ander moment nogmaals wordt aangemaakt.

Wat kan Recras aan de gebruikerskant verbeteren

Omdat we nog nooit met dataverlies te maken hadden gehad zijn we hier in onze advisering naar leden ook nooit heel uitgebreid op ingegaan. Nu bleek pas hoe vervelend het is als je echt niet meer kunt achterhalen wat je in je Recras hebt gedaan. Het is frustrerend als je instellingen zijn verdwenen waar je mee bezig bent geweest, maar die zaken kun je over het algemeen prima opnieuw instellen.

Het is vooral vervelend dat je weet dat je een mooie nieuwe aanvraag had en dat je niet meer weet wie dat is geweest. Of dat er mensen een online boeking hebben gedaan die ook keurig een ticket hebben gekregen maar ze staan niet meer in je systeem.

Hieronder staan 2 belangrijke punten waar de Recrasleden en ook het programma Recras wat kunnen doen om in geval van dataverlies toch te kunnen achterhalen wat er was verstuurd.

Leden attenderen op in te stellen BCC-mailadres

Je kunt in Recras een BCC-mailadres instellen. Er wordt dan van alle mails die door Recras verstuurd worden een blinde kopie naar dit mailadres gestuurd. Dit kan als backup van je gegevens een handig middel zijn. Zie hier meer informatie over het instellen van een BCC mailadres.

Melding ingevuld contactformulier uitbreiden

Bij contactformulier-instellingen kun je instellen dat er een melding wordt gemaild aan een bepaald mailadres op het moment dat er een nieuw formulier is ingevuld. Echter in die mail zie je vervolgens niet de inhoud van het ingevulde formulier. Als je dat wel zou zien, dan kun je in de mailbox de inhoud van de aanvraag zien en dan had je in het geval van afgelopen maandag in ieder geval kunnen achterhalen wat de aanvraag was geweest. Deze fix zullen we op korte termijn uitrollen.

Hoe kunnen we alle leden bereiken in geval van een calamiteit?

Op het moment dat we alle Recrasleden willen bereiken, gebruiken we de lijst die we ook gebruiken om de nieuwsbrief te sturen. Echter kunnen we niet garanderen dat die compleet is. Gebruikers kunnen zich afmelden voor de nieuwsbrief of er zijn nieuwe mensen hoofdverantwoordelijk geworden voor Recras in de loop der tijd, terwijl die niet lid waren van de nieuwsbrief.

We hebben besloten dat we bij een volgend moment dat er informatie met alle Recrasleden gedeeld moet worden, we een mail sturen naar het mailadres dat is ingesteld bij het bedrijf in Recras. (Overig – Bedrijfsgegevens – Bedrijf selecteren).

Uiteraard blijven we werken met recras.com/status daarmee kunnen we snel belangrijke informatie delen.

Tot slot

Het waren twee intense dagen waarin wij een grote verantwoordelijkheid voelen voor alle Recrasleden om de boel goed aan de praat te houden. We balen van het dataverlies dat is opgetreden. Maar het is mooi dat we al acties hebben kunnen treffen waardoor de kans op een soortgelijke situatie veel kleiner is geworden. Daarnaast hebben we nog punten om Recras nog beter en betrouwbaarder te maken. En we zijn blij met de support van de professionals van Osso. We zijn blij dat we deze samenwerking zijn aangegaan.