Приложение log4j закрывается из-за перехваченного исключения

Исторический контекст: Эта проблема оказалась совсем не такой, как я думал. Причина и решение приведены ниже, но исходное сообщение оставлено для справки.

Я разрабатываю простую структуру для периодического опроса каталога для файлов .properties, а затем выполнения SQL-запросов и отправки сообщений электронной почты на основе их конфигураций. Поскольку каждый файл .properties имеет одинаковый спектр операций, все они интерпретируются одним и тем же классом Task. Но поскольку каждый из них представляет разные логические операции, каждый из них получает отдельные файлы журнала.

Это достигается путем совместного использования одного экземпляра log4j RollingFileAppender и динамического изменения его выходного файла на основе значения в файле .properties. Поскольку это однопоточное приложение, это прекрасно работает.

Однако я заметил, что в определенных ситуациях этот RollingFileAppender закрывается, и приложение продолжает работать, не обращая внимания, за исключением того, что теперь регистрация не ведется. Мне удалось уловить это в действии только один раз, благодаря выходным данным консоли, поскольку обычно эта служба работает как фоновый процесс на сервере Linux. Вот что произошло:

1) StartScheduler, основной класс, каждую минуту создает новый экземпляр TaskPoller.

2) TaskPoller сканирует каталог, загружает небольшую информацию из каждого файла .properties и определяет, следует ли его запускать. У него также есть собственный отдельный RollingFileAppender, который он получает через Logger.getLogger (TaskPoller.class). Если задача должна быть запущена, она создает экземпляр объекта задачи, передавая конкретный файл .properties для запуска.

3) Задача получает свой RollingFileAppender, затем вызывает fileAppender.setFile ("newtaskname.log") и fileAppender.activateOptions (), чтобы изменить расположение выходного файла. Затем во время его выполнения происходит что-то вроде этого:

[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;
}

Что происходит, так это то, что во время DBDAO.Connect () я иногда получаю com.mysql.jdbc.exceptions.jdbc4.CommunicationsException (или другое неожиданное исключение из любого загруженного класса jdbc). Это не будет перехвачено Connect (), но будет перехвачено Execute ().

Каким-то образом этот процесс приводит к закрытию объекта Task's RollingFileAppender. Единственное, что я могу придумать особенным для этой ситуации, в отличие от его последовательной и стабильной нормальной работы, - это то, что генерируемое исключение не объявляется как выброшенное Connect (). Но я не думаю, что это должно привести к закрытию приложения log4j.

Итак, мой вопрос: что могло вызвать неожиданное закрытие этого приложения в методах, которые не имеют ничего общего с его конфигурацией?

- Редактировать - Похоже, меня полностью неверно направили; проблема где-то во взаимодействии между Quartz, который я использовал, чтобы TaskPoller запускался каждую минуту, и log4j. Я еще не совсем понимаю его причину, но [это решение] [1], похоже, решает эту проблему. Просто до сих пор это не проявлялось как наблюдаемая проблема, поэтому я подумал, что это как-то связано с тем, что происходило недавно.


person Hammer Bro.    schedule 21.10.2010    source источник
comment
+1 за исследования и готовность поделиться решением. Мой совет: выделите жирным заголовком вверху, говоря, что проблема решена, а решение следует внизу; остальное оставьте как есть, а раствор добавьте внизу. Таким образом, мы не теряем историю вопроса и то, как он развивался.   -  person Isaac    schedule 22.10.2010
comment
На самом деле, вам следует переместить раздел ответов в этом посте вниз до фактического ответа, чтобы за него можно было проголосовать, и вы могли его принять. Это отображается на вкладке «Без ответа», но на самом деле не должно.   -  person Bill the Lizard    schedule 25.10.2010


Ответы (1)


Настоящая причина этой проблемы - взаимодействие между планировщиком Quartz и тем, как я использовал log4j. Оказывается, если вы измените свойства log4j (что я делал, вызывая fileAppender.setFile (fileName) и fileAppender.activateOptions ()) в рабочем потоке Quartz (даже если Quartz настроен на одновременное выполнение только одного потока ) вещи ломаются. Это исправлено путем перезагрузки свойств log4j в каждом новом экземпляре рабочего потока перед его использованием, что я сделал следующим образом:

[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);
person Hammer Bro.    schedule 26.10.2010