производительность log4j
Я разрабатываю веб-приложение, и я хотел бы зарегистрировать некоторую информацию, чтобы помочь мне улучшить и наблюдать приложение. (Я использую Tomcat6),
Сначала я думал, что буду использовать StringBuilders, добавлять журналы им, и задача сохранила бы их в базу данных как каждые 2 минуты. Поскольку я волновался по поводу производительности out-of-the-box системы регистрации. Затем я сделал некоторый тест. Особенно с log4j.
Вот мой код:
Main.java
public static void main(String[] args) {
Thread[] threads = new Thread[LoggerThread.threadsNumber];
for(int i = 0; i < LoggerThread.threadsNumber; ++i){
threads[i] = new Thread(new LoggerThread("name - " + i));
}
LoggerThread.startTimestamp = System.currentTimeMillis();
for(int i = 0; i < LoggerThread.threadsNumber; ++i){
threads[i].start();
}
LoggerThread.java
public class LoggerThread implements Runnable{
public static int threadsNumber = 10;
public static long startTimestamp;
private static int counter = 0;
private String name;
public LoggerThread(String name) {
this.name = name;
}
private Logger log = Logger.getLogger(this.getClass());
@Override
public void run() {
for(int i=0; i<10000; ++i){
log.info(name + ": " + i);
if(i == 9999){
int c = increaseCounter();
if(c == threadsNumber){
System.out.println("Elapsed time: " +
(System.currentTimeMillis() - startTimestamp));
}
}
}
}
private synchronized int increaseCounter(){
return ++counter;
}
}
}
log4j.properties
log4j.logger.main.LoggerThread=debug, f
log4j.appender.f=org.apache.log4j.RollingFileAppender
log4j.appender.f.layout=org.apache.log4j.PatternLayout
log4j.appender.f.layout.ConversionPattern=%d{ABSOLUTE} %5p %c{1}:%L - %m%n
log4j.appender.f.File=c:/logs/logging.log
log4j.appender.f.MaxFileSize=15000KB
log4j.appender.f.MaxBackupIndex=50
Я думаю, что это - очень общая конфигурация для log4j. Сначала я использовал log4j 1.2.14 затем, я понял, что была более новая версия, таким образом, я переключился на 1.2.16
Вот числа (все в миллисекунду)
LoggerThread.threadsNumber = 10
1.2.14: 4235, 4267, 4328, 4282
1.2.16: 2780, 2781, 2797, 2781
LoggerThread.threadsNumber = 100
1.2.14: 41312, 41014, 42251
1.2.16: 25606, 25729, 25922
Я думаю, что это очень быстро. Не забывайте что: в каждом цикле метод выполнения не только входит в файл, он должен связать строки (name + ": " + i), и проверьте если тест (i == 9999).
Когда threadsNumber равняется 10, существует 100 000 регистраций и если тесты и конкатенации. Когда это 100, существует 1 000 000 регистраций и если тесты и конкатенации. (Я считал где-нибудь использование JVM, которое StringBuilder добавляют для конкатенации, не простой конкатенации).
Я пропускал что-то? Я делаю что-то не так? Я забывал фактор, который мог уменьшить производительность? Если эти числа корректны, я думаю, что не должен волноваться о производительности log4j, даже если я в большой степени регистрируюсь, не так ли?
Я считал что: "Типичная стоимость фактического входа составляет приблизительно 100 - 300 микросекунд". Это корректно? (log4J руководство)
6 ответов
Да, Log4J известен как быстрый, благодаря сознательным усилиям его разработчиков. См. также раздел "Производительность" в конце этого введения в Log4J.
Мне не нужно беспокоиться о log4j производительность, даже если я сильно логирую
Точно. Не выполняйте оптимизацию, пока об этом не скажут результаты профилирования. Бывают случаи, когда производительность протоколирования является узким местом, но вам нужно сначала выполнить этот случай, а затем оптимизировать его.
горлышко бутылки должно быть жестким диском. Ваш тест показывает скорость записи на диск примерно 1 МБ / с, что на самом деле довольно мало.
Убедитесь, что у вас есть правильная стратегия ведения журнала. Это означает, что убедитесь, что вы определили, что нужно регистрировать, и разделили это на отладку, трассировку, информацию, предупреждение и ошибку, а также на некоторые другие, если они вам нужны. Также убедитесь, что у вас есть возможность включать и выключать его, чтобы задействовать производительность / отладку по мере необходимости.
Ведение журнала может оказать значительное влияние на активно используемый сайт / приложение. Кроме того, слишком большое количество журналов дает вам больше информации, чем вы можете отсортировать. Иногда ведение журнала является единственным инструментом отладки после инцидента, который у вас есть, поэтому убедитесь, что вы учитываете его.
Если производительность действительно важна, поищите slf4j: http://www.slf4j.org/manual.html
С их подходом заполнителя они быстрее, чем log4j, когда вы отключили регистрацию этих сообщений, потому что в log4j конкатенация строк происходит независимо, сообщение действительно необходимо. Slf4j заменяет заполнитель только в том случае, если это сообщение действительно будет зарегистрировано.
Но вы можете сделать что-то вроде этого в log4j:
if(l.isDebugEnabled()) l.debug("log entry: " + 7);
Но я думаю, что это много шаблонного кода, поэтому я использую slf4j
Если производительность вызывает беспокойство, обязательно обратите особое внимание на документацию по макету шаблона и избегайте дорогостоящих символов преобразования, таких как C, F, L и M. Это требует махинаций для получения этой информации .
Вместо C используйте c и соответствующим образом назовите ваши объекты Logger при их создании. Это означает, что вы не можете наследовать регистраторы от родительских классов, но неудобство переопределения регистратора стоит увеличения производительности. F, L и M не имеют простой замены для их функциональности, но хорошо сформулированные сообщения журнала должно быть очень легко найти в вашем источнике, поэтому необходимость указывать точный метод, файл и строку уменьшается.
Наконец, избегайте динамической конкатенации строк в сообщениях журнала. Когда необходимо использовать конкатенацию, не забудьте заключить создание этой строки журнала в соответствующий метод проверки.
private final static Logger LOG = Logger.get(MyClass.class);
...
void someMethod() {
if (LOG.isDebugEnabled()) {
LOG.debug("some really expensive string concatenation: " + someInstanceVariable + " a bunch of other text!");
}
}
isDebugEnabled () всегда выполняется в постоянное время. Сам LOG.debug () по существу выполняет проверку isDebugEnabled () в начале, но строка, переданная в качестве параметра, должна быть полностью построена до того, как эта проверка может произойти, что вызывает ненужную задержку при отключении уровня отладки.