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