libc_logging.cpp revision 11331f60dd735613eee902b43a02b646ae873032 
1/*
2 * Copyright (C) 2010 The Android Open Source Project
3 * All rights reserved.
4 *
5 * Redistribution and use in source and binary forms, with or without
6 * modification, are permitted provided that the following conditions
7 * are met:
8 *  * Redistributions of source code must retain the above copyright
9 *    notice, this list of conditions and the following disclaimer.
10 *  * Redistributions in binary form must reproduce the above copyright
11 *    notice, this list of conditions and the following disclaimer in
12 *    the documentation and/or other materials provided with the
13 *    distribution.
14 *
15 * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
16 * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
17 * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS
18 * FOR A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE
19 * COPYRIGHT OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT,
20 * INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING,
21 * BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS
22 * OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED
23 * AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,
24 * OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT
25 * OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
26 * SUCH DAMAGE.
27 */
28
29#include "../private/libc_logging.h" // Relative path so we can #include this .cpp file for testing.
30#include "../private/ScopedPthreadMutexLocker.h"
31
32#include <android/set_abort_message.h>
33#include <assert.h>
34#include <errno.h>
35#include <fcntl.h>
36#include <pthread.h>
37#include <stdarg.h>
38#include <stddef.h>
39#include <stdlib.h>
40#include <string.h>
41#include <sys/mman.h>
42#include <sys/socket.h>
43#include <sys/types.h>
44#include <sys/uio.h>
45#include <sys/un.h>
46#include <time.h>
47#include <unistd.h>
48
49static pthread_mutex_t g_abort_msg_lock = PTHREAD_MUTEX_INITIALIZER;
50
51__LIBC_HIDDEN__ abort_msg_t** __abort_message_ptr; // Accessible to __libc_init_common.
52
53// Must be kept in sync with frameworks/base/core/java/android/util/EventLog.java.
54enum AndroidEventLogType {
55  EVENT_TYPE_INT      = 0,
56  EVENT_TYPE_LONG     = 1,
57  EVENT_TYPE_STRING   = 2,
58  EVENT_TYPE_LIST     = 3,
59  EVENT_TYPE_FLOAT    = 4,
60};
61
62struct BufferOutputStream {
63 public:
64  BufferOutputStream(char* buffer, size_t size) : total(0) {
65    buffer_ = buffer;
66    end_ = buffer + size - 1;
67    pos_ = buffer_;
68    pos_[0] = '\0';
69  }
70
71  ~BufferOutputStream() {
72  }
73
74  void Send(const char* data, int len) {
75    if (len < 0) {
76      len = strlen(data);
77    }
78
79    total += len;
80
81    while (len > 0) {
82      int avail = end_ - pos_;
83      if (avail == 0) {
84        return;
85      }
86      if (avail > len) {
87        avail = len;
88      }
89      memcpy(pos_, data, avail);
90      pos_ += avail;
91      pos_[0] = '\0';
92      len -= avail;
93    }
94  }
95
96  size_t total;
97
98 private:
99  char* buffer_;
100  char* pos_;
101  char* end_;
102};
103
104struct FdOutputStream {
105 public:
106  FdOutputStream(int fd) : total(0), fd_(fd) {
107  }
108
109  void Send(const char* data, int len) {
110    if (len < 0) {
111      len = strlen(data);
112    }
113
114    total += len;
115
116    while (len > 0) {
117      int rc = TEMP_FAILURE_RETRY(write(fd_, data, len));
118      if (rc == -1) {
119        return;
120      }
121      data += rc;
122      len -= rc;
123    }
124  }
125
126  size_t total;
127
128 private:
129  int fd_;
130};
131
132/*** formatted output implementation
133 ***/
134
135/* Parse a decimal string from 'format + *ppos',
136 * return the value, and writes the new position past
137 * the decimal string in '*ppos' on exit.
138 *
139 * NOTE: Does *not* handle a sign prefix.
140 */
141static unsigned parse_decimal(const char *format, int *ppos) {
142    const char* p = format + *ppos;
143    unsigned result = 0;
144
145    for (;;) {
146        int ch = *p;
147        unsigned d = static_cast<unsigned>(ch - '0');
148
149        if (d >= 10U) {
150            break;
151        }
152
153        result = result*10 + d;
154        p++;
155    }
156    *ppos = p - format;
157    return result;
158}
159
160// Writes number 'value' in base 'base' into buffer 'buf' of size 'buf_size' bytes.
161// Assumes that buf_size > 0.
162static void format_unsigned(char* buf, size_t buf_size, uint64_t value, int base, bool caps) {
163  char* p = buf;
164  char* end = buf + buf_size - 1;
165
166  // Generate digit string in reverse order.
167  while (value) {
168    unsigned d = value % base;
169    value /= base;
170    if (p != end) {
171      char ch;
172      if (d < 10) {
173        ch = '0' + d;
174      } else {
175        ch = (caps ? 'A' : 'a') + (d - 10);
176      }
177      *p++ = ch;
178    }
179  }
180
181  // Special case for 0.
182  if (p == buf) {
183    if (p != end) {
184      *p++ = '0';
185    }
186  }
187  *p = '\0';
188
189  // Reverse digit string in-place.
190  size_t length = p - buf;
191  for (size_t i = 0, j = length - 1; i < j; ++i, --j) {
192    char ch = buf[i];
193    buf[i] = buf[j];
194    buf[j] = ch;
195  }
196}
197
198static void format_integer(char* buf, size_t buf_size, uint64_t value, char conversion) {
199  // Decode the conversion specifier.
200  int is_signed = (conversion == 'd' || conversion == 'i' || conversion == 'o');
201  int base = 10;
202  if (conversion == 'x' || conversion == 'X') {
203    base = 16;
204  } else if (conversion == 'o') {
205    base = 8;
206  }
207  bool caps = (conversion == 'X');
208
209  if (is_signed && static_cast<int64_t>(value) < 0) {
210    buf[0] = '-';
211    buf += 1;
212    buf_size -= 1;
213    value = static_cast<uint64_t>(-static_cast<int64_t>(value));
214  }
215  format_unsigned(buf, buf_size, value, base, caps);
216}
217
218template <typename Out>
219static void SendRepeat(Out& o, char ch, int count) {
220  char pad[8];
221  memset(pad, ch, sizeof(pad));
222
223  const int pad_size = static_cast<int>(sizeof(pad));
224  while (count > 0) {
225    int avail = count;
226    if (avail > pad_size) {
227      avail = pad_size;
228    }
229    o.Send(pad, avail);
230    count -= avail;
231  }
232}
233
234/* Perform formatted output to an output target 'o' */
235template <typename Out>
236static void out_vformat(Out& o, const char* format, va_list args) {
237    int nn = 0;
238
239    for (;;) {
240        int mm;
241        int padZero = 0;
242        int padLeft = 0;
243        char sign = '\0';
244        int width = -1;
245        int prec  = -1;
246        size_t bytelen = sizeof(int);
247        int slen;
248        char buffer[32];  /* temporary buffer used to format numbers */
249
250        char  c;
251
252        /* first, find all characters that are not 0 or '%' */
253        /* then send them to the output directly */
254        mm = nn;
255        do {
256            c = format[mm];
257            if (c == '\0' || c == '%')
258                break;
259            mm++;
260        } while (1);
261
262        if (mm > nn) {
263            o.Send(format+nn, mm-nn);
264            nn = mm;
265        }
266
267        /* is this it ? then exit */
268        if (c == '\0')
269            break;
270
271        /* nope, we are at a '%' modifier */
272        nn++;  // skip it
273
274        /* parse flags */
275        for (;;) {
276            c = format[nn++];
277            if (c == '\0') {  /* single trailing '%' ? */
278                c = '%';
279                o.Send(&c, 1);
280                return;
281            }
282            else if (c == '0') {
283                padZero = 1;
284                continue;
285            }
286            else if (c == '-') {
287                padLeft = 1;
288                continue;
289            }
290            else if (c == ' ' || c == '+') {
291                sign = c;
292                continue;
293            }
294            break;
295        }
296
297        /* parse field width */
298        if ((c >= '0' && c <= '9')) {
299            nn --;
300            width = static_cast<int>(parse_decimal(format, &nn));
301            c = format[nn++];
302        }
303
304        /* parse precision */
305        if (c == '.') {
306            prec = static_cast<int>(parse_decimal(format, &nn));
307            c = format[nn++];
308        }
309
310        /* length modifier */
311        switch (c) {
312        case 'h':
313            bytelen = sizeof(short);
314            if (format[nn] == 'h') {
315                bytelen = sizeof(char);
316                nn += 1;
317            }
318            c = format[nn++];
319            break;
320        case 'l':
321            bytelen = sizeof(long);
322            if (format[nn] == 'l') {
323                bytelen = sizeof(long long);
324                nn += 1;
325            }
326            c = format[nn++];
327            break;
328        case 'z':
329            bytelen = sizeof(size_t);
330            c = format[nn++];
331            break;
332        case 't':
333            bytelen = sizeof(ptrdiff_t);
334            c = format[nn++];
335            break;
336        default:
337            ;
338        }
339
340        /* conversion specifier */
341        const char* str = buffer;
342        if (c == 's') {
343            /* string */
344            str = va_arg(args, const char*);
345            if (str == NULL) {
346                str = "(null)";
347            }
348        } else if (c == 'c') {
349            /* character */
350            /* NOTE: char is promoted to int when passed through the stack */
351            buffer[0] = static_cast<char>(va_arg(args, int));
352            buffer[1] = '\0';
353        } else if (c == 'p') {
354            uint64_t  value = reinterpret_cast<uintptr_t>(va_arg(args, void*));
355            buffer[0] = '0';
356            buffer[1] = 'x';
357            format_integer(buffer + 2, sizeof(buffer) - 2, value, 'x');
358        } else if (c == 'd' || c == 'i' || c == 'o' || c == 'u' || c == 'x' || c == 'X') {
359            /* integers - first read value from stack */
360            uint64_t value;
361            int is_signed = (c == 'd' || c == 'i' || c == 'o');
362
363            /* NOTE: int8_t and int16_t are promoted to int when passed
364             *       through the stack
365             */
366            switch (bytelen) {
367            case 1: value = static_cast<uint8_t>(va_arg(args, int)); break;
368            case 2: value = static_cast<uint16_t>(va_arg(args, int)); break;
369            case 4: value = va_arg(args, uint32_t); break;
370            case 8: value = va_arg(args, uint64_t); break;
371            default: return;  /* should not happen */
372            }
373
374            /* sign extension, if needed */
375            if (is_signed) {
376                int shift = 64 - 8*bytelen;
377                value = static_cast<uint64_t>((static_cast<int64_t>(value << shift)) >> shift);
378            }
379
380            /* format the number properly into our buffer */
381            format_integer(buffer, sizeof(buffer), value, c);
382        } else if (c == '%') {
383            buffer[0] = '%';
384            buffer[1] = '\0';
385        } else {
386            __assert(__FILE__, __LINE__, "conversion specifier unsupported");
387        }
388
389        /* if we are here, 'str' points to the content that must be
390         * outputted. handle padding and alignment now */
391
392        slen = strlen(str);
393
394        if (sign != '\0' || prec != -1) {
395            __assert(__FILE__, __LINE__, "sign/precision unsupported");
396        }
397
398        if (slen < width && !padLeft) {
399            char padChar = padZero ? '0' : ' ';
400            SendRepeat(o, padChar, width - slen);
401        }
402
403        o.Send(str, slen);
404
405        if (slen < width && padLeft) {
406            char padChar = padZero ? '0' : ' ';
407            SendRepeat(o, padChar, width - slen);
408        }
409    }
410}
411
412int __libc_format_buffer(char* buffer, size_t buffer_size, const char* format, ...) {
413  BufferOutputStream os(buffer, buffer_size);
414  va_list args;
415  va_start(args, format);
416  out_vformat(os, format, args);
417  va_end(args);
418  return os.total;
419}
420
421int __libc_format_fd(int fd, const char* format, ...) {
422  FdOutputStream os(fd);
423  va_list args;
424  va_start(args, format);
425  out_vformat(os, format, args);
426  va_end(args);
427  return os.total;
428}
429
430static int __libc_write_stderr(const char* tag, const char* msg) {
431  int fd = TEMP_FAILURE_RETRY(open("/dev/stderr", O_CLOEXEC | O_WRONLY | O_APPEND));
432  if (fd == -1) {
433    return -1;
434  }
435
436  iovec vec[4];
437  vec[0].iov_base = const_cast<char*>(tag);
438  vec[0].iov_len = strlen(tag);
439  vec[1].iov_base = const_cast<char*>(": ");
440  vec[1].iov_len = 2;
441  vec[2].iov_base = const_cast<char*>(msg);
442  vec[2].iov_len = strlen(msg);
443  vec[3].iov_base = const_cast<char*>("\n");
444  vec[3].iov_len = 1;
445
446  int result = TEMP_FAILURE_RETRY(writev(fd, vec, 4));
447  close(fd);
448  return result;
449}
450
451#ifdef TARGET_USES_LOGD
452static int __libc_open_log_socket() {
453  // ToDo: Ideally we want this to fail if the gid of the current
454  // process is AID_LOGD, but will have to wait until we have
455  // registered this in private/android_filesystem_config.h. We have
456  // found that all logd crashes thus far have had no problem stuffing
457  // the UNIX domain socket and moving on so not critical *today*.
458
459  int log_fd = TEMP_FAILURE_RETRY(socket(PF_UNIX, SOCK_DGRAM | SOCK_CLOEXEC, 0));
460  if (log_fd < 0) {
461    return -1;
462  }
463
464  if (fcntl(log_fd, F_SETFL, O_NONBLOCK) == -1) {
465    close(log_fd);
466    return -1;
467  }
468
469  union {
470    struct sockaddr    addr;
471    struct sockaddr_un addrUn;
472  } u;
473  memset(&u, 0, sizeof(u));
474  u.addrUn.sun_family = AF_UNIX;
475  strlcpy(u.addrUn.sun_path, "/dev/socket/logdw", sizeof(u.addrUn.sun_path));
476
477  if (TEMP_FAILURE_RETRY(connect(log_fd, &u.addr, sizeof(u.addrUn))) != 0) {
478    close(log_fd);
479    return -1;
480  }
481
482  return log_fd;
483}
484
485struct log_time { // Wire format
486  uint32_t tv_sec;
487  uint32_t tv_nsec;
488};
489#endif
490
491static int __libc_write_log(int priority, const char* tag, const char* msg) {
492#ifdef TARGET_USES_LOGD
493  int main_log_fd = __libc_open_log_socket();
494  if (main_log_fd == -1) {
495    // Try stderr instead.
496    return __libc_write_stderr(tag, msg);
497  }
498
499  iovec vec[6];
500  char log_id = (priority == ANDROID_LOG_FATAL) ? LOG_ID_CRASH : LOG_ID_MAIN;
501  vec[0].iov_base = &log_id;
502  vec[0].iov_len = sizeof(log_id);
503  uint16_t tid = gettid();
504  vec[1].iov_base = &tid;
505  vec[1].iov_len = sizeof(tid);
506  timespec ts;
507  clock_gettime(CLOCK_REALTIME, &ts);
508  log_time realtime_ts;
509  realtime_ts.tv_sec = ts.tv_sec;
510  realtime_ts.tv_nsec = ts.tv_nsec;
511  vec[2].iov_base = &realtime_ts;
512  vec[2].iov_len = sizeof(realtime_ts);
513
514  vec[3].iov_base = &priority;
515  vec[3].iov_len = 1;
516  vec[4].iov_base = const_cast<char*>(tag);
517  vec[4].iov_len = strlen(tag) + 1;
518  vec[5].iov_base = const_cast<char*>(msg);
519  vec[5].iov_len = strlen(msg) + 1;
520#else
521  int main_log_fd = TEMP_FAILURE_RETRY(open("/dev/log/main", O_CLOEXEC | O_WRONLY));
522  if (main_log_fd == -1) {
523    if (errno == ENOTDIR) {
524      // /dev/log isn't a directory? Maybe we're running on the host? Try stderr instead.
525      return __libc_write_stderr(tag, msg);
526    }
527    return -1;
528  }
529
530  iovec vec[3];
531  vec[0].iov_base = &priority;
532  vec[0].iov_len = 1;
533  vec[1].iov_base = const_cast<char*>(tag);
534  vec[1].iov_len = strlen(tag) + 1;
535  vec[2].iov_base = const_cast<char*>(msg);
536  vec[2].iov_len = strlen(msg) + 1;
537#endif
538
539  int result = TEMP_FAILURE_RETRY(writev(main_log_fd, vec, sizeof(vec) / sizeof(vec[0])));
540  close(main_log_fd);
541  return result;
542}
543
544int __libc_format_log_va_list(int priority, const char* tag, const char* format, va_list args) {
545  char buffer[1024];
546  BufferOutputStream os(buffer, sizeof(buffer));
547  out_vformat(os, format, args);
548  return __libc_write_log(priority, tag, buffer);
549}
550
551int __libc_format_log(int priority, const char* tag, const char* format, ...) {
552  va_list args;
553  va_start(args, format);
554  int result = __libc_format_log_va_list(priority, tag, format, args);
555  va_end(args);
556  return result;
557}
558
559static int __libc_android_log_event(int32_t tag, char type, const void* payload, size_t len) {
560#ifdef TARGET_USES_LOGD
561  iovec vec[6];
562  char log_id = LOG_ID_EVENTS;
563  vec[0].iov_base = &log_id;
564  vec[0].iov_len = sizeof(log_id);
565  uint16_t tid = gettid();
566  vec[1].iov_base = &tid;
567  vec[1].iov_len = sizeof(tid);
568  timespec ts;
569  clock_gettime(CLOCK_REALTIME, &ts);
570  log_time realtime_ts;
571  realtime_ts.tv_sec = ts.tv_sec;
572  realtime_ts.tv_nsec = ts.tv_nsec;
573  vec[2].iov_base = &realtime_ts;
574  vec[2].iov_len = sizeof(realtime_ts);
575
576  vec[3].iov_base = &tag;
577  vec[3].iov_len = sizeof(tag);
578  vec[4].iov_base = &type;
579  vec[4].iov_len = sizeof(type);
580  vec[5].iov_base = const_cast<void*>(payload);
581  vec[5].iov_len = len;
582
583  int event_log_fd = __libc_open_log_socket();
584#else
585  iovec vec[3];
586  vec[0].iov_base = &tag;
587  vec[0].iov_len = sizeof(tag);
588  vec[1].iov_base = &type;
589  vec[1].iov_len = sizeof(type);
590  vec[2].iov_base = const_cast<void*>(payload);
591  vec[2].iov_len = len;
592
593  int event_log_fd = TEMP_FAILURE_RETRY(open("/dev/log/events", O_CLOEXEC | O_WRONLY));
594#endif
595
596  if (event_log_fd == -1) {
597    return -1;
598  }
599  int result = TEMP_FAILURE_RETRY(writev(event_log_fd, vec, sizeof(vec) / sizeof(vec[0])));
600  close(event_log_fd);
601  return result;
602}
603
604void __libc_android_log_event_int(int32_t tag, int value) {
605  __libc_android_log_event(tag, EVENT_TYPE_INT, &value, sizeof(value));
606}
607
608void __libc_android_log_event_uid(int32_t tag) {
609  __libc_android_log_event_int(tag, getuid());
610}
611
612void __fortify_chk_fail(const char* msg, uint32_t tag) {
613  if (tag != 0) {
614    __libc_android_log_event_uid(tag);
615  }
616  __libc_fatal("FORTIFY: %s", msg);
617}
618
619static void __libc_fatal(const char* format, va_list args) {
620  char msg[1024];
621  BufferOutputStream os(msg, sizeof(msg));
622  out_vformat(os, format, args);
623
624  // Log to stderr for the benefit of "adb shell" users.
625  struct iovec iov[2] = {
626    { msg, os.total },
627    { const_cast<char*>("\n"), 1 },
628  };
629  TEMP_FAILURE_RETRY(writev(2, iov, 2));
630
631  // Log to the log for the benefit of regular app developers (whose stdout and stderr are closed).
632  __libc_write_log(ANDROID_LOG_FATAL, "libc", msg);
633
634  android_set_abort_message(msg);
635}
636
637void __libc_fatal_no_abort(const char* format, ...) {
638  va_list args;
639  va_start(args, format);
640  __libc_fatal(format, args);
641  va_end(args);
642}
643
644void __libc_fatal(const char* format, ...) {
645  va_list args;
646  va_start(args, format);
647  __libc_fatal(format, args);
648  va_end(args);
649  abort();
650}
651
652void android_set_abort_message(const char* msg) {
653  ScopedPthreadMutexLocker locker(&g_abort_msg_lock);
654
655  if (__abort_message_ptr == NULL) {
656    // We must have crashed _very_ early.
657    return;
658  }
659
660  if (*__abort_message_ptr != NULL) {
661    // We already have an abort message.
662    // Assume that the first crash is the one most worth reporting.
663    return;
664  }
665
666  size_t size = sizeof(abort_msg_t) + strlen(msg) + 1;
667  void* map = mmap(NULL, size, PROT_READ | PROT_WRITE, MAP_ANON | MAP_PRIVATE, -1, 0);
668  if (map == MAP_FAILED) {
669    return;
670  }
671
672  // TODO: if we stick to the current "one-shot" scheme, we can remove this code and
673  // stop storing the size.
674  if (*__abort_message_ptr != NULL) {
675    munmap(*__abort_message_ptr, (*__abort_message_ptr)->size);
676  }
677  abort_msg_t* new_abort_message = reinterpret_cast<abort_msg_t*>(map);
678  new_abort_message->size = size;
679  strcpy(new_abort_message->msg, msg);
680  *__abort_message_ptr = new_abort_message;
681}
682