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