Faire parler les logs sans s'endormir

Il y a une vérité que tout le monde apprend tôt ou tard dans le métier: les logs, on les écrit avec enthousiasme, pis on les lit avec désespoir. En septembre 2012, sur mes systèmes embarqués chez NOVIPRO, je vis ça en plein. Une tablette durcie qui tourne dehors, sur un véhicule, dans des conditions où je peux pas juste m’asseoir à côté avec un débogueur. Quand quelque chose plante, mon seul témoin, c’est le journal. Pis souvent, ce témoin-là parle pour rien dire.

Le problème, c’est jamais qu’il manque de logs. C’est qu’il y en a trop. Des milliers de lignes qui disent « tout va bien » jusqu’à la seconde où plus rien va bien. Pis là, noyé dans le bruit, le message important est passé inaperçu. Faire parler les logs, c’est pas en générer plus. C’est en générer mieux.

Le piège du log qui endort

Quand chaque ligne a le même poids visuel, le cerveau décroche. On scrolle, les yeux glissent, pis on rate le seul détail qui comptait. Mon objectif, c’est de rendre l’anormal visible sans avoir à chercher.

flowchart LR
    A[Evenement] --> B{Niveau?}
    B -->|DEBUG| C[Garde local<br/>jeté vite]
    B -->|INFO| D[Trace normale<br/>contexte]
    B -->|WARN| E[Quelque chose<br/>cloche]
    B -->|ERROR| F[Action requise<br/>visible]
    E --> G[Remonté<br/>et corrélé]
    F --> G

L’idée, c’est de hiérarchiser pour de vrai. Le DEBUG, c’est du détail jetable, utile sur le moment, pas conservé longtemps. Le INFO raconte le déroulement normal. Mais le WARN pis le ERROR, eux, doivent crever l’écran. Si tout est ERROR, plus rien l’est.

Donner du contexte, pas juste un message

L’autre affaire qui change tout, c’est le contexte. Un log qui dit « échec de connexion », c’est inutile. Échec avec quoi? Sur quel appareil? Dans quel état? Un bon log, c’est celui qu’un collègue peut lire à trois heures du matin, six mois plus tard, sans connaître toute l’histoire.

// log pauvre - me dit rien d'utile
LOG("erreur GPS");

// log riche - me raconte ce qui s'est passe
LOG_WARN("GPS perdu",
    "device", id_tablette,
    "derniere_position", last_fix,
    "satellites", nb_sat,
    "duree_perte_ms", delta);

La deuxième version coûte trois minutes de plus à écrire. Mais elle m’en sauve trois heures quand le véhicule revient du terrain avec un problème intermittent que je peux pas reproduire au bureau. Sur de l’embarqué, où je peux pas brancher mon environnement de dev sur place, ce contexte-là vaut de l’or.

Corréler au lieu de chercher

Le dernier morceau, c’est de pouvoir relier les événements entre eux. Un identifiant qui suit une opération du début à la fin, c’est ce qui transforme une pile de lignes éparpillées en une histoire qu’on peut suivre. Sans ça, on reconstitue le casse-tête à la main. Avec ça, on filtre par identifiant pis le déroulement apparaît tout seul.

Ce que je retiens

Faire parler les logs sans s’endormir, en septembre 2012, c’est moins une question d’outil qu’une question de discipline. Écrire chaque ligne en pensant à la personne qui va la lire plus tard, fatiguée, pressée, sans contexte. Hiérarchiser les niveaux pour que l’anormal saute aux yeux. Mettre du contexte au lieu d’un message vague. Relier les événements pour suivre une histoire au lieu de fouiller.

C’est pas glamour, pis ça paraît pas dans une démo. Mais le jour où un système plante au loin pis que je peux pas le toucher, c’est exactement ça qui décide si je règle le problème en dix minutes ou si je passe ma nuit dans le brouillard. Un bon journal, c’est un collègue silencieux qui a pris des notes pendant que je dormais.