Debug log in Scala with no performance impact

Question

In languages like C/C++/Objective-C it's common to use preprocessor macros to define logging mechanisms that are not even compiled for released binaries, thus causing no performance hit. Something along the lines of:

#ifdef DEBUG
printf("some event we want to log\n");
#endif

Now, I know there's no preprocessor in Scala. So my question is: what is the best way to implement a mechanism to log program activity for debug purposes, while impacting performance the least when it's turned off?

Answer 1

Current practice (in Scala 2.9.x or earlier) is to use a thunk type (e.g. see Simple Logging Facade for Scala SLFS):

def log(x: =>Any) = if (logging) println(x)

// later in code
log("var1: " + myVar1)

This is often less expensive than actually constructing the string, since the string creation (and any subsequent activity) is only done if logging is true. However, it still incurs the cost of closure creation for the thunk x above.

However, starting from Scala 2.10.x, there is an experimental macro implementation included in the standard distribution (see this page, or SIP). The macro system will allow you to write logging calls which incur almost no runtime cost (other than the logging variable check) - they allow you to inline the call to log, so that this:

log("var1: " + myVar1)

becomes:

if (logging) log("var1: " + myVar1)

Notice that in this case there is no closure created for log, and the logging message string is only evaluated if logging is true - the cost is only the if-check.

Answer 2

Log4J is a common JVM logging framework. It is specifically designed to have minimal performance impact:

On an AMD Duron clocked at 800Mhz running JDK 1.3.1, it costs about 5 nanoseconds to determine if a logging statement should be logged or not. Actual logging is also quite fast, ranging from 21 microseconds using the SimpleLayout, 37 microseconds using the TTCCLayout. The performance of the PatternLayout is almost as good as the dedicated layouts, except that it is much more flexible.

So when you make a call like:

LOG.debug("something here")

the framework will first check if "debug" logging is enabled. This check is very fast. If logging is disabled, then it doesn't do any more work.

There is one catch however. If you write

LOG.debug(expensiveOperation())

then the framework won't do the debug-enabled check before performing the expensive operation. The way to correct for this is to say:

if(LOG.isDebugEnabled) LOG.debug(expensiveOperation())

Answer 3

You can use scala.annotation.elidable

An annotation for methods for which invocations might be removed in the generated code.

Behavior is influenced by passing -Xelide-below to scalac. Methods marked elidable will be omitted from generated code if the priority given the annotation is lower than to the command line argument. Examples: