Introduction à la méthode d'impression asynchrone des logback logs (exemple de code)

Cet article vous apporte une introduction à la méthode d'impression asynchrone des journaux de connexion (exemples de code). Il a une certaine valeur de référence. Les amis dans le besoin peuvent s'y référer.

Problème récemment rencontré : le programme serveur du client répond parfois trop lentement aux demandes. En vérifiant le journal, il a été constaté que le code de la signature de vérification RSA a été exécuté pendant plus de 20 secondes. , alors que dans des circonstances normales, cela ne prend que 16 ms.

Le certificat RSA est chargé au démarrage du serveur, il n'y a donc aucun problème de lecture lente des fichiers. Après avoir examiné ces lignes de code, la chose la plus suspecte est le code d'impression du journal de connexion.

Vérifié la configuration du journal de production. La configuration dans logback.xml est de générer un dossier chaque mois. Les fichiers journaux du mois en cours sont tous dans le même dossier. de janvier 2019. document. Chaque fichier est configuré avec le suffixe *.log.zip et la taille est 10 Mo, ce qui signifie que 10 Mo est un fichier délimité par une taille. La classe d'impression du journal est configurée avec RollingFileAppender.

Au 30/01/2019, plus de 5 000 fichiers journaux ont été générés dans le dossier de janvier 2019, avec une moyenne de 167 fichiers journaux par jour.

On soupçonne donc qu'il y a trop de fichiers journaux et que le temps d'indexation des fichiers est trop long, ce qui ralentit l'exécution du code. En d'autres termes, si vous voulez en douter, il y a. une prémisse : l'impression du journal est synchrone et le journal d'impression est appelé. Une fois la ligne de code exécutée et écrite dans le fichier, le code métier continuera à être exécuté.

J'ai demandé à plusieurs collègues et ils m'ont tous dit que l'impression des journaux était effectuée de manière asynchrone. Un seul ami a dit que c'était synchrone. Nous pensons tous que l'impression de journaux et l'écriture de fichiers prennent du temps et que le cadre de journalisation ne doit pas écrire de fichiers de manière synchrone. Cependant, le fait est que si l'impression asynchrone n'est pas configurée, le journal sera imprimé de manière synchrone.

Le code de suivi du point d'arrêt a détecté que le journal est écrit dans le fichier de manière synchrone. Uniquement lorsque l'appender configuré est AsyncAppender, l'impression du journal est imprimée de manière asynchrone.

Voici la situation de l'impression synchrone des journaux :

configuration logback.xml :

<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    ......
</appender>

<root level="DEBUG">
    <appender-ref ref="CONSOLE"/>
</root>

Code d'exécution :

LogWork.debug("111111111111");
System.out.println("2222222222222");

Résultat d'exécution :

Comme vous pouvez le voir, le résultat de l'exécution est le cadre logique en premier Une fois l'impression du journal terminée, le code métier suivant est exécuté. C'est donc synchrone.

Voici comment configurer la classe de journal d'impression asynchrone :

La classe de journal d'impression asynchrone AsyncAppender doit référencer une autre classe d'impression de journal, et ASYNC n'a besoin que d'imprimer le journal qui doit être imprimé Écrivez dans la file d'attente de cache définie, puis démarrez un thread démon pour obtenir le journal de la file d'attente et appelez l'imprimante de journal CONSOLE pour écrire le fichier. De cette manière, l'impression du journal est effectuée de manière asynchrone.

Configuration logback.xml :

<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    ......
</appender>

<appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
    <discardingThreshold>0</discardingThreshold>
    <queueSize>100</queueSize>
    <neverBlock>true</neverBlock>
    <appender-ref ref="CONSOLE"/>
</appender>

<root level="INFO">
    <appender-ref ref="ASYNC"/>
</root>

Code d'exécution :

LogWork.debug("111111111111");
System.out.println("2222222222222");

Résultat de l'exécution :

Le résultat de l'exécution montre qu'après l'exécution du code qui appelle le framework de journal à imprimer, il place simplement le journal à imprimer dans la file d'attente du cache, puis continue. Le code suivant est exécuté vers le bas, donc le 222222 suivant est imprimé en premier, puis 111111 est imprimé. L'explication est que l'impression du journal est désormais configurée pour fonctionner de manière asynchrone.

Parce que la question en début d'article soulevait la problématique de la synchronisation de l'impression des logs, j'ai fait quelques recherches, mais au final je n'ai pas fait de lien avec le problème rencontré, car même si je savais que le log a été imprimé de manière synchrone. Il n'y a aucun moyen d'expliquer pourquoi l'exécution du code est extrêmement lente pendant quelques minutes de temps en temps. Les preuves étant insuffisantes, aucune conclusion ne peut être tirée.

Ce qui précède est le contenu détaillé de. pour plus d'informations, suivez d'autres articles connexes sur le site Web de PHP en chinois!