hadoop-common-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Luke Lu (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (HADOOP-7055) Update of commons logging libraries causes EventCounter to count logging events incorrectly
Date Sun, 27 Mar 2011 17:52:05 GMT

    [ https://issues.apache.org/jira/browse/HADOOP-7055?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13011825#comment-13011825

Luke Lu commented on HADOOP-7055:

bq. When EventCounter appender is triggered, it only updates its counts field. So equals overhead
is not negligible compared to the actual logging which is counts field updating in this case.

When the appender is triggered, a new LoggingEvent object is created and at least one synchronization
happened which is probably 100x more expensive then the method call. Note, updating the counts
field is a *synchronized* call, which is about 30x more expensive then the equals call. If
don't believe it, just benchmark it and make sure you have at least two threads doing the
update, so jvm doesn't elide the locks.

> Update of commons logging libraries causes EventCounter to count logging events incorrectly
> -------------------------------------------------------------------------------------------
>                 Key: HADOOP-7055
>                 URL: https://issues.apache.org/jira/browse/HADOOP-7055
>             Project: Hadoop Common
>          Issue Type: Bug
>          Components: metrics
>    Affects Versions: 0.21.0, 0.21.1, 0.22.0, 0.23.0
>            Reporter: Jingguo Yao
>            Assignee: Jingguo Yao
>   Original Estimate: 0.5h
>  Remaining Estimate: 0.5h
> Hadoop 0.20.2 uses commons logging 1.0.4. EventCounter works correctly with this version
of commons logging. Hadoop 0.21.0 uses commons logging 1.1.1 which causes EventCounter to
count logging events incorrectly. I have verified it with Hadoop 0.21.0. After start-up of
hadoop, I checked jvmmetrics.log after several minutes. In every metrics record, "logError=0,
logFatal=0, logInfo=3, logWarn=0" was shown. The following text is an example.
> jvm.metrics: hostName=jingguolin, processName=DataNode, sessionId=, gcCount=3, gcTimeMillis=31,
logError=0, logFatal=0, logInfo=3, logWarn=0, maxMemoryM=888.9375, memHeapCommittedM=38.0625,
memHeapUsedM=3.6539612, memNonHeapCommittedM=18.25, memNonHeapUsedM=11.335686, threadsBlocked=0,
threadsNew=0, threadsRunnable=8, threadsTerminated=0, threadsTimedWaiting=6, threadsWaiting=6
> Then I stopped hadoop and replaced commons logging 1.1.1 with 1.0.4. After the re-start
of hadoop, a lot of logging events showed up in jvmmetrics.log.
> I have checked the source code of Log4JLogger for both 1.0.4 (http://svn.apache.org/viewvc/commons/proper/logging/tags/LOGGING_1_0_4/src/java/org/apache/commons/logging/impl/Log4JLogger.java?view=markup)
and 1.1.1 (http://svn.apache.org/viewvc/commons/proper/logging/tags/commons-logging-1.1.1/src/java/org/apache/commons/logging/impl/Log4JLogger.java?view=markup).
For 1.0.4, Level instances such as Level.INFO are used to construct LoggingEvent. But for
1.1.1, Priority instances such as Priority.INFO are used to construct LoggingEvent. So 1.1.1
version's event.getLevel() always returns Priority instances. EventCounter append method's
"==" check always fails between a Level instance and a Priority instance. For "logInfo=3"
metrics records produced by commons logging 1.1.1., I think that these 3 logging events are
produced by log4j code directly instead of through commons logging API. The following code
is EventCounter's append method.
>     public void append(LoggingEvent event) {
>         Level level = event.getLevel();
>         if (level == Level.INFO) {
>             counts.incr(INFO);
>         }
>         else if (level == Level.WARN) {
>             counts.incr(WARN);
>         }
>         else if (level == Level.ERROR) {
>             counts.incr(ERROR);
>         }
>         else if (level == Level.FATAL) {
>             counts.incr(FATAL);
>         }
>     }

This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

View raw message