前文咱們瞭解到,在android系統中打log,其實就是向幾個設備文件中的一箇中寫入字符串。但咱們又要如何來查看這些log呢?是logcat工具,它會讀取log,對log作一個格式化,而後呈現給咱們。下面咱們來看一下logcat的實現。 android
先來看一下logcat的用法。下面是logcat打印出來的help信息: git
Usage: logcat [options] [filterspecs] options include: -s Set default filter to silent. Like specifying filterspec '*:s' -f <filename> Log to file. Default to stdout -r [<kbytes>] Rotate log every kbytes. (16 if unspecified). Requires -f -n <count> Sets max number of rotated logs to <count>, default 4 -v <format> Sets the log print format, where <format> is one of: brief process tag thread raw time threadtime long -c clear (flush) the entire log and exit -d dump the log and then exit (don't block) -t <count> print only the most recent <count> lines (implies -d) -g get the size of the log's ring buffer and exit -b <buffer> Request alternate ring buffer, 'main', 'system', 'radio' or 'events'. Multiple -b parameters are allowed and the results are interleaved. The default is -b main -b system. -B output the log in binary filterspecs are a series of <tag>[:priority] where <tag> is a log component tag (or * for all) and priority is: V Verbose D Debug I Info W Warn E Error F Fatal S Silent (supress all output) '*' means '*:d' and <tag> by itself means <tag>:v If not specified on the commandline, filterspec is set from ANDROID_LOG_TAGS. If no filterspec is found, filter defaults to '*:I' If not specified with -v, format is set from ANDROID_PRINTF_LOG or defaults to "brief"
由上面的help信息,咱們能夠看到,logcat主要有3個功能,一是清除log設備中的log(-c參數);二是獲取log的ring buffer的大小(-g參數,所謂ring buffer指的也就是某個log設備);三是打印格式化的log(其餘),這也是logcat最爲主要的功能。用於控制格式化的log輸出的參數比較多,大體包括,是否爲非阻塞輸出log(-d),輸出的log的內容(-t),輸出log的buffer(-b,此參數對三種功能都有效),輸出log到文件(-f),log文件最大大小(-r),輸出log文件的最大個數(-n),是否爲binary輸出(-B),輸出log的格式(-v),log的filter(-s)等。控制log輸出的這麼多參數看得人眼花繚亂,總結一下,打印log,也就是將所選擇的log設備中,內容符合特定規則的特定數量的log,以必定的格式寫入到特定的最大數量及最大大小有限的文件中去。接下來咱們會看一下logcat是如何組織它的code,以實現這些功能的。 shell
不難想到,logcat要實現這些功能,勢必會抽象出來一些數據結構,以方便代碼的組織。沒錯,logcat主要是定義了struct log_device_t來描述一個log設備,也就是log的來源,及AndroidLogFormat,用於對所要輸出的log進行過濾。先來看一下struct log_device_t的定義: express
struct queued_entry_t { union { unsigned char buf[LOGGER_ENTRY_MAX_LEN + 1] __attribute__((aligned(4))); struct logger_entry entry __attribute__((aligned(4))); }; queued_entry_t* next; queued_entry_t() { next = NULL; } }; struct log_device_t { char* device; bool binary; int fd; bool printed; char label; queued_entry_t* queue; log_device_t* next; log_device_t(char* d, bool b, char l) { device = d; binary = b; label = l; queue = NULL; next = NULL; printed = false; } void enqueue(queued_entry_t* entry) { if (this->queue == NULL) { this->queue = entry; } else { queued_entry_t** e = &this->queue; while (*e && cmp(entry, *e) >= 0) { e = &((*e)->next); } entry->next = *e; *e = entry; } } };
由此,咱們能夠看到,log設備的屬性主要是其文件描述符,設備名稱等。有那個next指針,咱們不難想到系統在組織log設備中的log內容時,是會將各個log設備用一個鏈表鏈接起來。而每一個log設備都有本身的一個queued_entry_t類型的鏈表,用於存放該設備中的log。queued_entry_t的 數據部分爲一個char型的buf或struct logger_entry,表示log設備的一個項。上面的LOGGER_ENTRY_MAX_LEN和struct logger_entry定義在system/core/include/cutils/logger.h文件中: 數據結構
/* * The userspace structure for version 1 of the logger_entry ABI. * This structure is returned to userspace by the kernel logger * driver unless an upgrade to a newer ABI version is requested. */ struct logger_entry { uint16_t len; /* length of the payload */ uint16_t __pad; /* no matter what, we get 2 bytes of padding */ int32_t pid; /* generating process's pid */ int32_t tid; /* generating process's tid */ int32_t sec; /* seconds since Epoch */ int32_t nsec; /* nanoseconds */ char msg[0]; /* the entry's payload */ }; /* * The maximum size of a log entry which can be read from the * kernel logger driver. An attempt to read less than this amount * may result in read() returning EINVAL. */ #define LOGGER_ENTRY_MAX_LEN (5*1024)
組織log設備及log設備中的內容的結構大體就如上面所述的那樣。而後咱們再來看一下AndroidLogFormat,它表示用戶想要查看的log的格式,其定義爲(在system/core/include/cutils/logprint.h中): app
41typedef struct AndroidLogFormat_t AndroidLogFormat;
再來看struct AndroidLogFormat_t的定義(在system/core/liblog/logprint.c中): less
typedef struct FilterInfo_t { char *mTag; android_LogPriority mPri; struct FilterInfo_t *p_next; } FilterInfo; struct AndroidLogFormat_t { android_LogPriority global_pri; FilterInfo *filters; AndroidLogPrintFormat format; };
這個結構描述了用戶想要的log的內容及輸出log的格式。用戶能夠指定本身所想要的log,其TAG及其優先級爲何,各個TAG及其優先級用一個FilterInfo來描述,並最終用一個鏈表鏈接起來。其中的優先級用android_LogPriority描述,在system/core/include/android/log.h中定義: 函數
/* * Android log priority values, in ascending priority order. */ typedef enum android_LogPriority { ANDROID_LOG_UNKNOWN = 0, ANDROID_LOG_DEFAULT, /* only for SetMinPriority() */ ANDROID_LOG_VERBOSE, ANDROID_LOG_DEBUG, ANDROID_LOG_INFO, ANDROID_LOG_WARN, ANDROID_LOG_ERROR, ANDROID_LOG_FATAL, ANDROID_LOG_SILENT, /* only for SetMinPriority(); must be last */ } android_LogPriority;
而輸出log的格式則用AndroidLogPrintFormat描述,其定義在system/core/include/cutils/logprint.h中: 工具
typedef enum { FORMAT_OFF = 0, FORMAT_BRIEF, FORMAT_PROCESS, FORMAT_TAG, FORMAT_THREAD, FORMAT_RAW, FORMAT_TIME, FORMAT_THREADTIME, FORMAT_LONG, } AndroidLogPrintFormat;
總結一下, AndroidLogFormat描述了用戶想要查看的log及輸出log的格式,所想要查看的log指的是用戶能夠指定log的TAG及其優先級。 oop
接着咱們來看一下logcat的這些功能是如何被一個個實現的。
咱們會先從main() 函數的參數解析部分開始,下面是這個部分的code:
int main(int argc, char **argv) { int err; int hasSetLogFormat = 0; int clearLog = 0; int getLogSize = 0; int mode = O_RDONLY; const char *forceFilters = NULL; log_device_t* devices = NULL; log_device_t* dev; bool needBinary = false; g_logformat = android_log_format_new(); if (argc == 2 && 0 == strcmp(argv[1], "--test")) { logprint_run_tests(); exit(0); } if (argc == 2 && 0 == strcmp(argv[1], "--help")) { android::show_help(argv[0]); exit(0); } for (;;) { int ret; ret = getopt(argc, argv, "cdt:gsQf:r::n:v:b:B"); if (ret < 0) { break; } switch(ret) { case 's': // default to all silent android_log_addFilterRule(g_logformat, "*:s"); break; case 'c': clearLog = 1; mode = O_WRONLY; break; case 'd': g_nonblock = true; break; case 't': g_nonblock = true; g_tail_lines = atoi(optarg); break; case 'g': getLogSize = 1; break; case 'b': { char* buf = (char*) malloc(strlen(LOG_FILE_DIR) + strlen(optarg) + 1); strcpy(buf, LOG_FILE_DIR); strcat(buf, optarg); bool binary = strcmp(optarg, "events") == 0; if (binary) { needBinary = true; } if (devices) { dev = devices; while (dev->next) { dev = dev->next; } dev->next = new log_device_t(buf, binary, optarg[0]); } else { devices = new log_device_t(buf, binary, optarg[0]); } android::g_devCount++; } break; case 'B': android::g_printBinary = 1; break; case 'f': // redirect output to a file android::g_outputFileName = optarg; break; case 'r': if (optarg == NULL) { android::g_logRotateSizeKBytes = DEFAULT_LOG_ROTATE_SIZE_KBYTES; } else { long logRotateSize; char *lastDigit; if (!isdigit(optarg[0])) { fprintf(stderr,"Invalid parameter to -r\n"); android::show_help(argv[0]); exit(-1); } android::g_logRotateSizeKBytes = atoi(optarg); } break; case 'n': if (!isdigit(optarg[0])) { fprintf(stderr,"Invalid parameter to -r\n"); android::show_help(argv[0]); exit(-1); } android::g_maxRotatedLogs = atoi(optarg); break; case 'v': err = setLogFormat (optarg); if (err < 0) { fprintf(stderr,"Invalid parameter to -v\n"); android::show_help(argv[0]); exit(-1); } hasSetLogFormat = 1; break; case 'Q': /* this is a *hidden* option used to start a version of logcat */ /* in an emulated device only. it basically looks for androidboot.logcat= */ /* on the kernel command line. If something is found, it extracts a log filter */ /* and uses it to run the program. If nothing is found, the program should */ /* quit immediately */ #define KERNEL_OPTION "androidboot.logcat=" #define CONSOLE_OPTION "androidboot.console=" { int fd; char* logcat; char* console; int force_exit = 1; static char cmdline[1024]; fd = open("/proc/cmdline", O_RDONLY); if (fd >= 0) { int n = read(fd, cmdline, sizeof(cmdline)-1 ); if (n < 0) n = 0; cmdline[n] = 0; close(fd); } else { cmdline[0] = 0; } logcat = strstr( cmdline, KERNEL_OPTION ); console = strstr( cmdline, CONSOLE_OPTION ); if (logcat != NULL) { char* p = logcat + sizeof(KERNEL_OPTION)-1;; char* q = strpbrk( p, " \t\n\r" );; if (q != NULL) *q = 0; forceFilters = p; force_exit = 0; } /* if nothing found or invalid filters, exit quietly */ if (force_exit) exit(0); /* redirect our output to the emulator console */ if (console) { char* p = console + sizeof(CONSOLE_OPTION)-1; char* q = strpbrk( p, " \t\n\r" ); char devname[64]; int len; if (q != NULL) { len = q - p; } else len = strlen(p); len = snprintf( devname, sizeof(devname), "/dev/%.*s", len, p ); fprintf(stderr, "logcat using %s (%d)\n", devname, len); if (len < (int)sizeof(devname)) { fd = open( devname, O_WRONLY ); if (fd >= 0) { dup2(fd, 1); dup2(fd, 2); close(fd); } } } } break; default: fprintf(stderr,"Unrecognized Option\n"); android::show_help(argv[0]); exit(-1); break; } } 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++; } } if (android::g_logRotateSizeKBytes != 0 && android::g_outputFileName == NULL ) { fprintf(stderr,"-r requires -f as well\n"); android::show_help(argv[0]); exit(-1); } android::setupOutput(); if (hasSetLogFormat == 0) { const char* logFormat = getenv("ANDROID_PRINTF_LOG"); if (logFormat != NULL) { err = setLogFormat(logFormat); if (err < 0) { fprintf(stderr, "invalid format in ANDROID_PRINTF_LOG '%s'\n", logFormat); } } } if (forceFilters) { err = android_log_addFilterString(g_logformat, forceFilters); if (err < 0) { fprintf (stderr, "Invalid filter expression in -logcat option\n"); exit(0); } } else if (argc == optind) { // Add from environment variable char *env_tags_orig = getenv("ANDROID_LOG_TAGS"); if (env_tags_orig != NULL) { err = android_log_addFilterString(g_logformat, env_tags_orig); if (err < 0) { fprintf(stderr, "Invalid filter expression in" " ANDROID_LOG_TAGS\n"); android::show_help(argv[0]); exit(-1); } } } else { // Add from commandline for (int i = optind ; i < argc ; i++) { err = android_log_addFilterString(g_logformat, argv[i]); if (err < 0) { fprintf (stderr, "Invalid filter expression '%s'\n", argv[i]); android::show_help(argv[0]); exit(-1); } } }
拋開前面那一堆局部變量的定義不看,main()函數是先調用android_log_format_new(),建立了一個全局的AndroidLogFormat對象。咱們能夠看一下 android_log_format_new()的定義(在文件system/core/liblog/logprint.c中):
AndroidLogFormat *android_log_format_new() { AndroidLogFormat *p_ret; p_ret = calloc(1, sizeof(AndroidLogFormat)); p_ret->global_pri = ANDROID_LOG_VERBOSE; p_ret->format = FORMAT_BRIEF; return p_ret; }
主要就是爲 AndroidLogFormat 對象分配了一塊內存,而後初始化了其中的global_pri和format成員。
緊接着,main()函數是處理了兩個單獨的功能(兩個if block),一個是run test,另外一個是show help。不知道Google寫logcat的人是怎麼考慮的,(1)、其實感受將調用android_log_format_new()建立AndroidLogFormat對象的過程放在兩個if block的後面可能會更好一點,反正兩個if block是要exit的,而同時又都沒有用到g_logformat對象。此外,(2)、咱們搜遍logcat.cpp,是發現對android::show_help()的調用後面就老是緊接着對exit()的調用,其實將exit()放在android::show_help()的定義中也不錯,這樣就能夠減小一些的重複code,能夠外加一個exit code參數,並將函數更名爲show_help_and_exit()。
接下來,main()函數是藉助於getopt()函數,將各個參數解析出來,而後保存在一些局部變量或全局變量中。能夠稍微看一下那些略顯複雜的參數的解析。咱們將分析-s,-b,-v這幾個參數。
先是-s參數,它會調用android_log_addFilterRule()函數,給log format添加一個filter,表示用戶不想看到任何的log。咱們能夠看一下android_log_addFilterRule()函數的定義:
static FilterInfo * filterinfo_new(const char * tag, android_LogPriority pri) { FilterInfo *p_ret; p_ret = (FilterInfo *)calloc(1, sizeof(FilterInfo)); p_ret->mTag = strdup(tag); p_ret->mPri = pri; return p_ret; } /* * Note: also accepts 0-9 priorities * returns ANDROID_LOG_UNKNOWN if the character is unrecognized */ static android_LogPriority filterCharToPri (char c) { android_LogPriority pri; c = tolower(c); if (c >= '0' && c <= '9') { if (c >= ('0'+ANDROID_LOG_SILENT)) { pri = ANDROID_LOG_VERBOSE; } else { pri = (android_LogPriority)(c - '0'); } } else if (c == 'v') { pri = ANDROID_LOG_VERBOSE; } else if (c == 'd') { pri = ANDROID_LOG_DEBUG; } else if (c == 'i') { pri = ANDROID_LOG_INFO; } else if (c == 'w') { pri = ANDROID_LOG_WARN; } else if (c == 'e') { pri = ANDROID_LOG_ERROR; } else if (c == 'f') { pri = ANDROID_LOG_FATAL; } else if (c == 's') { pri = ANDROID_LOG_SILENT; } else if (c == '*') { pri = ANDROID_LOG_DEFAULT; } else { pri = ANDROID_LOG_UNKNOWN; } return pri; } int android_log_addFilterRule(AndroidLogFormat *p_format, const char *filterExpression) { size_t i=0; size_t tagNameLength; android_LogPriority pri = ANDROID_LOG_DEFAULT; tagNameLength = strcspn(filterExpression, ":"); if (tagNameLength == 0) { goto error; } if(filterExpression[tagNameLength] == ':') { pri = filterCharToPri(filterExpression[tagNameLength+1]); if (pri == ANDROID_LOG_UNKNOWN) { goto error; } } if(0 == strncmp("*", filterExpression, tagNameLength)) { // This filter expression refers to the global filter // The default level for this is DEBUG if the priority // is unspecified if (pri == ANDROID_LOG_DEFAULT) { pri = ANDROID_LOG_DEBUG; } p_format->global_pri = pri; } else { // for filter expressions that don't refer to the global // filter, the default is verbose if the priority is unspecified if (pri == ANDROID_LOG_DEFAULT) { pri = ANDROID_LOG_VERBOSE; } char *tagName; // Presently HAVE_STRNDUP is never defined, so the second case is always taken // Darwin doesn't have strnup, everything else does #ifdef HAVE_STRNDUP tagName = strndup(filterExpression, tagNameLength); #else //a few extra bytes copied... tagName = strdup(filterExpression); tagName[tagNameLength] = '\0'; #endif /*HAVE_STRNDUP*/ FilterInfo *p_fi = filterinfo_new(tagName, pri); free(tagName); p_fi->p_next = p_format->filters; p_format->filters = p_fi; } return 0; error: return -1; }
這個函數所作的事情就是,將filer字串掰開成兩部分,一部分是TAG,另一部分是priority。priority的部分,能夠用字符,如"v"、"d"等來指定,也能夠用"2"、"3"等這些數字來指定。而TAG的部分,則當TAG爲"*"時,表示要設置全局的priority,不然,須要新建一個filter info,並插入到p_format對象filter info鏈表的頭部。
而後是-b參數,它是要添加一個log 設備。由此實現能夠看到,若是咱們想要指定多個devices,好比events、radio和system,則方法應該爲-b events -b radio -b system,而不是-b events radio system。另外,device會被添加到device鏈表的尾部。
最後是-v 參數。咱們主要來看一下setLogFormat()函數的定義:
static int setLogFormat(const char * formatString) { static AndroidLogPrintFormat format; format = android_log_formatFromString(formatString); if (format == FORMAT_OFF) { // FORMAT_OFF means invalid string return -1; } android_log_setPrintFormat(g_logformat, format); return 0; }
很簡單,將string形式的format作一個轉換,而後設給g_logformat。咱們也順便看一下android_log_formatFromString()和android_log_setPrintFormat()的定義:
void android_log_setPrintFormat(AndroidLogFormat *p_format, AndroidLogPrintFormat format) { p_format->format=format; } /** * Returns FORMAT_OFF on invalid string */ AndroidLogPrintFormat android_log_formatFromString(const char * formatString) { static AndroidLogPrintFormat format; if (strcmp(formatString, "brief") == 0) format = FORMAT_BRIEF; else if (strcmp(formatString, "process") == 0) format = FORMAT_PROCESS; else if (strcmp(formatString, "tag") == 0) format = FORMAT_TAG; else if (strcmp(formatString, "thread") == 0) format = FORMAT_THREAD; else if (strcmp(formatString, "raw") == 0) format = FORMAT_RAW; else if (strcmp(formatString, "time") == 0) format = FORMAT_TIME; else if (strcmp(formatString, "threadtime") == 0) format = FORMAT_THREADTIME; else if (strcmp(formatString, "long") == 0) format = FORMAT_LONG; else format = FORMAT_OFF; return format; }
由這個實現,咱們又發現一個能夠對logcat作加強的地方。即,在main() 函數裏,調用setLogFormat()函數的地方,或者在setLogFormat()函數中,將formatString參數先作一點點處理,即把全部的字符都轉爲小寫字符,大概會稍稍提高一點logcat的可用性。
參數解析完了以後呢?固然就是要看一下用戶所指定的參數是否合適了。首先是devices參數。這個參數是必須的,但用戶可能漏設了這個參數,因而要添加幾個默認的device,就是"main"和"system"兩個device了。而後是-r參數的問題。即"-r"參數是在設置了"-f"參數的狀況下才有效,不然應用退出。接着是調用setupOutput()函數,來爲輸出的文件作進一步的設置。setupOutput()函數定義以下:
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; } }
主要就是初始化輸出文件的文件描述符。緊接着是log format參數。若是用戶沒有設置此參數,則logcat將嘗試從環境變量中讀取,若是仍是讀不到,那就只好用默認的FORMAT_BRIEF了。最後是filter參數。咱們無論跟-Q參數有關的部分。要給logcat指定filters,都是要在參數列表的最後,用TAG:PRI這種形式來指定。若是用戶沒有指定filters參數,則logcat會嘗試從環境變量中讀取,若是指定了一個或多個filter參數,則將它們一個個的添加給g_logformat。若是咱們只想看到TAG爲某些值的log,則老是須要在最後添加上"*:s" filter,不然,logcat就仍是會把全部的log都顯示出來。此處彷佛有改進的空間,其實能夠在發現用戶有指定filters時,就先把"*:s"這個filter添加給g_logformat。
在main()函數裏:
dev = devices; while (dev) { dev->fd = open(dev->device, mode); if (dev->fd < 0) { fprintf(stderr, "Unable to open log device '%s': %s\n", dev->device, strerror(errno)); exit(EXIT_FAILURE); } if (clearLog) { int ret; ret = android::clearLog(dev->fd); if (ret) { perror("ioctl"); exit(EXIT_FAILURE); } } if (getLogSize) { int size, readable; size = android::getLogSize(dev->fd); if (size < 0) { perror("ioctl"); exit(EXIT_FAILURE); } readable = android::getLogReadableSize(dev->fd); if (readable < 0) { perror("ioctl"); exit(EXIT_FAILURE); } printf("%s: ring buffer is %dKb (%dKb consumed), " "max entry is %db, max payload is %db\n", dev->device, size / 1024, readable / 1024, (int) LOGGER_ENTRY_MAX_LEN, (int) LOGGER_ENTRY_MAX_PAYLOAD); } dev = dev->next; } if (getLogSize) { exit(0); } if (clearLog) { exit(0); }
再看那幾個輔助函數:
static int clearLog(int logfd) { return ioctl(logfd, LOGGER_FLUSH_LOG); } /* returns the total size of the log's ring buffer */ static int getLogSize(int logfd) { return ioctl(logfd, LOGGER_GET_LOG_BUF_SIZE); } /* returns the readable size of the log's ring buffer (that is, amount of the log consumed) */ static int getLogReadableSize(int logfd) { return ioctl(logfd, LOGGER_GET_LOG_LEN); }
總的來講,就是利用logger驅動提供的ioctl功能,將一個log設備中的log內容清空,或者獲取log設備的一些信息。
在main()函數裏:
//LOG_EVENT_INT(10, 12345); //LOG_EVENT_LONG(11, 0x1122334455667788LL); //LOG_EVENT_STRING(0, "whassup, doc?"); if (needBinary) android::g_eventTagMap = android_openEventTagMap(EVENT_TAG_MAP_FILE); android::readLogLines(devices); return 0; }
主要就是調用readLogLines()了。該函數定義爲:
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!\n"); exit(EXIT_FAILURE); } else if (entry->entry.len != ret - sizeof(struct logger_entry)) { fprintf(stderr, "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] = '\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: ; } }
因爲可能要同時輸出多個log設備文件中的log,這裏使用了select機制來監控這些log設備文件中的哪一個設備可讀:
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);
若是result>=0,則表示有log設備文件可讀或者超時。接着就用一個for循環檢查哪一個設備可讀,即FD_ISSET(dev->fd, &readset)是否爲true,若是爲true,則代表該log設備可讀,則須要進一步將該log設備中的日誌讀出。對於select系統調用而言,readset既是一個傳入參數,又是一個傳出參數,做爲傳入參數時,它表示須要監聽哪些文件描述符上的事件,作爲傳出參數時,則表示select()返回,是因爲哪些文件上的事件。這也便是在for循環的開始處,每次都要從新構造readset的緣由。爲什麼此處是用的select機制,而沒有使用opoll機制,此處是否有可能使用epoll機制呢?留待後續分析。
logcat在讀取log時,是輪流讀取每個能夠讀取的log設備,每一個設備中讀取一條。此處的一條log的含義,有必要經過實驗或從log設備驅動的角度來進一步釐清,一個struct queued_entry_t居然都要佔用5KB的內存空間呢。這個部分對應於以下的code:
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!\n"); exit(EXIT_FAILURE); } else if (entry->entry.len != ret - sizeof(struct logger_entry)) { fprintf(stderr, "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] = '\0'; dev->enqueue(entry); ++queued_lines; } }
調用read函數以前,先建立一個queued_entry_t的entry,接着調用read函數將log讀到entry->buf中,最後調用dev->enqueue(entry)將log記錄加入到對應的log設備的log項隊例中去。回想咱們前面看到的struct log_device_t的定義中的enqueue()函數,在插入一條log以後,它老是會保證log設備的log隊列中的各log是有序的,有cmp()函數來決定各條log的先後。咱們來看cmp()函數的定義:
static int cmp(queued_entry_t* a, queued_entry_t* b) { int n = a->entry.sec - b->entry.sec; if (n != 0) { return n; } return a->entry.nsec - b->entry.nsec; }
即log隊列中各條log將以時間順序由早到晚的排列。將一條log插入隊列的同時,還會把當前的log記錄數保存在queued_lines變量中。
繼續進一步處理log:
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; } }
此處有一點讓人弄不明白,result>0才意味着log設備中有內容須要讀取。爲什麼此處沒有把讀取log設備文件的代碼直接放在處理result>0這一case的block中,而要單獨拎出來呢?留待後續分析。接着看此處大代碼。
若是result == 0,就代表select的返回是因爲超時,目前沒有新的log能夠讀取,這時就要先處理以前已經讀取的log。會用一個while循環來輸出所需數量的log。在while循環中,調用chooseFirst()函數選擇log隊列不爲空,且log隊列中第一條日誌記錄時間戳最小的設備,即先輸出最舊的日誌:
static void chooseFirst(log_device_t* dev, log_device_t** firstdev) { for (*firstdev = NULL; dev != NULL; dev = dev->next) { if (dev->queue != NULL && (*firstdev == NULL || cmp(dev->queue, (*firstdev)->queue) < 0)) { *firstdev = dev; } } }
若是存在這樣的設備,則依據於g_tail_lines(-t參數能夠指定)的值,初步判斷一條log是應該要輸出仍是要丟棄:
if (g_tail_lines == 0 || queued_lines <= g_tail_lines) { printNextEntry(dev); } else { skipNextEntry(dev); }
g_tail_lines表示顯示最新log記錄的條數,若是爲0,就表示所有顯示。若是g_tail_lines == 0或者queued_lines <= g_tail_lines,就表示這條log記錄應該輸出,不然就要丟棄。每處理完一條日誌記錄,queued_lines就減1,這樣,最新的g_tail_lines就能夠輸出出來了。
若是result > 0,就表示select是因爲有設備文件可讀而返回。分兩種狀況,一是用戶指定了要顯示的最新log的數量,則會檢查已經讀取的log條數是否已經超越了用戶想要的log數量,若是是,則要丟棄最老的那些log記錄;二是沒有指定要顯示的最新log的數量的狀況,即都要顯示,則會輸出前面讀取的全部的log。能夠看一下這段代碼:
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; }
丟棄一條日誌,用skipNextEntry()函數,咱們能夠看一下它的定義:
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); } } } } static void skipNextEntry(log_device_t* dev) { maybePrintStart(dev); queued_entry_t* entry = dev->queue; dev->queue = entry->next; delete entry; }
在首次被調用同時以前沒有輸出國任何log時,會先輸出一行提示信息。而後就是從log設備log隊列的頭部取下一個log記錄,並將其空間釋放掉。後面會再來看輸出一條log記錄的printNextEntry()函數。
從前面的分析中看出,最終log設備文件內容的輸出是經過printNextEntry()函數進行的,這個函數的定義以下:
static void printNextEntry(log_device_t* dev) { maybePrintStart(dev); if (g_printBinary) { printBinary(&dev->queue->entry); } else { processBuffer(dev, &dev->queue->entry); } skipNextEntry(dev); }
maybePrintStart(dev),這個咱們前面看過了,就是用來打印咱們每次用logcat打log都會看到的最開始的那幾行的。而後就是分兩種狀況來打印log。當g_printBinary爲true時,以二進制方式輸出log到指定的文件中:
void printBinary(struct logger_entry *buf) { size_t size = sizeof(logger_entry) + buf->len; int ret; do { ret = write(g_outFD, buf, size); } while (ret < 0 && errno == EINTR); }
所謂的二進制格式,主要是相對於純文本格式而言的,指的是,log驅動在存儲log時是有必定的結構的,也就是struct logger_entry的結構,log驅動返回給logcat的也將是這種結構,這種結構並非很適合直接給用戶來查看。而二進制格式的輸出則指,將會不作任何修飾及轉換地將struct logger_entry寫入文件中。
咱們再來看g_printBinary爲false的狀況。此時,logcat在輸出log以前,會先對一個log記錄作一個到文本形式的格式化。其處理過程都在processBuffer()函數中:
static void processBuffer(log_device_t* dev, struct logger_entry *buf) { int bytesWritten = 0; int err; AndroidLogEntry entry; char binaryMsgBuf[1024]; if (dev->binary) { err = android_log_processBinaryLogBuffer(buf, &entry, g_eventTagMap, binaryMsgBuf, sizeof(binaryMsgBuf)); //printf(">>> pri=%d len=%d msg='%s'\n", // entry.priority, entry.messageLen, entry.message); } else { err = android_log_processLogBuffer(buf, &entry); } if (err < 0) { goto error; } if (android_log_shouldPrintLine(g_logformat, entry.tag, entry.priority)) { if (false && g_devCount > 1) { binaryMsgBuf[0] = dev->label; binaryMsgBuf[1] = ' '; bytesWritten = write(g_outFD, binaryMsgBuf, 2); if (bytesWritten < 0) { perror("output error"); exit(-1); } } bytesWritten = android_log_printLogLine(g_logformat, g_outFD, &entry); if (bytesWritten < 0) { perror("output error"); exit(-1); } } g_outByteCount += bytesWritten; if (g_logRotateSizeKBytes > 0 && (g_outByteCount / 1024) >= g_logRotateSizeKBytes ) { rotateLogs(); } error: //fprintf (stderr, "Error processing record\n"); return; }
總體的流程大體爲:一、依據一個log設備是不是binary的,將一條log作進一步的處理,結果存放在一個AndroidLogEntry entry中;二、依據於用戶添加的那些filters,判斷一條log是不是用戶所想要的,若是是,則其寫入文件中;三、更新g_outByteCount,使其依然可以正確的表示已經寫入文件的log的字節數;四、檢查已經寫入文件的log字節數,若是該值超出了用戶設定的單個log文件最大大小時,則調用rotateLogs()換一個log文件來寫。
對於前述第1步,設備的binary不一樣於用戶指定的全局的二進制格式的輸出,該屬性只與設備自己有關。回憶咱們前面在參數解析部分(-b參數)看到的,只有"events" log設備是binary的。此外,咱們再來看一下,所謂的對log的進一步處理,其結果到底是什麼樣的,咱們看一下AndroidLogEntry結構的定義(在system/core/include/cutils/logprint.h文件中):
typedef struct AndroidLogEntry_t { time_t tv_sec; long tv_nsec; android_LogPriority priority; int32_t pid; int32_t tid; const char * tag; size_t messageLen; const char * message; } AndroidLogEntry;
而後呢,咱們暫時先拋開binary設備的狀況無論,先來看一下通常的device,其一條log的處理過程,即android_log_processLogBuffer()函數(在system/core/liblog/logprint.c中):
/** * Splits a wire-format buffer into an AndroidLogEntry * entry allocated by caller. Pointers will point directly into buf * * Returns 0 on success and -1 on invalid wire format (entry will be * in unspecified state) */ int android_log_processLogBuffer(struct logger_entry *buf, AndroidLogEntry *entry) { entry->tv_sec = buf->sec; entry->tv_nsec = buf->nsec; entry->pid = buf->pid; entry->tid = buf->tid; /* * format: <priority:1><tag:N>\0<message:N>\0 * * tag str * starts at buf->msg+1 * msg * starts at buf->msg+1+len(tag)+1 * * The message may have been truncated by the kernel log driver. * When that happens, we must null-terminate the message ourselves. */ if (buf->len < 3) { // An well-formed entry must consist of at least a priority // and two null characters fprintf(stderr, "+++ LOG: entry too small\n"); return -1; } int msgStart = -1; int msgEnd = -1; int i; for (i = 1; i < buf->len; i++) { if (buf->msg[i] == '\0') { if (msgStart == -1) { msgStart = i + 1; } else { msgEnd = i; break; } } } if (msgStart == -1) { fprintf(stderr, "+++ LOG: malformed log message\n"); return -1; } if (msgEnd == -1) { // incoming message not null-terminated; force it msgEnd = buf->len - 1; buf->msg[msgEnd] = '\0'; } entry->priority = buf->msg[0]; entry->tag = buf->msg + 1; entry->message = buf->msg + msgStart; entry->messageLen = msgEnd - msgStart; return 0; }
用戶寫入log設備的部分,在logcat讀取時,全都會被放在struct logger_entry結構的msg成員中,在android_log_processLogBuffer()函數中,則會再次將一條log的priority、TAG及message三個部分解析出來存放在AndroidLogEntry的單獨成員裏。其餘倒還比較直觀。
processBuffer()中處理log的第二步,即,依據於用戶添加的那些filters,判斷一條log是不是用戶所想要的,若是是,則將其寫入文件中。是經過android_log_shouldPrintLine()函數(在system/core/liblog/logprint.c中)來作判斷的:
static android_LogPriority filterPriForTag( AndroidLogFormat *p_format, const char *tag) { FilterInfo *p_curFilter; for (p_curFilter = p_format->filters ; p_curFilter != NULL ; p_curFilter = p_curFilter->p_next ) { if (0 == strcmp(tag, p_curFilter->mTag)) { if (p_curFilter->mPri == ANDROID_LOG_DEFAULT) { return p_format->global_pri; } else { return p_curFilter->mPri; } } } return p_format->global_pri; } int android_log_shouldPrintLine ( AndroidLogFormat *p_format, const char *tag, android_LogPriority pri) { return pri >= filterPriForTag(p_format, tag); }
當讀出的一條log,其priority高於用戶添加的TAG相同的filter的priority時,即認爲是用戶須要的。在發現一條log須要寫入文件時,則會在要打印的log設備大於1時,先將log設備的label寫入文件。而後則是調用 android_log_printLogLine()函數,將AndroidLogEntry的entry格式化並寫入文件:
static char filterPriToChar (android_LogPriority pri) { switch (pri) { case ANDROID_LOG_VERBOSE: return 'V'; case ANDROID_LOG_DEBUG: return 'D'; case ANDROID_LOG_INFO: return 'I'; case ANDROID_LOG_WARN: return 'W'; case ANDROID_LOG_ERROR: return 'E'; case ANDROID_LOG_FATAL: return 'F'; case ANDROID_LOG_SILENT: return 'S'; case ANDROID_LOG_DEFAULT: case ANDROID_LOG_UNKNOWN: default: return '?'; } } /** * Formats a log message into a buffer * * Uses defaultBuffer if it can, otherwise malloc()'s a new buffer * If return value != defaultBuffer, caller must call free() * Returns NULL on malloc error */ char *android_log_formatLogLine ( AndroidLogFormat *p_format, char *defaultBuffer, size_t defaultBufferSize, const AndroidLogEntry *entry, size_t *p_outLength) { #if defined(HAVE_LOCALTIME_R) struct tm tmBuf; #endif struct tm* ptm; char timeBuf[32]; char headerBuf[128]; char prefixBuf[128], suffixBuf[128]; char priChar; int prefixSuffixIsHeaderFooter = 0; char * ret = NULL; priChar = filterPriToChar(entry->priority); /* * Get the current date/time in pretty form * * It's often useful when examining a log with "less" to jump to * a specific point in the file by searching for the date/time stamp. * For this reason it's very annoying to have regexp meta characters * in the time stamp. Don't use forward slashes, parenthesis, * brackets, asterisks, or other special chars here. */ #if defined(HAVE_LOCALTIME_R) ptm = localtime_r(&(entry->tv_sec), &tmBuf); #else ptm = localtime(&(entry->tv_sec)); #endif //strftime(timeBuf, sizeof(timeBuf), "%Y-%m-%d %H:%M:%S", ptm); strftime(timeBuf, sizeof(timeBuf), "%m-%d %H:%M:%S", ptm); /* * Construct a buffer containing the log header and log message. */ size_t prefixLen, suffixLen; switch (p_format->format) { case FORMAT_TAG: prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "%c/%-8s: ", priChar, entry->tag); strcpy(suffixBuf, "\n"); suffixLen = 1; break; case FORMAT_PROCESS: prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "%c(%5d) ", priChar, entry->pid); suffixLen = snprintf(suffixBuf, sizeof(suffixBuf), " (%s)\n", entry->tag); break; case FORMAT_THREAD: prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "%c(%5d:%5d) ", priChar, entry->pid, entry->tid); strcpy(suffixBuf, "\n"); suffixLen = 1; break; case FORMAT_RAW: prefixBuf[0] = 0; prefixLen = 0; strcpy(suffixBuf, "\n"); suffixLen = 1; break; case FORMAT_TIME: prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "%s.%03ld %c/%-8s(%5d): ", timeBuf, entry->tv_nsec / 1000000, priChar, entry->tag, entry->pid); strcpy(suffixBuf, "\n"); suffixLen = 1; break; case FORMAT_THREADTIME: prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "%s.%03ld %5d %5d %c %-8s: ", timeBuf, entry->tv_nsec / 1000000, entry->pid, entry->tid, priChar, entry->tag); strcpy(suffixBuf, "\n"); suffixLen = 1; break; case FORMAT_LONG: prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "[ %s.%03ld %5d:%5d %c/%-8s ]\n", timeBuf, entry->tv_nsec / 1000000, entry->pid, entry->tid, priChar, entry->tag); strcpy(suffixBuf, "\n\n"); suffixLen = 2; prefixSuffixIsHeaderFooter = 1; break; case FORMAT_BRIEF: default: prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "%c/%-8s(%5d): ", priChar, entry->tag, entry->pid); strcpy(suffixBuf, "\n"); suffixLen = 1; break; } /* snprintf has a weird return value. It returns what would have been * written given a large enough buffer. In the case that the prefix is * longer then our buffer(128), it messes up the calculations below * possibly causing heap corruption. To avoid this we double check and * set the length at the maximum (size minus null byte) */ if(prefixLen >= sizeof(prefixBuf)) prefixLen = sizeof(prefixBuf) - 1; if(suffixLen >= sizeof(suffixBuf)) suffixLen = sizeof(suffixBuf) - 1; /* the following code is tragically unreadable */ size_t numLines; size_t i; char *p; size_t bufferSize; const char *pm; if (prefixSuffixIsHeaderFooter) { // we're just wrapping message with a header/footer numLines = 1; } else { pm = entry->message; numLines = 0; // The line-end finding here must match the line-end finding // in for ( ... numLines...) loop below while (pm < (entry->message + entry->messageLen)) { if (*pm++ == '\n') numLines++; } // plus one line for anything not newline-terminated at the end if (pm > entry->message && *(pm-1) != '\n') numLines++; } // this is an upper bound--newlines in message may be counted // extraneously bufferSize = (numLines * (prefixLen + suffixLen)) + entry->messageLen + 1; if (defaultBufferSize >= bufferSize) { ret = defaultBuffer; } else { ret = (char *)malloc(bufferSize); if (ret == NULL) { return ret; } } ret[0] = '\0'; /* to start strcat off */ p = ret; pm = entry->message; if (prefixSuffixIsHeaderFooter) { strcat(p, prefixBuf); p += prefixLen; strncat(p, entry->message, entry->messageLen); p += entry->messageLen; strcat(p, suffixBuf); p += suffixLen; } else { while(pm < (entry->message + entry->messageLen)) { const char *lineStart; size_t lineLen; lineStart = pm; // Find the next end-of-line in message while (pm < (entry->message + entry->messageLen) && *pm != '\n') pm++; lineLen = pm - lineStart; strcat(p, prefixBuf); p += prefixLen; strncat(p, lineStart, lineLen); p += lineLen; strcat(p, suffixBuf); p += suffixLen; if (*pm == '\n') pm++; } } if (p_outLength != NULL) { *p_outLength = p - ret; } return ret; } /** * Either print or do not print log line, based on filter * * Returns count bytes written */ int android_log_printLogLine( AndroidLogFormat *p_format, int fd, const AndroidLogEntry *entry) { int ret; char defaultBuffer[512]; char *outBuffer = NULL; size_t totalLen; outBuffer = android_log_formatLogLine(p_format, defaultBuffer, sizeof(defaultBuffer), entry, &totalLen); if (!outBuffer) return -1; do { ret = write(fd, outBuffer, totalLen); } while (ret < 0 && errno == EINTR); if (ret < 0) { fprintf(stderr, "+++ LOG: write failed (errno=%d)\n", errno); ret = 0; goto done; } if (((size_t)ret) < totalLen) { fprintf(stderr, "+++ LOG: write partial (%d of %d)\n", ret, (int)totalLen); goto done; } done: if (outBuffer != defaultBuffer) { free(outBuffer); } return ret; }
格式化log的部分再也不細述。
processBuffer函數的最後,還有一個rotateLogs的操做:
static int openLogFile (const char *pathname) { return open(pathname, O_WRONLY | O_APPEND | O_CREAT, S_IRUSR | S_IWUSR); } static void rotateLogs() { int err; // Can't rotate logs if we're not outputting to a file if (g_outputFileName == NULL) { return; } close(g_outFD); for (int i = g_maxRotatedLogs ; i > 0 ; i--) { char *file0, *file1; asprintf(&file1, "%s.%d", g_outputFileName, i); if (i - 1 == 0) { asprintf(&file0, "%s", g_outputFileName); } else { asprintf(&file0, "%s.%d", g_outputFileName, i - 1); } err = rename (file0, file1); if (err < 0 && errno != ENOENT) { perror("while rotating log files"); } free(file1); free(file0); } g_outFD = openLogFile (g_outputFileName); if (g_outFD < 0) { perror ("couldn't open output file"); exit(-1); } g_outByteCount = 0; }
這個函數只有在執行logcat命令,指定了-f <filename>參數,即g_outputFileName不爲NULL時才起做用。它的做用是將log循環輸出到一組文件中。例如,指定-f參數爲logfile,g_maxRotatedLogs爲3,則這組文件分別爲:logfile,logfile.1,logfile.2,logfile.3。
噹噹前輸入到logfile文件中的log大小g_outByteCount大於等於g_logRotateSizeKBytes時,就要將logfile.2的內容移至logfile.3中,同時將logfile.1的內容移至logfile.2中,同時logfle的內容移至logfile.1中,再從新打開logfile文件進入後續輸入,而原來的logfile.3文件則至關於被移除掉了。這樣作的做用是不至於使得日誌文件變得愈來愈來大,以致於佔用過多的磁盤空間,而是隻在磁盤上保存必定量的最新的日誌記錄。這樣,舊的日誌記錄就會可能被新的日誌記錄所覆蓋。
遺留的問題,binary device,即/dev/log/events,其log記錄的格式化。
Done。