Afgelopen maandag hebben we 2x een periode gehad waarin Picqer langzaam werkte. Eerste keer 75 minuten, de 2e keer 30 minuten. Op sommige plekken werd dat zo langzaam dat niet goed met Picqer te werken was. Hierbij een kort overzicht van de gebeurtenissen tijdens de storing en onze acties sinds maandag.
Door het coronavirus draait het Picqer platform sinds begin maart bijna elke dag op het niveau van black friday 2019. We draaien daarom al maanden met extra servercapaciteit en kunnen dit volume goed aan. Maandagen zijn altijd de drukste dagen van de week en met de weersberichten van een zomerse hemelvaartsdag was het echt een drukke dag op ons platform.
Daarmee draaide we maandag op ongeveer 30-40% van onze servercapaciteit, waarbij we normaal mikken op ongeveer 10-20% van de capaciteit.
Op maandag werden er rond 12.00 uur enkele zware taken via onze API ingeschoten door een paar klanten. Het verwerken daarvan ging de eerste 45 minuten goed, zonder gevolgen in de gemiddelde reactietijd.
Het veroorzaakte wel veel nieuwe indexeringen op onze zoekmachine (Elasticsearch). Na 45 minuten zaten de wachtrijen van Elasticsearch vol en konden we geen nieuwe zoekopdrachten meer uitvoeren. In zo'n geval vallen we terug op zoeken via onze SQL database, die daar minder goed in is.
Als er af en toe een zoekopdracht mislukt kan de SQL server die prima opvangen. Maar nu gingen bijna alle zoekopdrachten via de SQL server die dat niet aankon.
Net op deze uitzonderlijk drukke dag konden zowel de zoekmachine als onze database deze zware taken net niet meer aan.
Hierdoor vertraagde alle pagina's binnen Picqer. Pagina's die veel zoekopdrachten doen werden het traagst, zoals het dashboard en het bestellingen overzicht.
Voor de wachtrijen van Elasticsearch hadden we geen monitoring die ons kon waarschuwen. Daarom kwamen we er pas achter toen onze SQL server het druk kreeg en Picqer trager reageerde.
Om 13:38 had onze monitoring het in de gaten en kregen we ook berichten van klanten. Toen startte ons interne onderzoek. Om 13.44 uur hebben we de storing op onze statuspagina geplaatst.
Om 13.45 waren we achter de oorspronkelijke oorzaak en zochten we naar manieren om dit te herstellen.
Om 13:57 uur deden we de eerste deploy van nieuwe code om de oorzaken weg te nemen. Maar het totale volume was nog zo hoog dat onze servers niet bij konden komen. Daarom hebben we op verschillende plekken zoekfuncties uitgeschakeld zodat onze servers rustig konden worden.
Om 14.50 uur was alles weer normaal en schakelde we de zoekfunctionaliteit overal weer in.
Om 16.23 uur liepen we weer tegen de performance van ons Elasticsearch cluster aan, de wachtrijen waren weer langzaam volgelopen. We hebben het aantal Elasticsearch servers verdubbeld en de data laten verdelen over de nieuwe servers. Dit was rond 16:50 uur afgerond waarna alle performance weer normaal werd. Ons team heeft tot 21:30 uur de situatie in de gaten gehouden om snel in te kunnen grijpen bij eventuelen problemen. Maar dat was niet meer nodig.
Uiteraard hadden we deze situatie liever voorkomen. Daarom hebben we er deze week alles aan gedaan om zoveel mogelijk van deze situatie te leren. We hebben enkele wijzigingen gemaakt aan onze software en de servers om deze situatie in de toekomst te voorkomen.
Op maandagmiddag hebben we al extra monitoring toegevoegd op de performance van onze Elasticsearch servers en van de grootte van de wachtrij. Zodra dit op 5% van de capaciteit komt, krijgen we hiervan direct notificaties. Zo kunnen we bij eventuele problemen in een vroeg stadium ingrijpen.
De capaciteit van ons Elasticsearch cluster is blijvend verdubbeld en de verdeling van data is op dinsdag en woensdag verder bijgesteld voor optimale performance.
We hebben nieuwe monitoring om bij te houden hoelang elke zoekopdracht duurt. Ook dit om al in een vroeger stadium in te kunnen grijpen, voordat er merkbare vertraging is.
Sinds dinsdag zoeken we niet meer via onze SQL server als het via Elasticsearch niet gelukt is. Dit voorkomt dat heel Picqer traag wordt bij problemen met Elasticsearch. Voor de API hebben we hiervoor een nieuwe errorcode 42 toegevoegd als de zoekopdracht mislukt is. We hadden al monitoring op wanneer zoekopdrachten mislukten, dat is minder dan 5 keer per maand en zou dus bijna nooit voor moeten komen.
Op dit moment zijn we nog bezig om de zware taken die de oorzaak waren lichter te maken. Deze veroorzaken nu veel drukte op de zoekmachine wat niet per se nodig is. We proberen deze zware taken slimmer te maken zodat ze lichter zijn voor ons platform om te verwerken.
Onze excuses voor deze storing. Met bovenstaande wijzigingen hebben we vertrouwen dat deze en soortgelijke situaties in de toekomst minder snel zullen voorkomen.
Mocht je nog vragen hebben over deze storing, dan horen we dat graag op info@picqer.com.
Casper Bakker