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