Perf4j не регистрируется правильно

Question

Я настроил некоторые вызовы секундомера в своем коде для измерения некоторых блоков кода, и все сообщения поступают в мой основной журнал, а не в журнал синхронизации. Файл perfStats.log создается просто отлично, но все сообщения отправляются в корневой журнал, который, как я не думал, должен был происходить в соответствии с документами, которые я прочитал. Есть ли что-то очевидное, что я здесь упускаю?

ссылка на руководство по perf4j

Пример кода

import org.apache.log4j.Logger;
import org.perf4j.LoggingStopWatch;
import org.perf4j.StopWatch;

public class PerfLogger {

    /**
     * @param args
     */
    public static void main(String[] args) 
    {
        Logger  logger = Logger.getLogger(PerfLogger.class.getName());

        logger.info("Starting perf log test");

        StopWatch stopWatch = new LoggingStopWatch("test time");

        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            // TODO Auto-generated catch block
            e.printStackTrace();
        }
        stopWatch.stop();

    }

}

Пример log4j.xml

<log4j:configuration xmlns:log4j='http://jakarta.apache.org/log4j/'>    

    <appender name="STDOUT-DEBUG" class="org.apache.log4j.ConsoleAppender">
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d %-5p [%t]%x %M (%F:%L) - %m%n"/>
        </layout>
    </appender>


   <!-- Perf4J appenders -->
    <!--
       This AsyncCoalescingStatisticsAppender groups StopWatch log messages
       into GroupedTimingStatistics messages which it sends on the
       file appender defined below
    -->
    <appender name="CoalescingStatistics"
              class="org.perf4j.log4j.AsyncCoalescingStatisticsAppender">
        <!--
          The TimeSlice option is used to determine the time window for which
          all received StopWatch logs are aggregated to create a single
          GroupedTimingStatistics log. Here we set it to 10 seconds, overriding
          the default of 30000 ms
        -->
        <param name="TimeSlice" value="10000"/>
        <appender-ref ref="fileAppender"/>
    </appender>


    <!-- This file appender is used to output aggregated performance statistics -->
    <appender name="fileAppender" class="org.apache.log4j.FileAppender">
        <param name="File" value="perfStats.log"/>
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%m%n"/>
        </layout>
    </appender>

    <!-- Loggers -->
    <!--
      The Perf4J logger. Note that org.perf4j.TimingLogger is the value of the
      org.perf4j.StopWatch.DEFAULT_LOGGER_NAME constant. Also, note that
      additivity is set to false, which is usually what is desired - this means
      that timing statements will only be sent to this logger and NOT to
      upstream loggers.
    -->
    <logger name="org.perf4j.TimingLogger" additivity="false">
        <level value="INFO"/>
        <appender-ref ref="CoalescingStatistics"/>
    </logger>

    <root>
        <priority value="info"/>
        <appender-ref ref="STDOUT-DEBUG"/>
    </root>

</log4j:configuration>

Answer 1

Я проверил jar, и в jar perf4j нет класса с именем TimingLogger, это также можно увидеть здесь, выполнив поиск по хранилищу кода, который объяснил бы, что сообщения не попадают в файл, который вы ожидаете от них. Если вы используете класс LoggingStopWatch по умолчанию, который они показывают в примере, похоже, что единственное, что он когда-либо сделает, - это печать в std err, которую вы можете увидеть здесь. Я попытался изменить регистратор в своем коде, чтобы вместо этого использовать их класс Log4JStopWatch, и изменил регистратор в файле xml на org.perf4j.log4j.Log4JStopWatch, но сообщения отправляются вместо стандартного stdout, что, вероятно, связано с тем, что он не использует конфиги, указанные в log4j.xml, я думаю. Я постараюсь проконсультироваться с командой, обслуживающей проект, чтобы узнать, есть ли у них обновленный пример или исправление ошибки.

Answer 2

Проблема в том, что вы используете LoggingStopWatch, который по умолчанию отправляет весь свой вывод в stderr. Вы хотите использовать Log4JStopWatch. Каждый из прямых подклассов LoggingStopWatch предназначен для отдельной среды (см. http://perf4j.codehaus.org/apidocs/org/perf4j/LoggingStopWatch.html).

Answer 3

org.log4j.TimingLogger - это не имя класса, а имя регистратора по умолчанию, используемое Perf4j. Если вы используете Log4j, вы должны использовать класс org.perf4j.log4j.Log4JStopWatch и не забывайте использовать правильный тег при его создании, так как статистика будет сгруппирована по нему.

Следуя вашему примеру:

import org.apache.log4j.Logger;
import org.perf4j.LoggingStopWatch;
import org.perf4j.StopWatch;

public class PerfLogger {

    /**
     * @param args
     */
    public static void main(String[] args) 
    {

        StopWatch stopWatch = new LoggingStopWatch("main(..)");

        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            // TODO Auto-generated catch block
            e.printStackTrace();
        }
        stopWatch.stop();

    }
}

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

Performance Statistics   2012-07-03 22:13:20 - 2012-07-03 22:13:30
Tag                        Avg(ms)         Min         Max   Std Dev       Count
main(..)                   999.0           999         999       0.0           1

Надеюсь, что это проясняет эту проблему.