前文咱们了解到,在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。