8

I've been looking at the various scala logging libraries lately, and the vast majority of them implement their logging functions as

def debug(s: => String)

So that if you have debug logging turned off, it won't execute the statement. However, I just came across logula which specifically states as one of its benefits

Unlike a lot of Scala logging libraries, Logula doesn't use pass-by-name semantics (e.g., f: => A) for its logging statements, which means two things:

  • The Scala compiler doesn't have to create one-off closure objects for each logging statement. This should reduce the amount of garbage collection pressure.

Which actually makes total sense to me. So my question is, is there any real world performance benchmarks/data comparing the 2 approaches? Ideally something from a live project versus contrived benchmarks?

Rex Kerr
  • 166,841
  • 26
  • 322
  • 407
Falmarri
  • 47,727
  • 41
  • 151
  • 191

2 Answers2

8

Which is faster depends entirely upon use cases. If you are logging static strings, then it's faster to just pass that constant string in and ignore it. Otherwise, if you're creating strings you have to create at least one object anyway. Function objects are tiny and cheap--you're better off creating one of those than the string if you're going to ignore it.

Personally, I think this sort of first-principles understanding of the tradeoffs is even more valuable than a case study of a particular application that may have used one or the other, because it lets you understand why you would choose one or the other (and you'll still always want to benchmark your own application).

(Note: how expensive object creation is depends on how heavily impacted the garbage collector is; generally, short-lived objects can be created and disposed of at a rate of on the order of 108 per second, which shouldn't be a concern except in tight inner loops. If you're putting logging statements in tight inner loops, I think something is wrong. You should be writing unit tests for that instead.)

Rex Kerr
  • 166,841
  • 26
  • 322
  • 407
  • 1
    `Personally, I think this sort of first-principles understanding of the tradeoffs is even more valuable than a case study of a particular application` While I definitely agree with the principle here, reality can be a completely different beast than what you anticipate. That's why I'm looking for real life cases instead of benchmarks, because anyone can write a benchmark that makes one way look a million times faster. Mostly for my own curiosity, because honestly, what application is logging really the bottleneck? – Falmarri Jul 31 '12 at 16:52
  • @Falmarri - It can be different than you expect _especially_ if you reason from examples. That's why I explained the fundamental tradeoffs. I agree that logging ought not be the bottleneck in most applications. – Rex Kerr Jul 31 '12 at 16:55
  • @Falmarri Well... do you measure everything? There are people who swear by measuring every step in their application, including queue size, throughput and response time. If you go that route, you don't want your logging to add to the total time. In fact, you want it to be async. – Daniel C. Sobral Jul 31 '12 at 19:00
3

I'll go out on a limb and say that philosophical discussions about tradeoffs are more useful when there is some interesting tradeoff to be made, which is to say, not here.

class A {
  var debugging = true
  @inline final def debug(msg: => String) = if (debugging) println(msg)

  def f = { debug("I'm debugging!") ; 5 }
}
% scalac292 -optimise a.scala
% ls -l *.class
-rw-r--r--  1 paulp  staff  1503 Jul 31 22:40 A.class
%

Count the closure objects.

psp
  • 12,138
  • 1
  • 41
  • 51
  • 1
    Very good to know! Although it may be more difficult to achieve the elision if you are trying to use an external library's log method to do the logging...but this just argues that you should have your own local `@inline final def debug` wrapping the library call in those places that you need it. – Rex Kerr Aug 01 '12 at 14:25