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