Overhead (speed & garbage) of calling functions that do nothing.

Question

I am trying to reduce the performance/garbage collection costs of logging statements. I want to have lots of logging statements that I could enable for debugging, but also have a way to turn them off for fast production.

I ran a benchmark on calling the following methods:

public static final isLogging = false; 

public static logObjs(Object[] params) {
  if(isLogging)
    System.out.println(params[0]);
}

public static log3Obj(Object a, Object b, Object c) {
  if(isLogging)
     System.out.println(a);
}

public static logInts(int a, int b, int c) {
  if(isLogging)
    System.out.println(a);
}

I benchmarked the functions with a driver method

long sum = 0;
for(int i = 0; i < 100000000; ++i) {
   int a = i; int b = i+1; int c = i+2;
   logFoo(a,b,c);
   sum += a; }

logObjs(i, i+1, i+2) takes about 2 seconds for 1e8 iterations and produces lots of garbage. The sources are, I assume, autoboxing of integers and the Object[] creation for the variable # of parameters.

log3Obj produces a lot (though less) garbage and takes about 1.2 seconds; again, I assume the autoboxing still happens.

logInts is very fast (0.2 sec), just as fast as the loop with no function call.

So, the issue is that even though the function deterministically doesn't do anything, the autoboxing still happens. In my code, I'd actually prefer to have isLogging not be final, but rather have it be a runtime parameter, but in order to do that, this simpler case (where the compiler can prove that the function doesn't do anything) should run. Of course, I can replace all my logging statements with

if(isLogging)
   logObjs(a, b, c);

but that's very inelegant. I thought this is something that the JIT should take care of. I've tried a bunch of compiler settings, but maybe there's something I'm missing? How do I make the code not generate so much garbage while doing nothing?

Answer 1

This is extremly similar to this question: http://stackoverflow.com/questions/3092004/will-the-java-optimizer-remove-parameter-construction-for-empty-method-calls/3092053#3092053

As I wrote there: the JIT very well might realize that it will not have to do anything (a bit less in your case as its more involved). But apparantly it does not seem to do so.

What I would propose is a to make multiple log methods, a general one with some vararg parameters and some overloaded ones taking integers and preventing autoboxing in the first place:

Log(Object... arguments) { /* do logging */ }
Log(Object a, Object b, Object c}  { /* special case for 3 objects */ }
Log(int a, int b, int c}  { /* special case for 3 ints */ }

UPDATE: Better yet, see Péter Török 'do not re-invent the wheel' answer...

Answer 2

You should really prefer an existing logging framework like Log4J instead of reinventing the wheel. Those guys have put in way more effort into optimizing their logging framework than you can ever realistically have. See the "Performance" section near the end of this Short introduction to log4j.

Moreover, don't try to optimize prematurely. Chances are, putting serious effort into optimizing logging statements (or for that matter, whichever part of your app) without actual measurements and proof that this actually improves things is not going to pay off.

Answer 3

I think you should log what you need to log, rather than convert the integers to objects.

Calling logObjs() or log3Obj() to log integers is just a waste of time - you are going to create temporary objects for the boxing/unboxing and they will need to be disposed. Nothing you can do about that.

I suspect that most of the time when you are going to be calling logObjs() you would be passing real objects to the function, in which case the GC cost is almost zero, as you will simply be pass references to those objects into logObjs() and no object creation or disposal is required.

Write several logging functions that take different argument lists appropriate to what you are intending to log at that time. Thats what I do. If I need to log a string and a 32 bit value, I have a logging API with those params, etc. No (or little) un-necessary/temporary object creation.

If you need to log 3 integers write an API that takes 3 integers. If you need to log a weeble object and wobble object and a dont-fall-down object then write an API for that too. Minimise the box/unobx/GC effects by using appropriate APIs for your logging functions.