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