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