(Androidシステム)android logメカニズムの概要

androidの下でdebug、最も主要な方法はlogcatでlogを捕まえて、私達はprintfを使って印刷することを試みたことがあるかもしれなくて、もちろん結果はだめで、ここで時間があってandroidプラットフォームの下でlogのflowを見て、ここでメモを取って記録します
私達は普通ALOGDを使ってlogを印刷して、だからここでALOGDのflowについて
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)

ここで発見されたALOGDは実は一連のマクロであり、最終的には
__android_log_print(prio,tag,fmt)、この関数には3つのパラメータがあります.
1、優先度、これは私たちが普段言っているlog levelで、ALOGDのlog levelはLOG_です.DEBUG;
2、tag、これが私たちがcodeで指定したLOGです.TAG
3,__VA_ARGS__,これが一般的なフォーマット入力です.つまり、ALOGDバンドのパラメータはフォーマットされたフォーマットを使用することができます.
についてandroid_log_printの具体的な実現は以下の通りである.
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);
}

ここでは、フォーマットされた入力がbufの文字配列に変換され、bufが3番目のパラメータとして呼び出される_android_log_write
についてandroid_log_writeの具体的な実現は以下の通りである.

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);
}

priority,tag,msgの3つのパラメータがiovecのstructにそれぞれ埋め込まれていることがわかります.
iovecはio vetorであり、readvとwritevに関連するstructであり、readvとreadvは高度なI/Oであり、ここでは深く説明しない.
呼び出し元から渡されたパラメータがiovecに固定されたフォーマットで埋め込まれていることを知っておく必要があります.最後にwrite_を呼び出します.to_log(log_id, vec, 3);
ここでwriteを見てみましょうto_ロゴの具体的な実装:

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

write_を見つけることができますto_logは関数ポインタで、__に初期化されます.write_to_log_init
でもwrite_to_logはinitの時に__に割り当てられますwrite_to_log_kernel

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;

次に_を見てみましょう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;
}

は、log_が呼び出されたことを示します.writev(log_fd,vec,nr)、ここで3つのパラメータはそれぞれ:
1,log_fd、つまり私たちのALOGDが生成したlogに書き込む必要があるfdです.ここでは/dev/log/main、/dev/log/radio/、dev/log/event、/dev/log/systemなどのファイルです.
2,vec,priority,tag,msgなどの情報を含むiovec,readvやwirtev専用struct
3:nr,ここではvec構造体配列の個数であるべきで,ここでは3個でpriority,tag,msgがそれぞれ充填されている

#if FAKE_LOG_DEVICE
// This will be defined when building for the host.
#define log_open(pathname, flags) fakeLogOpen(pathname, 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

見たでしょう.ここではwritevでvecに埋め込まれた内容を固定形式でlog_に書きます.fdに対応するパスが作成され、これでALOGDで印刷するmsgが/dev/log/mainなどに書き込まれます
次にlogcatのflowを見てみましょう.なぜ端末がlogcatを入力すると、log情報が端末に印刷されるのでしょうか.
まず、printfが端末に情報を印刷できない理由を説明する必要があります.
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);
}

もともとinitプロセスは起動時に0,1,2など3つのfdを/dev/nullに指向していたので、printfがstdout(つまりfd 1)に出力して/dev/nullに捨ててしまったので、情報は得られませんでした
Androidの公式解釈は以下の通りです(system/core/init/readme.txt):
By default, programs executed by init will drop stdout and stderr into
/dev/null. To help with debugging, you can execute your program via the
Andoird program logwrapper. This will redirect stdout/stderr into the
Android logging system (accessed via logcat).
system/core/logcat/logcat.cpp
まずlogcatのmain関数から歩くと、まず重要な場所に遭遇します.

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 available
	if (0 == access("/dev/"LOGGER_LOG_SYSTEM, accessmode)) {
		devices->next = new log_device_t(strdup("/dev/"LOGGER_LOG_SYSTEM), false, 's');
		android::g_devCount++;
	}
}

ここではlogcatが/dev/log/mainと/dev/log/systemの2つのパスをdeviceとして使用していることがわかりました.ここでg_devCountの値は2です
次にoutputのパスを設定します.ここで重要なのは、logの出力に直接関連し、stdOUT_に出力できることです.FILENOは、システムが指定したパラメータであってもよく、これは-fが指定したものであり、-fの役割についてはhelpドキュメントで確認してもよい

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;
    }
}

一般的にlogcatを直接使用する場合、g_outFDに対応する出力装置が私たちの端末です.これはlogcatがlogを端末に印刷できる理由です.
最後に重要な点は、selectのメカニズムで/dev/log/mainと/dev/log/systemの2つのパスにlog情報が印刷できるかどうかをクエリーすることです.
あれば端末に印刷し、なければsleep 5 ms、ここの時間はselect関数の最後のパラメータで指定します

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;
        }
    }


    while (1) {
        do {
            timeval timeout = { 0, 5000 /* 5ms */ }; // If we oversleep it's ok, i.e. ignore EINTR.
            FD_ZERO(&readset);
            for (dev=devices; dev; dev = dev->next) {
                FD_SET(dev->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->fd, &readset)) {
                    queued_entry_t* entry = new queued_entry_t();
                    /* NOTE: driver guarantees we read exactly one full entry */
                    ret = read(dev->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!
");
                        exit(EXIT_FAILURE);
                    }
                    else if (entry->entry.len != ret - sizeof(struct logger_entry)) {
                        fprintf(stderr, "read: unexpected length. Expected %d, got %d
",
                                entry->entry.len, ret - sizeof(struct logger_entry));
                        exit(EXIT_FAILURE);


                    entry->entry.msg[entry->entry.len] = '\0';


                    dev->enqueue(entry);
                    ++queued_lines;
                }
            }


            if (result == 0) {
                // we did our short timeout trick and there's nothing new
                // print everything we have 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 that 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:
        ;
    }
}

result>0の場合、つまりselectが/dev/log/mainと/dev/log/systemの2つのパスのいずれかがreadableであると判断した場合、次の関数を実行することがわかります.

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;
}

ここでは/dev/log/mainまたは/dev/log/systemで読み取った情報(つまり前にALOGDで格納した情報)をg_に印刷しますoutFD対応のデバイスでは、デフォルトでは端末

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
", dev->device);
            if (write(g_outFD, buf, strlen(buf)) < 0) {
                perror("output error");
                exit(-1);
            }
        }
    }
}

ここまでlogcatのプロセス全体が終わりましたので、皆さんの役に立つことを願っています.