Exile on Keyboard St. - Blog sur Linux et Debian

Aller au contenu | Aller au menu | Aller à la recherche

mercredi 10 octobre 2018

Des logs claires et utiles en Java

L'utilisateur final d'un logiciel est toujours heureux lorsque ce logiciel produit des logs claires et utiles.

Malheureusement, les développeurs ne font pas toujours suffisamment le nécessaire pour:

  • Ajouter des logs et traces là ou c'est utile
  • Mettre ces logs dans le bon niveau de log
  • Les mettre à jour quand besoin est
  • Faire en sorte que ces logs ne pénalisent pas trop les performances du logiciel

Et pourtant, la deuxième plus grande catégorie d'utilisateurs d'un logicel, c'est .... l'équipe de développement de ce logiciel !!!

On va donc faire un tour des erreurs les plus communément faites en matière de logs, et ce dans le but de s'amélirorer !

1. Pas de logs du tout

La première erreur que je vois trop souvent, c'est l'absence complète de logs dans une méthode ou même dans un composant tout entier. Il est donc impossible en cas de doute(s) sur le fonctionnement de ce code, de savoir ce qu'il se passe, à part se connecter en debug sur le serveur, ce qui n'est évidemment pas possible chez un client.

2. Des logs uniquement en TRACE ou en FINEST

Deuxième erreur trop souvent commise, on a des logs mais seulement dans le niveau de log maximum !

Comme en pratique, il est déconseillé de configurer un logiciel avec un niveau de log maximum, il en résulte que ces logs ne sortiront la plupart du temps pas chez les clients.

Ce cas arrive souvent quand le développeur veut mettre des logs mais il n'est pas certain du niveau de logs qu'il faut choisir. Et comme il développe avec un niveau de log en TRACE, ses logs s'affichent et il est content !

3. Des logs sans suffisamment de contexte

C'est moins fréquent, mais j'ai aussi vu des logs qui ressemblent à ça:

LOGGER.log(Level.INFO, "Creating user");

ou

LOGGER.log(Level.INFO, "Entering method 'needsRestart'");

Des logs comme celles-cis ne donnant aucun contexte, elles ne sont pas vraiment utiles.

Il s'agit en fait de traces utilisées lors du développement ou plus précisément du debug et qui auraient dù être enlevées ensuite.

4. Des logs avec une chaîne de formatage fausse

Le cas le plus courant de chaîne de formatage fausse est l'erreur sur le nombre de paramètres, par exemple:

LOGGER.info("Computing user: {} identifier: {}", user.getName());

Manifestement, il va nous manquer une information dans la log ...

Si à la place on avait:

LOGGER.info("Computing user: {} identifier: {}", getParam("user"), getParam("identifier"), getParam("extra"));

La méthode getParam serait appelée trois fois alors que le troisième paramètre n'est pas utilisé. Cela nous amènera à utiliser un Supplier et les méthodes lambdas avec Java 8.

5. Des logs faites par des anciens développeurs C

Dans les logs en Java, on trouve aussi le résultat de la programmation en C: le développeur Java qui met des String.format(...) partout !

LOGGER.info(String.format("Computing user: %s identifier: %s", getParam("user"), getParam("identifier")));

Ce qui va formater la chaîne même si le niveau de log ne permet pas que le message s'affiche. On en revient aux Suppliers.

Ensuite il est inutile de recourir à String.format(....) puisque Log4j ou java.util.logging formattent très bien le message en convertissant tout en chaînes de caractères.

Parfois le String.format(...) est tout simplement oublié:

LOGGER.info("Computing user: %s identifier: %s", getParam("user"), getParam("identifier"));

Ce qui affiche quelque chose comme:

06:48:36.094 main INFO org.grumpyf0x48.test.Log4j2Test - Computing user: %s identifier: %s

ce qui n'était probablement pas souhaité !

6. Des logs avec des passages de paramètres .... illisibles

On voit aussi des développeurs qui veulent logger beaucoup de choses dans le même message, et qui ont la hantise du plantage, et qui donc non content de passer 8 paramètres au message de log (et ce tout sur la même ligne temps qu'à faire), font une vérification pour chacun (ou presque) comme: (name == null) ? "no name supplied" : name.

C'est parfaitement inutile puisque dans ce cas Log4J affichera simplement "null" sans se planter. En outre ce genre de message compliqué est difficile à lire et à maintenir, donc à bannir.

Voilà, j'imagine qu'il y a des cas d'erreurs que j'oublie, n'hésitez pas à faire un commentaire si c'est le cas.

samedi 2 juin 2018

Chercher dans des fichiers de log avec lnav

Quand on développe, on passe beaucoup de temps à consulter et à chercher des informations dans les fichiers de logs des produits ou du système.

J'ai longtemps utilisé glogg et maintenant il me parait lourd et peu efficace.

lnav que je vais vous présenter maintenant est plus léger et s'avère très performant grâce à de nombreux raccourcis clavier.

Au lancement, on obtient le résultat suivant:

lnav.png

Vous constatez qu'on est au début du fichier. Pour naviguer dans le fichier, on peut utiliser:

  • g pour aller au début
  • G pour aller à la fin
  • Page up ou Backspace/ Page down ou Espace pour naviguer de page en page

Mais ce qu'il y a de commode, c'est que lnav permet d'aller à la prochaine erreur, en tappant 'e' ou au prochain warning en tappant 'w'.

De la même façon, 'E' vous positionne sur l'erreur précédente et 'W' sur le warning précédent.

On peut également naviguer dans le temps, c'est à dire que la touche 'o' vous fait avancer de 24h dans le fichier et 'O' le fait dans le sens inverse. Si l'intervalle recherché est de 24h, il faut utiliser respectivement 'd' ou 'D'.

lnav vous autorise aussi à rechercher un motif en tappant /<regexp>, les regular expressions acceptées étant les PCRE (Perl-Compatible Regular Expressions).

Autre fonctionnalité intéressante, on peut marquer une ligne pour la retrouver plus tard avec la touche 'm'. Ensuite l'appui sur les touches 'u' et 'U' permet de naviguer d'une ligne marquée à l'autre. C'est très utile pour débugger.

Bref, lnav devient rapidement un outil indispensable du quotidien du développeur, et le fait qu'il soit utilisable directement dans un terminal est un atout non négligeable.

Je n'ai évidemment pas décrit ici tout ce qu'on faire avec, pour découvrir d'autres fonctionnalités, vous pouvez utiliser la touche '?' au démarrage de lnav.