javaperformanceunit-testingtestingperf4j

perf4j settings for logback.xml


hi folks I want to know exact config settings of logback.xml when it was using with perf4j. i create this configuration in logback.xml

<configuration>
    <!-- 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.logback.AsyncCoalescingStatisticsAppender">
        <param name="TimeSlice" value="60000"/>
        <appender-ref ref="graphExecutionTimes"/>
        <appender-ref ref="graphExecutionTPS"/>
        <!-- We add the JMX Appender reference onto the CoalescingStatistics -->
        <appender-ref ref="perf4jJmxAppender"/>
    </appender>

    <appender name="graphExecutionTimes" class="org.perf4j.logback.GraphingStatisticsAppender">
        <!-- Possible GraphTypes are Mean, Min, Max, StdDev, Count and TPS -->
        <param name="GraphType" value="Mean"/>
        <!-- The tags of the timed execution blocks to graph are specified here -->
        <param name="TagNamesToGraph" value="DESTROY_TICKET_GRANTING_TICKET,GRANT_SERVICE_TICKET,GRANT_PROXY_GRANTING_TICKET,VALIDATE_SERVICE_TICKET,CREATE_TICKET_GRANTING_TICKET" />
    </appender>

    <appender name="graphExecutionTPS" class="org.perf4j.logback.GraphingStatisticsAppender">
        <param name="GraphType" value="TPS" />
        <param name="TagNamesToGraph" value="DESTROY_TICKET_GRANTING_TICKET,GRANT_SERVICE_TICKET,GRANT_PROXY_GRANTING_TICKET,VALIDATE_SERVICE_TICKET,CREATE_TICKET_GRANTING_TICKET" />
    </appender>

    <!--
      This JMX appender creates an MBean and publishes it to the platform MBean server by
      default.
    -->
    <appender name="perf4jJmxAppender" class="org.perf4j.logback.JmxAttributeStatisticsAppender">
        <!--
          You must specify the tag names whose statistics should be exposed as
          MBean attributes.
        -->
        <TagNamesToExpose>firstBlock,secondBlock</TagNamesToExpose>
        <!--
          The NotificationThresholds param configures the sending of JMX notifications
          when statistic values exceed specified thresholds. This config states that
          the firstBlock max value should be between 0 and 800ms, and the secondBlock max
          value should be less than 1500 ms. You can also set thresholds on the Min,
          Mean, StdDev, Count and TPS statistics - e.g. firstBlockMean(<600).

        <NotificationThresholds>firstBlockMax(0-800),secondBlockMax(<1500)</NotificationThresholds>-->
        <!--
          You can also specify an optional MBeanName param, which overrides
          the default MBean name of org.perf4j:type=StatisticsExposingMBean,name=Perf4J
        -->
    </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"/>
        <appender-ref ref="perf4jFileAppender"/>
    </logger>

    <!-- This file appender is used to output aggregated performance statistics -->
    <appender name="perf4jFileAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <File>logs/perf4j.log</File>
        <encoder>
            <Pattern>%date %-5level [%thread] %logger{36} [%file:%line] %msg%n</Pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <FileNamePattern>logs/perf4j.%d{yyyy-MM-dd}.log</FileNamePattern>
        </rollingPolicy>
    </appender>
</configuration>


i got it from perf4j logback documentation . So when i tried to use this logback conf it tdidn't through any exception but it prints some strange statements which are given below

18:26:19,945 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
18:26:19,945 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
18:26:19,945 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/home/ifkaar/Backup/eclipse/workspace/Perf4jTestProject/bin/logback.xml]
18:26:20,245 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
18:26:20,263 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [org.perf4j.logback.AsyncCoalescingStatisticsAppender]
18:26:20,308 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [CoalescingStatistics]
18:26:20,462 |-ERROR in ch.qos.logback.core.joran.action.AppenderRefAction - Could not find an appender named [graphExecutionTimes]. Did you define it below in the config file?
18:26:20,462 |-ERROR in ch.qos.logback.core.joran.action.AppenderRefAction - See http://logback.qos.ch/codes.html#appender_order for more details.
18:26:20,462 |-ERROR in ch.qos.logback.core.joran.action.AppenderRefAction - Could not find an appender named [graphExecutionTPS]. Did you define it below in the config file?
18:26:20,462 |-ERROR in ch.qos.logback.core.joran.action.AppenderRefAction - See http://logback.qos.ch/codes.html#appender_order for more details.
18:26:20,462 |-ERROR in ch.qos.logback.core.joran.action.AppenderRefAction - Could not find an appender named [perf4jJmxAppender]. Did you define it below in the config file?
18:26:20,462 |-ERROR in ch.qos.logback.core.joran.action.AppenderRefAction - See http://logback.qos.ch/codes.html#appender_order for more details.
18:26:20,471 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [org.perf4j.logback.GraphingStatisticsAppender]
18:26:20,506 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [graphExecutionTimes]
18:26:20,535 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [org.perf4j.logback.GraphingStatisticsAppender]
18:26:20,535 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [graphExecutionTPS]
18:26:20,538 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [org.perf4j.logback.JmxAttributeStatisticsAppender]
18:26:20,554 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [perf4jJmxAppender]
18:26:20,913 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [org.perf4j.TimingLogger] to false
18:26:20,914 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - org.perf4j.TimingLogger level set to INFO
18:26:20,914 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [CoalescingStatistics] to Logger[org.perf4j.TimingLogger]
18:26:20,914 |-ERROR in ch.qos.logback.core.joran.action.AppenderRefAction - Could not find an appender named [perf4jFileAppender]. Did you define it below in the config file?
18:26:20,914 |-ERROR in ch.qos.logback.core.joran.action.AppenderRefAction - See http://logback.qos.ch/codes.html#appender_order for more details.
18:26:20,914 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
18:26:20,930 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [perf4jFileAppender]
18:26:20,962 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
18:26:21,136 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - No compression will be used
18:26:21,141 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use the pattern logs/perf4j.%d{yyyy-MM-dd}.log for the active file
18:26:21,151 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - The date pattern is 'yyyy-MM-dd' from file name pattern 'logs/perf4j.%d{yyyy-MM-dd}.log'.
18:26:21,151 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Roll-over at midnight.
18:26:21,158 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Setting initial period to Thu May 31 18:26:21 PKT 2012
18:26:21,161 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[perf4jFileAppender] - Active log file name: logs/perf4j.log
18:26:21,161 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[perf4jFileAppender] - File property is set to [logs/perf4j.log]

enter code here

Solution

  • The error message is very descriptive:

    18:26:20,462 |-ERROR in ch.qos.logback.core.joran.action.AppenderRefAction - Could not find an appender named [graphExecutionTimes]. Did you define it below in the config file?

    [...]

    18:26:20,506 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [graphExecutionTimes]

    The error message explicitly asks you: Did you define [graphExecutionTimes] appender below in the config file? And in fact, this is the case, as shown above. Just switch these declarations:

    <appender name="graphExecutionTimes" class="org.perf4j.logback.GraphingStatisticsAppender">
        <!-- Possible GraphTypes are Mean, Min, Max, StdDev, Count and TPS -->
        <param name="GraphType" value="Mean"/>
        <!-- The tags of the timed execution blocks to graph are specified here -->
        <param name="TagNamesToGraph" value="DESTROY_TICKET_GRANTING_TICKET,GRANT_SERVICE_TICKET,GRANT_PROXY_GRANTING_TICKET,VALIDATE_SERVICE_TICKET,CREATE_TICKET_GRANTING_TICKET" />
    </appender>
    
    <appender name="graphExecutionTPS" class="org.perf4j.logback.GraphingStatisticsAppender">
        <param name="GraphType" value="TPS" />
        <param name="TagNamesToGraph" value="DESTROY_TICKET_GRANTING_TICKET,GRANT_SERVICE_TICKET,GRANT_PROXY_GRANTING_TICKET,VALIDATE_SERVICE_TICKET,CREATE_TICKET_GRANTING_TICKET" />
    </appender>
    
    <appender name="CoalescingStatistics" class="org.perf4j.logback.AsyncCoalescingStatisticsAppender">
        <param name="TimeSlice" value="60000"/>
        <appender-ref ref="graphExecutionTimes"/>
        <appender-ref ref="graphExecutionTPS"/>
        <!-- We add the JMX Appender reference onto the CoalescingStatistics -->
        <appender-ref ref="perf4jJmxAppender"/>
    </appender>
    

    Just in case move perf4jFileAppender to the top as well. If this code snippet comes from Perf4J documentation, you should ask the authors to fix it.