Lazy message evaluation all the way

[consp1racy]

Lazy evaluation of the message is one of the selling points of TimberKt, BUT...

Currently TimberKt doesn't care if a tag is loggable or not. It evaluates the message string and lets Timber do the dirty work. The message evaluation happens always, including cases when the log would be discarded.

if (Timber.treeCount() > 0) is just not good enough for this case.

Example: I have a CrashlyticsTree that logs just warnings and errors to Crashlytics. However, all log messages are evaluated just so that debug, info, and verbose could be dropped later.

class CrashlyticsTree : Timber.Tree() {

    override fun isLoggable(tag: String?, priority: Int): Boolean = priority >= Log.WARN

    override fun log(priority: Int, tag: String?, message: String, t: Throwable?) {
        Crashlytics.log(message)
        t?.let { Crashlytics.logException(it) }
    }
}

Another example: Logging that's controlled at runtime. With a permanently attached tree.

class AndroidTree : Timber.Tree() {

    override fun isLoggable(priority: Int): Boolean = Log.isLoggable("ASDF", priority)

    override fun log(priority: Int, tag: String?, message: String, t: Throwable?) {
        // ...
    }
}

or something like this

class AndroidTree(private val prefs: SharedPreferences) : Timber.Tree() {

    override fun isLoggable(priority: Int): Boolean = prefs.getBoolean("log", false)

    override fun log(priority: Int, tag: String?, message: String, t: Throwable?) {
        // ...
    }
}

Solution 1)

Wrap the message lambda in a object that's only evaluated when timber gets to format the output.

private class MessageWrapper internal constructor(messageProvider: () -> String) {

    private val message by lazy(LazyThreadSafetyMode.NONE) { messageProvider() }

    override fun toString(): String = message
}

inline fun td1(throwable: Throwable? = null, noinline message: () -> String) {
    Timber.d(throwable, "%s", MessageWrapper(message))
}

inline fun td1(throwable: Throwable) {
    Timber.d(throwable)
}

inline fun td1(noinline message: () -> String) {
    Timber.d("%s", MessageWrapper(message))
}

This could be made more efficient maybe with inline classes or whatnot... Current cost of this is one extra wrapper object and one extra lazy delegate object per call.

Solution 2)

Well... totally copy Timber into TimberKt and adapt prepareLog method for Kotlin use style.

private void prepareLog(int priority, Throwable t, String message, Object... args) {
  // Consume tag even when message is not loggable so that next message is correctly tagged.
  String tag = getTag();

  if (!isLoggable(tag, priority)) {
    return;
  }
  if (message != null && message.length() == 0) {
    message = null;
  }
  if (message == null) {
    if (t == null) {
      return; // Swallow message if it's null and there's no throwable.
    }
    message = getStackTraceString(t);
  } else {
    if (args != null && args.length > 0) {
      message = formatMessage(message, args);
    }
    if (t != null) {
      message += "\n" + getStackTraceString(t);
    }
  }

  log(priority, tag, message, t);
}

private fun prepareLog(priority: Int, t: Throwable?, messageProvider: () -> String?) {
    // ...
}

[ajalt]

I agree that more lazyness would be great.

Timberkt actually used to do something like your solution 1, but I changed it in version 1.2.0. The reason why is that the noinline wrapper cause a new class to be created for each log call, which adds a lot of methods.

I also thought about your second solution, but then this library wouldn't be compatible with existing code bases that use regular timber, so I don't want to do that either.

Maybe the right solution would be to make a PR to upstream timber to allow this sort of lazyness with inline methods.

[consp1racy]

Oh hey, it's been there for half a year!

https://github.com/JakeWharton/timber/blob/6f7ecafd5f9d410106dcd02b2373b40cfb9e6809/common/src/main/kotlin/timber/log/Timber.kt#L79

If this works, with static imports the new multiplatform Timber renders TimberKt obsolete. Well, mostly (w vs. warn). Or import aliasing. This is interesting.

[klemensz]

I've been using this library for many years now thinking that messages are being evaluated lazily ... just to read now that it's not the case 😆