logcat.cpp revision 6fa09a066d6b6898a394a3ccf6c32111665cdbcb 
1// Copyright 2006 The Android Open Source Project
2
3#include <cutils/logger.h>
4#include <cutils/logd.h>
5#include <cutils/sockets.h>
6#include <cutils/logprint.h>
7#include <cutils/event_tag_map.h>
8
9#include <stdio.h>
10#include <stdlib.h>
11#include <stdarg.h>
12#include <string.h>
13#include <unistd.h>
14#include <fcntl.h>
15#include <time.h>
16#include <errno.h>
17#include <assert.h>
18#include <ctype.h>
19#include <sys/socket.h>
20#include <sys/stat.h>
21#include <arpa/inet.h>
22
23#define DEFAULT_LOG_ROTATE_SIZE_KBYTES 16
24#define DEFAULT_MAX_ROTATED_LOGS 4
25
26static AndroidLogFormat * g_logformat;
27
28/* logd prefixes records with a length field */
29#define RECORD_LENGTH_FIELD_SIZE_BYTES sizeof(uint32_t)
30
31#define LOG_FILE_DIR    "/dev/log/"
32
33struct queued_entry_t {
34    union {
35        unsigned char buf[LOGGER_ENTRY_MAX_LEN + 1] __attribute__((aligned(4)));
36        struct logger_entry entry __attribute__((aligned(4)));
37    };
38    queued_entry_t* next;
39
40    queued_entry_t() {
41        next = NULL;
42    }
43};
44
45static int cmp(queued_entry_t* a, queued_entry_t* b) {
46    int n = a->entry.sec - b->entry.sec;
47    if (n != 0) {
48        return n;
49    }
50    return a->entry.nsec - b->entry.nsec;
51}
52
53struct log_device_t {
54    char* device;
55    bool binary;
56    int fd;
57    bool printed;
58    char label;
59
60    queued_entry_t* queue;
61    log_device_t* next;
62
63    log_device_t(char* d, bool b, char l) {
64        device = d;
65        binary = b;
66        label = l;
67        next = NULL;
68        printed = false;
69    }
70
71    void enqueue(queued_entry_t* entry) {
72        if (this->queue == NULL) {
73            this->queue = entry;
74        } else {
75            queued_entry_t** e = &this->queue;
76            while (*e && cmp(entry, *e) >= 0) {
77                e = &((*e)->next);
78            }
79            entry->next = *e;
80            *e = entry;
81        }
82    }
83};
84
85namespace android {
86
87/* Global Variables */
88
89static const char * g_outputFileName = NULL;
90static int g_logRotateSizeKBytes = 0;                   // 0 means "no log rotation"
91static int g_maxRotatedLogs = DEFAULT_MAX_ROTATED_LOGS; // 0 means "unbounded"
92static int g_outFD = -1;
93static off_t g_outByteCount = 0;
94static int g_printBinary = 0;
95static int g_devCount = 0;
96
97static EventTagMap* g_eventTagMap = NULL;
98
99static int openLogFile (const char *pathname)
100{
101    return open(g_outputFileName, O_WRONLY | O_APPEND | O_CREAT, S_IRUSR | S_IWUSR);
102}
103
104static void rotateLogs()
105{
106    int err;
107
108    // Can't rotate logs if we're not outputting to a file
109    if (g_outputFileName == NULL) {
110        return;
111    }
112
113    close(g_outFD);
114
115    for (int i = g_maxRotatedLogs ; i > 0 ; i--) {
116        char *file0, *file1;
117
118        asprintf(&file1, "%s.%d", g_outputFileName, i);
119
120        if (i - 1 == 0) {
121            asprintf(&file0, "%s", g_outputFileName);
122        } else {
123            asprintf(&file0, "%s.%d", g_outputFileName, i - 1);
124        }
125
126        err = rename (file0, file1);
127
128        if (err < 0 && errno != ENOENT) {
129            perror("while rotating log files");
130        }
131
132        free(file1);
133        free(file0);
134    }
135
136    g_outFD = openLogFile (g_outputFileName);
137
138    if (g_outFD < 0) {
139        perror ("couldn't open output file");
140        exit(-1);
141    }
142
143    g_outByteCount = 0;
144
145}
146
147void printBinary(struct logger_entry *buf)
148{
149    size_t size = sizeof(logger_entry) + buf->len;
150    int ret;
151
152    do {
153        ret = write(g_outFD, buf, size);
154    } while (ret < 0 && errno == EINTR);
155}
156
157static void processBuffer(log_device_t* dev, struct logger_entry *buf)
158{
159    int bytesWritten;
160    int err;
161    AndroidLogEntry entry;
162    char binaryMsgBuf[1024];
163
164    if (!dev->printed) {
165        dev->printed = true;
166        if (g_devCount > 1) {
167            snprintf(binaryMsgBuf, sizeof(binaryMsgBuf), "--------- beginning of %s\n",
168                    dev->device);
169            bytesWritten = write(g_outFD, binaryMsgBuf, strlen(binaryMsgBuf));
170            if (bytesWritten < 0) {
171                perror("output error");
172                exit(-1);
173            }
174        }
175    }
176
177    if (g_devCount > 1) {
178        binaryMsgBuf[0] = dev->label;
179        binaryMsgBuf[1] = ' ';
180        bytesWritten = write(g_outFD, binaryMsgBuf, 2);
181        if (bytesWritten < 0) {
182            perror("output error");
183            exit(-1);
184        }
185    }
186
187    if (dev->binary) {
188        err = android_log_processBinaryLogBuffer(buf, &entry, g_eventTagMap,
189                binaryMsgBuf, sizeof(binaryMsgBuf));
190        //printf(">>> pri=%d len=%d msg='%s'\n",
191        //    entry.priority, entry.messageLen, entry.message);
192    } else {
193        err = android_log_processLogBuffer(buf, &entry);
194    }
195    if (err < 0)
196        goto error;
197
198    bytesWritten = android_log_filterAndPrintLogLine(
199                        g_logformat, g_outFD, &entry);
200
201    if (bytesWritten < 0) {
202        perror("output error");
203        exit(-1);
204    }
205
206    g_outByteCount += bytesWritten;
207
208    if (g_logRotateSizeKBytes > 0
209        && (g_outByteCount / 1024) >= g_logRotateSizeKBytes
210    ) {
211        rotateLogs();
212    }
213
214error:
215    //fprintf (stderr, "Error processing record\n");
216    return;
217}
218
219static void chooseFirst(log_device_t* dev, log_device_t** firstdev, queued_entry_t** firstentry) {
220    *firstdev = NULL;
221    *firstentry = NULL;
222    int i=0;
223    for (; dev; dev=dev->next) {
224        i++;
225        if (dev->queue) {
226            if ((*firstentry) == NULL || cmp(dev->queue, *firstentry) < 0) {
227                (*firstentry) = dev->queue;
228                *firstdev = dev;
229            }
230        }
231    }
232}
233
234static void printEntry(log_device_t* dev, queued_entry_t* entry) {
235    if (g_printBinary) {
236        printBinary(&entry->entry);
237    } else {
238        processBuffer(dev, &entry->entry);
239    }
240}
241
242static void eatEntry(log_device_t* dev, queued_entry_t* entry) {
243    if (dev->queue != entry) {
244        perror("assertion failed: entry isn't first in queue");
245        exit(1);
246    }
247    printEntry(dev, entry);
248    dev->queue = entry->next;
249    delete entry;
250}
251
252static void readLogLines(log_device_t* devices)
253{
254    log_device_t* dev;
255    int max = 0;
256    queued_entry_t* entry;
257    queued_entry_t* old;
258    int ret;
259    bool somethingForEveryone;
260    bool sleep = true;
261
262    int result;
263    fd_set readset;
264
265    for (dev=devices; dev; dev = dev->next) {
266        if (dev->fd > max) {
267            max = dev->fd;
268        }
269    }
270
271    while (1) {
272        do {
273            timeval timeout = { 0, 5000 /* 5ms */ }; // If we oversleep it's ok, i.e. ignore EINTR.
274            FD_ZERO(&readset);
275            for (dev=devices; dev; dev = dev->next) {
276                FD_SET(dev->fd, &readset);
277            }
278            result = select(max + 1, &readset, NULL, NULL, sleep ? NULL : &timeout);
279        } while (result == -1 && errno == EINTR);
280
281        if (result >= 0) {
282            for (dev=devices; dev; dev = dev->next) {
283                if (FD_ISSET(dev->fd, &readset)) {
284                    entry = new queued_entry_t;
285                    /* NOTE: driver guarantees we read exactly one full entry */
286                    ret = read(dev->fd, entry->buf, LOGGER_ENTRY_MAX_LEN);
287                    if (ret < 0) {
288                        if (errno == EINTR) {
289                            delete entry;
290                            goto next;
291                        }
292                        if (errno == EAGAIN) {
293                            delete entry;
294                            break;
295                        }
296                        perror("logcat read");
297                        exit(EXIT_FAILURE);
298                    }
299                    else if (!ret) {
300                        fprintf(stderr, "read: Unexpected EOF!\n");
301                        exit(EXIT_FAILURE);
302                    }
303
304                    entry->entry.msg[entry->entry.len] = '\0';
305
306                    dev->enqueue(entry);
307                }
308            }
309
310            if (result == 0) {
311                // we did our short timeout trick and there's nothing new
312                // print all that aren't the last in their list
313                sleep = true;
314                while (true) {
315                    chooseFirst(devices, &dev, &entry);
316                    if (!entry) {
317                        break;
318                    }
319                    eatEntry(dev, entry);
320                }
321            } else {
322                // print all that aren't the last in their list
323                while (true) {
324                    chooseFirst(devices, &dev, &entry);
325                    if (!entry) {
326                        sleep = false;
327                        break;
328                    } else if (entry->next == NULL) {
329                        sleep = false;
330                        break;
331                    }
332                    eatEntry(dev, entry);
333                }
334            }
335        }
336next:
337        ;
338    }
339}
340
341static int clearLog(int logfd)
342{
343    return ioctl(logfd, LOGGER_FLUSH_LOG);
344}
345
346/* returns the total size of the log's ring buffer */
347static int getLogSize(int logfd)
348{
349    return ioctl(logfd, LOGGER_GET_LOG_BUF_SIZE);
350}
351
352/* returns the readable size of the log's ring buffer (that is, amount of the log consumed) */
353static int getLogReadableSize(int logfd)
354{
355    return ioctl(logfd, LOGGER_GET_LOG_LEN);
356}
357
358static void setupOutput()
359{
360
361    if (g_outputFileName == NULL) {
362        g_outFD = STDOUT_FILENO;
363
364    } else {
365        struct stat statbuf;
366
367        g_outFD = openLogFile (g_outputFileName);
368
369        if (g_outFD < 0) {
370            perror ("couldn't open output file");
371            exit(-1);
372        }
373
374        fstat(g_outFD, &statbuf);
375
376        g_outByteCount = statbuf.st_size;
377    }
378}
379
380static void show_help(const char *cmd)
381{
382    fprintf(stderr,"Usage: %s [options] [filterspecs]\n", cmd);
383
384    fprintf(stderr, "options include:\n"
385                    "  -s              Set default filter to silent.\n"
386                    "                  Like specifying filterspec '*:s'\n"
387                    "  -f <filename>   Log to file. Default to stdout\n"
388                    "  -r [<kbytes>]   Rotate log every kbytes. (16 if unspecified). Requires -f\n"
389                    "  -n <count>      Sets max number of rotated logs to <count>, default 4\n"
390                    "  -v <format>     Sets the log print format, where <format> is one of:\n\n"
391                    "                  brief process tag thread raw time threadtime long\n\n"
392                    "  -c              clear (flush) the entire log and exit\n"
393                    "  -d              dump the log and then exit (don't block)\n"
394                    "  -g              get the size of the log's ring buffer and exit\n"
395                    "  -b <buffer>     request alternate ring buffer\n"
396                    "                  ('main' (default), 'radio', 'events')\n"
397                    "  -B              output the log in binary");
398
399
400    fprintf(stderr,"\nfilterspecs are a series of \n"
401                   "  <tag>[:priority]\n\n"
402                   "where <tag> is a log component tag (or * for all) and priority is:\n"
403                   "  V    Verbose\n"
404                   "  D    Debug\n"
405                   "  I    Info\n"
406                   "  W    Warn\n"
407                   "  E    Error\n"
408                   "  F    Fatal\n"
409                   "  S    Silent (supress all output)\n"
410                   "\n'*' means '*:d' and <tag> by itself means <tag>:v\n"
411                   "\nIf not specified on the commandline, filterspec is set from ANDROID_LOG_TAGS.\n"
412                   "If no filterspec is found, filter defaults to '*:I'\n"
413                   "\nIf not specified with -v, format is set from ANDROID_PRINTF_LOG\n"
414                   "or defaults to \"brief\"\n\n");
415
416
417
418}
419
420
421} /* namespace android */
422
423static int setLogFormat(const char * formatString)
424{
425    static AndroidLogPrintFormat format;
426
427    format = android_log_formatFromString(formatString);
428
429    if (format == FORMAT_OFF) {
430        // FORMAT_OFF means invalid string
431        return -1;
432    }
433
434    android_log_setPrintFormat(g_logformat, format);
435
436    return 0;
437}
438
439extern "C" void logprint_run_tests(void);
440
441int main(int argc, char **argv)
442{
443    int err;
444    int hasSetLogFormat = 0;
445    int clearLog = 0;
446    int getLogSize = 0;
447    int mode = O_RDONLY;
448    const char *forceFilters = NULL;
449    log_device_t* devices = NULL;
450    log_device_t* dev;
451    bool needBinary = false;
452
453    g_logformat = android_log_format_new();
454
455    if (argc == 2 && 0 == strcmp(argv[1], "--test")) {
456        logprint_run_tests();
457        exit(0);
458    }
459
460    if (argc == 2 && 0 == strcmp(argv[1], "--help")) {
461        android::show_help(argv[0]);
462        exit(0);
463    }
464
465    for (;;) {
466        int ret;
467
468        ret = getopt(argc, argv, "cdgsQf:r::n:v:b:B");
469
470        if (ret < 0) {
471            break;
472        }
473
474        switch(ret) {
475            case 's':
476                // default to all silent
477                android_log_addFilterRule(g_logformat, "*:s");
478            break;
479
480            case 'c':
481                clearLog = 1;
482                mode = O_WRONLY;
483            break;
484
485            case 'd':
486                mode |= O_NONBLOCK;
487            break;
488
489            case 'g':
490                getLogSize = 1;
491            break;
492
493            case 'b': {
494                char* buf = (char*) malloc(strlen(LOG_FILE_DIR) + strlen(optarg) + 1);
495                strcpy(buf, LOG_FILE_DIR);
496                strcat(buf, optarg);
497
498                bool binary = strcmp(optarg, "events") == 0;
499                if (binary) {
500                    needBinary = true;
501                }
502
503                if (devices) {
504                    dev = devices;
505                    while (dev->next) {
506                        dev = dev->next;
507                    }
508                    dev->next = new log_device_t(buf, binary, optarg[0]);
509                } else {
510                    devices = new log_device_t(buf, binary, optarg[0]);
511                }
512                android::g_devCount++;
513            }
514            break;
515
516            case 'B':
517                android::g_printBinary = 1;
518            break;
519
520            case 'f':
521                // redirect output to a file
522
523                android::g_outputFileName = optarg;
524
525            break;
526
527            case 'r':
528                if (optarg == NULL) {
529                    android::g_logRotateSizeKBytes
530                                = DEFAULT_LOG_ROTATE_SIZE_KBYTES;
531                } else {
532                    long logRotateSize;
533                    char *lastDigit;
534
535                    if (!isdigit(optarg[0])) {
536                        fprintf(stderr,"Invalid parameter to -r\n");
537                        android::show_help(argv[0]);
538                        exit(-1);
539                    }
540                    android::g_logRotateSizeKBytes = atoi(optarg);
541                }
542            break;
543
544            case 'n':
545                if (!isdigit(optarg[0])) {
546                    fprintf(stderr,"Invalid parameter to -r\n");
547                    android::show_help(argv[0]);
548                    exit(-1);
549                }
550
551                android::g_maxRotatedLogs = atoi(optarg);
552            break;
553
554            case 'v':
555                err = setLogFormat (optarg);
556                if (err < 0) {
557                    fprintf(stderr,"Invalid parameter to -v\n");
558                    android::show_help(argv[0]);
559                    exit(-1);
560                }
561
562                hasSetLogFormat = 1;
563            break;
564
565            case 'Q':
566                /* this is a *hidden* option used to start a version of logcat                 */
567                /* in an emulated device only. it basically looks for androidboot.logcat=      */
568                /* on the kernel command line. If something is found, it extracts a log filter */
569                /* and uses it to run the program. If nothing is found, the program should     */
570                /* quit immediately                                                            */
571#define  KERNEL_OPTION  "androidboot.logcat="
572#define  CONSOLE_OPTION "androidboot.console="
573                {
574                    int          fd;
575                    char*        logcat;
576                    char*        console;
577                    int          force_exit = 1;
578                    static char  cmdline[1024];
579
580                    fd = open("/proc/cmdline", O_RDONLY);
581                    if (fd >= 0) {
582                        int  n = read(fd, cmdline, sizeof(cmdline)-1 );
583                        if (n < 0) n = 0;
584                        cmdline[n] = 0;
585                        close(fd);
586                    } else {
587                        cmdline[0] = 0;
588                    }
589
590                    logcat  = strstr( cmdline, KERNEL_OPTION );
591                    console = strstr( cmdline, CONSOLE_OPTION );
592                    if (logcat != NULL) {
593                        char*  p = logcat + sizeof(KERNEL_OPTION)-1;;
594                        char*  q = strpbrk( p, " \t\n\r" );;
595
596                        if (q != NULL)
597                            *q = 0;
598
599                        forceFilters = p;
600                        force_exit   = 0;
601                    }
602                    /* if nothing found or invalid filters, exit quietly */
603                    if (force_exit)
604                        exit(0);
605
606                    /* redirect our output to the emulator console */
607                    if (console) {
608                        char*  p = console + sizeof(CONSOLE_OPTION)-1;
609                        char*  q = strpbrk( p, " \t\n\r" );
610                        char   devname[64];
611                        int    len;
612
613                        if (q != NULL) {
614                            len = q - p;
615                        } else
616                            len = strlen(p);
617
618                        len = snprintf( devname, sizeof(devname), "/dev/%.*s", len, p );
619                        fprintf(stderr, "logcat using %s (%d)\n", devname, len);
620                        if (len < (int)sizeof(devname)) {
621                            fd = open( devname, O_WRONLY );
622                            if (fd >= 0) {
623                                dup2(fd, 1);
624                                dup2(fd, 2);
625                                close(fd);
626                            }
627                        }
628                    }
629                }
630                break;
631
632            default:
633                fprintf(stderr,"Unrecognized Option\n");
634                android::show_help(argv[0]);
635                exit(-1);
636            break;
637        }
638    }
639
640    if (!devices) {
641        devices = new log_device_t(strdup("/dev/"LOGGER_LOG_MAIN), false, LOGGER_LOG_MAIN[0]);
642        android::g_devCount = 1;
643    }
644
645    if (android::g_logRotateSizeKBytes != 0
646        && android::g_outputFileName == NULL
647    ) {
648        fprintf(stderr,"-r requires -f as well\n");
649        android::show_help(argv[0]);
650        exit(-1);
651    }
652
653    android::setupOutput();
654
655    if (hasSetLogFormat == 0) {
656        const char* logFormat = getenv("ANDROID_PRINTF_LOG");
657
658        if (logFormat != NULL) {
659            err = setLogFormat(logFormat);
660
661            if (err < 0) {
662                fprintf(stderr, "invalid format in ANDROID_PRINTF_LOG '%s'\n",
663                                    logFormat);
664            }
665        }
666    }
667
668    if (forceFilters) {
669        err = android_log_addFilterString(g_logformat, forceFilters);
670        if (err < 0) {
671            fprintf (stderr, "Invalid filter expression in -logcat option\n");
672            exit(0);
673        }
674    } else if (argc == optind) {
675        // Add from environment variable
676        char *env_tags_orig = getenv("ANDROID_LOG_TAGS");
677
678        if (env_tags_orig != NULL) {
679            err = android_log_addFilterString(g_logformat, env_tags_orig);
680
681            if (err < 0) {
682                fprintf(stderr, "Invalid filter expression in"
683                                    " ANDROID_LOG_TAGS\n");
684                android::show_help(argv[0]);
685                exit(-1);
686            }
687        }
688    } else {
689        // Add from commandline
690        for (int i = optind ; i < argc ; i++) {
691            err = android_log_addFilterString(g_logformat, argv[i]);
692
693            if (err < 0) {
694                fprintf (stderr, "Invalid filter expression '%s'\n", argv[i]);
695                android::show_help(argv[0]);
696                exit(-1);
697            }
698        }
699    }
700
701    dev = devices;
702    while (dev) {
703        dev->fd = open(dev->device, mode);
704        if (dev->fd < 0) {
705            fprintf(stderr, "Unable to open log device '%s': %s\n",
706                dev->device, strerror(errno));
707            exit(EXIT_FAILURE);
708        }
709
710        if (clearLog) {
711            int ret;
712            ret = android::clearLog(dev->fd);
713            if (ret) {
714                perror("ioctl");
715                exit(EXIT_FAILURE);
716            }
717            return 0;
718        }
719
720        if (getLogSize) {
721            int size, readable;
722
723            size = android::getLogSize(dev->fd);
724            if (size < 0) {
725                perror("ioctl");
726                exit(EXIT_FAILURE);
727            }
728
729            readable = android::getLogReadableSize(dev->fd);
730            if (readable < 0) {
731                perror("ioctl");
732                exit(EXIT_FAILURE);
733            }
734
735            printf("%s: ring buffer is %dKb (%dKb consumed), "
736                   "max entry is %db, max payload is %db\n", dev->device,
737                   size / 1024, readable / 1024,
738                   (int) LOGGER_ENTRY_MAX_LEN, (int) LOGGER_ENTRY_MAX_PAYLOAD);
739        }
740
741        dev = dev->next;
742    }
743
744    if (getLogSize) {
745        return 0;
746    }
747
748    //LOG_EVENT_INT(10, 12345);
749    //LOG_EVENT_LONG(11, 0x1122334455667788LL);
750    //LOG_EVENT_STRING(0, "whassup, doc?");
751
752    if (needBinary)
753        android::g_eventTagMap = android_openEventTagMap(EVENT_TAG_MAP_FILE);
754
755    android::readLogLines(devices);
756
757    return 0;
758}
759