[Log4J] Bonnes pratiques

Version imprimable

22/01/2009, 21h49
tatemilio2

[Log4J] Bonnes pratiques
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:

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
22/01/2009, 22h39
Astartee

Citation:

Envoyé par tatemilio2

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:

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).

Citation:

Envoyé par tatemilio2

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 :koi: 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...

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:

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+

23/01/2009, 09h41
sewatech

Citation:

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.
23/01/2009, 10h04
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...:aie:
23/01/2009, 10h05
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...
23/01/2009, 10h15
sewatech

Citation:

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.

Citation:

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.
23/01/2009, 10h20
Astartee

Citation:

Envoyé par sewatech

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 :mrgreen: 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 :aie:
23/01/2009, 10h25
millie

Citation:

Envoyé par sewatech

-
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 ?
23/01/2009, 10h29
OButterlin

Citation:

Envoyé par millie

Salut, quelle chaine de caractères ?

Le message qui est passé...
23/01/2009, 10h32
millie

Citation:

Envoyé par OButterlin

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.
23/01/2009, 10h38
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 :mouarf:
Mieux vaut rendre le code lisible...
23/01/2009, 10h41
millie

Citation:

Envoyé par OButterlin

Ç
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 :

Citation:

Envoyé par sewatech

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.