Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

Appearance settings

Commit 3de0f96

Browse filesBrowse files
committed
Fix #948
Oke, een korte uiteenzetting van waardoor het komt dat de stek af en toe niet meer wil werken en de op dit moment gevonden oplossing(en). Zoals ik het nu zie gaat het mis als er twee processen zijn die op hetzelfde moment bezig zijn met het berekenen van een waarde in de cache. Het ene proces berekent een waarde met sleutel `a` en heeft voor die waarde een waarde met sleutel `b` nodig, en het andere process berekent een waarde met sleutel `b` en heeft hier een waarde met sleutel `a` nodig. Voordat het systeem een waarde gaat berekenen lockt het proces de sleutel, zodat er geen andere processen dezelfde waarde gaan berekenen, maar netjes wachten totdat het huidige proces klaar is met berekenen. De processen wachten nu op elkaar totdat ze klaar zijn (of totdat ze afgeschoten worden). Oftewel je klassieke [deadlock](https://en.wikipedia.org/wiki/Deadlock) probleem, en ook al worden processen afgeschoten na een paar seconden ontstaat er zo een gigantische wachtrij aan requests dat het bijna onmogelijk is om hier bovenop te komen en zorgt de vloed aan processen er voor dat nieuwe deadlocks ontstaan. Maar hoe kan dit probleem dan ontstaan? In de code hebben we nergens dat er een deadlock zou moeten kunnen ontstaan omdat dingen elkaar nodig hebben bij het vullen van de cache. Als er iets in de cache moet worden gemaakt wordt er inderdaad soms nóg iets nieuws in de cache gezet, maar dit is áltijd kleiner (en heeft dus niet dezelfde sleutel). Er zijn op dit moment twee onderdelen die expliciet cachen: - Menu, deze bevat Permissie (per menu item wordt aangegeven wie deze mag zien) - Permissie, deze bevat een substring van Permissie (bijv: `bestuur,commissie:SocCie` moet `bestuur` en `commissie:SocCie` opzoeken) (noot: in de huidige versie wordt hier geen recursieve cache-lookup meer gedaan) Op deze manier kan niet zomaar een deadlock ontstaan, omdat er geen overlap bestaat in sleutels. (Als a er voor zorgt dat b nodig is, zal het nooit voorkomen dat b er voor zorgt dat a nodig is) Het probleem zit hem vooral in de oude implementatie van het locken in symfony/cache. De locks werden aangemaakt mbv bestanden, er werden 23 bestanden gebruikt om locks te creëren voor het schrijven naar de cache. Waarschijnlijk omdat het te zwaar is om nieuwe bestanden naar de schijf te schrijven en omdat je sowieso zeker weet dat deze bestanden daar staan. De volgende code werd gebruikt om een sleutel te genereren (uit `symfony/cache:5.3`): ```php $key = self::$files ? abs(crc32($item->getKey())) % \count(self::$files) : -1; ``` Dit zorgt ervoor dat er maar 23 verschillende sleutels zijn. Nu is de kans opeens erg groot dat sleutel a een waarde met sleutel b bevat en omgekeerd, het gaat hier namelijk om honderden lookups als een pagina voor het eerst wordt geladen (ongeveer 350 voor de thuispagina met een lege cache). Deze sleutels zijn ook nog eens gedeeld tussen processen. Een nieuwe deploy met een lege cache heeft nu opeens een best grote kans op een deadlock, zeker als er verschillende mensen tegelijk de stek bezoeken en er pagina's met honderden plaatjes parallel geladen worden. De nieuwe logica (met semaphores, aka php's ingebouwde manier van locks fixen zonder bestanden) zijn er zo'n 4.4 miljard verschillende locks te verkrijgen en is de kans op dubbele sleutels véél kleiner geworden. Dit is de code die nu de sleutels genereerd (uit `symfony/cache:5.4`): ```php $key = unpack('i', md5($item->getKey(), true))[1]; ``` De kans dat de md5 hashes van twee verschillende sleutels hetzelfde is is heel erg klein (én dat dit twee keer op hetzelfde moment gebeurt én dat het precies zo gebeurt dat er een deadlock ontstaat). Ik denk dat het voorkomen van geneste cache lookups nog steeds iets is wat we moeten fixen, zodat vergelijkbare problemen niet nog een keer voorkomen. En het uberhaupt niet kan voorkomen dat er eventueel een deadlock ontstaat hier. Helaas is deze verandering weer terug gedraaid omdat semaphores blijkbaar op andere plekken voor onverwachte problemen kunnen zorgen. Deze fout zit dus nog steeds in en dus zijn geneste cache lookups in symfony/cache gevaarlijk omdat ze snel deadlocks kunnen veroorzaken. Daarnaast vraag je je misschien af, waarom zou je het laden van de cache locken? Fix je al deze problemen niet gewoon door potentieel dingen vaker te berekenen, ook al kost dat wat extra rekenkracht. Dit cachen is geimplementeerd om ["Cache Stampede"](https://en.wikipedia.org/wiki/Cache_stampede) te voorkomen. Het idee hiervan is dat bij een lege (of verlopen) cache het kan zijn dat heel veel mensen tegelijk een specifieke waarde willen hebben en dat je de server kan overbelasten als je dit allemaal wil berekenen en dat het dus beter is om de waarde maar één keer te berekenen en de rest maar te laten wachten. In de stek is dit niet een heel erg reeel probleem, maar zou er kunnen zorgen dat de stek nóg meer onder druk komt te staan na een nieuwe deploy, zeker als op een later moment nog meer dingen in een cache belanden (die misschien nog zwaarder zijn om te berekenen). Ik denk dat cache stampede voor ons geen reëel probleem is op dit moment en dat we dit op dit moment kunnen uitzetten. De boel refactoren om vanuit Menu een call te doen naar een niet-gecachede permissie check is misschien ook iets moois om te hebben. Zeker als we op een later moment nog meer coole dingen met de cache gaan doen, maar dan is het misschien ook een goed idee om de cache op te splitsen. Het vinden van deze bug was een flinke klus, de fout was niet zomaar te reproduceren, en soms zat er maanden tussen twee crashes. De laatste weken ging de frequentie omhoog, en daarmee ook de urgentie. Op een gegeven moment konden we wel binnen vijf minuten zeggen dat de stek eruit lag, maar hadden we nog geen idee waar het precies vandaan kwam. Gelukkig kwamen we op een gegeven moment de slowlog optie in de server tegen, deze optie schiet een te lang draaiend proces af én geeft een overzicht van wat dat proces op dat moment aan het doen was. Hierna was het al snel duidelijk waar de fout voorkwam en kon er gericht gezocht worden naar een oplossing (schreeuw uit naar @knorrie voor het instellen van slowlog én het scherp lezen van de logs). Hopelijk is dit de daadwerkelijke oorzaak van deze fout en kunnen we na bijna anderhalf jaar (sinds 24/06/2020!) dit hoofdstuk afsluiten. Linkjes: - Een melding van een vergelijkbaar probleem: symfony/symfony#41130 - De fix voor het aantal sleutels in symfony/cache: symfony/symfony#41989 - Documentatie over slowlog: https://robertbasic.com/blog/php-fpm-slow-log/ - Fix in hasPermission in de stek (en de introductie van een nieuwe bug, kan jij m spotten?): e0b7a66
1 parent 210f9ed commit 3de0f96
Copy full SHA for 3de0f96

File tree

1 file changed

+12
-0
lines changed
Filter options

1 file changed

+12
-0
lines changed

‎lib/Kernel.php

Copy file name to clipboardExpand all lines: lib/Kernel.php
+12Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -8,17 +8,29 @@
88
use CsrDelft\view\bbcode\prosemirror\Mark;
99
use CsrDelft\view\bbcode\prosemirror\Node;
1010
use Symfony\Bundle\FrameworkBundle\Kernel\MicroKernelTrait;
11+
use Symfony\Component\Cache\LockRegistry;
1112
use Symfony\Component\DependencyInjection\ContainerBuilder;
1213
use Symfony\Component\DependencyInjection\Loader\Configurator\ContainerConfigurator;
1314
use Symfony\Component\HttpKernel\Kernel as BaseKernel;
1415
use Symfony\Component\Routing\Loader\Configurator\RoutingConfigurator;
16+
use Symfony\Contracts\Cache\CacheInterface;
1517

1618
/**
1719
* Configureer waar configuratie bestanden te vinden zijn.
1820
*/
1921
class Kernel extends BaseKernel {
2022
use MicroKernelTrait;
2123

24+
public function __construct(string $environment, bool $debug)
25+
{
26+
parent::__construct($environment, $debug);
27+
28+
// Gebruik geen cache stampede beveiliging
29+
// https://github.com/csrdelft/csrdelft.nl/issues/948
30+
LockRegistry::setFiles([]);
31+
}
32+
33+
2234
/**
2335
* @param ContainerConfigurator $container
2436
*/

0 commit comments

Comments
0 (0)
Morty Proxy This is a proxified and sanitized view of the page, visit original site.