Lenteur de MySQL, Drupal, Views & User Relationship
Suite à la mise en production d’une nouvelle version d’un gros site communautaire basé sur Drupal, le serveur ne répondait plus au bout d’une heure… Une rapide étude avec la commande top permet de voir que la base du site semble surchargée. Première décision prise avec le client : séparer la base MySQL et Apache sur deux serveurs. Deux heures plus tard, la base du site tombe à nouveau…
Dans cet article je vais retracer les étapes pour identifier et corriger le problème.
1. Activation du log des requêtes lentes MySQL
Alors qu’il est 2 heures du matin et que le trafic est assez faible, la base tombe. Le probleme vient donc forcement des changements de la nouvelle version. Toute fois, entre la version précédente et celle en ligne on a 200 revisions sur plusieurs dizaines de fichiers, sans parler des modifications en base de données sur les Panels et Views… Autant dire qu’il serait trop long d’analyser chaque révision SVN. On va donc aller identifier la ou les requêtes qui posent problème.
Premiere étape : activer le log des requêtes lentes sur MySQL. Pour cela, il faut aller éditer le fichier de configuration MySQL my.cnf. Il se trouve probablement dans
/etc/my.cnf
Dans la séction [mysqld], rajouter ou éditer les lignes suivantes :
log-slow-queries = /var/log/mysql-slow-queries.log long_query_time = 1
MySQL va alors logguer toutes les requêtes dont le temps d’exécution est supérieur à 1 seconde. En fonction du site que vous avez ou des problèmes constatés, il serait peut-être judicieux d’augmenter ce paramètre.
Redémarrez MySQL avec la commande
/etc/init.d/mysql restart
Laissez tourner le site quelques instants histoire de remplir le log.
2. Étude du log des requêtes lentes
Une fois rempli, vous pouvez étudier les requêtes avec un vim ou en utilisant la commande mysql : mysqldumpslow
mysqldumpslow -s c -t 10
Chez nous, la requete suivante posait problème, avec plus de 300 secondes pour s’exécuter… !
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 | SELECT DISTINCT(node.nid), bio_node_data_field_photo.field_photo_fid AS bio_node_data_field_photo_field_photo_fid, bio_node_data_field_photo.field_photo_title AS bio_node_data_field_photo_field_photo_title, bio_node_data_field_photo.field_photo_alt AS bio_node_data_field_photo_field_photo_alt, node_data_field_user_motto.field_user_motto_value AS node_data_field_user_motto_field_user_motto_value, user_relationships.approved AS user_relationships_approved, node.title AS node_title, node.changed AS node_changed, user_bio.uid AS node_uid, user_relationships_add_friend.approved AS user_relationships_add_friend_add_friend_link, bio.nid AS bio_nid FROM node node LEFT JOIN user_relationships user_relationships_to_user ON node.uid = user_relationships_to_user.requester_id LEFT JOIN user_relationships user_relationships_to_user2 ON node.uid = user_relationships_to_user2.requester_id LEFT JOIN node bio ON node.uid = bio.uid AND bio.type = 'bio' LEFT JOIN content_type_bio bio_node_data_field_photo ON bio.vid = bio_node_data_field_photo.vid LEFT JOIN content_type_bio node_data_field_user_motto ON node.vid = node_data_field_user_motto.vid LEFT JOIN user_relationships user_relationships ON node.uid = user_relationships.requestee_id LEFT JOIN bio user_bio ON node.nid = user_bio.nid LEFT JOIN user_relationships user_relationships_add_friend ON node.uid = user_relationships_add_friend.requester_id INNER JOIN node_access na ON na.nid = node.nid WHERE (na.grant_view >= 1 AND ((na.gid = 0 AND na.realm = 'all') OR (na.gid = 1 AND na.realm = 'nodeaccess_rid') OR (na.gid = 0 AND na.realm = 'nodeaccess_uid') OR (na.gid = 0 AND na.realm = 'nodeaccess_author') OR (na.gid = 0 AND na.realm = 'user_relationship_node_access_author') OR (na.gid = 0 AND na.realm = 'og_public'))) AND ( (node.type IN ('bio')) AND (user_relationships_to_user.requestee_id = 116) AND (user_relationships_to_user.approved = 1) ) GROUP BY node.nid LIMIT 0, 10; |
L’autre moyen simple de surveiller l’état de MySQL est d’installer l’utilitaire mytop (yum install mytop / apt-get mytop….). En lancant mytop on voit la charge du serveur et, surtout, la liste des requêtes les plus lentes.
3. Rechercher la source de la requête.
Personne n’ayant écrit une pareille merveille il fallait donc rechercher dans le code la provenance de la requete. Un grep -R sur /sites/all n’a rien donné. Il faut donc étudier de plus près la requete, Drupal ayant plusieurs modules générant des requetes de maniere dynamique. Premiere constatation : il y a peu de logique dans l’aligement des JOINS, on peut donc penser à CCK ou Views, en effet les tables concernent uniquement le contenu et le module Node Access.
Les tables balayées appartenant a plusieurs types de contenus, on retient Views en éliminant CCK. On a donc une view qui génère une requete trop lente. Le site a des centaines de Views, autant chercher une aiguille dans une botte de foin… On revient sur le grep… En effet, on constate que parmi les tables de contenu on a Node Access et User relationship. Node Access override toutes les requêtes de manière automatique, il reste dont un handler de views proposé par User Relationship. Oui mais comment trouver ?
Un handler de view demander la déclaration de tableaux, chaque tableau est attribué d’un nom et qui recouvre plusieurs tableaux MySQL. Coté SQL, views va attribué des alias, tels que déclaré dans le handler. On peut donc rechercher dans le code un alias de la requête. J’ai pris celui qui me semblait le moins évident : user_relationships_add_friend_add_friend_link.
grep -R "user_relationships_add_friend_add_friend_link" /sites/all/*
Bingo, un seul module est pointé, mais pas User Relationship. C’est un module à nous, un handler de views qui permet d’ajouter automatiquement les liens “Ajouter à un ami” à tous les listings des membres du site.
4. Correction du bug dans le handler de views
En fait il ne s’agit pas vraiment d’un bug, disons d’une optimisation, pas évidente à trouver pour le développeur. En effet nous développons le site sur une version allégée, qui n’a pas le contenu de la production. La requête passait plutôt bien et on y a vu que du feu. Analysons le code de la version posant problème :
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 | function user_relationships_views_extends_arg_handler($op, &$query, $arg_type, $arg = '') { if ('filter' == $op) { switch ($arg_type['type']) { case 'ur_uid_requestee': $arg = intval($arg); $query->add_table('user_relationships_to_user', true); $query->add_where('user_relationships_to_user.requestee_id = %d', $arg); break; case 'ur_approved_requestee': $arg = intval($arg); $query->add_table('user_relationships_to_user', true); $query->add_where('user_relationships_to_user.approved = %d', $arg); break; } } } |
On remarque dans la requete que nous avons deux JOINs dont le second est complétement inutile, force MySQL a dupliquer les données pour chaque ligne retourner et provoque donc un full scan.
1 2 | LEFT JOIN user_relationships user_relationships_to_user ON node.uid = user_relationships_to_user.requester_id LEFT JOIN user_relationships user_relationships_to_user2 ON node.uid = user_relationships_to_user2.requester_id |
On vois immédiatement que le probleme vient du fait que nous rajoutons deux fois la table “user_relationships_to_user” dans le handler d’argument.
La correction consiste en la vérification de l’existance de la table, grâce à la fonction de l’API views : ensure_table :
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 | function user_relationships_views_extends_arg_handler($op, &$query, $arg_type, $arg = '') { if ('filter' == $op) { switch ($arg_type['type']) { case 'ur_uid_requestee': $arg = intval($arg); $query->ensure_table('user_relationships_to_user'); $query->add_where('user_relationships_to_user.requestee_id = %d', $arg); break; case 'ur_approved_requestee': $arg = intval($arg); $query->ensure_table('user_relationships_to_user'); $query->add_where('user_relationships_to_user.approved = %d', $arg); break; } } } |
5. Pour aller plus loin…
Je profite de ce petit post pour vous conseiller d’utiliser la commande EXPLAIN de MySQL permettant d’analyser la maniere de gérer un requete par MySQL. Pour des requetes simples il est souvent simple de prévoir quels indexes MySQL va utiliser ou pas. Il en va autrement pour des requetes complexes construites par Views. En rajoutant EXPLAIN devant notre grosse requete, on obtient le résultat suivant :
Pour plus d’informations sur la syntaxe de EXPLAIN, visitez le site de MySQL.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 | +----+-------------+-------------------------------+--------+-------------------------------------------------+--------------+---------+--------------------------------------------------+------+----------------------------------------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +----+-------------+-------------------------------+--------+-------------------------------------------------+--------------+---------+--------------------------------------------------+------+----------------------------------------------+ | 1 | SIMPLE | user_relationships_to_user | ref | relationship,requester_id,requestee_id,approved | requestee_id | 4 | const | 6 | Using where; Using temporary; Using filesort | | 1 | SIMPLE | node | ref | PRIMARY,node_type,uid,nid | uid | 4 | familler.user_relationships_to_user.requester_id | 1 | Using where | | 1 | SIMPLE | user_relationships_to_user2 | ref | relationship,requester_id | requester_id | 4 | familler.user_relationships_to_user.requester_id | 8 | Using index | | 1 | SIMPLE | bio | ref | node_type,uid | uid | 4 | familler.node.uid | 1 | | | 1 | SIMPLE | bio_node_data_field_photo | eq_ref | PRIMARY | PRIMARY | 4 | familler.bio.vid | 1 | | | 1 | SIMPLE | node_data_field_user_motto | eq_ref | PRIMARY | PRIMARY | 4 | familler.node.vid | 1 | | | 1 | SIMPLE | user_relationships | ref | requestee_id | requestee_id | 4 | familler.node.uid | 2 | | | 1 | SIMPLE | na | ref | PRIMARY,nid | nid | 4 | familler.node.nid | 3 | Using where | | 1 | SIMPLE | user_bio | ref | PRIMARY | PRIMARY | 4 | familler.na.nid | 61 | Using index | | 1 | SIMPLE | user_relationships_add_friend | ref | relationship,requester_id | requester_id | 4 | familler.node.uid | 8 | | +----+-------------+-------------------------------+--------+-------------------------------------------------+--------------+---------+--------------------------------------------------+------+----------------------------------------------+ 10 rows in set (0.01 sec) |
Enfin, suite au commentaire d’Alexandre, je vous invite à lire l’excellent article de Maximilian sur le cache MySQL.

< Voir le site
Je suis le fameux client et l’analyse effectuée durant toute la nuit a démontrer une faiblesse du module “view”.
Il n’y a pas de gestion d’optimisation des requettes sur sur la fonction add_table.
Pourquoi ajouter un ensure_table alors que add_table pourrait être codé pour le faire automatiquement.
Ceci est choix et je respecte.
Quand à la configuration de ce site, après une division de la BDD sur un autre serveur, nous avons ajouter un gestion du cache MYSQL.
Résultat, le site tourne à merveille et a depuis explosé les records d’inscriptions.
Un grand merci aux équipes d’Adyax.
Bonjour,
ça me laisse sans voix.
Moi qui ait l’habitude de travailler avec l’archaïque SPIP en tombe à la renverse. Dans ce vieux CMS passé de mode :
- les requêtes sont construites par le système de boucles à la compilation (et pas à l’exécution)
- corrolairement elles sont optimisées (y compris dans la gestion des jointures), puisqu’on peut se permettre de payer le coût d’optimisation qui ne sera payé qu’une seule fois, à la compilation
- il y a un outil intégré d’optimisation et de diagnostique directement utilisable sur le site, qui permet de voir en détail
- l’ensemble des requêtes générées pour le calcul d’une page
- classées par temps d’exécution * nombre d’exécutions
- accompagnées du détail de la requête et la référence du code qui la génère
Quand je lis tout cet article, je crois comprendre un peu mieux les retours d’expérience que j’entends ici ou là concernant les ressources machines consommées par les sites réalisés avec Drupal …
Et les architectures serveurs déployées pour fournir …
Bonjour Cédric !
Petits compléments d’informations, je ne voudrais surtout pas tomber dans le débat SPIP vs Drupal vs Typo3 vs ez…..
1. Il faut bien garder à l’esprit que le choix d’un CMS se fait en premier lieu sur les fonctionnalités, puis sur la simplicité d’utilisation et seulement à la fin sur la vitesse d’exécution. L’optimisation, dans tout logiciel doit venir à la fin.
2. La compilation des requêtes a du sens pour un site statique (qui peut être caché), encore que je n’en vois pas l’intérêt si un bon système de cache fonctionne derrière. N’oubliez pas que SPIP se base sur le système très propriétaire de squelettes, mais tu dois mieux savoir que moi, car j’ai jamais eu l’occasion de bosser avec SPIP.
3. La structure modulaire et les fonctionnalités communautaires de Drupal fait que ce CMS a connu un tel succès, elle empêche aussi la compilation. Enfin je reste assez songeur quant à cette compilation… La puissance de Views est son niveau d’abstraction, tout module peut injecter du contenu pour Views, le templating est rendu très simple.
4. Globalement Drupal consomme plus de ressources qu’un site sous SPIP, mais je dirais c’est normal, proposant beaucoup plus de fonctionnalités… Un peu comme Windows 3.11 consomme beaucoup moins que Windows XP….
5. Il faut pas tomber à la renverse à cause de détails, il faut analyser la puissance structurelle d’un systeme. Le détails, optimisations se régleront avec le temps (c’est d’ailleurs déjà le cas avec Drupal 6 et Views 2), en revanche le design modulaire, un code très pur et bien commenté en ANGLAIS fait de Drupal une machine de guerre terrible. Les modules Views & CCK n’ont pas d’équivalent sur d’autres CMS.
Donc globalement, Drupal reste loin devant SPIP sur la qualité du code et l’architecture globale. Il reste biensur, comme sur n’importe quel projet de grosses pistes d’amélioration et d’optimisation. Mais le combat n’est pas là. Il est sur l’ergonomie des interfaces et la simplicité d’utilisation. C’est, pour Drupal, le combat de demain, celui qu’il doit gagner pour continuer à être le CMS numéro 1 du marché.
Maxime.