3

Contexte historique: Ce problème n'a finalement pas été du tout ce que je pensais que c'était. La cause et la solution sont ci-dessous, mais la publication originale est laissée pour référence.log4j Appender étant fermé par exception interceptée

Je développe un framework simple pour interroger périodiquement un répertoire de fichiers .properties, puis effectuer des requêtes SQL et envoyer des e-mails en fonction de leurs configurations. Parce que chaque fichier .properties a le même spectre d'opérations, ils sont tous interprétés par la même classe Task. Mais comme ils représentent chacun des opérations logiques différentes, ils ont chacun des fichiers journaux distincts.

Ceci est réalisé en partageant une instance d'un fichier roll4FlogApp Log4j et en modifiant dynamiquement son fichier de sortie en fonction d'une valeur dans le fichier .properties. Comme il s'agit d'une application monothread, cela fonctionne très bien.

Cependant, j'ai remarqué que dans certaines situations, ce RollingFileAppender va se fermer, et l'application continuera inconsciemment, sauf que maintenant aucune journalisation n'a lieu. J'ai seulement réussi à attraper ceci en action une fois, grâce à la sortie de la console, puisque généralement ce service fonctionne comme un processus d'arrière-plan sur un serveur Linux. Voici ce qui s'est passé:

1) StartScheduler, la classe principale, crée une nouvelle instance de TaskPoller toutes les minutes. 2) TaskPoller analyse le répertoire, charge un peu d'informations de chaque fichier .properties et détermine s'il doit être exécuté. Il possède également son propre RollingFileAppender, qu'il récupère via Logger.getLogger (TaskPoller.class). Si une tâche doit être exécutée, elle instancie un objet Task, en transmettant le fichier .properties spécifique à exécuter.

3) Task obtient son RollingFileAppender, puis appelle fileAppender.setFile ("newtaskname.log") et fileAppender.activateOptions() pour changer l'emplacement du fichier de sortie. Puis, au cours de son exécution, quelque chose comme cela se produit:

[TaskPoller] 
... 
task = new Task(fileName); //Points RollingFileAppender to the right place 
if (!task.Execute()) 
    logger.warn(fileName + " returned with an error code."); //Succeeds 
[Task.Execute] 
... 
try { 
    dbDAO.Connect(); 
} catch (Exception e) { 
    logger.fatal{"Database connection error.", e}; //Different RFA; Fails 
    return false; 
} 
[DBDAO.Connect throws SQLException, ClassNotFoundException] 
... 
try { 
    Class.forName(dbDriver); //Dynamically loaded jdbc driver class name 
    connection = DriverManager.getConnection(urlString, userName, password); 
} catch (SQLException e) { 
    if (connection != null) 
     try { connection.close(); } catch (Exception e2) { ; } 
    throw e; 
} 

Qu'est-ce qui se passe est que pendant DBDAO.Connect(), je vais parfois obtenir un com.mysql.jdbc.exceptions.jdbc4.CommunicationsException (ou un autre exception inattendue de la classe jdbc chargée). Cela ne sera pas capturé par Connect(), mais il sera intercepté par Execute().

D'une certaine manière, ce processus provoque la fermeture de RollingFileAppender de Task. La seule chose que je peux penser de spéciale à cette situation, par opposition à son fonctionnement normal stable et stable, est que l'exception lancée n'est pas déclarée comme étant lancée par Connect(). Mais je ne pense pas que cela devrait entraîner la fermeture d'un Appender log4j. Donc, ma question est, qu'est-ce qui pourrait provoquer la fermeture inattendue de cet appender dans des méthodes qui n'ont rien à voir avec sa configuration?

--Edit-- Il semble que j'ai été mal orienté complètement; le problème se situe quelque part dans les interactions entre Quartz, que j'utilisais pour que TaskPoller tire à chaque minute, et log4j. Je ne comprends pas encore complètement sa cause, mais [cette solution] [1] semble résoudre ce problème. Cela ne s'est pas manifesté jusqu'à présent comme un problème observé, alors j'ai pensé que cela avait quelque chose à voir avec ce qui se passait récemment.

+1

+1 pour la recherche et la volonté de partager la solution. Mon conseil: mettre un en-tête gras, en disant que le problème a été résolu et que la solution suit en bas; laissez le reste tel quel, et ajoutez la solution au fond. De cette façon, nous ne perdons pas l'histoire de la question et comment elle a évolué. – Isaac

+0

En fait, vous devez déplacer la section de réponse de cette publication vers une réponse réelle afin qu'elle puisse être mise à jour et que vous puissiez l'accepter. Cela apparaît sur l'onglet Sans réponse, et ce ne devrait pas être le cas. –

Répondre

0

La cause réelle de ce problème est une interaction entre le planificateur Quartz et la façon dont j'utilisais log4j. Il s'avère, si vous modifiez les propriétés de log4j (ce que je faisais en appelant fileAppender.setFile (fileName) et fileAppender.activateOptions()) sur un thread de travail Quartz (même si Quartz est configuré pour avoir un seul thread à la fois), les choses tombent en panne.Ce problème est résolu en rechargeant les propriétés log4j sur chaque nouvelle instance du thread de travail avant de l'utiliser, que j'accompli comme ceci:

[Task() Constructor] 
Properties props = new Properties(); 
URL url = ClassLoader.getSystemResource("log4j.properties"); 
try { 
    props.load(url.openStream()); 
    PropertyConfigurator.configure(props); 
} catch (Exception e) { 
    //The logger that never got renamed never stopped working. 
    Logger.getLogger(TaskPoller.class).error("Diagnostics!"); 
} 
logger = Logger.getLogger(Task.class); 
Questions connexes