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