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