An analysis of Android log mechanism (Android system)

Under Android Debug, the main way is to use logcat capture log, we may have tried to print with printf, of course, the result is not, there is time to look at the Android platform log flow, here to make a note to record


We usually use ALOGD to print log, so here's the flow of ALOGD.
System/core/include/log/log.h

System/core/include/log/log.h

#ifndef alogd                                                                                                                      #define ALOGD (...) (void) ALOG (Log_debug, Log_tag, __va_args__)) #endif #ifndef Alog#define ALOG (priority, TAG, ...)     Log_pri (android_# #priority, Tag, __va_args__) #endif #ifndef log_pri                                                                                                                    #define LOG_PRI (priority, tag, ...)     Android_printlog (priority, tag, __va_args__) #endif # define Android_printlog (Prio, tag, fmt ...) \                                                                                          __android_log_ Print (Prio, tag, FMT)

Here's what we found Alogd is actually a series of macros that will eventually be called to __android_log_print (Prio, Tag, FMT), this function takes three parameters:
1, priority, this is what we usually say log Level,alogd's log level is log_debug;
2,tag, this is the log_tag we specified in code.
3,__va_args__, this is our common format input, which means we can use formatted format for ALOGD parameters.


The specific implementation of __android_log_print is as follows:
System/core/liblog/logd_write.c

int __android_log_print (int prio, const char *tag, const char *fmt, ...)                                                           {    va_list ap;    Char buf[log_buf_size];    Va_start (AP, FMT);    vsnprintf (buf, log_buf_size, FMT, AP);    Va_end (AP);    Return __android_log_write (Prio, tag, buf);}

Here you can see that the formatted input is converted into an array of buf characters, and then BUF is called as the third argument __android_log_write


The specific implementation of __android_log_write is as follows:

int __android_log_write (int prio, const char *tag, const char *msg) {struct Iovec vec[3];    log_id_t log_id = Log_id_main;    Char tmp_tag[32];    if (!tag) tag = ""; /* Xxx:this needs to go!        */if (!STRCMP (tag, "Htc_ril") | | !STRNCMP (Tag, "RIL", 3) | | /* Any log tag with "RIL" as the prefix */!strncmp (tag, "IMS", 3) | |        /* Any log tag with "IMS" as the prefix */!strcmp (tag, "at") | |        !STRCMP (Tag, "GSM") | |        !STRCMP (Tag, "STK") | |        !STRCMP (Tag, "CDMA") | |        !STRCMP (Tag, "PHONE") | |            !STRCMP (Tag, "SMS")) {log_id = Log_id_radio; Inform Third party Apps/ril/radio.            To use Rlog or Rlog snprintf (tmp_tag, sizeof (Tmp_tag), "use-rlog/rlog-%s", tag);    tag = Tmp_tag;    } vec[0].iov_base = (unsigned char *) &prio;    Vec[0].iov_len = 1;    Vec[1].iov_base = (void *) tag;    Vec[1].iov_len = strlen (tag) + 1;    Vec[2].iov_base = (void *) msg;    Vec[2].iov_len= strlen (msg) + 1; Return Write_to_log (log_id, VEC, 3);}

You can see that the priority,tag,msg three parameters were filled into the Iovec's struct,
Iovec is IO vetor, a struct,readv and readv associated with READV and Writev are advanced I/O, not explained in depth here,
All we need to know is that the parameters passed in by the caller are populated into the Iovec in a fixed format, and the Last Call is Write_to_log (log_id, VEC, 3);


Here you can look at the specific implementation of Write_to_log:

static int (*write_to_log) (log_id_t, struct Iovec *vec, size_t nr) = __write_to_log_init;

You can see that Write_to_log is a function pointer initialized to __write_to_log_init


But Write_to_log was assigned to __write_to_log_kernel at Init.

static int __write_to_log_init (log_id_t log_id, struct Iovec *vec, size_t nr) {#ifdef have_pthreads    pthread_mutex_ Lock (&log_init_lock), #endif    if (write_to_log = = __write_to_log_init) {        Log_fds[log_id_main] = Log_open (" /dev/"Logger_log_main, o_wronly);        Log_fds[log_id_radio] = Log_open ("/dev/" Logger_log_radio, o_wronly);        Log_fds[log_id_events] = Log_open ("/dev/" logger_log_events, o_wronly);        Log_fds[log_id_system] = Log_open ("/dev/" Logger_log_system, o_wronly);        Write_to_log = __write_to_log_kernel;

Let's take a look at the concrete implementation of __write_to_log_kernel

static int __write_to_log_kernel (log_id_t log_id, struct Iovec *vec, size_t nr) {    ssize_t ret;    int log_fd;    if (/* (int) log_id >= 0 &&*/(int) log_id < (int) log_id_max) {        log_fd = log_fds[(int) log_id];    } else {        return EBADF;    }    do {        ret = Log_writev (LOG_FD, VEC, nr);    } while (Ret < 0 && errno = = eintr);    return ret;}

You can see that it is called Log_writev (LOG_FD, VEC, nr), where the three parameters are:
1,LOG_FD, which is the FD we need to write for the log that we alogd, this is/dev/log/main,/dev/log/radio/,dev/log/event,/dev/log/system file
2,vec, this is Iovec, which contains information such as Priority,tag,msg, and is dedicated to the READV and Wirtev use of the struct
3:NR, this should be the number of VEC struct arrays, here are 3, filled with priority,tag,msg

#if fake_log_device//This would be defined if building for the host. #define LOG_OPEN (pathname, flags) Fakelogopen (Pathna Me, Flags) #define LOG_WRITEV (filedes, Vector, Count) Fakelogwritev (filedes, Vector, count) #define Log_close (Filedes) Fakelogclose (filedes) #else # define LOG_OPEN (pathname, flags) Open (pathname, (flags) | O_CLOEXEC) #define LOG_WRITEV (filedes, Vector, Count) Writev (filedes, Vector, count) #define Log_close (filedes) Close ( Filedes) #endif

See, here is to use Writev to fill the content of the VEC in a fixed format to write to the log_fd corresponding path, so alogd to print the MSG is written to the/dev/log/main and other paths



Next we look at the flow of Logcat, why the log information is printed on the terminal after the terminal has entered Logcat
First we need to explain why printf cannot print information to the terminal:
System/core/init/init.c

static void Open_console () {    int fd;    if (fd = open (Console_name, O_RDWR)) < 0) {        fd = open ("/dev/null", O_RDWR);    }    IOCTL (FD, Tiocsctty, 0);    Dup2 (FD, 0);    Dup2 (FD, 1);    Dup2 (FD, 2);    Close (FD);}

The original Init process at the start of the 0,1,2 and other three fd are directed to the/dev/null, so our printf output to stdout (that is, FD 1) are lost to the/dev/null, this way there will be no information


Android's official explanations are as follows (System/core/init/readme.txt):
By default, programs executed by Init would drop stdout and stderr into
/dev/null. To help with debugging, you can execute your program via the
Andoird program Logwrapper. This would redirect Stdout/stderr into the
Android logging System (accessed via Logcat).




System/core/logcat/logcat.cpp
Starting with the main function of Logcat, you will first encounter an important place

if (!devices) {                                                                                                                devices = new log_device_t (StrDup ("/dev/" Logger_log_main), False, ' m '); Android::g_devcount = 1;int AccessMode =  (Mode & o_rdonly)? r_ok:0| (Mode & o_wronly)? w_ok:0;//only add this if it ' s availableif (0 = = Access ("/dev/" Logger_log_system, AccessMode)) {Devices->next = new log_device_t (StrDup ("/dev/" Logger_log_system), False, ' s '); android::g_devcount++;}}

Here we find that Logcat uses/dev/log/main and/dev/log/system two paths as device, here the value of G_devcount is 2


Next will set the output path, here is very important, directly related to the output of log, we found that can be output to Stdout_fileno, also can be the system specified parameters, this is specified by-F, on the role of-F, you can use the Help document to confirm

static void Setupoutput ()                                                                                                          {    if (g_outputfilename = = NULL) {        g_outfd = Stdout_fileno;    } else {        struct Stat statbuf;        G_OUTFD = OpenLogFile (g_outputfilename);        if (G_outfd < 0) {            perror ("couldn ' t open output file");            Exit ( -1);        }        Fstat (G_OUTFD, &statbuf);        G_outbytecount = Statbuf.st_size;    }}

In general, when we use Logcat directly, the corresponding output device of G_OUTFD is our terminal, which is why Logcat can print the log to the terminal


Finally is a very important place, here with select mechanism to query/dev/log/main and/dev/log/system two path whether there is log information can be printed,
If there is a word to print to the terminal, if not, then sleep 5ms, the time here is the last parameter of the SELECT function specified

static void Readloglines (log_device_t* devices) {log_device_t* dev;    int max = 0;    int ret;    int queued_lines = 0;    BOOL sleep = false;    int result;    Fd_set Readset;        for (dev=devices; dev; dev = dev->next) {if (Dev->fd > Max) {max = dev->fd; }} and (1) {do {timeval timeout = {0, +/-5ms */};//If We oversleep it's OK, i.e. IGN            Ore eintr.            Fd_zero (&readset);            for (dev=devices; dev; dev = dev->next) {fd_set (DEV-&GT;FD, &readset); } result = Select (Max + 1, &readset, NULL, NULL, sleep?)        NULL: &timeout);        } while (result = =-1 && errno = = eintr); If (Result >= 0) {for (dev=devices; dev; dev = dev->next) {if (Fd_isset (DEV-&GT;FD, &amp                    ; readset)) {queued_entry_t* entry = new queued_entry_t (); /* Note:driver guarantees we read ExactlY One full entry */ret = read (DEV-&GT;FD, entry->buf, Logger_entry_max_len);                            if (Ret < 0) {if (errno = = eintr) {Delete entry;                        Goto Next;                            } if (errno = = eagain) {Delete entry;                        Break                        } perror ("Logcat read");                    Exit (Exit_failure);                        } else if (!ret) {fprintf (stderr, "read:unexpected eof!\n");                    Exit (Exit_failure); } else if (Entry->entry.len! = ret-sizeof (struct logger_entry)) {fprintf (s Tderr, "read:unexpected length.                        Expected%d, got%d\n ", Entry->entry.len, ret-sizeof (struct logger_entry)); ExiT (exit_failure);                    Entry->entry.msg[entry->entry.len] = ' + ';                    Dev->enqueue (entry);                ++queued_lines;                }} if (result = = 0) {//We did our short timeout trick and there's nothing new                Print everything we have an and wait for more data sleep = true;                    while (true) {Choosefirst (Devices, &dev);                    if (dev = = NULL) {break; } if (G_tail_lines = = 0 | | queued_lines <= g_tail_lines) {printnextentry (dev                    );                    } else {skipnextentry (dev);                }--queued_lines;                    }//The caller requested to just dump the log and exit if (G_nonblock) {                Return       }} else {         Print all, aren ' t the last in their list sleep = false;                    while (G_tail_lines = = 0 | | queued_lines > G_tail_lines) {choosefirst (Devices, &dev);                    if (dev = = NULL | | dev->queue->next = = NULL) {break;                    } if (G_tail_lines = = 0) {printnextentry (dev);                    } else {skipnextentry (dev);                }--queued_lines;    }}}next:; }}

Can see in the result>0, that is, select in judging/dev/log/main and/dev/log/system two of the path of any one is readable, go to perform the following function

static void Printnextentry (log_device_t* dev) {                                                                                        maybeprintstart (dev);    if (g_printbinary) {        printbinary (&dev->queue->entry);    } else {        processbuffer (dev, &dev- >queue->entry);    }    Skipnextentry (dev);} static void Skipnextentry (log_device_t* dev) {    maybeprintstart (dev);    queued_entry_t* entry = dev->queue;    Dev->queue = entry->next;    Delete entry;}

This will be/dev/log/main or/dev/log/system read the information (that is, the information previously deposited with ALOGD) printed to the corresponding device G_OUTFD, the default is the terminal

static void Maybeprintstart (log_device_t* dev) {    if (!dev->printed) {        dev->printed = true;        if (G_devcount > 1 &&!g_printbinary) {            char buf[1024];            snprintf (buf, sizeof (BUF), "---------beginning of%s\n", dev->device);            if (Write (G_OUTFD, buf, strlen (buf)) < 0) {                perror ("Output error");                Exit ( -1);}}}    

The whole process of logcat here has been completed, and we hope to help you.