Adoptons nos erreurs

Dans la vie d’un logiciel, il est une entité qui est souvent délaissée, mal aimée car porteuse de mauvaises nouvelles : il s’agit de la trace d’erreur. On sait qu’il ne faut pas ignorer une erreur, qu’elle soit technique ou fonctionnelle, alors on la trace, on la logue. Mais qu’en fait-on vraiment après ? Si par hasard on en croise une, alors oui, peut-être va-t-on lui tendre la main et tenter d’apporter un peu de réconfort à notre application. Mais pour chaque erreur adoptée, combien restent orphelines ?

Tracer nos erreurs plutôt que de fermer les yeux, c’est bien mais sans traitement par la suite cela ne change pas grand chose. Tout au plus développons-nous un sentiment de culpabilité en les voyant s’entasser dans le grand orphelinat du log. Et plus les erreurs s’accumulent, et moins nous risquons de les traiter tellement la tâche devient dantesque.

Il est temps de mettre en place un programme d’adoption !

Nos besoins

  1. Trouver les erreurs s’étant produites, sur demande : c’est le rôle du log.
  2. Être averti des erreurs qui se produisent à l’instant présent : c’est le rôle d’un système d’alerte.
  3. Identifier, classifier, puis traiter les différents types d’erreur, de la même manière qu’un bug remonté par un utilisateur : c’est le rôle d’un système de ticketing.

Allez hop, intéressons-nous au premier point…

Les traces (logging)

Côté serveur, nous sommes généralement bien équipés pour ce besoin : par exemple en Java, Logback ou Log4j sont des outils éprouvés pour enregistrer des traces de manière plus ou moins structurée. De même dans le monde Node.js avec Bunyan. Chaque écosystème a sa réponse “classique” et éprouvée à ce besoin.

Cependant, il n’est généralement pas question d’aller consulter les logs sur la machine car 1) ce n’est pas pratique, surtout quand on a beaucoup de machines, 2) les machines ne devraient jamais être accédées et parfois ne le peuvent d’ailleurs pas, pour des raisons de sécurité. Il est donc nécessaire d’avoir un dépôt centralisé de logs, si possible proposant des fonctionnalités de requêtage avancées.

Une solution courante est d’installer une stack “ELK” (Elasticsearch Logstash Kibana), une autre possibilité est de passer par un SAAS dédié. Chez Hopwork, nous avons choisi il y a longtemps Logentries. Il est simple mais il fournit la base : collecte et recherche de logs, et alerting comme nous allons le voir plus loin.

Notre code Java se base sur un duo classique Logback/SLF4j configuré de manière à envoyer les logs sur Logentries. Quand à nos services JS, ils sont tellement micro qu’ils ne loguent qu’en 5 endroits différents au maximum. Nous nous sommes donc contentés de mettre une petite façade à la lib fournie par Logentries pour que les logs finissent dans le même dépôt.

Côté client, l’idée a fait son chemin depuis quelques années qu’il était bon de collecter des traces également, beaucoup d’entre nous exposent donc un service Web destiné à les recueillir. Par contre, chacun a tendance à le faire à sa manière. Chez Hopwork nous avons là encore délégué ce travail à Logentries, qui fournit une petite lib à cet effet. Notre code front lui envoie donc toutes nos traces ainsi que les erreurs non attrapées.

Recherche de logs dans logentries

Il nous est donc possible de naviguer au sein de nos traces, fort bien. Mais il est assez évident que personne ne va s’amuser à regarder défiler ces traces pour y détecter des erreurs éventuelles et agir. C’est là qu’interviennent…

Les alertes

Stocker des traces c’est bien, mais être avertis en cas d’erreur c’est mieux. Il faut donc pouvoir monitorer les traces qui arrivent pour détecter les erreurs et envoyer des notifications.
Encore une fois, chez Hopwork nous nous reposons sur Logentries qui nous permet :

  • de catégoriser les traces en fonction des informations qu’elles contiennent (niveau de criticité, pattern dans le message, etc.)
  • de lever des alertes par catégorie : par email, dans des produits tiers (Slack dans notre cas), par webhook, etc.
  • et ce selon des modalités définies : “pas plus d’une alerte du même type par heure”, “à chaque erreur”, etc.
Création d’une alerte dans Logentries

À présent, nous ne pouvons plus complètement ignorer qu’une erreur s’est produite, et surtout qu’elle se produit régulièrement !

Cependant :

  • si trop d’erreurs tombent en même temps, on ne pourra pas toutes les traiter d’un coup ;
  • il est probable que nous finissions par en oublier certaines (les moins prioritaires) ;
  • il serait bon d’avoir un moyen de dire facilement “je m’en occupe” pour bien se coordonner au sein de l’équipe.
Une alerte suivie d’une autre alerte suivie d’une autre…

Bref, nous aimerions pouvoir prendre acte d’un type d’erreur, le prioriser et suivre son traitement. Alors entre en scène…

Le système de suivi

Il est probable que quelques SAAS assez avancés fournissent des fonctionnalités de suivi, ou se proposent de créer des tickets directement dans un système existant. À l’inverse, à ma connaissance aucun ne permettra de détecter si deux traces différentes présentent des similarités montrant qu’il s’agit en fait d’un même type d’erreur, selon nos critères. Par exemple, une même section de code peut être atteinte par différents chemins et on peut donc avoir une même erreur tracée avec différentes stacktraces. Nous aimerions donc n’enregistrer (et ne traiter) qu’une seule fois une telle erreur dans notre système. Et Logentries ne nous propose pas de créer de tickets dans notre système Jira.

Pour ces raisons, nous avons développé les briques qu’il nous manquait, sous le nom de Watson.

Pour notre code Java, nous avons développé un appender Logback (WatsonAppender donc) qui n’est branché que sur les logs ayant pour sévérité “ERROR”. Cet appender va :

  • Épurer la trace d’erreur pour n’en garder que des morceaux significatifs de la zone de notre code qui a été traversée. On évite ainsi de lever plusieurs fois une même erreur parce qu’un numéro de ligne a changé suite à une montée de version de notre framework Web par exemple.
  • Calculer un hash unique pour cette trace épurée.
  • Vérifier qu’aucun ticket Jira n’a déjà été créé avec ce hash, en utilisant l’API de Jira. (Idéalement on garde et vérifie également ces hash en mémoire pour ne pas requêter Jira inutilement).
  • Au besoin créer un ticket Jira avec toutes les informations (y-compris la trace non-épurée), et en incluant bien le hash pour que la recherche fonctionne.
  • Par sécurité nous avons également mis en place une sécurité limitant la fréquence de création de tickets pour éviter une attaque DDOS de notre système Jira et de notre application (car après tout on fait tout cela dans l’appender, donc dans un thread de notre application).
Un ticket Jira créé par Watson

Ce système fonctionnant de manière satisfaisante, nous avons voulu récemment faire de même pour nos logs JS front.
Sauf qu’il est hors de question de mettre un token d’accès à notre système Jira dans notre code front. Par ailleurs, faire cela serait la porte ouverte à une attaque DDOS (volontaire ou non) sur notre Jira.

Nous avons donc opéré différemment, en nous reposant sur la capacité de Logentries d’appeler un webhook pour nous alerter :

  • un log est émis et envoyé à Logentries ;
  • Logentries décide ou non de nous envoyer une alerte pour ce log, en fonction de notre configuration ;
  • cette alerte nous est transmise en appelant un service dédié chez nous (webhook) ;
  • ce service (nommé watson-server) décide ou non de créer un ticket Jira, de la même manière que notre WatsonAppender : génération d’un hash sur la base de la stacktrace incluse dans le log, puis création d’un ticket Jira si le hash n’est pas connu dans le système.

Et du coup qu’est-ce qu’on obtient ?

Le résultat

Désormais, toute erreur est stockée et notifiée, et peut être priorisée et traitée en son temps. On sait si quelqu’un travaille sur un point ou non, et qui. Et il n’est plus possible d’ignorer un problème (car nous surveillons évidemment notre backlog de fiches Jira).

Clairement, nous pourrions apporter des améliorations à notre logique qui détermine si une erreur est connue ou non. Certaines peuvent remonter après quelques temps, avec une stacktrace différente. Mais cela nous arrange plutôt pour l’instant car cela veut souvent dire qu’elle est réapparue et qu’il s’agit d’une régression. Pour la même raison, nous pourrions d’ailleurs ne rechercher que des tickets récents et ne pas hésiter à en recréer.

Une autre amélioration possible serait de traiter toutes nos erreurs (Java, JS) de la même manière, via notre hook “watson-server”, plutôt que d’implementer deux fois cette même logique.

Dans tous les cas, nous sommes déjà bien contents du résultat !

Ce sera tout pour aujourd’hui, mais si ces problématiques vous intéressent, n’hésitez pas à nous contacter : nous recrutons :-P