CODEWITHSUNDEEP
androidandroid-logcat
Neil Townsend
Neil Townsend

Reputation: 6084

Rather odd behaviour of Log

I wrote a very simple Android Activity:

import android.os.Bundle;
import android.app.Activity;
import android.util.Log;

public class MainActivity extends Activity {

    @Override
    protected void onCreate(Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);

        Log.d("TAG", "onCreate() Log call 1");
        Log.d("SMS", "onCreate() Log call 2");
        Log.d("TEST", "onCreate() Log call 3");

        finish();
    }

    @Override
    protected void onDestroy() {
        Log.d("TAG", "onDestroy() Log call 1");
        Log.d("SMS", "onDestroy() Log call 2");
        Log.d("TEST", "onDestroy() Log call 3");

        super.onDestroy();
    }
}

I would expect this to generate 6 log messages (3 from onCreate(), 3 from onDestroy()). Here is the logcat:

04-14 17:31:58.363: D/TAG(18084): onCreate() Log call 1
04-14 17:31:58.363: D/TEST(18084): onCreate() Log call 3
04-14 17:31:59.905: D/TAG(18084): onDestroy() Log call 1
04-14 17:31:59.905: D/TEST(18084): onDestroy() Log call 3

As can be seen, the lines with the tag "SMS" don't get through. This is not, as far as I can tell a documented thing. The question is, why?

EDIT: More details on the answer.

A rather good answer is given below by Matthew Burke. In short, on the basis of the source code for logd_write.c, it seems that:

Upvotes: 3

Views: 484

Answers (2)

Matthew Burke
Matthew Burke

Reputation: 2364

I should have read the documentation for logcat before I started hunting through source. According to logcat's documentation:

The Android logging system keeps multiple circular buffers for log messages, and not all of the log messages are sent to the default circular buffer.

Messages with a tag of SMS are sent to the radio buffer, not the main buffer. Hence you won't see them unless you go out of your way to do so. If you run the command:

adb logcat -b radio

you should see your missing log messages. The above information can be found in https://developer.android.com/tools/debugging/debugging-log.html.

Now, for those of you interested in code spelunking, below is my original answer:

The methods in the Log class are all wrappers around println_native which is a JNI method.
println_native performs some validation of its parameters and then calls __android_log_buf_write.

Now this latter method compares the tag parameter (from the original Log.d call) against several hard-coded strings (with the tag SMS being one of this list) and if it finds a match, winds up writing the log message to a different file!

By the way, other tags that get rerouted are GSM, STK, PHONE, CDMA, and a few others.

Relevant source can be read in

These aren't the official links and may disappear at some point. I'll try and track down the official links and edit this later this evening.

Upvotes: 4

Kevin Coppock
Kevin Coppock

Reputation: 134664

EDIT Ignore this, I'm apparently quite off base according to this.

So I thought this was interesting, and after digging through the source, I ended up finding out about Log.isLoggable():

Checks to see whether or not a log for the specified tag is loggable at the specified level. The default level of any tag is set to INFO. This means that any level above and including INFO will be logged. Before you make any calls to a logging method you should check to see if your tag should be logged. You can change the default level by setting a system property: 'setprop log.tag. ' Where level is either VERBOSE, DEBUG, INFO, WARN, ERROR, ASSERT, or SUPPRESS. SUPPRESS will turn off all logging for your tag. You can also create a local.prop file that with the following in it: 'log.tag.=' and place that in /data/local.prop.

Parameters
tag The tag to check.
level The level to check.

Returns
Whether or not that this is allowed to be logged.

Apparently some tags are not allowed at certain log levels, seemingly defined in /data/local.prop, but there must be some system level properties file I haven't found yet. You can check against it using something like this, though:

boolean isLoggableV = Log.isLoggable("SMS", Log.VERBOSE);
boolean isLoggableD = Log.isLoggable("SMS", Log.DEBUG);
boolean isLoggableI = Log.isLoggable("SMS", Log.INFO);
boolean isLoggableW = Log.isLoggable("SMS", Log.WARN);
boolean isLoggableE = Log.isLoggable("SMS", Log.ERROR);
boolean isLoggableA = Log.isLoggable("SMS", Log.ASSERT);

Log.v("LogTest", String.format("Verbose: %b Debug: %b Info: %b Warn: %b Error: %b Assert: %b", isLoggableV, isLoggableD, isLoggableI, isLoggableW, isLoggableE, isLoggableA));

Which for me returned the following:

Verbose: false Debug: false Info: true Warn: true Error: true Assert: true

So you can log the tag SMS at a log level of INFO and above, but not VERBOSE or DEBUG.

I have to assume this is to prevent applications from accidentally logging personal information, but it seems like a fairly crude way of doing so.

Upvotes: 0

Related Questions