Discussion :

[tatemilio2]

Bonjour,
Je souhaite mettre de bonnes pratiques dans mes projets. J'aimerais avoir vos retours d'expérience concernant l'utilisation de Log4J.

Voici les éléments que je souhaite mettre en place, si vous pouvez me donner des conseils.

Tout d'abord, pour toutes mes méthodes je souhaite logger en debug l'entrée et la sortie des méthodes, idem pour les paramètres des méthodes.
Par contre j'ai vu qu'il faut tester si on est en mode debug par le code suivant:

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
 
if (logger.isDebugEnabled()) {
    logger.debug("TOTO");
}

Si quelqu'un peut m'expliquer pourquoi.

De plus j'aimerais savoir si l'utilisation de log de type info peuvent être pour diagnostiquer des incidents.

Dernier point si quelqu'un peut me donner des exemples de pattern je suis preneur.

Merci d'avance

[Astartee]

J'ai vu qu'il faut tester si on est en mode debug par le code suivant [...] Si quelqu'un peut m'expliquer pourquoi.

Alors, ce test n'est pas nécessaire, dans le sens où si supprimes l'appel à isDebugEnabled ça marchera quand même... Cependant commencer par tester le niveau de log permet d'éviter des traitements inutiles.
Exemple :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

logger.debug("Etat de bli[" + i + "] : " + bli[i].getState() );

Là on effectue au moins 1 appel de méthode et 3 concaténations afin de calculer le paramètre de la méthode debug, alors que le logger va peut-être finalement rejeter la chaîne de caractère car il est configuré de façon à n'écrire que les messages de niveau info ou supérieur...
En faisant précéder l'appel à la méthode debug par un test isDebugEnabled, on évite alors le calcul inutile du paramètre.
Par contre, on rajoute des tests "inutiles" pour les cas où le logger est configuré en mode debug, mais ce ne sont pas ces traitements qui sont les plus longs...
Sur un exemple comme logger.debug("TOTO") la différence est évidemment minime (mais je crois que la version avec test est quand même un tout petit poil plus rapide).

De plus j'aimerais savoir si l'utilisation de log de type info peuvent être pour diagnostiquer des incidents.

Tu peux évidemment logguer toutes les informations que tu veux avec le niveau de log que tu veux, mais il est quand même beaucoup plus logique de logguer les erreurs graves en tant que error, les incidents mineurs en tant que warning et les traces informatives en tant que info Ne serait-ce que parce que les utilisateurs de ton appli[*] ne penseront pas en cas de problème à chercher les "erreurs" dans les "infos", et qu'ils auront peut-être même désactivé le log de niveau info...

[*]si ça se trouve tu es le seul utilisateur de ton projet, mais une bonne pratique "basique" consiste à regarder ton code ou ton application en te demandant si quelqu'un d'autre pourrait le comprendre...

[OButterlin]

Bien d'accord avec Astartee...
Le test n'a d'intérêt que si tu fais un traitement lourd (d'extraction etc...) pour la trace.
Avec les 3 niveaux de base (error, debug, info), on peut faire suffisamment de choses.
Il faut noter également que log4j permet un paramétrage très fin des niveaux de consignation pour :
- des packages
- des classes
le tout de manière générique

Dans l'exemple ci-dessous

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
8
 
log4j.rootLogger=ERROR, defaultAppender
log4j.appender.defaultAppender=org.apache.log4j.ConsoleAppender
log4j.appender.defaultAppender.layout=org.apache.log4j.PatternLayout
log4j.appender.defaultAppender.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p [%c{1}] %m%n
 
log4j.logger.obia.kernel.ServletBasicFunctions=DEBUG
log4j.logger.obia.kernel=INFO

Toutes les classes ont un niveau par défaut ERROR.
Toutes les classes du package obia.kernel (et tous les sous-package) ont un niveau INFO MAIS la classe ServletBasicFunctions (qui fait partie de obia.kernel) a le niveau DEBUG

A+

[sewatech]

Le test n'a d'intérêt que si tu fais un traitement lourd (d'extraction etc...) pour la trace.

Je ne suis pas tout à fait d'accord.

Pour chaque appel de debug, on instancie au minimum un chaîne de caractères qui ne sert à rien. C'est d'autant plus gênant que le niveau debug est souvent utilisé de façon verbeuse. Sur des applications JavaEE, avec beaucoup d'utilisateurs, ça peut faire beaucoup d'instanciations inutiles et donc faire travailler inutilement le garbage collector. Quand on sait que le GC est souvent source de problèmes de pref en JavaEE, on sait qu'il faut faire attention à ce genre de choses.

[OButterlin]

D'un autre côté, le test coûte également de la cpu, sans compter que ça ne rend pas le code super lisible...
Tout est question de compromis...

[Tommy31]

J'étais également dans la pratique de OButterlin, à savoir placer une garde lorsque le traitement du log fait apparaitre un traitement accentué.

Toi, sewatech tu préconnise la mise en place d'une garde systématique pour toute invocation du logger ?

Je me demande si le respect de la règle, peut pas être pris en charge par checkstyle...

[sewatech]

le test coûte également de la cpu

Si tu ne fais pas le test avant l'appel du debug, il sera fait dans le debug. Il n'y a pas de perte de perf.

a ne rend pas le code super lisible

OK, c'est vrai. J'ai longtemp été réticent pour cela, puis j'ai été converti par des collègues puis par des problèmes de GC.

[Astartee]

Si tu ne fais pas le test avant l'appel du debug, il sera fait dans le debug. Il n'y a pas de perte de perf.

Enfin, le test sera quand même fait deux fois au lieu d'une...
Mais la perte de performance est quand même minime par rapport aux traitements (affectation de chaînes, concaténations, traitements lourds éventuels) effectués pour l'évaluation du paramètre Et puis, même si l'application est un poil ralentie en mode "debug", normalement elle n'est pas destinée à tourner dans ce mode.... les logs kilométriques en prod c'est complètement illisible

[millie]

-
Pour chaque appel de debug, on instancie au minimum un chaîne de caractères qui ne sert à rien. -

Salut, quelle chaine de caractères ?

[OButterlin]

Salut, quelle chaine de caractères ?

Le message qui est passé...

[millie]

Le message qui est passé...

Ouais, mais pour une chaine en dur, est-ce qu'il y a vraiment instanciation d'un objet lors de l'appel de la méthode ?

Comme c'est non mutable (et que String est une classe particulière), je ne suis même pas sûr qu'il y ait instanciation pour une chaine en dur.

[OButterlin]

Ça c'est clair, si c'est une chaine en dur, ça ne changera rien elle sera créée à la "compilation"
Mais pour un message du genre "Le client " + nomClient + " n'existe pas", c'est une autre histoire...
Ceci dit, si on commence à chercher à ce niveau d'optimisation, c'est que l'application a de sacrées contraintes de performances
Mieux vaut rendre le code lisible...

[millie]

Ç
Mais pour un message du genre "Le client " + nomClient + " n'existe pas", c'est une autre histoire...

Oui tout à fait, c'est pour ça que je demande il parlait de quelle chaine car j'avais l'impression que c'était une chaine en dur déjà construite :

Je ne suis pas tout à fait d'accord.

Pour chaque appel de debug, on instancie au minimum un chaîne de caractères qui ne sert à rien.