721461 - Add LOGD checks so Fennec can skip logging (and log message construction) when logcat is not listening

Status: RESOLVED WONTFIX

(Firefox for Android Graveyard :: General, defect, P5)

Description

[Chris Peterson [:cpeterson]]

This would be a run-time, not compile-time, check so testers in the field could still collect logs if they want.

For example, bug 717349 calculates checkboard regions (on every frame), but these calculations are unnecessary if adb logcat is not listening for our Log.d() messages. This is the normal use case for 99% of our users.

    private static final boolean LOGD = Log.isLoggable(LOGTAG);

    if (LOGD) {
        String msg = DoSomeExpensiveOperationsToConstructDebugMessage();
        Log.d(LOGTAG, msg);
    }

Note that Log.isLoggable() is more expensive than it seems. It calls out to JNI, mallocs some strings, and does an O(n) search of system properties flags. So we would want to cache isLoggable() values when the app is launched.

https://github.com/android/platform_frameworks_base/blob/master/core/jni/android_util_Log.cpp#L59

PMD has describes its "ProtectLogD" and "ProtectLogV" checks here:
http://pmd.sourceforge.net/rules/android.html

Comment 1

[Doug Turner (:dougt)]

does this help at all with perf?

Comment 2

[Richard Newman [:rnewman]]

(In reply to Doug Turner (:dougt) from comment #1)
> does this help at all with perf?

It would help some with perf, assuming the conditional were false. To quote:

  http://developer.android.com/reference/android/util/Log.html

  Tip: Don't forget that when you make a call like

  Log.v(TAG, "index=" + i);

  that when you're building the string to pass into Log.d, the compiler uses a
  StringBuilder and at least three allocations occur: the StringBuilder itself,
  the buffer, and the String object. Realistically, there is also another buffer
  allocation and copy, and even more pressure on the gc. That means that if your
  log message is filtered out, you might be doing significant work and incurring
  significant overhead. 

The log call itself isn't too bad, but the constant string building and GC can't be good.

Community wisdom says to do exactly as Chris suggests, and furthermore to use ProGuard to eliminate debug logging entirely in release builds:

  http://stackoverflow.com/a/2466662/22003

The Android release checklist even mentions this, though a quick look at logcat output suggests that it's not enforced, of course. (Because Android.)

  http://developer.android.com/guide/publishing/preparing.html#publishing-configure

Comment 3

[Chris Peterson [:cpeterson]]

> http://developer.android.com/guide/publishing/preparing.html#publishing-configure

I love Google's "Configuring our Application for Release" advice: "You can deactivate logging by removing calls to Log methods in your source files."


> Community wisdom says to do exactly as Chris suggests, and furthermore to use ProGuard to 
> eliminate debug logging entirely in release builds:

Note that ProGuard can eliminate the Log() method calls, but the expensive string-building of Log() parameters may not be removed.

Comment 4

[Kartikaya Gupta (email:[e-mail])]

Also proguard is compile-time, not run-time. We should enable/disable logging based on prefs. I had a script to clean up log lines, it shouldn't be too hard to modify it to do what we want here.

Comment 5

[Kartikaya Gupta (email:[e-mail])]

The script is attached to bug 703059. Download it to $SOMEFOLDER/logtag.java, compile it, and run like so from inside mobile/android/base/ (and the other folders)

grep -l "Log" *.java* | xargs java -cp $SOMEFOLDER logtag

It will update *.java* and clean up log lines to be consistent. You can modify line 42 of logtag.java to insert something like "if (LogHelper.loggingEnabled)" before each log line, and create a LogHelper class that updates a loggingEnabled variable with a pref or whatever.

Comment 6

[Richard Newman [:rnewman]]

(In reply to Kartikaya Gupta (:kats) from comment #5)

> grep -l "Log" *.java* | xargs java -cp $SOMEFOLDER logtag

You probably want

  --exclude sync/

in your grep invocation. We already have methods in place to handle this.

Also, wow. You wrote a text transformation in Java, not sed! Go you!

Comment 7

[Kartikaya Gupta (email:[e-mail])]

The invocation I had above actually doesn't even recurse into subfolders. Back when I first wrote it everything was in a couple of folders so I just ran it manually on each folder. But yeah, adjust as necessary to get the right files.

I did consider sed, but inserting the LOGTAG line seemed like it would be too convoluted in sed or even awk and java is my default language for when i don't have a more specific tool :)

Comment 8

[Chris Peterson [:cpeterson]]

If we are going to update every Log() call, I suggest we standardize on:

1. Log.d() for all developer log output (replacing a mess of calls to Log.e/w/i/v)
2. and Log.wtf() [1] for conditions that should be reported in Bugzilla if seen in logcat.

Log.wtf() is only available >= Froyo, so if we continue to support Eclair, we can call Log.e(LOGTAG, msg, new AssertionError()) instead.

[1] http://developer.android.com/reference/android/util/Log.html#wtf%28java.lang.String,%20java.lang.String%29

Comment 9

[Kartikaya Gupta (email:[e-mail])]

Sounds good to me.

Comment 10

[Chris Peterson [:cpeterson]]

WONTFIX because bug 815684 will read logcat retroactively when uploading a crash report.