Perf4j Not Logging Correctly
- by Jehud
I setup some stop watch calls in my code to measure some code blocks and all the messages are going into my primary log and not into the timing log. The perfStats.log file gets created just fine but all the messages go to the root log which I didn't think was supposed to happen according to the docs I've read. Is there something obvious I'm missing here?
perf4j tutorial link: http://perf4j.codehaus.org/devguide.html#Using_the_log4j_Appenders_to_Generate_Real-Time_Performance_Information
Example code
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();
}
}
Example 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>