You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@tez.apache.org by "Tsuyoshi Ozawa (JIRA)" <ji...@apache.org> on 2016/03/10 10:22:40 UTC

[jira] [Commented] (TEZ-2215) TezMerger$MergeQueue.next() should not invoke org.apache.commons.logging.impl.Log4JLogger.debug()

    [ https://issues.apache.org/jira/browse/TEZ-2215?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15188950#comment-15188950 ] 

Tsuyoshi Ozawa commented on TEZ-2215:
-------------------------------------

Opened HADOOP-12912 to add isDebugEnabled guard in Progress.set.

As a workaround, we can add the guard at Tez layer against Progress.set. Is it too aggressive for us?

> TezMerger$MergeQueue.next() should not invoke org.apache.commons.logging.impl.Log4JLogger.debug()
> -------------------------------------------------------------------------------------------------
>
>                 Key: TEZ-2215
>                 URL: https://issues.apache.org/jira/browse/TEZ-2215
>             Project: Apache Tez
>          Issue Type: Bug
>            Reporter: Rajesh Balamohan
>
> {noformat}
> Thread 11953: (state = IN_JAVA)
>  - org.apache.log4j.Category.log(java.lang.String, org.apache.log4j.Priority, java.lang.Object, java.lang.Throwable) @bci=8, line=852 (Compiled frame; information may be imprecise)
>  - org.apache.commons.logging.impl.Log4JLogger.debug(java.lang.Object) @bci=12, line=155 (Compiled frame)
>  - org.apache.hadoop.util.Progress.set(float) @bci=57, line=175 (Compiled frame)
>  - org.apache.tez.runtime.library.common.sort.impl.TezMerger$MergeQueue.next() @bci=145, line=586 (Compiled frame)
>  - org.apache.tez.runtime.library.common.ValuesIterator.readNextKey() @bci=5, line=181 (Compiled frame)
>  - org.apache.tez.runtime.library.common.ValuesIterator.access$300(org.apache.tez.runtime.library.common.ValuesIterator) @bci=1, line=47 (Compiled frame)
>  - org.apache.tez.runtime.library.common.ValuesIterator$1$1.next() @bci=67, line=140 (Compiled frame)
>  - EchoProcessor.run() @bci=158, line=48 (Compiled frame)
>  - org.apache.tez.runtime.library.processor.SimpleProcessor.run(java.util.Map, java.util.Map) @bci=15, line=53 (Interpreted frame)
>  - org.apache.tez.runtime.LogicalIOProcessorRuntimeTask.run() @bci=65, line=330 (Interpreted frame)
>  - org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run() @bci=119, line=179 (Interpreted frame)
>  - org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable$1.run() @bci=1, line=171 (Interpreted frame)
>  - java.security.AccessController.doPrivileged(java.security.PrivilegedExceptionAction, java.security.AccessControlContext) @bci=0 (Compiled frame)
>  - javax.security.auth.Subject.doAs(javax.security.auth.Subject, java.security.PrivilegedExceptionAction) @bci=42, line=422 (Interpreted frame)
>  - org.apache.hadoop.security.UserGroupInformation.doAs(java.security.PrivilegedExceptionAction) @bci=14, line=1628 (Interpreted frame)
>  - org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal() @bci=15, line=171 (Interpreted frame)
>  - org.apache.tez.runtime.task.TezTaskRunner$TaskRunnerCallable.callInternal() @bci=1, line=167 (Interpreted frame)
>  - org.apache.tez.common.CallableWithNdc.call() @bci=8, line=36 (Interpreted frame)
>  - java.util.concurrent.FutureTask.run() @bci=42, line=266 (Interpreted frame)
>  - java.util.concurrent.ThreadPoolExecutor.runWorker(java.util.concurrent.ThreadPoolExecutor$Worker) @bci=95, line=1142 (Interpreted frame)
>  - java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=5, line=617 (Interpreted frame)
>  - java.lang.Thread.run() @bci=11, line=745 (Interpreted frame)
> {noformat}
> Haven't gone through in detail on when this would be triggered.  But in any case, MergeQueue.next() is hot path and it should avoid this.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)