1/*
2**
3** Copyright 2006-2014, The Android Open Source Project
4**
5** Licensed under the Apache License, Version 2.0 (the "License");
6** you may not use this file except in compliance with the License.
7** You may obtain a copy of the License at
8**
9**     http://www.apache.org/licenses/LICENSE-2.0
10**
11** Unless required by applicable law or agreed to in writing, software
12** distributed under the License is distributed on an "AS IS" BASIS,
13** WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14** See the License for the specific language governing permissions and
15** limitations under the License.
16*/
17
18#define _GNU_SOURCE /* for asprintf */
19#ifndef __MINGW32__
20#define HAVE_STRSEP
21#endif
22
23#include <assert.h>
24#include <ctype.h>
25#include <errno.h>
26#include <inttypes.h>
27#ifndef __MINGW32__
28#include <pwd.h>
29#endif
30#include <stdbool.h>
31#include <stdint.h>
32#include <stdio.h>
33#include <stdlib.h>
34#include <string.h>
35#include <sys/param.h>
36#include <sys/types.h>
37
38#include <cutils/list.h>
39#include <log/log.h>
40#include <log/logprint.h>
41
42#include "log_portability.h"
43
44#define MS_PER_NSEC 1000000
45#define US_PER_NSEC 1000
46
47#ifndef MIN
48#define MIN(a, b) (((a) < (b)) ? (a) : (b))
49#endif
50
51typedef struct FilterInfo_t {
52  char* mTag;
53  android_LogPriority mPri;
54  struct FilterInfo_t* p_next;
55} FilterInfo;
56
57struct AndroidLogFormat_t {
58  android_LogPriority global_pri;
59  FilterInfo* filters;
60  AndroidLogPrintFormat format;
61  bool colored_output;
62  bool usec_time_output;
63  bool nsec_time_output;
64  bool printable_output;
65  bool year_output;
66  bool zone_output;
67  bool epoch_output;
68  bool monotonic_output;
69  bool uid_output;
70  bool descriptive_output;
71};
72
73/*
74 * API issues prevent us from exposing "descriptive" in AndroidLogFormat_t
75 * during android_log_processBinaryLogBuffer(), so we break layering.
76 */
77static bool descriptive_output = false;
78
79/*
80 *  gnome-terminal color tags
81 *    See http://misc.flogisoft.com/bash/tip_colors_and_formatting
82 *    for ideas on how to set the forground color of the text for xterm.
83 *    The color manipulation character stream is defined as:
84 *      ESC [ 3 8 ; 5 ; <color#> m
85 */
86#define ANDROID_COLOR_BLUE 75
87#define ANDROID_COLOR_DEFAULT 231
88#define ANDROID_COLOR_GREEN 40
89#define ANDROID_COLOR_ORANGE 166
90#define ANDROID_COLOR_RED 196
91#define ANDROID_COLOR_YELLOW 226
92
93static FilterInfo* filterinfo_new(const char* tag, android_LogPriority pri) {
94  FilterInfo* p_ret;
95
96  p_ret = (FilterInfo*)calloc(1, sizeof(FilterInfo));
97  p_ret->mTag = strdup(tag);
98  p_ret->mPri = pri;
99
100  return p_ret;
101}
102
103/* balance to above, filterinfo_free left unimplemented */
104
105/*
106 * Note: also accepts 0-9 priorities
107 * returns ANDROID_LOG_UNKNOWN if the character is unrecognized
108 */
109static android_LogPriority filterCharToPri(char c) {
110  android_LogPriority pri;
111
112  c = tolower(c);
113
114  if (c >= '0' && c <= '9') {
115    if (c >= ('0' + ANDROID_LOG_SILENT)) {
116      pri = ANDROID_LOG_VERBOSE;
117    } else {
118      pri = (android_LogPriority)(c - '0');
119    }
120  } else if (c == 'v') {
121    pri = ANDROID_LOG_VERBOSE;
122  } else if (c == 'd') {
123    pri = ANDROID_LOG_DEBUG;
124  } else if (c == 'i') {
125    pri = ANDROID_LOG_INFO;
126  } else if (c == 'w') {
127    pri = ANDROID_LOG_WARN;
128  } else if (c == 'e') {
129    pri = ANDROID_LOG_ERROR;
130  } else if (c == 'f') {
131    pri = ANDROID_LOG_FATAL;
132  } else if (c == 's') {
133    pri = ANDROID_LOG_SILENT;
134  } else if (c == '*') {
135    pri = ANDROID_LOG_DEFAULT;
136  } else {
137    pri = ANDROID_LOG_UNKNOWN;
138  }
139
140  return pri;
141}
142
143static char filterPriToChar(android_LogPriority pri) {
144  switch (pri) {
145    /* clang-format off */
146    case ANDROID_LOG_VERBOSE: return 'V';
147    case ANDROID_LOG_DEBUG:   return 'D';
148    case ANDROID_LOG_INFO:    return 'I';
149    case ANDROID_LOG_WARN:    return 'W';
150    case ANDROID_LOG_ERROR:   return 'E';
151    case ANDROID_LOG_FATAL:   return 'F';
152    case ANDROID_LOG_SILENT:  return 'S';
153
154    case ANDROID_LOG_DEFAULT:
155    case ANDROID_LOG_UNKNOWN:
156    default:                  return '?';
157    /* clang-format on */
158  }
159}
160
161static int colorFromPri(android_LogPriority pri) {
162  switch (pri) {
163    /* clang-format off */
164    case ANDROID_LOG_VERBOSE: return ANDROID_COLOR_DEFAULT;
165    case ANDROID_LOG_DEBUG:   return ANDROID_COLOR_BLUE;
166    case ANDROID_LOG_INFO:    return ANDROID_COLOR_GREEN;
167    case ANDROID_LOG_WARN:    return ANDROID_COLOR_ORANGE;
168    case ANDROID_LOG_ERROR:   return ANDROID_COLOR_RED;
169    case ANDROID_LOG_FATAL:   return ANDROID_COLOR_RED;
170    case ANDROID_LOG_SILENT:  return ANDROID_COLOR_DEFAULT;
171
172    case ANDROID_LOG_DEFAULT:
173    case ANDROID_LOG_UNKNOWN:
174    default:                  return ANDROID_COLOR_DEFAULT;
175    /* clang-format on */
176  }
177}
178
179static android_LogPriority filterPriForTag(AndroidLogFormat* p_format,
180                                           const char* tag) {
181  FilterInfo* p_curFilter;
182
183  for (p_curFilter = p_format->filters; p_curFilter != NULL;
184       p_curFilter = p_curFilter->p_next) {
185    if (0 == strcmp(tag, p_curFilter->mTag)) {
186      if (p_curFilter->mPri == ANDROID_LOG_DEFAULT) {
187        return p_format->global_pri;
188      } else {
189        return p_curFilter->mPri;
190      }
191    }
192  }
193
194  return p_format->global_pri;
195}
196
197/**
198 * returns 1 if this log line should be printed based on its priority
199 * and tag, and 0 if it should not
200 */
201LIBLOG_ABI_PUBLIC int android_log_shouldPrintLine(AndroidLogFormat* p_format,
202                                                  const char* tag,
203                                                  android_LogPriority pri) {
204  return pri >= filterPriForTag(p_format, tag);
205}
206
207LIBLOG_ABI_PUBLIC AndroidLogFormat* android_log_format_new() {
208  AndroidLogFormat* p_ret;
209
210  p_ret = calloc(1, sizeof(AndroidLogFormat));
211
212  p_ret->global_pri = ANDROID_LOG_VERBOSE;
213  p_ret->format = FORMAT_BRIEF;
214  p_ret->colored_output = false;
215  p_ret->usec_time_output = false;
216  p_ret->nsec_time_output = false;
217  p_ret->printable_output = false;
218  p_ret->year_output = false;
219  p_ret->zone_output = false;
220  p_ret->epoch_output = false;
221#ifdef __ANDROID__
222  p_ret->monotonic_output = android_log_clockid() == CLOCK_MONOTONIC;
223#else
224  p_ret->monotonic_output = false;
225#endif
226  p_ret->uid_output = false;
227  p_ret->descriptive_output = false;
228  descriptive_output = false;
229
230  return p_ret;
231}
232
233static list_declare(convertHead);
234
235LIBLOG_ABI_PUBLIC void android_log_format_free(AndroidLogFormat* p_format) {
236  FilterInfo *p_info, *p_info_old;
237
238  p_info = p_format->filters;
239
240  while (p_info != NULL) {
241    p_info_old = p_info;
242    p_info = p_info->p_next;
243
244    free(p_info_old);
245  }
246
247  free(p_format);
248
249  /* Free conversion resource, can always be reconstructed */
250  while (!list_empty(&convertHead)) {
251    struct listnode* node = list_head(&convertHead);
252    list_remove(node);
253    free(node);
254  }
255}
256
257LIBLOG_ABI_PUBLIC int android_log_setPrintFormat(AndroidLogFormat* p_format,
258                                                 AndroidLogPrintFormat format) {
259  switch (format) {
260    case FORMAT_MODIFIER_COLOR:
261      p_format->colored_output = true;
262      return 0;
263    case FORMAT_MODIFIER_TIME_USEC:
264      p_format->usec_time_output = true;
265      return 0;
266    case FORMAT_MODIFIER_TIME_NSEC:
267      p_format->nsec_time_output = true;
268      return 0;
269    case FORMAT_MODIFIER_PRINTABLE:
270      p_format->printable_output = true;
271      return 0;
272    case FORMAT_MODIFIER_YEAR:
273      p_format->year_output = true;
274      return 0;
275    case FORMAT_MODIFIER_ZONE:
276      p_format->zone_output = !p_format->zone_output;
277      return 0;
278    case FORMAT_MODIFIER_EPOCH:
279      p_format->epoch_output = true;
280      return 0;
281    case FORMAT_MODIFIER_MONOTONIC:
282      p_format->monotonic_output = true;
283      return 0;
284    case FORMAT_MODIFIER_UID:
285      p_format->uid_output = true;
286      return 0;
287    case FORMAT_MODIFIER_DESCRIPT:
288      p_format->descriptive_output = true;
289      descriptive_output = true;
290      return 0;
291    default:
292      break;
293  }
294  p_format->format = format;
295  return 1;
296}
297
298static const char tz[] = "TZ";
299static const char utc[] = "UTC";
300
301/**
302 * Returns FORMAT_OFF on invalid string
303 */
304LIBLOG_ABI_PUBLIC AndroidLogPrintFormat
305android_log_formatFromString(const char* formatString) {
306  static AndroidLogPrintFormat format;
307
308  /* clang-format off */
309  if (!strcmp(formatString, "brief")) format = FORMAT_BRIEF;
310  else if (!strcmp(formatString, "process")) format = FORMAT_PROCESS;
311  else if (!strcmp(formatString, "tag")) format = FORMAT_TAG;
312  else if (!strcmp(formatString, "thread")) format = FORMAT_THREAD;
313  else if (!strcmp(formatString, "raw")) format = FORMAT_RAW;
314  else if (!strcmp(formatString, "time")) format = FORMAT_TIME;
315  else if (!strcmp(formatString, "threadtime")) format = FORMAT_THREADTIME;
316  else if (!strcmp(formatString, "long")) format = FORMAT_LONG;
317  else if (!strcmp(formatString, "color")) format = FORMAT_MODIFIER_COLOR;
318  else if (!strcmp(formatString, "colour")) format = FORMAT_MODIFIER_COLOR;
319  else if (!strcmp(formatString, "usec")) format = FORMAT_MODIFIER_TIME_USEC;
320  else if (!strcmp(formatString, "nsec")) format = FORMAT_MODIFIER_TIME_NSEC;
321  else if (!strcmp(formatString, "printable")) format = FORMAT_MODIFIER_PRINTABLE;
322  else if (!strcmp(formatString, "year")) format = FORMAT_MODIFIER_YEAR;
323  else if (!strcmp(formatString, "zone")) format = FORMAT_MODIFIER_ZONE;
324  else if (!strcmp(formatString, "epoch")) format = FORMAT_MODIFIER_EPOCH;
325  else if (!strcmp(formatString, "monotonic")) format = FORMAT_MODIFIER_MONOTONIC;
326  else if (!strcmp(formatString, "uid")) format = FORMAT_MODIFIER_UID;
327  else if (!strcmp(formatString, "descriptive")) format = FORMAT_MODIFIER_DESCRIPT;
328  /* clang-format on */
329
330#ifndef __MINGW32__
331  else {
332    extern char* tzname[2];
333    static const char gmt[] = "GMT";
334    char* cp = getenv(tz);
335    if (cp) {
336      cp = strdup(cp);
337    }
338    setenv(tz, formatString, 1);
339    /*
340     * Run tzset here to determine if the timezone is legitimate. If the
341     * zone is GMT, check if that is what was asked for, if not then
342     * did not match any on the system; report an error to caller.
343     */
344    tzset();
345    if (!tzname[0] ||
346        ((!strcmp(tzname[0], utc) || !strcmp(tzname[0], gmt)) /* error? */
347         && strcasecmp(formatString, utc) &&
348         strcasecmp(formatString, gmt))) { /* ok */
349      if (cp) {
350        setenv(tz, cp, 1);
351      } else {
352        unsetenv(tz);
353      }
354      tzset();
355      format = FORMAT_OFF;
356    } else {
357      format = FORMAT_MODIFIER_ZONE;
358    }
359    free(cp);
360  }
361#endif
362
363  return format;
364}
365
366/**
367 * filterExpression: a single filter expression
368 * eg "AT:d"
369 *
370 * returns 0 on success and -1 on invalid expression
371 *
372 * Assumes single threaded execution
373 */
374
375LIBLOG_ABI_PUBLIC int android_log_addFilterRule(AndroidLogFormat* p_format,
376                                                const char* filterExpression) {
377  size_t tagNameLength;
378  android_LogPriority pri = ANDROID_LOG_DEFAULT;
379
380  tagNameLength = strcspn(filterExpression, ":");
381
382  if (tagNameLength == 0) {
383    goto error;
384  }
385
386  if (filterExpression[tagNameLength] == ':') {
387    pri = filterCharToPri(filterExpression[tagNameLength + 1]);
388
389    if (pri == ANDROID_LOG_UNKNOWN) {
390      goto error;
391    }
392  }
393
394  if (0 == strncmp("*", filterExpression, tagNameLength)) {
395    /*
396     * This filter expression refers to the global filter
397     * The default level for this is DEBUG if the priority
398     * is unspecified
399     */
400    if (pri == ANDROID_LOG_DEFAULT) {
401      pri = ANDROID_LOG_DEBUG;
402    }
403
404    p_format->global_pri = pri;
405  } else {
406    /*
407     * for filter expressions that don't refer to the global
408     * filter, the default is verbose if the priority is unspecified
409     */
410    if (pri == ANDROID_LOG_DEFAULT) {
411      pri = ANDROID_LOG_VERBOSE;
412    }
413
414    char* tagName;
415
416/*
417 * Presently HAVE_STRNDUP is never defined, so the second case is always taken
418 * Darwin doesn't have strndup, everything else does
419 */
420#ifdef HAVE_STRNDUP
421    tagName = strndup(filterExpression, tagNameLength);
422#else
423    /* a few extra bytes copied... */
424    tagName = strdup(filterExpression);
425    tagName[tagNameLength] = '\0';
426#endif /*HAVE_STRNDUP*/
427
428    FilterInfo* p_fi = filterinfo_new(tagName, pri);
429    free(tagName);
430
431    p_fi->p_next = p_format->filters;
432    p_format->filters = p_fi;
433  }
434
435  return 0;
436error:
437  return -1;
438}
439
440#ifndef HAVE_STRSEP
441/* KISS replacement helper for below */
442static char* strsep(char** stringp, const char* delim) {
443  char* token;
444  char* ret = *stringp;
445
446  if (!ret || !*ret) {
447    return NULL;
448  }
449  token = strpbrk(ret, delim);
450  if (token) {
451    *token = '\0';
452    ++token;
453  } else {
454    token = ret + strlen(ret);
455  }
456  *stringp = token;
457  return ret;
458}
459#endif
460
461/**
462 * filterString: a comma/whitespace-separated set of filter expressions
463 *
464 * eg "AT:d *:i"
465 *
466 * returns 0 on success and -1 on invalid expression
467 *
468 * Assumes single threaded execution
469 *
470 */
471LIBLOG_ABI_PUBLIC int android_log_addFilterString(AndroidLogFormat* p_format,
472                                                  const char* filterString) {
473  char* filterStringCopy = strdup(filterString);
474  char* p_cur = filterStringCopy;
475  char* p_ret;
476  int err;
477
478  /* Yes, I'm using strsep */
479  while (NULL != (p_ret = strsep(&p_cur, " \t,"))) {
480    /* ignore whitespace-only entries */
481    if (p_ret[0] != '\0') {
482      err = android_log_addFilterRule(p_format, p_ret);
483
484      if (err < 0) {
485        goto error;
486      }
487    }
488  }
489
490  free(filterStringCopy);
491  return 0;
492error:
493  free(filterStringCopy);
494  return -1;
495}
496
497/**
498 * Splits a wire-format buffer into an AndroidLogEntry
499 * entry allocated by caller. Pointers will point directly into buf
500 *
501 * Returns 0 on success and -1 on invalid wire format (entry will be
502 * in unspecified state)
503 */
504LIBLOG_ABI_PUBLIC int android_log_processLogBuffer(struct logger_entry* buf,
505                                                   AndroidLogEntry* entry) {
506  entry->message = NULL;
507  entry->messageLen = 0;
508
509  entry->tv_sec = buf->sec;
510  entry->tv_nsec = buf->nsec;
511  entry->uid = -1;
512  entry->pid = buf->pid;
513  entry->tid = buf->tid;
514
515  /*
516   * format: <priority:1><tag:N>\0<message:N>\0
517   *
518   * tag str
519   *   starts at buf->msg+1
520   * msg
521   *   starts at buf->msg+1+len(tag)+1
522   *
523   * The message may have been truncated by the kernel log driver.
524   * When that happens, we must null-terminate the message ourselves.
525   */
526  if (buf->len < 3) {
527    /*
528     * An well-formed entry must consist of at least a priority
529     * and two null characters
530     */
531    fprintf(stderr, "+++ LOG: entry too small\n");
532    return -1;
533  }
534
535  int msgStart = -1;
536  int msgEnd = -1;
537
538  int i;
539  char* msg = buf->msg;
540  struct logger_entry_v2* buf2 = (struct logger_entry_v2*)buf;
541  if (buf2->hdr_size) {
542    if ((buf2->hdr_size < sizeof(((struct log_msg*)NULL)->entry_v1)) ||
543        (buf2->hdr_size > sizeof(((struct log_msg*)NULL)->entry))) {
544      fprintf(stderr, "+++ LOG: entry illegal hdr_size\n");
545      return -1;
546    }
547    msg = ((char*)buf2) + buf2->hdr_size;
548    if (buf2->hdr_size >= sizeof(struct logger_entry_v4)) {
549      entry->uid = ((struct logger_entry_v4*)buf)->uid;
550    }
551  }
552  for (i = 1; i < buf->len; i++) {
553    if (msg[i] == '\0') {
554      if (msgStart == -1) {
555        msgStart = i + 1;
556      } else {
557        msgEnd = i;
558        break;
559      }
560    }
561  }
562
563  if (msgStart == -1) {
564    /* +++ LOG: malformed log message, DYB */
565    for (i = 1; i < buf->len; i++) {
566      /* odd characters in tag? */
567      if ((msg[i] <= ' ') || (msg[i] == ':') || (msg[i] >= 0x7f)) {
568        msg[i] = '\0';
569        msgStart = i + 1;
570        break;
571      }
572    }
573    if (msgStart == -1) {
574      msgStart = buf->len - 1; /* All tag, no message, print truncates */
575    }
576  }
577  if (msgEnd == -1) {
578    /* incoming message not null-terminated; force it */
579    msgEnd = buf->len - 1; /* may result in msgEnd < msgStart */
580    msg[msgEnd] = '\0';
581  }
582
583  entry->priority = msg[0];
584  entry->tag = msg + 1;
585  entry->tagLen = msgStart - 1;
586  entry->message = msg + msgStart;
587  entry->messageLen = (msgEnd < msgStart) ? 0 : (msgEnd - msgStart);
588
589  return 0;
590}
591
592/*
593 * Extract a 4-byte value from a byte stream.
594 */
595static inline uint32_t get4LE(const uint8_t* src) {
596  return src[0] | (src[1] << 8) | (src[2] << 16) | (src[3] << 24);
597}
598
599/*
600 * Extract an 8-byte value from a byte stream.
601 */
602static inline uint64_t get8LE(const uint8_t* src) {
603  uint32_t low, high;
604
605  low = src[0] | (src[1] << 8) | (src[2] << 16) | (src[3] << 24);
606  high = src[4] | (src[5] << 8) | (src[6] << 16) | (src[7] << 24);
607  return ((uint64_t)high << 32) | (uint64_t)low;
608}
609
610static bool findChar(const char** cp, size_t* len, int c) {
611  while ((*len) && isspace(*(*cp))) {
612    ++(*cp);
613    --(*len);
614  }
615  if (c == INT_MAX) return *len;
616  if ((*len) && (*(*cp) == c)) {
617    ++(*cp);
618    --(*len);
619    return true;
620  }
621  return false;
622}
623
624/*
625 * Recursively convert binary log data to printable form.
626 *
627 * This needs to be recursive because you can have lists of lists.
628 *
629 * If we run out of room, we stop processing immediately.  It's important
630 * for us to check for space on every output element to avoid producing
631 * garbled output.
632 *
633 * Returns 0 on success, 1 on buffer full, -1 on failure.
634 */
635enum objectType {
636  TYPE_OBJECTS = '1',
637  TYPE_BYTES = '2',
638  TYPE_MILLISECONDS = '3',
639  TYPE_ALLOCATIONS = '4',
640  TYPE_ID = '5',
641  TYPE_PERCENT = '6',
642  TYPE_MONOTONIC = 's'
643};
644
645static int android_log_printBinaryEvent(const unsigned char** pEventData,
646                                        size_t* pEventDataLen, char** pOutBuf,
647                                        size_t* pOutBufLen, const char** fmtStr,
648                                        size_t* fmtLen) {
649  const unsigned char* eventData = *pEventData;
650  size_t eventDataLen = *pEventDataLen;
651  char* outBuf = *pOutBuf;
652  char* outBufSave = outBuf;
653  size_t outBufLen = *pOutBufLen;
654  size_t outBufLenSave = outBufLen;
655  unsigned char type;
656  size_t outCount = 0;
657  int result = 0;
658  const char* cp;
659  size_t len;
660  int64_t lval;
661
662  if (eventDataLen < 1) return -1;
663
664  type = *eventData++;
665  eventDataLen--;
666
667  cp = NULL;
668  len = 0;
669  if (fmtStr && *fmtStr && fmtLen && *fmtLen && **fmtStr) {
670    cp = *fmtStr;
671    len = *fmtLen;
672  }
673  /*
674   * event.logtag format specification:
675   *
676   * Optionally, after the tag names can be put a description for the value(s)
677   * of the tag. Description are in the format
678   *    (<name>|data type[|data unit])
679   * Multiple values are separated by commas.
680   *
681   * The data type is a number from the following values:
682   * 1: int
683   * 2: long
684   * 3: string
685   * 4: list
686   * 5: float
687   *
688   * The data unit is a number taken from the following list:
689   * 1: Number of objects
690   * 2: Number of bytes
691   * 3: Number of milliseconds
692   * 4: Number of allocations
693   * 5: Id
694   * 6: Percent
695   * s: Number of seconds (monotonic time)
696   * Default value for data of type int/long is 2 (bytes).
697   */
698  if (!cp || !findChar(&cp, &len, '(')) {
699    len = 0;
700  } else {
701    char* outBufLastSpace = NULL;
702
703    findChar(&cp, &len, INT_MAX);
704    while (len && *cp && (*cp != '|') && (*cp != ')')) {
705      if (outBufLen <= 0) {
706        /* halt output */
707        goto no_room;
708      }
709      outBufLastSpace = isspace(*cp) ? outBuf : NULL;
710      *outBuf = *cp;
711      ++outBuf;
712      ++cp;
713      --outBufLen;
714      --len;
715    }
716    if (outBufLastSpace) {
717      outBufLen += outBuf - outBufLastSpace;
718      outBuf = outBufLastSpace;
719    }
720    if (outBufLen <= 0) {
721      /* halt output */
722      goto no_room;
723    }
724    if (outBufSave != outBuf) {
725      *outBuf = '=';
726      ++outBuf;
727      --outBufLen;
728    }
729
730    if (findChar(&cp, &len, '|') && findChar(&cp, &len, INT_MAX)) {
731      static const unsigned char typeTable[] = {
732        EVENT_TYPE_INT, EVENT_TYPE_LONG, EVENT_TYPE_STRING, EVENT_TYPE_LIST,
733        EVENT_TYPE_FLOAT
734      };
735
736      if ((*cp >= '1') &&
737          (*cp < (char)('1' + (sizeof(typeTable) / sizeof(typeTable[0])))) &&
738          (type != typeTable[(size_t)(*cp - '1')]))
739        len = 0;
740
741      if (len) {
742        ++cp;
743        --len;
744      } else {
745        /* reset the format */
746        outBuf = outBufSave;
747        outBufLen = outBufLenSave;
748      }
749    }
750  }
751  outCount = 0;
752  lval = 0;
753  switch (type) {
754    case EVENT_TYPE_INT:
755      /* 32-bit signed int */
756      {
757        int32_t ival;
758
759        if (eventDataLen < 4) return -1;
760        ival = get4LE(eventData);
761        eventData += 4;
762        eventDataLen -= 4;
763
764        lval = ival;
765      }
766      goto pr_lval;
767    case EVENT_TYPE_LONG:
768      /* 64-bit signed long */
769      if (eventDataLen < 8) return -1;
770      lval = get8LE(eventData);
771      eventData += 8;
772      eventDataLen -= 8;
773    pr_lval:
774      outCount = snprintf(outBuf, outBufLen, "%" PRId64, lval);
775      if (outCount < outBufLen) {
776        outBuf += outCount;
777        outBufLen -= outCount;
778      } else {
779        /* halt output */
780        goto no_room;
781      }
782      break;
783    case EVENT_TYPE_FLOAT:
784      /* float */
785      {
786        uint32_t ival;
787        float fval;
788
789        if (eventDataLen < 4) return -1;
790        ival = get4LE(eventData);
791        fval = *(float*)&ival;
792        eventData += 4;
793        eventDataLen -= 4;
794
795        outCount = snprintf(outBuf, outBufLen, "%f", fval);
796        if (outCount < outBufLen) {
797          outBuf += outCount;
798          outBufLen -= outCount;
799        } else {
800          /* halt output */
801          goto no_room;
802        }
803      }
804      break;
805    case EVENT_TYPE_STRING:
806      /* UTF-8 chars, not NULL-terminated */
807      {
808        unsigned int strLen;
809
810        if (eventDataLen < 4) return -1;
811        strLen = get4LE(eventData);
812        eventData += 4;
813        eventDataLen -= 4;
814
815        if (eventDataLen < strLen) {
816          result = -1; /* mark truncated */
817          strLen = eventDataLen;
818        }
819
820        if (cp && (strLen == 0)) {
821          /* reset the format if no content */
822          outBuf = outBufSave;
823          outBufLen = outBufLenSave;
824        }
825        if (strLen < outBufLen) {
826          memcpy(outBuf, eventData, strLen);
827          outBuf += strLen;
828          outBufLen -= strLen;
829        } else {
830          if (outBufLen > 0) {
831            /* copy what we can */
832            memcpy(outBuf, eventData, outBufLen);
833            outBuf += outBufLen;
834            outBufLen -= outBufLen;
835          }
836          if (!result) result = 1; /* if not truncated, return no room */
837        }
838        eventData += strLen;
839        eventDataLen -= strLen;
840        if (result != 0) goto bail;
841        break;
842      }
843    case EVENT_TYPE_LIST:
844      /* N items, all different types */
845      {
846        unsigned char count;
847        int i;
848
849        if (eventDataLen < 1) return -1;
850
851        count = *eventData++;
852        eventDataLen--;
853
854        if (outBufLen <= 0) goto no_room;
855
856        *outBuf++ = '[';
857        outBufLen--;
858
859        for (i = 0; i < count; i++) {
860          result = android_log_printBinaryEvent(
861              &eventData, &eventDataLen, &outBuf, &outBufLen, fmtStr, fmtLen);
862          if (result != 0) goto bail;
863
864          if (i < (count - 1)) {
865            if (outBufLen <= 0) goto no_room;
866            *outBuf++ = ',';
867            outBufLen--;
868          }
869        }
870
871        if (outBufLen <= 0) goto no_room;
872
873        *outBuf++ = ']';
874        outBufLen--;
875      }
876      break;
877    default:
878      fprintf(stderr, "Unknown binary event type %d\n", type);
879      return -1;
880  }
881  if (cp && len) {
882    if (findChar(&cp, &len, '|') && findChar(&cp, &len, INT_MAX)) {
883      switch (*cp) {
884        case TYPE_OBJECTS:
885          outCount = 0;
886          /* outCount = snprintf(outBuf, outBufLen, " objects"); */
887          break;
888        case TYPE_BYTES:
889          if ((lval != 0) && ((lval % 1024) == 0)) {
890            /* repaint with multiplier */
891            static const char suffixTable[] = { 'K', 'M', 'G', 'T' };
892            size_t idx = 0;
893            outBuf -= outCount;
894            outBufLen += outCount;
895            do {
896              lval /= 1024;
897              if ((lval % 1024) != 0) break;
898            } while (++idx <
899                     ((sizeof(suffixTable) / sizeof(suffixTable[0])) - 1));
900            outCount = snprintf(outBuf, outBufLen, "%" PRId64 "%cB", lval,
901                                suffixTable[idx]);
902          } else {
903            outCount = snprintf(outBuf, outBufLen, "B");
904          }
905          break;
906        case TYPE_MILLISECONDS:
907          if (((lval <= -1000) || (1000 <= lval)) &&
908              (outBufLen || (outBuf[-1] == '0'))) {
909            /* repaint as (fractional) seconds, possibly saving space */
910            if (outBufLen) outBuf[0] = outBuf[-1];
911            outBuf[-1] = outBuf[-2];
912            outBuf[-2] = outBuf[-3];
913            outBuf[-3] = '.';
914            while ((outBufLen == 0) || (*outBuf == '0')) {
915              --outBuf;
916              ++outBufLen;
917            }
918            if (*outBuf != '.') {
919              ++outBuf;
920              --outBufLen;
921            }
922            outCount = snprintf(outBuf, outBufLen, "s");
923          } else {
924            outCount = snprintf(outBuf, outBufLen, "ms");
925          }
926          break;
927        case TYPE_MONOTONIC: {
928          static const uint64_t minute = 60;
929          static const uint64_t hour = 60 * minute;
930          static const uint64_t day = 24 * hour;
931
932          /* Repaint as unsigned seconds, minutes, hours ... */
933          outBuf -= outCount;
934          outBufLen += outCount;
935          uint64_t val = lval;
936          if (val >= day) {
937            outCount = snprintf(outBuf, outBufLen, "%" PRIu64 "d ", val / day);
938            if (outCount >= outBufLen) break;
939            outBuf += outCount;
940            outBufLen -= outCount;
941            val = (val % day) + day;
942          }
943          if (val >= minute) {
944            if (val >= hour) {
945              outCount = snprintf(outBuf, outBufLen, "%" PRIu64 ":",
946                                  (val / hour) % (day / hour));
947              if (outCount >= outBufLen) break;
948              outBuf += outCount;
949              outBufLen -= outCount;
950            }
951            outCount =
952                snprintf(outBuf, outBufLen,
953                         (val >= hour) ? "%02" PRIu64 ":" : "%" PRIu64 ":",
954                         (val / minute) % (hour / minute));
955            if (outCount >= outBufLen) break;
956            outBuf += outCount;
957            outBufLen -= outCount;
958          }
959          outCount = snprintf(outBuf, outBufLen,
960                              (val >= minute) ? "%02" PRIu64 : "%" PRIu64 "s",
961                              val % minute);
962        } break;
963        case TYPE_ALLOCATIONS:
964          outCount = 0;
965          /* outCount = snprintf(outBuf, outBufLen, " allocations"); */
966          break;
967        case TYPE_ID:
968          outCount = 0;
969          break;
970        case TYPE_PERCENT:
971          outCount = snprintf(outBuf, outBufLen, "%%");
972          break;
973        default: /* ? */
974          outCount = 0;
975          break;
976      }
977      ++cp;
978      --len;
979      if (outCount < outBufLen) {
980        outBuf += outCount;
981        outBufLen -= outCount;
982      } else if (outCount) {
983        /* halt output */
984        goto no_room;
985      }
986    }
987    if (!findChar(&cp, &len, ')')) len = 0;
988    if (!findChar(&cp, &len, ',')) len = 0;
989  }
990
991bail:
992  *pEventData = eventData;
993  *pEventDataLen = eventDataLen;
994  *pOutBuf = outBuf;
995  *pOutBufLen = outBufLen;
996  if (cp) {
997    *fmtStr = cp;
998    *fmtLen = len;
999  }
1000  return result;
1001
1002no_room:
1003  result = 1;
1004  goto bail;
1005}
1006
1007/**
1008 * Convert a binary log entry to ASCII form.
1009 *
1010 * For convenience we mimic the processLogBuffer API.  There is no
1011 * pre-defined output length for the binary data, since we're free to format
1012 * it however we choose, which means we can't really use a fixed-size buffer
1013 * here.
1014 */
1015LIBLOG_ABI_PUBLIC int android_log_processBinaryLogBuffer(
1016    struct logger_entry* buf, AndroidLogEntry* entry,
1017    const EventTagMap* map __unused, /* only on !__ANDROID__ */
1018    char* messageBuf, int messageBufLen) {
1019  size_t inCount;
1020  uint32_t tagIndex;
1021  const unsigned char* eventData;
1022
1023  entry->message = NULL;
1024  entry->messageLen = 0;
1025
1026  entry->tv_sec = buf->sec;
1027  entry->tv_nsec = buf->nsec;
1028  entry->priority = ANDROID_LOG_INFO;
1029  entry->uid = -1;
1030  entry->pid = buf->pid;
1031  entry->tid = buf->tid;
1032
1033  /*
1034   * Pull the tag out, fill in some additional details based on incoming
1035   * buffer version (v3 adds lid, v4 adds uid).
1036   */
1037  eventData = (const unsigned char*)buf->msg;
1038  struct logger_entry_v2* buf2 = (struct logger_entry_v2*)buf;
1039  if (buf2->hdr_size) {
1040    if ((buf2->hdr_size < sizeof(((struct log_msg*)NULL)->entry_v1)) ||
1041        (buf2->hdr_size > sizeof(((struct log_msg*)NULL)->entry))) {
1042      fprintf(stderr, "+++ LOG: entry illegal hdr_size\n");
1043      return -1;
1044    }
1045    eventData = ((unsigned char*)buf2) + buf2->hdr_size;
1046    if ((buf2->hdr_size >= sizeof(struct logger_entry_v3)) &&
1047        (((struct logger_entry_v3*)buf)->lid == LOG_ID_SECURITY)) {
1048      entry->priority = ANDROID_LOG_WARN;
1049    }
1050    if (buf2->hdr_size >= sizeof(struct logger_entry_v4)) {
1051      entry->uid = ((struct logger_entry_v4*)buf)->uid;
1052    }
1053  }
1054  inCount = buf->len;
1055  if (inCount < 4) return -1;
1056  tagIndex = get4LE(eventData);
1057  eventData += 4;
1058  inCount -= 4;
1059
1060  entry->tagLen = 0;
1061  entry->tag = NULL;
1062#ifdef __ANDROID__
1063  if (map != NULL) {
1064    entry->tag = android_lookupEventTag_len(map, &entry->tagLen, tagIndex);
1065  }
1066#endif
1067
1068  /*
1069   * If we don't have a map, or didn't find the tag number in the map,
1070   * stuff a generated tag value into the start of the output buffer and
1071   * shift the buffer pointers down.
1072   */
1073  if (entry->tag == NULL) {
1074    size_t tagLen;
1075
1076    tagLen = snprintf(messageBuf, messageBufLen, "[%" PRIu32 "]", tagIndex);
1077    if (tagLen >= (size_t)messageBufLen) {
1078      tagLen = messageBufLen - 1;
1079    }
1080    entry->tag = messageBuf;
1081    entry->tagLen = tagLen;
1082    messageBuf += tagLen + 1;
1083    messageBufLen -= tagLen + 1;
1084  }
1085
1086  /*
1087   * Format the event log data into the buffer.
1088   */
1089  const char* fmtStr = NULL;
1090  size_t fmtLen = 0;
1091#ifdef __ANDROID__
1092  if (descriptive_output && map) {
1093    fmtStr = android_lookupEventFormat_len(map, &fmtLen, tagIndex);
1094  }
1095#endif
1096
1097  char* outBuf = messageBuf;
1098  size_t outRemaining = messageBufLen - 1; /* leave one for nul byte */
1099  int result = 0;
1100
1101  if ((inCount > 0) || fmtLen) {
1102    result = android_log_printBinaryEvent(&eventData, &inCount, &outBuf,
1103                                          &outRemaining, &fmtStr, &fmtLen);
1104  }
1105  if ((result == 1) && fmtStr) {
1106    /* We overflowed :-(, let's repaint the line w/o format dressings */
1107    eventData = (const unsigned char*)buf->msg;
1108    if (buf2->hdr_size) {
1109      eventData = ((unsigned char*)buf2) + buf2->hdr_size;
1110    }
1111    eventData += 4;
1112    outBuf = messageBuf;
1113    outRemaining = messageBufLen - 1;
1114    result = android_log_printBinaryEvent(&eventData, &inCount, &outBuf,
1115                                          &outRemaining, NULL, NULL);
1116  }
1117  if (result < 0) {
1118    fprintf(stderr, "Binary log entry conversion failed\n");
1119  }
1120  if (result) {
1121    if (!outRemaining) {
1122      /* make space to leave an indicator */
1123      --outBuf;
1124      ++outRemaining;
1125    }
1126    *outBuf++ = (result < 0) ? '!' : '^'; /* Error or Truncation? */
1127    outRemaining--;
1128    /* pretend we ate all the data to prevent log stutter */
1129    inCount = 0;
1130    if (result > 0) result = 0;
1131  }
1132
1133  /* eat the silly terminating '\n' */
1134  if (inCount == 1 && *eventData == '\n') {
1135    eventData++;
1136    inCount--;
1137  }
1138
1139  if (inCount != 0) {
1140    fprintf(stderr, "Warning: leftover binary log data (%zu bytes)\n", inCount);
1141  }
1142
1143  /*
1144   * Terminate the buffer.  The NUL byte does not count as part of
1145   * entry->messageLen.
1146   */
1147  *outBuf = '\0';
1148  entry->messageLen = outBuf - messageBuf;
1149  assert(entry->messageLen == (messageBufLen - 1) - outRemaining);
1150
1151  entry->message = messageBuf;
1152
1153  return result;
1154}
1155
1156/*
1157 * One utf8 character at a time
1158 *
1159 * Returns the length of the utf8 character in the buffer,
1160 * or -1 if illegal or truncated
1161 *
1162 * Open coded from libutils/Unicode.cpp, borrowed from utf8_length(),
1163 * can not remove from here because of library circular dependencies.
1164 * Expect one-day utf8_character_length with the same signature could
1165 * _also_ be part of libutils/Unicode.cpp if its usefullness needs to
1166 * propagate globally.
1167 */
1168LIBLOG_WEAK ssize_t utf8_character_length(const char* src, size_t len) {
1169  const char* cur = src;
1170  const char first_char = *cur++;
1171  static const uint32_t kUnicodeMaxCodepoint = 0x0010FFFF;
1172  int32_t mask, to_ignore_mask;
1173  size_t num_to_read;
1174  uint32_t utf32;
1175
1176  if ((first_char & 0x80) == 0) { /* ASCII */
1177    return first_char ? 1 : -1;
1178  }
1179
1180  /*
1181   * (UTF-8's character must not be like 10xxxxxx,
1182   *  but 110xxxxx, 1110xxxx, ... or 1111110x)
1183   */
1184  if ((first_char & 0x40) == 0) {
1185    return -1;
1186  }
1187
1188  for (utf32 = 1, num_to_read = 1, mask = 0x40, to_ignore_mask = 0x80;
1189       num_to_read < 5 && (first_char & mask);
1190       num_to_read++, to_ignore_mask |= mask, mask >>= 1) {
1191    if (num_to_read > len) {
1192      return -1;
1193    }
1194    if ((*cur & 0xC0) != 0x80) { /* can not be 10xxxxxx? */
1195      return -1;
1196    }
1197    utf32 = (utf32 << 6) + (*cur++ & 0b00111111);
1198  }
1199  /* "first_char" must be (110xxxxx - 11110xxx) */
1200  if (num_to_read >= 5) {
1201    return -1;
1202  }
1203  to_ignore_mask |= mask;
1204  utf32 |= ((~to_ignore_mask) & first_char) << (6 * (num_to_read - 1));
1205  if (utf32 > kUnicodeMaxCodepoint) {
1206    return -1;
1207  }
1208  return num_to_read;
1209}
1210
1211/*
1212 * Convert to printable from message to p buffer, return string length. If p is
1213 * NULL, do not copy, but still return the expected string length.
1214 */
1215static size_t convertPrintable(char* p, const char* message, size_t messageLen) {
1216  char* begin = p;
1217  bool print = p != NULL;
1218
1219  while (messageLen) {
1220    char buf[6];
1221    ssize_t len = sizeof(buf) - 1;
1222    if ((size_t)len > messageLen) {
1223      len = messageLen;
1224    }
1225    len = utf8_character_length(message, len);
1226
1227    if (len < 0) {
1228      snprintf(buf, sizeof(buf),
1229               ((messageLen > 1) && isdigit(message[1])) ? "\\%03o" : "\\%o",
1230               *message & 0377);
1231      len = 1;
1232    } else {
1233      buf[0] = '\0';
1234      if (len == 1) {
1235        if (*message == '\a') {
1236          strcpy(buf, "\\a");
1237        } else if (*message == '\b') {
1238          strcpy(buf, "\\b");
1239        } else if (*message == '\t') {
1240          strcpy(buf, "\t"); /* Do not escape tabs */
1241        } else if (*message == '\v') {
1242          strcpy(buf, "\\v");
1243        } else if (*message == '\f') {
1244          strcpy(buf, "\\f");
1245        } else if (*message == '\r') {
1246          strcpy(buf, "\\r");
1247        } else if (*message == '\\') {
1248          strcpy(buf, "\\\\");
1249        } else if ((*message < ' ') || (*message & 0x80)) {
1250          snprintf(buf, sizeof(buf), "\\%o", *message & 0377);
1251        }
1252      }
1253      if (!buf[0]) {
1254        strncpy(buf, message, len);
1255        buf[len] = '\0';
1256      }
1257    }
1258    if (print) {
1259      strcpy(p, buf);
1260    }
1261    p += strlen(buf);
1262    message += len;
1263    messageLen -= len;
1264  }
1265  return p - begin;
1266}
1267
1268static char* readSeconds(char* e, struct timespec* t) {
1269  unsigned long multiplier;
1270  char* p;
1271  t->tv_sec = strtoul(e, &p, 10);
1272  if (*p != '.') {
1273    return NULL;
1274  }
1275  t->tv_nsec = 0;
1276  multiplier = NS_PER_SEC;
1277  while (isdigit(*++p) && (multiplier /= 10)) {
1278    t->tv_nsec += (*p - '0') * multiplier;
1279  }
1280  return p;
1281}
1282
1283static struct timespec* sumTimespec(struct timespec* left,
1284                                    struct timespec* right) {
1285  left->tv_nsec += right->tv_nsec;
1286  left->tv_sec += right->tv_sec;
1287  if (left->tv_nsec >= (long)NS_PER_SEC) {
1288    left->tv_nsec -= NS_PER_SEC;
1289    left->tv_sec += 1;
1290  }
1291  return left;
1292}
1293
1294static struct timespec* subTimespec(struct timespec* result,
1295                                    struct timespec* left,
1296                                    struct timespec* right) {
1297  result->tv_nsec = left->tv_nsec - right->tv_nsec;
1298  result->tv_sec = left->tv_sec - right->tv_sec;
1299  if (result->tv_nsec < 0) {
1300    result->tv_nsec += NS_PER_SEC;
1301    result->tv_sec -= 1;
1302  }
1303  return result;
1304}
1305
1306static long long nsecTimespec(struct timespec* now) {
1307  return (long long)now->tv_sec * NS_PER_SEC + now->tv_nsec;
1308}
1309
1310#ifdef __ANDROID__
1311static void convertMonotonic(struct timespec* result,
1312                             const AndroidLogEntry* entry) {
1313  struct listnode* node;
1314  struct conversionList {
1315    struct listnode node; /* first */
1316    struct timespec time;
1317    struct timespec convert;
1318  } * list, *next;
1319  struct timespec time, convert;
1320
1321  /* If we do not have a conversion list, build one up */
1322  if (list_empty(&convertHead)) {
1323    bool suspended_pending = false;
1324    struct timespec suspended_monotonic = { 0, 0 };
1325    struct timespec suspended_diff = { 0, 0 };
1326
1327    /*
1328     * Read dmesg for _some_ synchronization markers and insert
1329     * Anything in the Android Logger before the dmesg logging span will
1330     * be highly suspect regarding the monotonic time calculations.
1331     */
1332    FILE* p = popen("/system/bin/dmesg", "re");
1333    if (p) {
1334      char* line = NULL;
1335      size_t len = 0;
1336      while (getline(&line, &len, p) > 0) {
1337        static const char suspend[] = "PM: suspend entry ";
1338        static const char resume[] = "PM: suspend exit ";
1339        static const char healthd[] = "healthd";
1340        static const char battery[] = ": battery ";
1341        static const char suspended[] = "Suspended for ";
1342        struct timespec monotonic;
1343        struct tm tm;
1344        char *cp, *e = line;
1345        bool add_entry = true;
1346
1347        if (*e == '<') {
1348          while (*e && (*e != '>')) {
1349            ++e;
1350          }
1351          if (*e != '>') {
1352            continue;
1353          }
1354        }
1355        if (*e != '[') {
1356          continue;
1357        }
1358        while (*++e == ' ') {
1359          ;
1360        }
1361        e = readSeconds(e, &monotonic);
1362        if (!e || (*e != ']')) {
1363          continue;
1364        }
1365
1366        if ((e = strstr(e, suspend))) {
1367          e += sizeof(suspend) - 1;
1368        } else if ((e = strstr(line, resume))) {
1369          e += sizeof(resume) - 1;
1370        } else if (((e = strstr(line, healthd))) &&
1371                   ((e = strstr(e + sizeof(healthd) - 1, battery)))) {
1372          /* NB: healthd is roughly 150us late, worth the price to
1373           * deal with ntp-induced or hardware clock drift. */
1374          e += sizeof(battery) - 1;
1375        } else if ((e = strstr(line, suspended))) {
1376          e += sizeof(suspended) - 1;
1377          e = readSeconds(e, &time);
1378          if (!e) {
1379            continue;
1380          }
1381          add_entry = false;
1382          suspended_pending = true;
1383          suspended_monotonic = monotonic;
1384          suspended_diff = time;
1385        } else {
1386          continue;
1387        }
1388        if (add_entry) {
1389          /* look for "????-??-?? ??:??:??.????????? UTC" */
1390          cp = strstr(e, " UTC");
1391          if (!cp || ((cp - e) < 29) || (cp[-10] != '.')) {
1392            continue;
1393          }
1394          e = cp - 29;
1395          cp = readSeconds(cp - 10, &time);
1396          if (!cp) {
1397            continue;
1398          }
1399          cp = strptime(e, "%Y-%m-%d %H:%M:%S.", &tm);
1400          if (!cp) {
1401            continue;
1402          }
1403          cp = getenv(tz);
1404          if (cp) {
1405            cp = strdup(cp);
1406          }
1407          setenv(tz, utc, 1);
1408          time.tv_sec = mktime(&tm);
1409          if (cp) {
1410            setenv(tz, cp, 1);
1411            free(cp);
1412          } else {
1413            unsetenv(tz);
1414          }
1415          list = calloc(1, sizeof(struct conversionList));
1416          list_init(&list->node);
1417          list->time = time;
1418          subTimespec(&list->convert, &time, &monotonic);
1419          list_add_tail(&convertHead, &list->node);
1420        }
1421        if (suspended_pending && !list_empty(&convertHead)) {
1422          list = node_to_item(list_tail(&convertHead), struct conversionList,
1423                              node);
1424          if (subTimespec(&time, subTimespec(&time, &list->time, &list->convert),
1425                          &suspended_monotonic)
1426                  ->tv_sec > 0) {
1427            /* resume, what is convert factor before? */
1428            subTimespec(&convert, &list->convert, &suspended_diff);
1429          } else {
1430            /* suspend */
1431            convert = list->convert;
1432          }
1433          time = suspended_monotonic;
1434          sumTimespec(&time, &convert);
1435          /* breakpoint just before sleep */
1436          list = calloc(1, sizeof(struct conversionList));
1437          list_init(&list->node);
1438          list->time = time;
1439          list->convert = convert;
1440          list_add_tail(&convertHead, &list->node);
1441          /* breakpoint just after sleep */
1442          list = calloc(1, sizeof(struct conversionList));
1443          list_init(&list->node);
1444          list->time = time;
1445          sumTimespec(&list->time, &suspended_diff);
1446          list->convert = convert;
1447          sumTimespec(&list->convert, &suspended_diff);
1448          list_add_tail(&convertHead, &list->node);
1449          suspended_pending = false;
1450        }
1451      }
1452      pclose(p);
1453    }
1454    /* last entry is our current time conversion */
1455    list = calloc(1, sizeof(struct conversionList));
1456    list_init(&list->node);
1457    clock_gettime(CLOCK_REALTIME, &list->time);
1458    clock_gettime(CLOCK_MONOTONIC, &convert);
1459    clock_gettime(CLOCK_MONOTONIC, &time);
1460    /* Correct for instant clock_gettime latency (syscall or ~30ns) */
1461    subTimespec(&time, &convert, subTimespec(&time, &time, &convert));
1462    /* Calculate conversion factor */
1463    subTimespec(&list->convert, &list->time, &time);
1464    list_add_tail(&convertHead, &list->node);
1465    if (suspended_pending) {
1466      /* manufacture a suspend @ point before */
1467      subTimespec(&convert, &list->convert, &suspended_diff);
1468      time = suspended_monotonic;
1469      sumTimespec(&time, &convert);
1470      /* breakpoint just after sleep */
1471      list = calloc(1, sizeof(struct conversionList));
1472      list_init(&list->node);
1473      list->time = time;
1474      sumTimespec(&list->time, &suspended_diff);
1475      list->convert = convert;
1476      sumTimespec(&list->convert, &suspended_diff);
1477      list_add_head(&convertHead, &list->node);
1478      /* breakpoint just before sleep */
1479      list = calloc(1, sizeof(struct conversionList));
1480      list_init(&list->node);
1481      list->time = time;
1482      list->convert = convert;
1483      list_add_head(&convertHead, &list->node);
1484    }
1485  }
1486
1487  /* Find the breakpoint in the conversion list */
1488  list = node_to_item(list_head(&convertHead), struct conversionList, node);
1489  next = NULL;
1490  list_for_each(node, &convertHead) {
1491    next = node_to_item(node, struct conversionList, node);
1492    if (entry->tv_sec < next->time.tv_sec) {
1493      break;
1494    } else if (entry->tv_sec == next->time.tv_sec) {
1495      if (entry->tv_nsec < next->time.tv_nsec) {
1496        break;
1497      }
1498    }
1499    list = next;
1500  }
1501
1502  /* blend time from one breakpoint to the next */
1503  convert = list->convert;
1504  if (next) {
1505    unsigned long long total, run;
1506
1507    total = nsecTimespec(subTimespec(&time, &next->time, &list->time));
1508    time.tv_sec = entry->tv_sec;
1509    time.tv_nsec = entry->tv_nsec;
1510    run = nsecTimespec(subTimespec(&time, &time, &list->time));
1511    if (run < total) {
1512      long long crun;
1513
1514      float f = nsecTimespec(subTimespec(&time, &next->convert, &convert));
1515      f *= run;
1516      f /= total;
1517      crun = f;
1518      convert.tv_sec += crun / (long long)NS_PER_SEC;
1519      if (crun < 0) {
1520        convert.tv_nsec -= (-crun) % NS_PER_SEC;
1521        if (convert.tv_nsec < 0) {
1522          convert.tv_nsec += NS_PER_SEC;
1523          convert.tv_sec -= 1;
1524        }
1525      } else {
1526        convert.tv_nsec += crun % NS_PER_SEC;
1527        if (convert.tv_nsec >= (long)NS_PER_SEC) {
1528          convert.tv_nsec -= NS_PER_SEC;
1529          convert.tv_sec += 1;
1530        }
1531      }
1532    }
1533  }
1534
1535  /* Apply the correction factor */
1536  result->tv_sec = entry->tv_sec;
1537  result->tv_nsec = entry->tv_nsec;
1538  subTimespec(result, result, &convert);
1539}
1540#endif
1541
1542/**
1543 * Formats a log message into a buffer
1544 *
1545 * Uses defaultBuffer if it can, otherwise malloc()'s a new buffer
1546 * If return value != defaultBuffer, caller must call free()
1547 * Returns NULL on malloc error
1548 */
1549
1550LIBLOG_ABI_PUBLIC char* android_log_formatLogLine(AndroidLogFormat* p_format,
1551                                                  char* defaultBuffer,
1552                                                  size_t defaultBufferSize,
1553                                                  const AndroidLogEntry* entry,
1554                                                  size_t* p_outLength) {
1555#if !defined(_WIN32)
1556  struct tm tmBuf;
1557#endif
1558  struct tm* ptm;
1559  /* good margin, 23+nul for msec, 26+nul for usec, 29+nul to nsec */
1560  char timeBuf[64];
1561  char prefixBuf[128], suffixBuf[128];
1562  char priChar;
1563  int prefixSuffixIsHeaderFooter = 0;
1564  char* ret;
1565  time_t now;
1566  unsigned long nsec;
1567
1568  priChar = filterPriToChar(entry->priority);
1569  size_t prefixLen = 0, suffixLen = 0;
1570  size_t len;
1571
1572  /*
1573   * Get the current date/time in pretty form
1574   *
1575   * It's often useful when examining a log with "less" to jump to
1576   * a specific point in the file by searching for the date/time stamp.
1577   * For this reason it's very annoying to have regexp meta characters
1578   * in the time stamp.  Don't use forward slashes, parenthesis,
1579   * brackets, asterisks, or other special chars here.
1580   *
1581   * The caller may have affected the timezone environment, this is
1582   * expected to be sensitive to that.
1583   */
1584  now = entry->tv_sec;
1585  nsec = entry->tv_nsec;
1586#if __ANDROID__
1587  if (p_format->monotonic_output) {
1588    /* prevent convertMonotonic from being called if logd is monotonic */
1589    if (android_log_clockid() != CLOCK_MONOTONIC) {
1590      struct timespec time;
1591      convertMonotonic(&time, entry);
1592      now = time.tv_sec;
1593      nsec = time.tv_nsec;
1594    }
1595  }
1596#endif
1597  if (now < 0) {
1598    nsec = NS_PER_SEC - nsec;
1599  }
1600  if (p_format->epoch_output || p_format->monotonic_output) {
1601    ptm = NULL;
1602    snprintf(timeBuf, sizeof(timeBuf),
1603             p_format->monotonic_output ? "%6lld" : "%19lld", (long long)now);
1604  } else {
1605#if !defined(_WIN32)
1606    ptm = localtime_r(&now, &tmBuf);
1607#else
1608    ptm = localtime(&now);
1609#endif
1610    strftime(timeBuf, sizeof(timeBuf),
1611             &"%Y-%m-%d %H:%M:%S"[p_format->year_output ? 0 : 3], ptm);
1612  }
1613  len = strlen(timeBuf);
1614  if (p_format->nsec_time_output) {
1615    len += snprintf(timeBuf + len, sizeof(timeBuf) - len, ".%09ld", nsec);
1616  } else if (p_format->usec_time_output) {
1617    len += snprintf(timeBuf + len, sizeof(timeBuf) - len, ".%06ld",
1618                    nsec / US_PER_NSEC);
1619  } else {
1620    len += snprintf(timeBuf + len, sizeof(timeBuf) - len, ".%03ld",
1621                    nsec / MS_PER_NSEC);
1622  }
1623  if (p_format->zone_output && ptm) {
1624    strftime(timeBuf + len, sizeof(timeBuf) - len, " %z", ptm);
1625  }
1626
1627  /*
1628   * Construct a buffer containing the log header and log message.
1629   */
1630  if (p_format->colored_output) {
1631    prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "\x1B[38;5;%dm",
1632                         colorFromPri(entry->priority));
1633    prefixLen = MIN(prefixLen, sizeof(prefixBuf));
1634    suffixLen = snprintf(suffixBuf, sizeof(suffixBuf), "\x1B[0m");
1635    suffixLen = MIN(suffixLen, sizeof(suffixBuf));
1636  }
1637
1638  char uid[16];
1639  uid[0] = '\0';
1640  if (p_format->uid_output) {
1641    if (entry->uid >= 0) {
1642/*
1643 * This code is Android specific, bionic guarantees that
1644 * calls to non-reentrant getpwuid() are thread safe.
1645 */
1646#if !defined(__MINGW32__)
1647#if (FAKE_LOG_DEVICE == 0)
1648#ifndef __BIONIC__
1649#warning \
1650    "This code assumes that getpwuid is thread safe, only true with Bionic!"
1651#endif
1652#endif
1653      struct passwd* pwd = getpwuid(entry->uid);
1654      if (pwd && (strlen(pwd->pw_name) <= 5)) {
1655        snprintf(uid, sizeof(uid), "%5s:", pwd->pw_name);
1656      } else
1657#endif
1658      {
1659        /* Not worth parsing package list, names all longer than 5 */
1660        snprintf(uid, sizeof(uid), "%5d:", entry->uid);
1661      }
1662    } else {
1663      snprintf(uid, sizeof(uid), "      ");
1664    }
1665  }
1666
1667  switch (p_format->format) {
1668    case FORMAT_TAG:
1669      len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen,
1670                     "%c/%-8.*s: ", priChar, (int)entry->tagLen, entry->tag);
1671      strcpy(suffixBuf + suffixLen, "\n");
1672      ++suffixLen;
1673      break;
1674    case FORMAT_PROCESS:
1675      len = snprintf(suffixBuf + suffixLen, sizeof(suffixBuf) - suffixLen,
1676                     "  (%.*s)\n", (int)entry->tagLen, entry->tag);
1677      suffixLen += MIN(len, sizeof(suffixBuf) - suffixLen);
1678      len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen,
1679                     "%c(%s%5d) ", priChar, uid, entry->pid);
1680      break;
1681    case FORMAT_THREAD:
1682      len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen,
1683                     "%c(%s%5d:%5d) ", priChar, uid, entry->pid, entry->tid);
1684      strcpy(suffixBuf + suffixLen, "\n");
1685      ++suffixLen;
1686      break;
1687    case FORMAT_RAW:
1688      prefixBuf[prefixLen] = 0;
1689      len = 0;
1690      strcpy(suffixBuf + suffixLen, "\n");
1691      ++suffixLen;
1692      break;
1693    case FORMAT_TIME:
1694      len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen,
1695                     "%s %c/%-8.*s(%s%5d): ", timeBuf, priChar,
1696                     (int)entry->tagLen, entry->tag, uid, entry->pid);
1697      strcpy(suffixBuf + suffixLen, "\n");
1698      ++suffixLen;
1699      break;
1700    case FORMAT_THREADTIME:
1701      ret = strchr(uid, ':');
1702      if (ret) {
1703        *ret = ' ';
1704      }
1705      len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen,
1706                     "%s %s%5d %5d %c %-8.*s: ", timeBuf, uid, entry->pid,
1707                     entry->tid, priChar, (int)entry->tagLen, entry->tag);
1708      strcpy(suffixBuf + suffixLen, "\n");
1709      ++suffixLen;
1710      break;
1711    case FORMAT_LONG:
1712      len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen,
1713                     "[ %s %s%5d:%5d %c/%-8.*s ]\n", timeBuf, uid, entry->pid,
1714                     entry->tid, priChar, (int)entry->tagLen, entry->tag);
1715      strcpy(suffixBuf + suffixLen, "\n\n");
1716      suffixLen += 2;
1717      prefixSuffixIsHeaderFooter = 1;
1718      break;
1719    case FORMAT_BRIEF:
1720    default:
1721      len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen,
1722                     "%c/%-8.*s(%s%5d): ", priChar, (int)entry->tagLen,
1723                     entry->tag, uid, entry->pid);
1724      strcpy(suffixBuf + suffixLen, "\n");
1725      ++suffixLen;
1726      break;
1727  }
1728
1729  /* snprintf has a weird return value.   It returns what would have been
1730   * written given a large enough buffer.  In the case that the prefix is
1731   * longer then our buffer(128), it messes up the calculations below
1732   * possibly causing heap corruption.  To avoid this we double check and
1733   * set the length at the maximum (size minus null byte)
1734   */
1735  prefixLen += len;
1736  if (prefixLen >= sizeof(prefixBuf)) {
1737    prefixLen = sizeof(prefixBuf) - 1;
1738    prefixBuf[sizeof(prefixBuf) - 1] = '\0';
1739  }
1740  if (suffixLen >= sizeof(suffixBuf)) {
1741    suffixLen = sizeof(suffixBuf) - 1;
1742    suffixBuf[sizeof(suffixBuf) - 2] = '\n';
1743    suffixBuf[sizeof(suffixBuf) - 1] = '\0';
1744  }
1745
1746  /* the following code is tragically unreadable */
1747
1748  size_t numLines;
1749  char* p;
1750  size_t bufferSize;
1751  const char* pm;
1752
1753  if (prefixSuffixIsHeaderFooter) {
1754    /* we're just wrapping message with a header/footer */
1755    numLines = 1;
1756  } else {
1757    pm = entry->message;
1758    numLines = 0;
1759
1760    /*
1761     * The line-end finding here must match the line-end finding
1762     * in for ( ... numLines...) loop below
1763     */
1764    while (pm < (entry->message + entry->messageLen)) {
1765      if (*pm++ == '\n') numLines++;
1766    }
1767    /* plus one line for anything not newline-terminated at the end */
1768    if (pm > entry->message && *(pm - 1) != '\n') numLines++;
1769  }
1770
1771  /*
1772   * this is an upper bound--newlines in message may be counted
1773   * extraneously
1774   */
1775  bufferSize = (numLines * (prefixLen + suffixLen)) + 1;
1776  if (p_format->printable_output) {
1777    /* Calculate extra length to convert non-printable to printable */
1778    bufferSize += convertPrintable(NULL, entry->message, entry->messageLen);
1779  } else {
1780    bufferSize += entry->messageLen;
1781  }
1782
1783  if (defaultBufferSize >= bufferSize) {
1784    ret = defaultBuffer;
1785  } else {
1786    ret = (char*)malloc(bufferSize);
1787
1788    if (ret == NULL) {
1789      return ret;
1790    }
1791  }
1792
1793  ret[0] = '\0'; /* to start strcat off */
1794
1795  p = ret;
1796  pm = entry->message;
1797
1798  if (prefixSuffixIsHeaderFooter) {
1799    strcat(p, prefixBuf);
1800    p += prefixLen;
1801    if (p_format->printable_output) {
1802      p += convertPrintable(p, entry->message, entry->messageLen);
1803    } else {
1804      strncat(p, entry->message, entry->messageLen);
1805      p += entry->messageLen;
1806    }
1807    strcat(p, suffixBuf);
1808    p += suffixLen;
1809  } else {
1810    do {
1811      const char* lineStart;
1812      size_t lineLen;
1813      lineStart = pm;
1814
1815      /* Find the next end-of-line in message */
1816      while (pm < (entry->message + entry->messageLen) && *pm != '\n') pm++;
1817      lineLen = pm - lineStart;
1818
1819      strcat(p, prefixBuf);
1820      p += prefixLen;
1821      if (p_format->printable_output) {
1822        p += convertPrintable(p, lineStart, lineLen);
1823      } else {
1824        strncat(p, lineStart, lineLen);
1825        p += lineLen;
1826      }
1827      strcat(p, suffixBuf);
1828      p += suffixLen;
1829
1830      if (*pm == '\n') pm++;
1831    } while (pm < (entry->message + entry->messageLen));
1832  }
1833
1834  if (p_outLength != NULL) {
1835    *p_outLength = p - ret;
1836  }
1837
1838  return ret;
1839}
1840
1841/**
1842 * Either print or do not print log line, based on filter
1843 *
1844 * Returns count bytes written
1845 */
1846
1847LIBLOG_ABI_PUBLIC int android_log_printLogLine(AndroidLogFormat* p_format,
1848                                               int fd,
1849                                               const AndroidLogEntry* entry) {
1850  int ret;
1851  char defaultBuffer[512];
1852  char* outBuffer = NULL;
1853  size_t totalLen;
1854
1855  outBuffer = android_log_formatLogLine(
1856      p_format, defaultBuffer, sizeof(defaultBuffer), entry, &totalLen);
1857
1858  if (!outBuffer) return -1;
1859
1860  do {
1861    ret = write(fd, outBuffer, totalLen);
1862  } while (ret < 0 && errno == EINTR);
1863
1864  if (ret < 0) {
1865    fprintf(stderr, "+++ LOG: write failed (errno=%d)\n", errno);
1866    ret = 0;
1867    goto done;
1868  }
1869
1870  if (((size_t)ret) < totalLen) {
1871    fprintf(stderr, "+++ LOG: write partial (%d of %d)\n", ret, (int)totalLen);
1872    goto done;
1873  }
1874
1875done:
1876  if (outBuffer != defaultBuffer) {
1877    free(outBuffer);
1878  }
1879
1880  return ret;
1881}
1882