Pourquoi le Faucon Millenium ne passe jamais en hyperespace ?

Je garde la trace ou pas ?

… ou comment améliorer vos logs avec ces 7 règles

Le Faucon Millenium ne veut jamais passer en hyperespace, à moins que r2d2 ne le répare pour vous. Comment se fait-il que même l’intrépide Han Solo ait du mal à comprendre son vaisseau spatial ? Est-ce parce que les Corelliens ont un sens de l’humour très particulier en matière de logging ?

Laissez-moi illustrer cela avec quelques exemples de php, même si nous sommes tous convaincus que ce n’est pas un fameux langage.

Superstructure de journalisation

Ne vous lancez pas dans la journalisation de fichiers bruts. Vous avez besoin de quelque chose qui agrège vos logs en un seul endroit accessible, avec des outils de recherche et d’analyse puissants. Logstash et Kibana étant livrés dans des conteneurs Docker, vous n’avez vraiment aucune excuse pour éviter cela. Si vous ne les connaissez pas, je vous conseille vivement d’y jeter un coup d’œil.

Un bon framework de journalisation peut aider. Ajoutez des aides partout et assurez-vous que tout le monde les comprend (et lit cet article). Pour php, vous pouvez utiliser le classique mais incontournable monolog.

La plupart des framework de journalisation peuvent ajouter des métadonnées aux entrées du journal. Logstash par exemple comprend le champ type pour filtrer/transformer les entrées de logs.

Dans les exemples qui suivent, $logger sera une instance de Monolog\Logger correctement configurée.

De quoi parlez-vous ?

Essayez d’expliquer ce qui se passe, en faisant des phrases et en donnant le contexte. C’est important. Tout le monde ne comprend pas la signification d’un nombre entier, c’est pourquoi les codes d’état rfc2616 HTTP ont une explication sous forme de chaîne de caractères envoyée dans les en-têtes également, par exemple.

// ...mieux vaut 100 si on croise un Imperial Star Destroyer 
$shieldLevel = 20; 
// Mauvais
$logger->info($shieldLevel); // "20"

// Bon
$logger->info("Shieldlevel: $shieldLevel%"); // "Shieldlevel: 20%"
// Mieux, mais attention au spam du context
$logger->info("Shieldlevel: $shieldLevel%", ['shieldLevel' => $shieldLevel]);

Un autre exemple si vous n’êtes pas convaincu :

// Mauvais
$logger->info("no hd"); // hard drive or hyper drive ?
// Bon, sujet verbe complément, ponctuation, merci l'école !
$logger->info("Hyperdrive reports failure, Bezel condensator is discharged");

Ne supprimez pas d’informations

Certaines habitudes peuvent conduire à ce que des informations soient tronquées dans les messages du journal.

try {
    throw new \Exception("oops");
} catch(\Exception $e) {
    // Mauvais
    $logger->error($e->getMessage()); // "oops"
    
    // Bon
    $logger->error((string) $e); // "oops in Example at line:"
}

Principe de causalité

La journalisation fonctionne souvent à l’aide de files, et deux entrées de journal proches peuvent être séparées par beaucoup de bruit.

// Mauvais
$logger->info("The hyperdrive just failed");
$logger->info("It could be related to the Bezel condensator");

// "The hyperdrive just failed" (thread 1)
// "Cargo door is open" (thread 2)
// "Picking up weird hyperspace signals" (thread 3)
// "It could be related to the Bezel condensator" (thread 1)
// - Chewie, referme la porte cargo sinon on sautera pas !...
// ... Mais pourquoi on ne saute pas en vitesse lumière ?

// Bon
$logger->info("The hyperdrive just failed, probably because of the Bezel condensator");

Niveau terriblement erroné

Les niveaux de journalisation sont votre meilleure défense contre un rapport signal/bruit élevé. Il faut donc concevoir des journaux au niveau le plus juste. Heureusement, chaque framework propose des niveaux, respectez-les.

// Mauvais
$logger->debug("Dark Vador just boarded the falcon");
$logger->emergency("Bulb jammed in the ladies room");

// Bon
$logger->emergency("Dark Vador just boarded the falcon");
$logger->debug("Bulb jammed in the ladies room");

Id est pour l33t

Essayez de remplir vos messages de journal avec des informations granulaires lorsque cela est possible.

// Pas mal, mais...
$logger->debug("Tie just fired"); // Tie just fired
// ...Mieux
$logger->debug("Tie:$tieId just fired."); // Tie:2 just fired
// - Chewie, vise le second chasseur Tie !

Si votre langage favori permet un truc du goût de __toString, il est temps de l’utiliser:

class Tie {
    function __toString(){return __CLASS__.':'.2;}
}

$tie = new Tie();
$logger->debug("$tie just fired"); // Tie:2 just fired

Production var_dump

Évitez de déverser de gros objets dans les journaux. Voir guzzle où l’exception ne vide que les 120 premiers caractères de la requête.

// Mauvais
$logger->debug(var_export($darkStarTrooperCollection, true));

// Bon
$logger->debug("Current count of troopers on the darkstar is ".count($darkStarTrooperCollection));