5 Replies Latest reply on Mar 30, 2009 11:58 AM by bradsdavis

    Debug Logging

    bradsdavis

      I am going to clean up the trunk today to put isDebugEnabled statements around all log.debug calls.

      This will improve efficiency when debugging logs are not enabled.

      Please make sure to include log.isDebugEnabled() { log.debug... } around debug logs. If you dont, any string concatenation contained within the debug will occur even if the log is not set to debug.

      For example within AbstractTokenBaseCommand, the following statement:

      log.debug("executing " + this);
      


      This will result in 1) the to string being called on the object AbstractTokenBaseCommand then 2) the method log.debug being called.

      In other words, Java is going to resolve all parameters to method invocations before the method is called. The log statement should instead be:

      if(log.isDebugEnabled())
      {
       log.debug("executing " + this);
      }
      


        • 1. Re: Debug Logging
          dmlloyd

          Have a look at http://www.jboss.org/community/docs/DOC-11282 - in particular, any logging that's frequent enough to require filtering should be logged at TRACE, not DEBUG (this is why, in JBoss Common Logging, isDebugEnabled() is deprecated). If these logs are infrequent, then there's no need to optimize it.

          • 2. Re: Debug Logging
            bradsdavis

            Within that document, they also suggest that the debug level is for:


            Developer or in depth information required for support is the basis for this priority.


            That doesn't suggest that most will have debugging enabled in a production environment. We should be targeting production for efficient business processing.

            I haven't seen that isDebugEnabled is deprecated. Can you shoot me a link to that?

            Also, putting general debug messages that log full objects can lead to Hibernate lazy loading of objects when there is not necessarily a reason to load the object. This is definitely a place for efficiency bugs to creep up.

            • 3. Re: Debug Logging
              bradsdavis

              Within Commons Logging's documentation:
              http://commons.apache.org/logging/apidocs/index.html[/url]


              Performance is often a logging concern. By examining the appropriate property, a component can avoid expensive operations (producing information to be logged).

              For example,

              if (log.isDebugEnabled()) {
              ... do something expensive ...
              log.debug(theResult);
              }




              • 4. Re: Debug Logging
                dmlloyd

                 

                "bradsdavis" wrote:
                Within that document, they also suggest that the debug level is for:


                Developer or in depth information required for support is the basis for this priority.


                That doesn't suggest that most will have debugging enabled in a production environment. We should be targeting production for efficient business processing.


                The suggestion occurs later in the document. This has been discussed to death over several years, so I'm not going to argue about it. It's the policy.

                "bradsdavis" wrote:
                I haven't seen that isDebugEnabled is deprecated. Can you shoot me a link to that?


                Not Apache clogging, JBoss common logging. http://anonsvn.jboss.org/repos/common/common-logging-spi/trunk/src/main/java/org/jboss/logging/Logger.java

                "bradsdavis" wrote:
                Also, putting general debug messages that log full objects can lead to Hibernate lazy loading of objects when there is not necessarily a reason to load the object. This is definitely a place for efficiency bugs to creep up.


                Sounds like it ought to be a trace message.


                • 5. Re: Debug Logging
                  bradsdavis

                  David, I am not trying to argue about it. I think this is a genuine place we could improve efficiency.


                  Not Apache clogging, JBoss common logging. http://anonsvn.jboss.org/repos/common/common-logging-spi/trunk/src/main/java/org/jboss/logging/Logger.java


                  Correct me if I am wrong, but I think that most of the logging performed in jBPM is with Common's logging. Also, we want this to be portable to all containers, which means we should be programming for commons logging, and should also use the suggestions of Apache for how to use their logger.

                  I am sure there should be plenty of places where trace should be used rather than debug. However, I am trying to contribute something that is an easy and a proper fix for the issue at hand.