log_read.c revision 1345f38e4419607ea9c5b24109e5bd6df52dcffa 
1/*
2** Copyright 2013-2014, The Android Open Source Project
3**
4** Licensed under the Apache License, Version 2.0 (the "License");
5** you may not use this file except in compliance with the License.
6** You may obtain a copy of the License at
7**
8**     http://www.apache.org/licenses/LICENSE-2.0
9**
10** Unless required by applicable law or agreed to in writing, software
11** distributed under the License is distributed on an "AS IS" BASIS,
12** WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13** See the License for the specific language governing permissions and
14** limitations under the License.
15*/
16
17#define _GNU_SOURCE /* asprintf for x86 host */
18#include <errno.h>
19#include <fcntl.h>
20#include <poll.h>
21#include <string.h>
22#include <stdio.h>
23#include <stdlib.h>
24#include <cutils/list.h>
25#include <log/log.h>
26#include <log/logger.h>
27
28#include <sys/ioctl.h>
29
30#define __LOGGERIO     0xAE
31
32#define LOGGER_GET_LOG_BUF_SIZE    _IO(__LOGGERIO, 1) /* size of log */
33#define LOGGER_GET_LOG_LEN         _IO(__LOGGERIO, 2) /* used log len */
34#define LOGGER_GET_NEXT_ENTRY_LEN  _IO(__LOGGERIO, 3) /* next entry len */
35#define LOGGER_FLUSH_LOG           _IO(__LOGGERIO, 4) /* flush log */
36#define LOGGER_GET_VERSION         _IO(__LOGGERIO, 5) /* abi version */
37#define LOGGER_SET_VERSION         _IO(__LOGGERIO, 6) /* abi version */
38
39typedef char bool;
40#define false (const bool)0
41#define true (const bool)1
42
43#define LOG_FILE_DIR "/dev/log/"
44
45/* timeout in milliseconds */
46#define LOG_TIMEOUT_FLUSH 5
47#define LOG_TIMEOUT_NEVER -1
48
49#define logger_for_each(logger, logger_list) \
50    for (logger = node_to_item((logger_list)->node.next, struct logger, node); \
51         logger != node_to_item(&(logger_list)->node, struct logger, node); \
52         logger = node_to_item((logger)->node.next, struct logger, node))
53
54/* In the future, we would like to make this list extensible */
55static const char *LOG_NAME[LOG_ID_MAX] = {
56    [LOG_ID_MAIN] = "main",
57    [LOG_ID_RADIO] = "radio",
58    [LOG_ID_EVENTS] = "events",
59    [LOG_ID_SYSTEM] = "system"
60};
61
62const char *android_log_id_to_name(log_id_t log_id) {
63    if (log_id >= LOG_ID_MAX) {
64        log_id = LOG_ID_MAIN;
65    }
66    return LOG_NAME[log_id];
67}
68
69static int accessmode(int mode)
70{
71    if ((mode & O_ACCMODE) == O_WRONLY) {
72        return W_OK;
73    }
74    if ((mode & O_ACCMODE) == O_RDWR) {
75        return R_OK | W_OK;
76    }
77    return R_OK;
78}
79
80/* repeated fragment */
81static int check_allocate_accessible(char **n, const char *b, int mode)
82{
83    *n = NULL;
84
85    if (!b) {
86        return -EINVAL;
87    }
88
89    asprintf(n, LOG_FILE_DIR "%s", b);
90    if (!*n) {
91        return -1;
92    }
93
94    return access(*n, accessmode(mode));
95}
96
97log_id_t android_name_to_log_id(const char *logName) {
98    const char *b;
99    char *n;
100    int ret;
101
102    if (!logName) {
103        return -1; /* NB: log_id_t is unsigned */
104    }
105    b = strrchr(logName, '/');
106    if (!b) {
107        b = logName;
108    } else {
109        ++b;
110    }
111
112    ret = check_allocate_accessible(&n, b, O_RDONLY);
113    free(n);
114    if (ret) {
115        return ret;
116    }
117
118    for(ret = LOG_ID_MIN; ret < LOG_ID_MAX; ++ret) {
119        const char *l = LOG_NAME[ret];
120        if (l && !strcmp(b, l)) {
121            return ret;
122        }
123    }
124    return -1;   /* should never happen */
125}
126
127struct logger_list {
128    struct listnode node;
129    int mode;
130    unsigned int tail;
131    pid_t pid;
132    unsigned int queued_lines;
133    int timeout_ms;
134    int error;
135    bool flush;
136    bool valid_entry; /* valiant(?) effort to deal with memory starvation */
137    struct log_msg entry;
138};
139
140struct log_list {
141    struct listnode node;
142    struct log_msg entry; /* Truncated to event->len() + 1 to save space */
143};
144
145struct logger {
146    struct listnode node;
147    struct logger_list *top;
148    int fd;
149    log_id_t id;
150    short *revents;
151    struct listnode log_list;
152};
153
154/* android_logger_alloc unimplemented, no use case */
155/* android_logger_free not exported */
156static void android_logger_free(struct logger *logger)
157{
158    if (!logger) {
159        return;
160    }
161
162    while (!list_empty(&logger->log_list)) {
163        struct log_list *entry = node_to_item(
164            list_head(&logger->log_list), struct log_list, node);
165        list_remove(&entry->node);
166        free(entry);
167        if (logger->top->queued_lines) {
168            logger->top->queued_lines--;
169        }
170    }
171
172    if (logger->fd >= 0) {
173        close(logger->fd);
174    }
175
176    list_remove(&logger->node);
177
178    free(logger);
179}
180
181log_id_t android_logger_get_id(struct logger *logger)
182{
183    return logger->id;
184}
185
186/* worker for sending the command to the logger */
187static int logger_ioctl(struct logger *logger, int cmd, int mode)
188{
189    char *n;
190    int  f, ret;
191
192    if (!logger || !logger->top) {
193        return -EFAULT;
194    }
195
196    if (((mode & O_ACCMODE) == O_RDWR)
197     || (((mode ^ logger->top->mode) & O_ACCMODE) == 0)) {
198        return ioctl(logger->fd, cmd);
199    }
200
201    /* We go here if android_logger_list_open got mode wrong for this ioctl */
202    ret = check_allocate_accessible(&n, android_log_id_to_name(logger->id), mode);
203    if (ret) {
204        free(n);
205        return ret;
206    }
207
208    f = open(n, mode);
209    free(n);
210    if (f < 0) {
211        return f;
212    }
213
214    ret = ioctl(f, cmd);
215    close (f);
216
217    return ret;
218}
219
220int android_logger_clear(struct logger *logger)
221{
222    return logger_ioctl(logger, LOGGER_FLUSH_LOG, O_WRONLY);
223}
224
225/* returns the total size of the log's ring buffer */
226int android_logger_get_log_size(struct logger *logger)
227{
228    return logger_ioctl(logger, LOGGER_GET_LOG_BUF_SIZE, O_RDWR);
229}
230
231/*
232 * returns the readable size of the log's ring buffer (that is, amount of the
233 * log consumed)
234 */
235int android_logger_get_log_readable_size(struct logger *logger)
236{
237    return logger_ioctl(logger, LOGGER_GET_LOG_LEN, O_RDONLY);
238}
239
240/*
241 * returns the logger version
242 */
243int android_logger_get_log_version(struct logger *logger)
244{
245    int ret = logger_ioctl(logger, LOGGER_GET_VERSION, O_RDWR);
246    return (ret < 0) ? 1 : ret;
247}
248
249struct logger_list *android_logger_list_alloc(int mode,
250                                              unsigned int tail,
251                                              pid_t pid)
252{
253    struct logger_list *logger_list;
254
255    logger_list = calloc(1, sizeof(*logger_list));
256    if (!logger_list) {
257        return NULL;
258    }
259    list_init(&logger_list->node);
260    logger_list->mode = mode;
261    logger_list->tail = tail;
262    logger_list->pid = pid;
263    return logger_list;
264}
265
266/* android_logger_list_register unimplemented, no use case */
267/* android_logger_list_unregister unimplemented, no use case */
268
269/* Open the named log and add it to the logger list */
270struct logger *android_logger_open(struct logger_list *logger_list,
271                                   log_id_t id)
272{
273    struct listnode *node;
274    struct logger *logger;
275    char *n;
276
277    if (!logger_list || (id >= LOG_ID_MAX)) {
278        goto err;
279    }
280
281    logger_for_each(logger, logger_list) {
282        if (logger->id == id) {
283            goto ok;
284        }
285    }
286
287    logger = calloc(1, sizeof(*logger));
288    if (!logger) {
289        goto err;
290    }
291
292    if (check_allocate_accessible(&n, android_log_id_to_name(id),
293                                  logger_list->mode)) {
294        goto err_name;
295    }
296
297    logger->fd = open(n, logger_list->mode);
298    if (logger->fd < 0) {
299        goto err_name;
300    }
301
302    free(n);
303    logger->id = id;
304    list_init(&logger->log_list);
305    list_add_tail(&logger_list->node, &logger->node);
306    logger->top = logger_list;
307    logger_list->timeout_ms = LOG_TIMEOUT_FLUSH;
308    goto ok;
309
310err_name:
311    free(n);
312err_logger:
313    free(logger);
314err:
315    logger = NULL;
316ok:
317    return logger;
318}
319
320/* Open the single named log and make it part of a new logger list */
321struct logger_list *android_logger_list_open(log_id_t id,
322                                             int mode,
323                                             unsigned int tail,
324                                             pid_t pid)
325{
326    struct logger_list *logger_list = android_logger_list_alloc(mode, tail, pid);
327    if (!logger_list) {
328        return NULL;
329    }
330
331    if (!android_logger_open(logger_list, id)) {
332        android_logger_list_free(logger_list);
333        return NULL;
334    }
335
336    return logger_list;
337}
338
339/* prevent memory starvation when backfilling */
340static unsigned int queue_threshold(struct logger_list *logger_list)
341{
342    return (logger_list->tail < 64) ? 64 : logger_list->tail;
343}
344
345static bool low_queue(struct listnode *node)
346{
347    /* low is considered less than 2 */
348    return list_head(node) == list_tail(node);
349}
350
351/* Flush queues in sequential order, one at a time */
352static int android_logger_list_flush(struct logger_list *logger_list,
353                                     struct log_msg *log_msg)
354{
355    int ret = 0;
356    struct log_list *firstentry = NULL;
357
358    while ((ret == 0)
359     && (logger_list->flush
360      || (logger_list->queued_lines > logger_list->tail))) {
361        struct logger *logger;
362
363        /* Merge sort */
364        bool at_least_one_is_low = false;
365        struct logger *firstlogger = NULL;
366        firstentry = NULL;
367
368        logger_for_each(logger, logger_list) {
369            struct listnode *node;
370            struct log_list *oldest = NULL;
371
372            /* kernel logger channels not necessarily time-sort order */
373            list_for_each(node, &logger->log_list) {
374                struct log_list *entry = node_to_item(node,
375                                                      struct log_list, node);
376                if (!oldest
377                 || (entry->entry.entry.sec < oldest->entry.entry.sec)
378                 || ((entry->entry.entry.sec == oldest->entry.entry.sec)
379                  && (entry->entry.entry.nsec < oldest->entry.entry.nsec))) {
380                     oldest = entry;
381                }
382            }
383
384            if (!oldest) {
385                at_least_one_is_low = true;
386                continue;
387            } else if (low_queue(&logger->log_list)) {
388                at_least_one_is_low = true;
389            }
390
391            if (!firstentry
392             || (oldest->entry.entry.sec < firstentry->entry.entry.sec)
393             || ((oldest->entry.entry.sec == firstentry->entry.entry.sec)
394              && (oldest->entry.entry.nsec < firstentry->entry.entry.nsec))) {
395                firstentry = oldest;
396                firstlogger = logger;
397            }
398        }
399
400        if (!firstentry) {
401            break;
402        }
403
404        /* when trimming list, tries to keep one entry behind in each bucket */
405        if (!logger_list->flush
406         && at_least_one_is_low
407         && (logger_list->queued_lines < queue_threshold(logger_list))) {
408            break;
409        }
410
411        /* within tail?, send! */
412        if ((logger_list->tail == 0)
413         || (logger_list->queued_lines <= logger_list->tail)) {
414            ret = firstentry->entry.entry.hdr_size;
415            if (!ret) {
416                ret = sizeof(firstentry->entry.entry_v1);
417            }
418            ret += firstentry->entry.entry.len;
419
420            memcpy(log_msg->buf, firstentry->entry.buf, ret + 1);
421            log_msg->extra.id = firstlogger->id;
422        }
423
424        /* next entry */
425        list_remove(&firstentry->node);
426        free(firstentry);
427        if (logger_list->queued_lines) {
428            logger_list->queued_lines--;
429        }
430    }
431
432    /* Flushed the list, no longer in tail mode for continuing content */
433    if (logger_list->flush && !firstentry) {
434        logger_list->tail = 0;
435    }
436    return ret;
437}
438
439/* Read from the selected logs */
440int android_logger_list_read(struct logger_list *logger_list,
441                             struct log_msg *log_msg)
442{
443    struct logger *logger;
444    nfds_t nfds;
445    struct pollfd *p, *pollfds = NULL;
446    int error = 0, ret = 0;
447
448    memset(log_msg, 0, sizeof(struct log_msg));
449
450    if (!logger_list) {
451        return -ENODEV;
452    }
453
454    if (!(accessmode(logger_list->mode) & R_OK)) {
455        logger_list->error = EPERM;
456        goto done;
457    }
458
459    nfds = 0;
460    logger_for_each(logger, logger_list) {
461        ++nfds;
462    }
463    if (nfds <= 0) {
464        error = ENODEV;
465        goto done;
466    }
467
468    /* Do we have anything to offer from the buffer or state? */
469    if (logger_list->valid_entry) { /* implies we are also in a flush state */
470        goto flush;
471    }
472
473    ret = android_logger_list_flush(logger_list, log_msg);
474    if (ret) {
475        goto done;
476    }
477
478    if (logger_list->error) { /* implies we are also in a flush state */
479        goto done;
480    }
481
482    /* Lets start grinding on metal */
483    pollfds = calloc(nfds, sizeof(struct pollfd));
484    if (!pollfds) {
485        error = ENOMEM;
486        goto flush;
487    }
488
489    p = pollfds;
490    logger_for_each(logger, logger_list) {
491        p->fd = logger->fd;
492        p->events = POLLIN;
493        logger->revents = &p->revents;
494        ++p;
495    }
496
497    while (!ret && !error) {
498        int result;
499
500        /* If we oversleep it's ok, i.e. ignore EINTR. */
501        result = TEMP_FAILURE_RETRY(
502            poll(pollfds, nfds, logger_list->timeout_ms));
503
504        if (result <= 0) {
505            if (result) {
506                error = errno;
507            } else if (logger_list->mode & O_NDELAY) {
508                error = EAGAIN;
509            } else {
510                logger_list->timeout_ms = LOG_TIMEOUT_NEVER;
511            }
512
513            logger_list->flush = true;
514            goto try_flush;
515        }
516
517        logger_list->timeout_ms = LOG_TIMEOUT_FLUSH;
518
519        /* Anti starvation */
520        if (!logger_list->flush
521         && (logger_list->queued_lines > (queue_threshold(logger_list) / 2))) {
522            /* Any queues with input pending that is low? */
523            bool starving = false;
524            logger_for_each(logger, logger_list) {
525                if ((*(logger->revents) & POLLIN)
526                 && low_queue(&logger->log_list)) {
527                    starving = true;
528                    break;
529                }
530            }
531
532            /* pushback on any queues that are not low */
533            if (starving) {
534                logger_for_each(logger, logger_list) {
535                    if ((*(logger->revents) & POLLIN)
536                     && !low_queue(&logger->log_list)) {
537                        *(logger->revents) &= ~POLLIN;
538                    }
539                }
540            }
541        }
542
543        logger_for_each(logger, logger_list) {
544            unsigned int hdr_size;
545            struct log_list *entry;
546
547            if (!(*(logger->revents) & POLLIN)) {
548                continue;
549            }
550
551            memset(logger_list->entry.buf, 0, sizeof(struct log_msg));
552            /* NOTE: driver guarantees we read exactly one full entry */
553            result = read(logger->fd, logger_list->entry.buf,
554                          LOGGER_ENTRY_MAX_LEN);
555            if (result <= 0) {
556                if (!result) {
557                    error = EIO;
558                } else if (errno != EINTR) {
559                    error = errno;
560                }
561                continue;
562            }
563
564            if (logger_list->pid
565             && (logger_list->pid != logger_list->entry.entry.pid)) {
566                continue;
567            }
568
569            hdr_size = logger_list->entry.entry.hdr_size;
570            if (!hdr_size) {
571                hdr_size = sizeof(logger_list->entry.entry_v1);
572            }
573
574            if ((hdr_size > sizeof(struct log_msg))
575             || (logger_list->entry.entry.len
576               > sizeof(logger_list->entry.buf) - hdr_size)
577             || (logger_list->entry.entry.len != result - hdr_size)) {
578                error = EINVAL;
579                continue;
580            }
581
582            logger_list->entry.extra.id = logger->id;
583
584            /* speedup: If not tail, and only one list, send directly */
585            if (!logger_list->tail
586             && (list_head(&logger_list->node)
587              == list_tail(&logger_list->node))) {
588                ret = result;
589                memcpy(log_msg->buf, logger_list->entry.buf, result + 1);
590                log_msg->extra.id = logger->id;
591                break;
592            }
593
594            entry = malloc(sizeof(*entry) - sizeof(entry->entry) + result + 1);
595
596            if (!entry) {
597                logger_list->valid_entry = true;
598                error = ENOMEM;
599                break;
600            }
601
602            logger_list->queued_lines++;
603
604            memcpy(entry->entry.buf, logger_list->entry.buf, result);
605            entry->entry.buf[result] = '\0';
606            list_add_tail(&logger->log_list, &entry->node);
607        }
608
609        if (ret <= 0) {
610try_flush:
611            ret = android_logger_list_flush(logger_list, log_msg);
612        }
613    }
614
615    free(pollfds);
616
617flush:
618    if (error) {
619        logger_list->flush = true;
620    }
621
622    if (ret <= 0) {
623        ret = android_logger_list_flush(logger_list, log_msg);
624
625        if (!ret && logger_list->valid_entry) {
626            ret = logger_list->entry.entry.hdr_size;
627            if (!ret) {
628                ret = sizeof(logger_list->entry.entry_v1);
629            }
630            ret += logger_list->entry.entry.len;
631
632            memcpy(log_msg->buf, logger_list->entry.buf,
633                   sizeof(struct log_msg));
634            logger_list->valid_entry = false;
635        }
636    }
637
638done:
639    if (logger_list->error) {
640        error = logger_list->error;
641    }
642    if (error) {
643        logger_list->error = error;
644        if (!ret) {
645            ret = -error;
646        }
647    }
648    return ret;
649}
650
651/* Close all the logs */
652void android_logger_list_free(struct logger_list *logger_list)
653{
654    if (logger_list == NULL) {
655        return;
656    }
657
658    while (!list_empty(&logger_list->node)) {
659        struct listnode *node = list_head(&logger_list->node);
660        struct logger *logger = node_to_item(node, struct logger, node);
661        android_logger_free(logger);
662    }
663
664    free(logger_list);
665}
666