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