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