Résumé : si tu journalises les requêtes lentes avec le paramètre slow_query_log de MariaDB / MySQL, attention à log_slow_rate_limit (qui est désactivé par défaut), car, avec lui, seule une fraction des requêtes sera analysée et, si besoin, journalisée. Avec « log_slow_rate_limit = 10 », seule la dixième requête sera analysée et, si elle est lente, journalisée. Dans une séquence "4 requêtes OK suivies par 3 requêtes lentes suivies par 3 requêtes OK", les trois requêtes lentes passent inaperçues.

Sur l'un de nos serveurs MariaDB, mysqladmin status nous informe qu'il y a des requêtes lentes / slow queries. Une requête lente est une requête dont la durée d'exécution dépasse la valeur du paramètre long_query_time (10 secondes par défaut).

Nous journalisons les requêtes lentes avec les paramètres suivants dans /etc/mysql/mariadb.conf.d/60-surchargeLocale.cnf (cela permet qu'une mise à jour des paquets mette à jour les paramètres généraux dans 50-server.cnf sans affecter les paramètres que nous savons essentiels / vitaux pour nos besoins + de simplifier l'usage de Puppet puisqu'il suffit de déposer le fichier au lieu de modifier l'autre avec file_line ou concat ou…) :

slow_query_log      = 1
slow_query_log_file = /var/log/mysql/mariadb-slow.log

Je regarde donc le journal sus-mentionné : il est vide ! O_O

J'utilise le client en ligne de commande, mysql afin d'exécuter la requête « SELECT SLEEP(12); » (ben quoi, il s'agit d'une requête dont l'exécution va durer plus de 10 secondes). Elle n'est pas journalisée. mysqladmin nous mentirait ?

Après m'être cassé les dents, il s'avère que le paramètre log_slow_rate_limit, qui n'est pas activé par défaut dans Debian GNU/Linux ni sur nos autres serveurs, était activé sur ce serveur.

Je n'y avais pas pris garde car, dans les autres logiciels que je connais, comme OpenVPN, la limitation du débit signifie que le logiciel arrête de journaliser quand un même message d'erreur se répète X fois. log_slow_rate_limit fonctionne à l'envers : seule une fraction des requêtes sera analysée et, si elle est trop longue, alors la requête sera journalisée.

Avec « log_slow_rate_limit = 10 », seule 1 requête sur 10 sera analysée. Ainsi, si 8 requêtes OK sont suivies par deux requêtes lentes, alors la journalisation s'activera au bout de la deuxième requête lente. Si 13 requêtes sont OK puis 7 foireuses, la journalisation s'activera au bout de la 7e requête (13 + 7 + 20 qui est un multiple de 10). Autant dire que si t'as une séquence de la forme "4 requêtes OK suivies par 3 requêtes lentes suivies par 3 requêtes OK", tu vas attendre longtemps la journalisation, même si la connexion au serveur, la commande jouée à la connexion, etc. (qui sont considérées comme des requêtes) ajoutent de l'entropie.

Dans mon cas, la valeur de log_slow_rate_limit était 1000, donc, forcément, il fallait attendre loooongtemps avant qu'une requête soit journalisée.

On utilise mysqladmin status pour récupérer quelques métriques concernant nos serveurs MariaDB.
Sous Debian GNU/Linux, cet outil est fourni par le paquet mariadb-client.

Je relève trois points de vigilance à avoir quand on examine la sortie de cette commande :

• Le manuel ne le dit pas mais Queries per second avg, c'est le nombre de questions (alors que questions et queries ne sont pas synonymes… … …) divisé par l'uptime. Cela explique pourquoi ce nombre ne fluctue pas entre le jour et la nuit, en fonction de l'usage réel du serveur de bases de données. Pour contourner cela, je graphe, avec rrdtool, le nombre de « questions » avec un type COUNTER et hop ;
  
  
• Le champ Questions ne comptabilise pas uniquement les requêtes SELECT, INSERT, etc. Cela comptabilise aussi les connexions réussies au serveur (bind), les déconnexions propres (si tu fermes le client en ligne de commande ‒ mysql ‒ avec quit; ou avec un ctrl+c. Les fermetures de connexions PDO ne sont pas comptabilisées), la requête exécutée à la connexion (paramètre init-connect dans la configuration de MariaDB), le choix d'une base de données (use <nom_base> avec le client en ligne de commande mysql ‒ autant de questions qu'il y a de tables dans la base ‒. « dbname » dans le DSN d'une connexion PDO n'est pas comptabilisé), l'exécution de mysqladmin compte lui-même pour une question, etc. ;
  
  
• La sortie mélange des métriques instantanées / en direct / à l'instant T (GAUGE) comme « Threads » et « Open tables » avec des nombres incrémentés depuis le démarrage du serveur (COUNTER) comme « Questions », « Slow queries », « Opens » et « Flush tables ».