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