android logger spontaneously lowers its verbosity level (not Eclipse)

Question

Accepted answers:

It's a known bug (url)
It's a feature (url)

I can't figure out whether it's a bug or a feature of Android.

I have an app that calls Log.d() and I periodically launch logcat on my device and usually it's full of messages - around 300kb/min, but sometimes it just stops showing my and most of other messages. I don't have a clue what could be the reason.

After reboot everything works again.

Strange thing, I use Log.d(), but my messages are not there, but the log still contains some other rare D messages

public class AaaTest extends AndroidTestCase {
    public void testA() throws Exception {
        Log.wtf("foobar", "loggableE = " + Log.isLoggable("foobar", Log.ERROR));
        Log.wtf("foobar", "loggableW = " + Log.isLoggable("foobar", Log.WARN));
        Log.wtf("foobar", "loggableI = " + Log.isLoggable("foobar", Log.INFO));
        Log.wtf("foobar", "loggableD = " + Log.isLoggable("foobar", Log.DEBUG));
        Log.wtf("foobar", "loggableV = " + Log.isLoggable("foobar", Log.VERBOSE));
        Log.e("foobar", "this is error");
        Log.w("foobar", "this is warning");
        Log.i("foobar", "this is info");
        Log.d("foobar", "this is debug");
        Log.v("foobar", "this is verbose");
        Log.e("foobar", "this is error again");
        Log.wtf("foobar", "this is wtf");
    }
}

_

adb logcat -v threadtime "*:S" "foobar:V"
--------- beginning of /dev/log/system
--------- beginning of /dev/log/main
05-21 20:06:36.601 16052 16068 F foobar  : loggableE = true
05-21 20:06:36.629 16052 16068 F foobar  : loggableW = true
05-21 20:06:36.652 16052 16068 F foobar  : loggableI = true
05-21 20:06:36.672 16052 16068 F foobar  : loggableD = false
05-21 20:06:36.686 16052 16068 F foobar  : loggableV = false
05-21 20:06:36.808 16052 16068 E foobar  : this is error
05-21 20:06:36.808 16052 16068 E foobar  : this is error again
05-21 20:06:36.809 16052 16068 F foobar  : this is wtf

Looks like isLoggable() is completely unrelevant.

My device is Zopo ZP300+ with Android 4.0.4

`isLoggable()` is unrelevant since `Log.d()` method doesn't check its value. It's the responsibility of the developer to use `isLoggable` method if he wish to filter logs by loglevel. — Volo, May 30 '14 at 08:19

score 1 · Answer 1 · edited May 23 '17 at 10:26

Logcat logs are kept in circular buffers, so only the last "N" ( ~256K ) bytes are kept across all apps.

If some other app on your phone starts spewing logs and filling up the buffer you may start seeing logs being dropped. You may not see all the logs using up the buffer if you are filtering the logs ( by level or TAG ).

You can get stats about buffer size and usage with

adb logcat -g

If you pipe your logcat output to a file and tail -f the file, you should see most of the logs.

On Mac/Linux, you can save logcat locally with:

adb logcat -v long >> /tmp/logcat.txt &

And then inspect it:

tail -f /tmp/logcat.txt
grep <some_regex> /tmp/logcat.txt

If you see some app is producing lots of logs, you may consider disabling or uninstalling that app and see if that helps.

Some other tools to look into:

Pidcat: https://github.com/JakeWharton/pidcat
aLogcat: https://code.google.com/p/alogcat/

References

But that does not explain why only messages of a certain level are dropped — basin, May 26 '14 at 07:37

Martin Konecny · Answer 2 · 2014-05-30T03:43:45.147

0

This is definitely a bug.

After reboot everything works again.

The general advice in this situation is to restart adb. I use the following command:

sudo env PATH=$PATH adb kill-server && sudo env PATH=$PATH adb devices

You can alias this to make it shorter:

alias adbrestart='sudo env PATH=$PATH adb kill-server && sudo env PATH=$PATH adb devices'

edited May 30 '14 at 03:43

answered May 30 '14 at 03:13

Martin Konecny

57,827
19
139
159

android logger spontaneously lowers its verbosity level (not Eclipse)

2 Answers2