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