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