Instrumentation et performance

24 janvier 2011 par stephane

Instrumenter son application correctement représente un pas important dans la recherche des performances optimales. De bons outils permettent également de gagner du temps, qui est toujours précis. Cet article va vous donner un exemple de la valeur ajoutée que peut procurer un bon outil : le simple fait d’obtenir un rapport précis sur un problème rencontré permet de résoudre en 5 minutes un gros problème de performance qui ne trouvait pas de solution depuis des semaines.

L’application en question dispose d’une table user permettant (surprise !!) de stocker les informations sur les utilisateurs. Cette table contient environ 30 millions de lignes et a l’allure suivante :


CREATE TABLE user (
  user_id int(11) NOT NULL AUTO_INCREMENT,
  login varchar(30) NOT NULL DEFAULT '',
  name varchar(50) NOT NULL DEFAULT '',
  col_a varchar(30) NOT NULL DEFAULT '',
  col_b varchar(30) NOT NULL DEFAULT '',
  col_c varchar(30) NOT NULL DEFAULT '',
  PRIMARY KEY (user_id),
  UNIQUE KEY login (login)
) ENGINE=InnoDB;

Notons que la base ne tient pas en mémoire.

Un rapport quotidien basé sur mysqldumpslow envoyait les requêtes lentes de l’application. Parmi ces requêtes, on en trouvait une très étrange, prenant plus de 30s :

Count: 195 Time=33.05s (6445s) Lock=0.00s (0s) Rows=129903.9 (25331256), user[db]@81hosts
SELECT user_id FROM user WHERE login = N

Pourquoi est-il étrange que cette requête soit aussi lente ? Tout simplement parce qu’il existe un index sur la colonne login et que la table étant en InnoDB, on peut profiter de l’index cluster pour couvrir la requête avec l’index login. Si la dernière phrase ne vous a paru très claire, regardez donc cet article et celui-là également.

On peut confirmer facilement la validité de notre hypothèse sur le plan d’exécution avec EXPLAIN en prenant un login au hasard :

mysql> EXPLAIN SELECT user_id FROM test.user WHERE login="aqkme123456"\G
***** 1. row *****
   id: 1
   select_type: SIMPLE
   table: user
   type: const
   possible_keys: login
   key: login
   key_len: 32
   ref: const
   rows: 1
   Extra: Using index

Alors certes, la base ne tenant pas en mémoire, on ne sait pas si l’index login est en mémoire ou pas, mais dans la mesure où on accède directement à la bonne ligne, il n’y a vraiment aucune raison pour que la requête prenne plus de 30 secondes. Et en effet, les différents essais que j’ai pu faire avec des vraies valeurs donnent toujours un résultat instantané.

Poussons donc la réflexion : le problème de mysqldumpslow, c’est que l’outil ne donne qu’un exemple avec des valeurs abstraites. Il nous faudrait ici un exemple avec une valeur qui a provoqué une requête de 30s. Un autre outil permettrait-il d’avoir un tel exemple ? Oui, avec mk-query-digest de Maatkit par exemple.

Installons donc mk-query-digest, demandons lui de générer un rapport sur les logs de la veille, et regardons l’exemple réel donné par l’outil :


SELECT user_id FROM user WHERE login = 123456

Et voilà, soudainement tout est devenu limpide !! Non ? Mais si, regardez bien, la condition WHERE porte sur la colonne login de type VARCHAR et on passe un entier ! Ce qui change tout car MySQL convertit login en entier, ce qui empêche l’utilisation de l’index (rappelez-vous, MySQL ne connaît pas les function-based index) et conduit donc à un parcours complet de la table.

En réalité, cette analyse n’est pas tout à fait exacte car l’index sur login est couvrant pour la requête : il est donc possible de faire un parcours complet de la table non pas en parcourant la clé primaire mais en parcourant l’index sur login. Quelle stratégie préfère choisir MySQL ?

mysql> EXPLAIN SELECT user_id FROM test.user WHERE login=123456\G
***** 1. row *****
   id: 1
   select_type: SIMPLE
   table: user
   type: index
   possible_keys: login
   key: login
   key_len: 32
   ref: NULL
   rows: 33153173
   Extra: Using where; Using index

MySQL choisit d’utiliser l’index sur login. Etait-ce la meilleure idée, autrement dit, était-il plus rapide de scanner la table avec l’index sur login (ce qui conduit à de nombreuses lectures aléatoires) plutôt que de scanner la table séquentiellement ? Pour y répondre, le seul moyen est de faire un test avec les 2 méthodes, en utilisant le modificateur IGNORE INDEX(login) dans le second cas pour forcer le scan de la table. Et dans ce cas, les tests montrent que le scan avec l’index sur login est plus rapide.

Dernier point, qui montre à la fois que MySQL convertit bien le champ login en entier et que la requête est complètement erronée : si je joue la requête SELECT user_id FROM user WHERE login = 123456 sur mes données de production, j’obtiens non pas un résultat mais plus de 2000 ! Pourquoi un tel résultat alors que le login est censé être unique ? Tout simplement parce qu’en convertissant le champ login en entier, on perd de l’information : toutes les chaînes de caractères commençant par « 123456″ seront converties vers l’entier 123456 :

mysql> SELECT CONVERT("123456toto",UNSIGNED);
+--------------------------------+
| CONVERT("123456toto",UNSIGNED) |
+--------------------------------+
| 123456 |
+--------------------------------+


mysql> SHOW WARNINGS;
+---------+------+-------------------------------------------------+
| Level | Code | Message |
+---------+------+-------------------------------------------------+
| Warning | 1292 | Truncated incorrect INTEGER value: '123456toto' |
+---------+------+-------------------------------------------------+

La correction du problème a finalement été très simple : il a suffi au développeur de forcer l’ajout des quotes dans la requête.

Morale de l’histoire : utiliser de bons outils peut vous faire gagner un temps précieux ! Notez que si j’avais été très méticuleux, j’aurais pu arriver au même résultat avec mysqldumpslow, puisque la ligne qui m’était indiquée donnait WHERE login = N, où N représente la valeur abstraite d’un entier alors qu’il aurait fallu avoir WHERE login = S, S représentant une chaîne. Mais c’était plus facile avec mk-query-digest, non ?

Mots-clefs : , , ,

Laisser une réponse