Debug logging in Kotlin

There are many logging libraries for Android, but all of them have one common issue. They all have an impact on production performance to some extent. Let’s see how big this impact can be and how can it be minimized in Kotlin language.

Suppose we have a logging class like that:

public class MyLogger {
    public static void d(String message) {
        if (BuildConfig.DEBUG) {
            Log.d("TAG", message);
        }
    }
	
    // other logging methods
}

and it is called somewhere in the code like this

MyLogger.d("Hello, " + expensiveToCompute());

Does it have performance overhead if BuildConfig.DEBUG == false ?

Yes!

What’s the overhead?

There are several types of performance overhead a logger can bring:

  1. Logging method is called in production
    MyLogger.d(...);

    will not do anything in production, but it will still be called. And even worse,

  2. Logging method arguments are calculated
    "Hello, " + expensiveToCompute();

    expression will be calculated, which can be pretty expensive.

  3. Logging method invocation is still in the bytecode
    The performance impact is minimal, but it still increases the size of the production dex file a bit. Furthermore, it can reveal some text you didn’t mean to be read.

How can it be solved in Java?

The method call can be removed with the help of Proguard’s -assumenosideeffects tweak. Given the method call

MyLogger.d("Hello, " + expensiveToCompute());

and the proguard setting

-assumenosideeffects class MyLogger {
    public static void d(...);
}

the generated bytecode will strip out the MyLogger.d call, but what will stay is

expensiveToCompute()

That’s because Proguard is not sure that expinsiveToCompute() method will not have any side effects, so it leaves this method call in the bytecode untouched.
One more side effect of this approach is that line numbers in stacktraces can be slightly shifted.

The only non-hacky way to avoid the arguments calculation in Java is to wrap the method call with the if statement:

if (BuildConfig.DEBUG) MyLogger.d("Hello, " + expensiveToCompute());

But the problem with this solution is that it is too verbose. You have to write the if statement every time you log.

I’ve tried to avoid the calculation of arguments in production by performing source code manipulation with a custom Gradle plugin that was doing the following:

  1. Commenting out all logging calls before compilation (with a regexp)
  2. Compiling
  3. Uncommenting all the calls commented at step 1

This worked. It actually also removed the logging strings from the bytecode and did not shift the lines of the stacktraces. But I still feel that the solution is a bit too hacky to be used in large teams, as it requires developers to be careful when logging.

Let’s solve it in Kotlin!

In Kotlin we can defer arguments calculation by passing them into a method inside of lambda, like this:

fun log(lambda: () -> String) {
    if (BuildConfig.DEBUG) {
        Log.d("TAG", lambda())
    }
}

With this approach the logging arguments passed inside of the lambda will only be calculated if BuildConfig.DEBUG == true . But it still calls the method and also creates an extra lambda object for every logging call, which is not for free too.

And here is where the inline modifier comes into play.

inline fun log(lambda: () -> String) {
    if (BuildConfig.DEBUG) {
        Log.d("TAG", lambda())
    }
}

The inline modifier inlines both the method call and the lambdas passed into it.

The following method call

log { "Hello, ${expensiveToCompute()}" }

will be replaced with

if (BuildConfig.DEBUG) Log.d("TAG", "Hello, " + expensiveToCompute())

in the generated bytecode!

So, we get rid of the method call and argument calculation overhead in production while using the nice logging syntax!

By the way, if we need to perform additional calculations before logging, we can do it inside the same lambda:

log {
    val anotherExpensiveCalculation = calculate()
    "Hello, ${expensiveToCompute()} and $anotherExpensiveCalculation"
}

Drawbacks

There are several things you have to know before applying this approach.

First, exception stack traces may sometimes contain line numbers beyond the end of file, as stated in the M12 release notes in the Source Maps for Better Debugging (JSR-45) section. I was able to reproduce this behaviour when exception was thrown from the line next to inlined method call.

Second, even though BuildConfig.DEBUG == false in release builds, and it is constant, it will not be inlined, and the

if (BuildConfig.DEBUG) { ... }

statement will not be removed from the bytecode at compile time, as it would be in Java.

Conclusion

The lambda-based approach allows you to avoid logging method calls and arguments calculation. It still leaves the logging methods in the bytecode, despite the fact that they are unreachable.

You can find the source code on the Github.
The project performs logging in several ways using Java and Kotlin.
Build it with

./gradlew assembleRelease

After that you can convert apk to jar with dex2jar and inspect the code with JD-GUI, or use any other tools of your choice.

Leave a Reply