Si vous voulez bien faire les choses, vous devez d'abord affiner vos outils.
De nombreux programmeurs peuvent oublier à quel point il est important d'enregistrer le comportement des applications. Lorsque vous rencontrez des insectes simultanés causés par une haute pression dans des environnements multi-thread, vous pouvez comprendre l'importance de l'enregistrement des journaux.
Certaines personnes étaient très heureuses d'ajouter cette phrase au code:
Log.info ("journalisation heureuse et insouciante");
Il peut même ne pas réaliser l'importance des journaux des applications dans la maintenance, le réglage et l'identification des défauts. Je pense que SLF4J est la meilleure API de journalisation, principalement parce qu'elle prend en charge un excellent moyen d'injecter le schéma:
log.debug ("Found {} enregistre le filtre correspondant: '{}'", enregistrements, filtre);
Pour Log4J, vous ne pouvez le faire que:
Log.Debug ("Found" + Records + "RecordsMatching Filter: '" + Filter + "'");
Cette écriture n'est pas seulement plus verbeuse et mauvaise lisibilité, mais a également une épissage de chaîne qui affecte l'efficacité (lorsque ce niveau ne nécessite pas de sortie).
SLF4J présente la fonction d'injection {}, et comme l'épissage de la chaîne est évité à chaque fois, la méthode TOSTRING ne sera pas appelée, et il n'est pas nécessaire d'ajouter un isdebugeNabled. SLF4J est une application du mode d'apparence, ce n'est qu'une façade. Pour une implémentation spécifique, je recommande le Framework de journalisation. Je l'ai déjà annoncé une fois auparavant, au lieu du log4j déjà complet. Il a de nombreuses fonctionnalités intéressantes. Contrairement à Log4j, il est toujours sous le développement actif et l'amélioration.
Un autre outil à recommander est Perf4J:
Perf4j est à System.currentTimemillis () comme log4j est à System.out.println ()
Tout comme Log4j est une meilleure alternative à System.out.println, Perf4j ressemble plus à un remplacement de System.CurrentTimemillis (). J'ai introduit Perf4J dans un projet et observé comment il fonctionne sous des charges élevées. Les administrateurs et les utilisateurs professionnels sont tous deux stupéfaits par les beaux graphiques fournis par ce gadget. Nous pouvons voir les problèmes de performances à tout moment. Perf4j devrait être un article spécial pour parler. Maintenant, vous pouvez d'abord consulter son guide de développeur. Il existe également un CEKI Gülcü (Créateur de Log4J, SLF4J et Logback Project) qui nous permet de supprimer les dépendances sur les communs de communes.
N'oubliez pas le niveau du journal
Chaque fois que vous souhaitez ajouter une ligne de journaux, vous pensez, quel niveau de journal doit être utilisé ici? Environ 90% des programmeurs ne prêtent pas beaucoup d'attention à ce problème. Ils utilisent un niveau pour enregistrer des journaux, généralement des informations ou du débogage. Pourquoi?
Le cadre journal présente deux avantages majeurs par rapport au système.out: classification et niveau. Les deux vous permettent de filtrer sélectivement les journaux, en permanence ou tout simplement lors du dépannage des erreurs.
Erreur: une erreur grave s'est produite et doit être traitée immédiatement. Ce niveau d'erreur est intolérable à n'importe quel système. Par exemple: exception du pointeur nul, la base de données n'est pas disponible et les cas d'utilisation des chemins critiques ne peuvent pas continuer à être exécutés.
Avertissement: le processus ultérieur se poursuivra, mais il devrait être pris au sérieux. En fait, j'espère qu'il y a deux niveaux ici: l'un est le problème évident avec la solution (comme "les données actuelles ne sont pas disponibles, en utilisant des données mises en cache"), et l'autre est le problème et les suggestions potentiels (tels que "le programme s'exécute en mode de développement" ou "le mot de passe de la console de gestion n'est pas suffisamment sécurisé". Les applications peuvent tolérer ces informations, mais elles doivent être vérifiées et fixées.
Debug: ce qui concerne les développeurs. Plus tard, je parlerai de ce que les choses devraient être enregistrées à ce niveau.
Trace: des informations plus détaillées, uniquement utilisées au stade de développement. Vous devrez peut-être toujours faire attention à ces informations dans un court laps de temps après le lancement du produit, mais ces enregistrements de journal ne sont que temporaires et ne devraient éventuellement être désactivés. Il est difficile de distinguer la différence entre débogage et trace, mais si vous ajoutez une ligne de journaux et le supprimez après le développement et les tests, le journal doit être au niveau de la trace.
La liste ci-dessus n'est qu'une suggestion, vous pouvez vous connecter en fonction de vos propres règles, mais il est préférable d'avoir certaines règles. Mon expérience personnelle est: ne filtrez pas les journaux au niveau du code, mais utilisez le niveau de journal correct pour filtrer rapidement les informations souhaitées, ce qui peut vous faire gagner beaucoup de temps.
La dernière chose à dire est que cette tristement célèbre est * une déclaration conditionnelle activée. Certaines personnes aiment l'ajouter avant chaque journal:
if (log.isdebugeNable ()) log.debug ("place pour votre publicité");Personnellement, je pense que vous devez éviter d'ajouter cette chose désordonnée au code. Les performances ne semblent pas être bien améliorées (surtout après avoir utilisé SLF4J), ce qui ressemble plus à une optimisation prématurée. De plus, ne le trouvez-vous pas un peu redondant? Rarement, cette déclaration de jugement explicite est explicitement nécessaire à moins que nous prouvons que la construction de messages de journal lui-même est trop coûteux. Sinon, vous vous souvenez autant que vous le devriez et laisser le cadre du journal s'inquiéter à ce sujet.
Savez-vous ce que vous enregistrez?
Chaque fois que vous écrivez une ligne de journaux, prenez un moment pour voir ce que vous imprimez dans le fichier journal. Lisez votre journal et découvrez où se trouve l'exception. Tout d'abord, évitez au moins les exceptions du pointeur nul:
log.debug ("Demande de traitement avec id: {}", request.getId ());
Avez-vous confirmé que la demande n'est pas nul?
Les collections d'enregistrement sont également une grande fosse. Si vous utilisez HiberNate pour obtenir une collection d'objets de domaine à partir de la base de données, vous l'écrivez accidentellement comme ceci: log.debug ("Returning Users: {}", utilisateurs);
SLF4J n'appellera la méthode TOSTRING que lorsque cette déclaration est effectivement imprimée, bien sûr, c'est cool. Cependant, si la mémoire déborde, N + 1 Problèmes de sélection, le thread s'adresse à la mort, une exception d'initialisation retardée, l'espace de stockage de journaux s'épuise ... Tout cela peut se produire. La meilleure façon est d'enregistrer uniquement l'ID de l'objet (ou uniquement la taille de la collection). Cependant, la collecte d'ID nécessite d'appeler la méthode GETID pour chaque objet, ce qui n'est vraiment pas une tâche facile en Java. Groovy a un excellent opérateur d'extension (utilisateurs * .id). En Java, nous pouvons utiliser la bibliothèque Commons Beanutils pour simuler:
Log.Debug ("Renvoi des ID utilisateur: {}", Collect (utilisateurs, "id"));
C'est probablement ainsi que la méthode Collect est mise en œuvre:
Collection statique publique Collection (collection Collection, String PropertyName) {return CollectionUtils.Collect (Collection, New BeanToPropertyValueTransFormer (PropertyName));}Enfin, la méthode TOSTRING peut ne pas être implémentée correctement ou utilisée.
Premièrement, pour se connecter, il existe de nombreuses façons de créer un toString pour chaque classe. Il est préférable d'utiliser TostringBuilder pour générer (mais pas la version de son implémentation de réflexion).
Deuxièmement, faites attention aux tableaux et aux ensembles atypiques. La mise en œuvre de ToString des tableaux et certaines collections alternatives peuvent ne pas appeler la méthode TOSTRING de chaque élément un par un. La méthode des tableaux # DeepToString fournie par JDK peut être utilisée. Vérifiez les journaux que vous avez imprimés sur vous-même pour voir s'il existe des informations sur l'exception du format.
Évitez les effets secondaires
L'impression en journal n'a généralement pas beaucoup d'impact sur les performances du programme. Récemment, un de mes amis a lancé une exception Hibernate LazyInitializationException sur un système exécuté sur certaines plateformes spéciales. Comme vous l'avez peut-être deviné à partir de cela, certaines impressions de journaux entraînent le chargement des collections d'initialisation retardées lorsque la session est connectée. Dans ce cas, si le niveau de journal augmente, la collection ne sera plus initialisée. Si vous ne connaissez pas ces informations contextuelles, combien de temps vous faudra-t-il pour découvrir ce bogue.
Un autre effet secondaire est qu'il affecte la vitesse d'exécution du programme. Une réponse rapide à cette question: si les journaux sont trop imprimés ou si le TOSTRING et l'épissage des chaînes ne sont pas utilisés correctement, l'impression du journal aura un impact négatif sur les performances. Quelle est la taille? Eh bien, j'ai vu un programme redémarrer toutes les 15 minutes, car trop de bûches provoquent la mort des fils de fil. C'est l'effet secondaire! D'après mon expérience, l'impression d'une centaine de mégaoctets en une heure est presque la limite supérieure.
Bien sûr, si le processus métier est interdit en raison des exceptions d'impression logarithmique, cet effet secondaire sera excellent. Je vois souvent des gens écrire ceci pour éviter ceci:
essayez {log.trace ("id =" + request.getUser (). getID () + "Accessses" + manager.getPage (). getUrl (). toString ())} catch (nullpointerException e) {}C'est un vrai morceau de code, mais pour rendre le monde plus purifié, veuillez ne pas l'écrire comme ça.
Décrire clairement
Chaque enregistrement du journal contient des données et des description. Jetez un œil à cet exemple:
log.debug ("message traité"); log.debug (message.getjmsMessageId ()); log.debug ("message avec id '{}' traité", message.getjmsMessageId ()); Lors du dépannage des erreurs dans un système inconnu, quel type de journal préférez-vous voir? Croyez-moi, ces exemples sont courants. Il existe également un mode négatif:
if (instance de message de TextMessage)
// ...
autre
log.warn ("type de message inconnu");
Est-il difficile d'ajouter des types de messages, des identifiants de message, etc. à ce journal d'avertissement? Je sais qu'une erreur s'est produite, mais qu'est-ce que c'est? Quelles sont les informations contextuelles?
Le troisième exemple négatif est le "journal magique". Un vrai exemple: de nombreux programmeurs de l'équipe savent que 3 nombres ≥ suivent! Le numéro suivi d'un numéro #, suivi d'un journal de numéro pseudo-aléatoire signifie "le message avec id xyz a été reçu". Personne ne veut changer ce journal. Si quelqu'un tapait le clavier et sélectionnait une chaîne unique "&&&! #", Il trouverait rapidement les informations qu'il voulait.
Le résultat est que l'ensemble du fichier journal ressemble à une grande chaîne de caractères aléatoires. Certaines personnes ne peuvent s'empêcher de se demander s'il s'agit d'un programme Perl.
Les fichiers journaux doivent être lisibles, clairs et décrits. N'utilisez pas les nombres magiques, les valeurs d'enregistrement, les nombres, les ID et leur contexte. Enregistrez les données traitées et sa signification. Enregistrez ce que fait le programme. Un bon journal devrait être un bon document du code du programme.
Ai-je mentionné ne pas imprimer un mot de passe et avoir des informations personnelles? Je crois qu'il n'y a pas un programmeur aussi stupide.
Ajustez votre format
Le format de journal est un outil très utile, qui ajoute invisiblement des informations de contexte précieuses au journal. Mais vous devriez clairement réfléchir au type d'informations inclus dans votre format. Par exemple, il n'a pas de sens d'enregistrer les dates dans les journaux écrits chaque cycle horaire, car votre nom de journal contient déjà ces informations. Au contraire, si vous n'enregistrez pas le nom de thread, lorsque deux threads fonctionnent en parallèle, vous ne pourrez pas suivre les threads via les journaux - les journaux ont chevauché ensemble. Dans une application unique, c'est OK de le faire, mais c'est déjà une chose du passé.
D'après mon expérience, le format de journal idéal doit inclure (sauf les informations du journal elle-même, bien sûr): heure actuelle (pas de date, précision milliseconde), le niveau de journal, nom de thread, nom de journal simple (pas avec nom complet) et messages. En enregistrement, cela ressemblera à ceci:
<appender name = "stdout"> <ecoder> <mattern>% d {hh: mm: ss.sss}% -5level [% thread] [% logger {0}]% m% n </ motif> </coder> </ appender>Les noms de fichiers, les noms de classe, les numéros de ligne, n'ont pas besoin d'être répertoriés, bien qu'ils semblent utiles. J'ai également vu une connexion vide dans le code:
log.info (""); Parce que le programmeur estime que le numéro de ligne fera partie du format de journal, et il sait que si le message de journal vide apparaît sur la ligne 67 du fichier, cela signifie que l'utilisateur a été authentifié. Non seulement cela, l'enregistrement des noms de méthode de nom de classe ou des numéros de ligne a un grand impact sur les performances.
Une caractéristique plus avancée du cadre de journalisation est le contexte de diagnostic cartographié. MDC n'est qu'une carte locale à fil. Vous pouvez mettre toutes les paires de valeurs de clé dans cette carte, afin que tous les enregistrements de journal de ce thread puissent obtenir des informations correspondantes à partir de cette carte dans le cadre du format de sortie.
Enregistrez les paramètres et les valeurs de retour de la méthode
Si vous trouvez un bug dans la phase de développement, vous utilisez généralement un débogueur pour suivre la raison spécifique. Disons maintenant que vous n'utiliserez plus le débogueur. Par exemple, parce que ce bogue est apparu dans l'environnement de l'utilisateur il y a quelques jours, tout ce que vous pouvez obtenir est quelques journaux. Que pouvez-vous en savoir plus?
Si vous suivez le principe simple d'impression dans et hors des paramètres pour chaque méthode, vous n'avez pas du tout besoin d'un débogueur. Bien sûr, chaque méthode peut accéder aux systèmes externes, bloquer, attendre, etc., et ceux-ci doivent être pris en compte. Référez-vous simplement au format suivant:
Public String printDocument (document doc, mode mode) {log.debug ("entrant printDocument (doc = {}, mode = {})", doc, mode); String id = ...; // Long d'opération d'impression log.debug ("Laissant printDocument (): {}", id); ID de retour;}Étant donné que vous enregistrez les journaux au début et à la fin de la méthode, vous pouvez trouver manuellement des codes inefficaces, et même détecter des causes qui peuvent provoquer des blocages et une faim - il vous suffit de voir s'il n'y a pas de "sort" après "entrer". Si la signification du nom de votre méthode est claire, ce sera une chose agréable de vider le journal. De même, l'analyse des exceptions est plus facile car vous savez ce que vous faites à chaque étape. S'il existe de nombreuses méthodes à enregistrer dans le code, vous pouvez utiliser des sections AOP pour la compléter. Cela réduit le code en double, mais vous devez être très prudent lorsque vous l'utilisez, et si vous ne faites pas attention, cela peut conduire à une grande quantité de sortie de journal.
Les niveaux les plus appropriés pour ce type de journal sont le débogage et la trace. Si vous constatez qu'une méthode est appelée trop fréquemment et que l'enregistrement de son journal peut affecter les performances, il vous suffit de réduire son niveau de journal ou de supprimer directement le journal (ou seulement l'un des appels de la méthode?) Cependant, trop de journaux sont meilleurs que moins. Considérez la journalisation comme des tests unitaires, votre code doit être couvert de journaux tout comme ses tests unitaires sont partout. Aucune partie du système ne nécessite aucun journal. N'oubliez pas que parfois vous devez savoir si votre système fonctionne correctement, et vous ne pouvez afficher que les journaux qui inondent constamment l'écran.
Observer les systèmes externes
Cette suggestion est un peu différente de la précédente: si vous communiquez avec un système externe, n'oubliez pas d'enregistrer les données sortantes et de lecture de votre système. L'intégration du système est une corvée et le diagnostic de problèmes entre deux applications (imaginez différentes entreprises, environnements, équipes techniques) est particulièrement difficile. Récemment, nous avons constaté que l'enregistrement du contenu des messages complet, y compris les en-têtes SOAP et HTTP d'Apache CXF, est très efficace pendant la phase d'intégration et de test du système.
C'est cher, et si cela affecte les performances, vous ne pouvez désactiver le journal. Mais de cette façon, votre système peut fonctionner très rapidement et s'accrocher rapidement, donc vous ne pouvez rien y faire? Lorsque vous vous intégrez à des systèmes externes, vous ne pouvez être que très prudent et être prêt à sacrifier certaines frais généraux. Si vous avez la chance et que l'intégration du système est gérée par l'ESB, il est préférable d'enregistrer la demande et la réponse dans le bus. Vous pouvez vous référer à ce composant journal de Mule.
Parfois, la quantité de données échangées avec des systèmes externes détermine qu'il vous est impossible de tout noter. D'un autre côté, il est préférable de garder tout dans le journal pendant la phase de test et les étapes de libération anticipée et d'être prêt à sacrifier les performances. Cela peut être fait en ajustant le niveau de journal. Jetez un œil aux conseils suivants:
Collection <Integer> requersIDS = // ... if (log.isdebugeNable ()) log.debug ("Traitement ids: {}", requêtes); else log.info ("Traitement ids size: {}", request.size ()); Si cet enregistreur est configuré au niveau de débogage, il imprime la collection complète des ID de demande. S'il est configuré pour imprimer des informations sur les informations, il ne sortira que la taille de l'ensemble. Vous pouvez me demander si j'ai oublié la condition Isinfoenabled, veuillez consulter la deuxième suggestion. Une autre chose à noter ici est que l'ensemble des ID ne peut pas être nul. Bien qu'il puisse imprimer normalement sous débogage comme nul, il s'agit d'un grand pointeur nul lorsqu'il est configuré comme info. Rappelez-vous les effets secondaires mentionnés dans la 4ème suggestion?
Exceptions de journalisation correctes
Tout d'abord, ne connectez pas les exceptions, laissez le framework ou le conteneur le faire. Bien sûr, il y a une exception: si vous lancez des exceptions (RMI, EJB, etc.) à partir d'un service distant, les exceptions sont sérialisées pour s'assurer qu'elles peuvent être renvoyées au client (une partie de l'API). Sinon, le client recevra un NoclassdeffoundError ou une autre exception étrange au lieu d'un véritable message d'erreur.
L'enregistrement des exceptions est l'une des responsabilités les plus importantes de la journalisation, mais de nombreux programmeurs ont tendance à utiliser la journalisation comme un moyen de gérer les exceptions. Ils renvoie généralement la valeur par défaut (généralement nul, 0 ou une chaîne vide) et prétendent que rien ne s'est passé. Parfois, ils enregistreront d'abord l'exception, puis enveloppent l'exception, puis le jettent:
Log.Error ("IO Exception", E); Jetez une nouvelle gardienne (E);De cette façon, les informations de pile seront généralement imprimées deux fois, car les endroits où l'exception de MyCustomexception sont capturées seront à nouveau imprimées. Enregistrer les enregistrements, ou l'enveloppez-le et jetez-le, ne l'utilisez pas en même temps, sinon vos journaux auront l'air déroutants.
Et si nous voulons vraiment nous connecter? Pour une raison quelconque (sans doute ne lisant pas les API et la documentation?), Environ la moitié de l'exploitation forestière, je pense que c'est faux. Faire un petit test, lequel des instructions de journal suivantes peut correctement imprimer les exceptions du pointeur nul?
essayez {entier x = null; ++ x;} catch (exception e) {log.Error (e); // un log.Error (e, e); // b log.Error ("" + e); // c log.Error (e.toString ()); // d log.Error (e.getMessage ()); // e log.Error (null, e); // f log.Error ("", e); // g log.Error ("{}", e); // h log.Error ("{}", e.getMessage ()); // i log.Error ("Fichier de configuration de lecture d'erreur:" + e); // J log.Error ("Fichier de configuration de lecture d'erreur:" + e.getMessage ()); // k log.Error ("Fichier de configuration de lecture d'erreur", e); // l}C'est étrange que seuls G et L (c'est mieux) aient raison! A et B ne sont pas du tout compilés sous SLF4J. D'autres jetteront les informations de trace de pile ou imprimeront des informations incorrectes. Par exemple, E n'imprime rien car l'exception du pointeur nul lui-même ne fournit aucune information d'exception et que les informations de pile ne sont pas imprimées. N'oubliez pas que le premier paramètre est généralement des informations de texte, sur l'erreur elle-même. N'écrivez pas d'informations d'exception. Il sortira automatiquement après l'impression du journal, devant les informations de la pile. Mais si vous souhaitez imprimer cela, vous devez bien sûr passer l'exception au deuxième paramètre.
Les journaux doivent être lisibles et faciles à analyser
Maintenant, il y a deux groupes d'utilisateurs qui sont intéressés par vos journaux: nous, les humains (que vous soyez d'accord ou non, les codeurs sont ici), et les ordinateurs (généralement des scripts shell écrits par les administrateurs système). Les journaux doivent être adaptés aux deux utilisateurs. Si quelqu'un regarde le journal de votre programme derrière vous et voit ceci:
Ensuite, vous n'avez certainement pas suivi mes conseils. Les journaux doivent être aussi faciles à lire et à comprendre que le code.
D'un autre côté, si votre programme génère un demi-Go de journaux toutes les heures, personne ou aucun éditeur de texte graphique ne peut les terminer. À cette époque, nos vieux gars, Grep, Sed et Awk, sont venus quand ils sont venus sur le terrain. Si possible, il est préférable pour les journaux que vous enregistrez pour le rendre clairement à l'ordinateur. Ne formate pas les numéros, utilisez certains formats qui rendent régulièrement possible, etc. S'il n'est pas possible, imprimez les données en deux formats:
Log.debug ("Demande TTL Set sur: {} ({})", nouvelle date (TTL), TTL); // demande TTL définie sur: mer 28 avril 20:14:12 CEST 2010 (1272478452437) Durée finale = Durée {} ms ({}) ", duréemillis, durée); // Importation a pris: 123456789ms (1 jour 10 heures 17 minutes 36 secondes)Les ordinateurs voient "MS après 1970 époque" un tel format de temps vous remerciera, tandis que les gens sont heureux de voir quelque chose comme "1 jour 10 heures 17 minutes 36 secondes".
En bref, le journal peut également être écrit aussi élégant comme un poème, si vous êtes prêt à y penser.
Ce qui précède est une collection d'informations sur le format de sortie de réglage du journal Java. Les amis intéressés peuvent y faire référence.