Log4j: синхронизирован ли он для многопоточных вызовов?
Мы сталкиваемся с интересной проблемой, которую мы заметили при стресс-тестировании нашей системы. Мы очень хорошо используем log4j (в JBOSS) для нашего ведения журнала. Вот наивный пример некоторого ведения журнала, который мы представляем
void someFunction()
{
Log.info("entered some function");
...
Log.info("existed some function");
}
Теперь интересная вещь, которую мы заметили, состоит в том, что если мы запустим 100 потоков против этой функции; вызовы Log.info() блокируют поток. То есть поток 2 ожидает завершения потока1 для вызова "Log.info". В случае Thread 100; он заканчивается в ожидании довольно долго. Мы используем собственный регистратор файлов.
Это известная проблема?
Ответы
Ответ 1
Log4J должен быть синхронизирован, иначе вы увидите чередующиеся и искаженные сообщения журнала в вашем файле. Но, по крайней мере, в режиме "Резервное копирование" только экземпляры синхронизируются, а не все сообщения о регистрации (поэтому эффективный уровень протокола, сообщение журнала и т.д. Многопоточен).
Однако, даже если синхронизация была удалена, ввод-вывод будет узким местом, поскольку он по сути является однопоточным. Таким образом, рассмотрите возможность уменьшения количества ведения журнала, поскольку это медленный доступ к файлу, а не Log4J.
Вы также можете быть заинтересованы в AsyncAppender
для очереди сообщений журнала в одном и том же потоке.
Ответ 2
Что вам может понадобиться - это асинхронное ведение журнала, см. эту статью о том, как это сделать:
Асинхронный журнал с log4j
Также рассмотрим использование правильных уровней журнала. Операторы entered...
и exi(s)ted...
обычно должны регистрироваться на уровне TRACE
, что может быть удобно при отладке (затем установите configure log4j для входа на уровень TRACE
). В производственной настройке вы можете указать log4j для регистрации только с уровня INFO
или DEBUG
, тем самым избегая ненужных действий журнала.
См. также этот вопрос о производительности log4j:
производительность log4j
Ответ 3
Другие уже предложили вам альтернативы, я копал исходный код и действительно есть раздел synchronized
:
public void info(Object message) {
if(repository.isDisabled(Level.INFO_INT))
return;
if(Level.INFO.isGreaterOrEqual(this.getEffectiveLevel()))
forcedLog(FQCN, Level.INFO, message, null);
}
...
protected void forcedLog(String fqcn, Priority level, Object message, Throwable t) {
callAppenders(new LoggingEvent(fqcn, this, level, message, t));
}
...
public void callAppenders(LoggingEvent event) {
int writes = 0;
for(Category c = this; c != null; c=c.parent) {
// Protected against simultaneous call to addAppender, removeAppender,...
synchronized(c) {
if(c.aai != null) {
writes += c.aai.appendLoopOnAppenders(event);
}
if(!c.additive) {
break;
}
}
}
if(writes == 0) {
repository.emitNoAppenderWarning(this);
}
}
Ответ 4
Да, log4j использует многопоточную синхронизацию. И не совсем, иногда.
Мы столкнулись с некоторой деградацией производительности, вызванной конфликтом для блокировок log4j и даже взаимоблокировок с использованием сложного метода toString().
См. https://issues.apache.org/bugzilla/show_bug.cgi?id=24159 и https://issues.apache.org/bugzilla/show_bug.cgi?id=41214#c38, например.
Подробнее в моем другом ответе:
Файл настроек производительности для log4j?
Я думаю, что это одна из причин существования журнала и переход на пользовательский лог-менеджер с JBoss AS 6.
Ответ 5
Согласитесь с предыдущими ответами. Одним из первых шагов улучшения производительности в любом приложении является уменьшение уровня журнала и сокращение дампов журналов. Разработчики приложений должны стараться использовать правильные уровни регистрации. Ведение журнала имеет огромное влияние на производительность из-за ввода-вывода, а также синхронизации, особенно когда объекты журнала статичны и разделены между различными потоками.