Je vais ici résumer les détails d'une investigation technique sur un problème de performance MariaDB assez conséquent, faisant passer certaines requêtes de 5ms d'exécution à ~30min !
Contexte
En juin 2021, pour un de nos clients Occitech, nous avons effectué une assez grosse itération :
- montée en version Magento2
- montée en version PHP
- ajout de nouvelle features
À la mise en production, après notre période de validation habituelle en préproduction, nous avons été confrontés à beaucoup de soucis de performances.
La matinée étant passée et n'arrivant pas à corriger tous les soucis en production, la décision de "rollback" a été prise afin de nous donner le temps d'investiguer et corriger les différents bug sans pression.
Parmi les différents soucis, celui qui nous intéresse ici est qu'une requête sql était devenue beaucoup trop lente : environ ~30min
Reproduction
Données
Afin de trouver le coupable, il nous est nécessaire d'arriver à reproduire le problème en local. Pour cela nous avons :
- Récupéré la base de données de production
- Identifié et récupéré la requête SQL qui pose souci :
SELECT `e`.`entity_id`, IFNULL(st1.value, t1.value) AS `X`, IFNULL(st2.value, t2.value) AS `XX`, IFNULL(st3.value, t3.value) AS `XXX`, IFNULL(st4.value, t4.value) AS `XXXX`, [...]
FROM `catalog_product_entity` AS `e`
LEFT JOIN `catalog_product_entity_int` AS `t1` ON e.entity_id = t1.entity_id AND t1.attribute_id = 1689 AND t1.store_id = 0
LEFT JOIN `catalog_product_entity_int` AS `st1` ON e.entity_id = st1.entity_id AND st1.attribute_id = 1689 AND st1.store_id = 1
LEFT JOIN `catalog_product_entity_int` AS `t2` ON e.entity_id = t2.entity_id AND t2.attribute_id = 2094 AND t2.store_id = 0
[...]
Note : Je n'ai pas mis la requête en entier
Cette requête SQL provient du système d'indexation du catalogue produit dans une table à plat : https://docs.magento.com/user-guide/catalog/catalog-flat.html.
Note : Ce mécanisme est déprécié, cependant certaines de nos extensions ont encore besoin de cette table et il n'était donc pas encore prévue de notre coté de ne plus utiliser cette table.
Afin que cette table reste à jour, une requête sql d'indexation est effectuée. Cette requête est assez conséquente et réalise 32 jointures !
Environnement
Maintenant que notre environnement local possède les même données que le site de production, nous pouvons tenter d'exécuter la requête SQL qui pose problème et investiguer.
Mmmmh, en local la requête mysql en question ne pose pas de souci, elle s'exécute en 5ms ! Sur le serveur (avec les même données donc) elle prend cependant bien toujours 30min !
Bien qu'utilisant Docker afin d'avoir la même configuration de projet que le serveur de production, un détail nous est passé entre les doigts. Sur le serveur de production MariaDB est en 10.4, mais notre version local est en 10.3.
Une fois notre configuration Docker à jour, nous avons réussi à reproduire le souci.
Bonne nouvelle ! Nous allons pouvoir nous pencher à sa résolution.
Résolution
EXPLAIN
La requête sql incriminée est rapide avec MariaDB 10.3 mais extrêmement lente avec MariaDB 10.4, qu'est ce qui a pu provoquer cela ?
Afin de mieux comprendre ce qui ce passe avec cette requête, nous allons utiliser EXPLAIN afin d'avoir plus d'informations :
Lorsque MariaDB réalise des jointures, il a une liste des index qu'il peut utiliser, et en se basant sur ces index il décide d'en utiliser ou non.
Avec MariaDB 10.3, on peut voir qu'on a seulement des jointures de type eq_ref (cf https://stackoverflow.com/questions/4508055/what-does-eq-ref-and-ref-types-mean-in-mysql-explain) qui permet de très bonne performance. Dans notre cas, ceci est possible grace à l'index CATALOG_PRODUCT_ENTITY_INT_ENTITY_ID_ATTRIBUTE_ID_STORE_ID qui est unique.
Avec MariaDB 10.4, on peut voir que certaines jointures sont de type ref (cf https://stackoverflow.com/questions/4508055/what-does-eq-ref-and-ref-types-mean-in-mysql-explain), ce qui a des très mauvaise performance sur autant de données. MariaDB ignore notre index CATALOG_PRODUCT_ENTITY_INT_ENTITY_ID_ATTRIBUTE_ID_STORE_ID.
Cela n'a pas vraiment de sens dans notre cas, car :
- notre requête SQL réalise 32 fois la jointure sur la même table / même colonne
- nous avons un index CATALOG_PRODUCT_ENTITY_INT_ENTITY_ID_ATTRIBUTE_ID_STORE_ID à disposition que MariaDB devrait utiliser.
Recherches google
Avec les informations que nous avons collecté :
- avec MariaDB 10.3 cela marche, mais pas avec MariaDB 10.4
- le type de jointure utilisé change pour les même types de jointures
on a un bon début de piste pour trouver une réponse via des recherches googles (personne ayant eu le même souci, issues github, bug reporté, etc...)
Après plusieurs recherches et plusieurs mauvaises pistes, nous sommes tombés sur ce report de bug : https://jira.mariadb.org/browse/MDEV-21377
Explications
Il s'avère que MariaDB en version 10.4 a changé la valeur par défaut de la variable optimizer_use_condition_selectivity (cf https://mariadb.com/kb/en/server-system-variables/#optimizer_use_condition_selectivity).
Cette valeur passe de 1 à 4. Ce changement de valeur par défaut change la stratégie utilisée pour choisir le type de jointure à effectuer.
Le souci que l'on a, c'est qu'il y a un bug (encore non résolu) justement sur l'optimisation des JOINTURES lorsque optimizer_use_condition_selectivity est > 1 (cf https://jira.mariadb.org/browse/MDEV-21377)
Cela fait que MariaDB n'utilise pas la bonne stratégie et amène à des performances misérables sur des grosses requêtes avec des jointures et c'est notamment le cas de notre requête.
Résolution
En fixant la valeur de l'option optimizer_use_condition_selectivity à 1 , nous avons pu avoir le même comportement que MariaDB 10.3 et donc diviser notre temps d'indexation par 360 000 !
Informations complémentaires
Magento semble au courant de problème et celui-ci est documenté ici : https://devdocs.magento.com/guides/v2.4/install-gde/prereq/mysql.html#instgde-prereq-mysql-config (en bas de page)
Reindexing on MariaDB 10.4 takes more time compared to other MariaDB or MySQL versions. To speed up reindexing, we recommend setting these MariaDB configuration parameters:
- optimizer_switch=’rowid_filter=off’
- optimizer_use_condition_selectivity = 1
Merci Cédric pour l'information !
Conclusion
Ce bug n'a pas été facile à résoudre. Entre le temps d'analyse des soucis en production, la tentative de reproduction, l'identification du souci et la résolution, il nous a fallu environ ~2J.
Deux choses nous ont aidé à l'identification / résolution :
- Docker !
En très peu de temps nous avons pu lancer MariaDB en différentes versions avec les même données afin de réaliser les comparatifs. Sans cela, cela aurait été très complexe et long d'identifier le bug.
- Post-Mortem !
Après notre mise en production ratée, nous avons écris en détail et horadaté les différentes actions entreprises, les bugs constatés, à quel niveau etc.. Cela nous a permis de rapidement identifier et récupérer la requête SQL fautive.
