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