[ 
https://issues.apache.org/jira/browse/ZOOKEEPER-1767?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Patrick Hunt updated ZOOKEEPER-1767:
------------------------------------

    Assignee: Jackie Chang

> DEBUG log statements use SLF4j {} format to improve performance
> ---------------------------------------------------------------
>
>                 Key: ZOOKEEPER-1767
>                 URL: https://issues.apache.org/jira/browse/ZOOKEEPER-1767
>             Project: ZooKeeper
>          Issue Type: Improvement
>    Affects Versions: 3.4.5
>            Reporter: Jackie Chang
>            Assignee: Jackie Chang
>            Priority: Minor
>         Attachments: ZOOKEEPER-1767-correct-indents.patch, 
> ZOOKEEPER-1767-slf4j.patch
>
>
> As a coordination service, ZooKeeper is meant to be high performant. DEBUG 
> logs are not normally viewed (see Doug Cutting's comment in HADOOP-953). I 
> propose to add a conditional check to each DEBUG log stmt to improve 
> performance. 
> Firstly, previous issues added a condition check before a DEBUG log stmt. For 
> example, in ZOOKEEPER-558:
> {code}
> - LOG.debug("Got notification sessionid:0x" 
> -     + Long.toHexString(sessionId)); 
> + if (LOG.isDebugEnabled()) { 
> +     LOG.debug("Got notification sessionid:0x" + 
> +     Long.toHexString(sessionId)); 
> + }
> {code} 
> And in ZOOKEEPER-259:
> {code}
> -                LOG
> -                    .debug("Got ping sessionid:0x"
> -                    + Long.toHexString(sessionId));
> +                if (LOG.isDebugEnabled()) {
> +                    LOG.debug("Got ping response for sessionid:0x"
> +                            + Long.toHexString(sessionId)
> +                            + " after " 
> +                            + ((System.nanoTime() - lastPingSentNs) / 
> 1000000)
> +                            + "ms");
> +                }
> {code}
> Secondly, its underlying cause is that: 
> * *If a DEBUG log stmt is unguarded, the string operations (most likely 
> concatenations) are actually conducted even though the log event doesn't 
> happen b/c a level less verbose than DEBUG is configured.*
> * Adding the conditional check creates another basic block in Java bytecode. 
> And instructions inside that basicblock is executed only when execution path 
> goes into it. But this only happens when the path passes the test. Detailed 
> explanations are in a StackOverflow thread: 
> http://stackoverflow.com/questions/10428447/log-debug-enabled-check-in-java
> An alternative solution is to move from log4j to slf4j and use the "{}" 
> format. A workaround now is to add all conditional checks. The additional 
> overhead is marginal (possibly compare-and-jump instruction(s) in Java 
> bytecode) compared to saved computation of expensive string creations and 
> concatenations.  
> Its counterpart in Hadoop has been accepted: HADOOP-6884.



--
This message was sent by Atlassian JIRA
(v6.1#6144)

Reply via email to