| /* |
| ** |
| ** Copyright 2006-2014, The Android Open Source Project |
| ** |
| ** Licensed under the Apache License, Version 2.0 (the "License"); |
| ** you may not use this file except in compliance with the License. |
| ** You may obtain a copy of the License at |
| ** |
| ** http://www.apache.org/licenses/LICENSE-2.0 |
| ** |
| ** Unless required by applicable law or agreed to in writing, software |
| ** distributed under the License is distributed on an "AS IS" BASIS, |
| ** WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
| ** See the License for the specific language governing permissions and |
| ** limitations under the License. |
| */ |
| |
| #define _GNU_SOURCE /* for asprintf */ |
| #ifndef __MINGW32__ |
| #define HAVE_STRSEP |
| #endif |
| |
| #include <assert.h> |
| #include <ctype.h> |
| #include <errno.h> |
| #include <inttypes.h> |
| #ifndef __MINGW32__ |
| #include <pwd.h> |
| #endif |
| #include <stdbool.h> |
| #include <stdint.h> |
| #include <stdio.h> |
| #include <stdlib.h> |
| #include <string.h> |
| #include <sys/param.h> |
| #include <sys/types.h> |
| |
| #include <cutils/list.h> |
| #include <log/log.h> |
| #include <log/logprint.h> |
| |
| #include "log_portability.h" |
| |
| #define MS_PER_NSEC 1000000 |
| #define US_PER_NSEC 1000 |
| |
| #ifndef MIN |
| #define MIN(a, b) (((a) < (b)) ? (a) : (b)) |
| #endif |
| |
| typedef struct FilterInfo_t { |
| char* mTag; |
| android_LogPriority mPri; |
| struct FilterInfo_t* p_next; |
| } FilterInfo; |
| |
| struct AndroidLogFormat_t { |
| android_LogPriority global_pri; |
| FilterInfo* filters; |
| AndroidLogPrintFormat format; |
| bool colored_output; |
| bool usec_time_output; |
| bool nsec_time_output; |
| bool printable_output; |
| bool year_output; |
| bool zone_output; |
| bool epoch_output; |
| bool monotonic_output; |
| bool uid_output; |
| bool descriptive_output; |
| }; |
| |
| /* |
| * API issues prevent us from exposing "descriptive" in AndroidLogFormat_t |
| * during android_log_processBinaryLogBuffer(), so we break layering. |
| */ |
| static bool descriptive_output = false; |
| |
| /* |
| * gnome-terminal color tags |
| * See http://misc.flogisoft.com/bash/tip_colors_and_formatting |
| * for ideas on how to set the forground color of the text for xterm. |
| * The color manipulation character stream is defined as: |
| * ESC [ 3 8 ; 5 ; <color#> m |
| */ |
| #define ANDROID_COLOR_BLUE 75 |
| #define ANDROID_COLOR_DEFAULT 231 |
| #define ANDROID_COLOR_GREEN 40 |
| #define ANDROID_COLOR_ORANGE 166 |
| #define ANDROID_COLOR_RED 196 |
| #define ANDROID_COLOR_YELLOW 226 |
| |
| static FilterInfo* filterinfo_new(const char* tag, android_LogPriority pri) { |
| FilterInfo* p_ret; |
| |
| p_ret = (FilterInfo*)calloc(1, sizeof(FilterInfo)); |
| p_ret->mTag = strdup(tag); |
| p_ret->mPri = pri; |
| |
| return p_ret; |
| } |
| |
| /* balance to above, filterinfo_free left unimplemented */ |
| |
| /* |
| * Note: also accepts 0-9 priorities |
| * returns ANDROID_LOG_UNKNOWN if the character is unrecognized |
| */ |
| static android_LogPriority filterCharToPri(char c) { |
| android_LogPriority pri; |
| |
| c = tolower(c); |
| |
| if (c >= '0' && c <= '9') { |
| if (c >= ('0' + ANDROID_LOG_SILENT)) { |
| pri = ANDROID_LOG_VERBOSE; |
| } else { |
| pri = (android_LogPriority)(c - '0'); |
| } |
| } else if (c == 'v') { |
| pri = ANDROID_LOG_VERBOSE; |
| } else if (c == 'd') { |
| pri = ANDROID_LOG_DEBUG; |
| } else if (c == 'i') { |
| pri = ANDROID_LOG_INFO; |
| } else if (c == 'w') { |
| pri = ANDROID_LOG_WARN; |
| } else if (c == 'e') { |
| pri = ANDROID_LOG_ERROR; |
| } else if (c == 'f') { |
| pri = ANDROID_LOG_FATAL; |
| } else if (c == 's') { |
| pri = ANDROID_LOG_SILENT; |
| } else if (c == '*') { |
| pri = ANDROID_LOG_DEFAULT; |
| } else { |
| pri = ANDROID_LOG_UNKNOWN; |
| } |
| |
| return pri; |
| } |
| |
| static char filterPriToChar(android_LogPriority pri) { |
| switch (pri) { |
| /* clang-format off */ |
| case ANDROID_LOG_VERBOSE: return 'V'; |
| case ANDROID_LOG_DEBUG: return 'D'; |
| case ANDROID_LOG_INFO: return 'I'; |
| case ANDROID_LOG_WARN: return 'W'; |
| case ANDROID_LOG_ERROR: return 'E'; |
| case ANDROID_LOG_FATAL: return 'F'; |
| case ANDROID_LOG_SILENT: return 'S'; |
| |
| case ANDROID_LOG_DEFAULT: |
| case ANDROID_LOG_UNKNOWN: |
| default: return '?'; |
| /* clang-format on */ |
| } |
| } |
| |
| static int colorFromPri(android_LogPriority pri) { |
| switch (pri) { |
| /* clang-format off */ |
| case ANDROID_LOG_VERBOSE: return ANDROID_COLOR_DEFAULT; |
| case ANDROID_LOG_DEBUG: return ANDROID_COLOR_BLUE; |
| case ANDROID_LOG_INFO: return ANDROID_COLOR_GREEN; |
| case ANDROID_LOG_WARN: return ANDROID_COLOR_ORANGE; |
| case ANDROID_LOG_ERROR: return ANDROID_COLOR_RED; |
| case ANDROID_LOG_FATAL: return ANDROID_COLOR_RED; |
| case ANDROID_LOG_SILENT: return ANDROID_COLOR_DEFAULT; |
| |
| case ANDROID_LOG_DEFAULT: |
| case ANDROID_LOG_UNKNOWN: |
| default: return ANDROID_COLOR_DEFAULT; |
| /* clang-format on */ |
| } |
| } |
| |
| static android_LogPriority filterPriForTag(AndroidLogFormat* p_format, |
| const char* tag) { |
| FilterInfo* p_curFilter; |
| |
| for (p_curFilter = p_format->filters; p_curFilter != NULL; |
| p_curFilter = p_curFilter->p_next) { |
| if (0 == strcmp(tag, p_curFilter->mTag)) { |
| if (p_curFilter->mPri == ANDROID_LOG_DEFAULT) { |
| return p_format->global_pri; |
| } else { |
| return p_curFilter->mPri; |
| } |
| } |
| } |
| |
| return p_format->global_pri; |
| } |
| |
| /** |
| * returns 1 if this log line should be printed based on its priority |
| * and tag, and 0 if it should not |
| */ |
| LIBLOG_ABI_PUBLIC int android_log_shouldPrintLine(AndroidLogFormat* p_format, |
| const char* tag, |
| android_LogPriority pri) { |
| return pri >= filterPriForTag(p_format, tag); |
| } |
| |
| LIBLOG_ABI_PUBLIC AndroidLogFormat* android_log_format_new() { |
| AndroidLogFormat* p_ret; |
| |
| p_ret = calloc(1, sizeof(AndroidLogFormat)); |
| |
| p_ret->global_pri = ANDROID_LOG_VERBOSE; |
| p_ret->format = FORMAT_BRIEF; |
| p_ret->colored_output = false; |
| p_ret->usec_time_output = false; |
| p_ret->nsec_time_output = false; |
| p_ret->printable_output = false; |
| p_ret->year_output = false; |
| p_ret->zone_output = false; |
| p_ret->epoch_output = false; |
| #ifdef __ANDROID__ |
| p_ret->monotonic_output = android_log_clockid() == CLOCK_MONOTONIC; |
| #else |
| p_ret->monotonic_output = false; |
| #endif |
| p_ret->uid_output = false; |
| p_ret->descriptive_output = false; |
| descriptive_output = false; |
| |
| return p_ret; |
| } |
| |
| static list_declare(convertHead); |
| |
| LIBLOG_ABI_PUBLIC void android_log_format_free(AndroidLogFormat* p_format) { |
| FilterInfo *p_info, *p_info_old; |
| |
| p_info = p_format->filters; |
| |
| while (p_info != NULL) { |
| p_info_old = p_info; |
| p_info = p_info->p_next; |
| |
| free(p_info_old); |
| } |
| |
| free(p_format); |
| |
| /* Free conversion resource, can always be reconstructed */ |
| while (!list_empty(&convertHead)) { |
| struct listnode* node = list_head(&convertHead); |
| list_remove(node); |
| free(node); |
| } |
| } |
| |
| LIBLOG_ABI_PUBLIC int android_log_setPrintFormat(AndroidLogFormat* p_format, |
| AndroidLogPrintFormat format) { |
| switch (format) { |
| case FORMAT_MODIFIER_COLOR: |
| p_format->colored_output = true; |
| return 0; |
| case FORMAT_MODIFIER_TIME_USEC: |
| p_format->usec_time_output = true; |
| return 0; |
| case FORMAT_MODIFIER_TIME_NSEC: |
| p_format->nsec_time_output = true; |
| return 0; |
| case FORMAT_MODIFIER_PRINTABLE: |
| p_format->printable_output = true; |
| return 0; |
| case FORMAT_MODIFIER_YEAR: |
| p_format->year_output = true; |
| return 0; |
| case FORMAT_MODIFIER_ZONE: |
| p_format->zone_output = !p_format->zone_output; |
| return 0; |
| case FORMAT_MODIFIER_EPOCH: |
| p_format->epoch_output = true; |
| return 0; |
| case FORMAT_MODIFIER_MONOTONIC: |
| p_format->monotonic_output = true; |
| return 0; |
| case FORMAT_MODIFIER_UID: |
| p_format->uid_output = true; |
| return 0; |
| case FORMAT_MODIFIER_DESCRIPT: |
| p_format->descriptive_output = true; |
| descriptive_output = true; |
| return 0; |
| default: |
| break; |
| } |
| p_format->format = format; |
| return 1; |
| } |
| |
| static const char tz[] = "TZ"; |
| static const char utc[] = "UTC"; |
| |
| /** |
| * Returns FORMAT_OFF on invalid string |
| */ |
| LIBLOG_ABI_PUBLIC AndroidLogPrintFormat |
| android_log_formatFromString(const char* formatString) { |
| static AndroidLogPrintFormat format; |
| |
| /* clang-format off */ |
| if (!strcmp(formatString, "brief")) format = FORMAT_BRIEF; |
| else if (!strcmp(formatString, "process")) format = FORMAT_PROCESS; |
| else if (!strcmp(formatString, "tag")) format = FORMAT_TAG; |
| else if (!strcmp(formatString, "thread")) format = FORMAT_THREAD; |
| else if (!strcmp(formatString, "raw")) format = FORMAT_RAW; |
| else if (!strcmp(formatString, "time")) format = FORMAT_TIME; |
| else if (!strcmp(formatString, "threadtime")) format = FORMAT_THREADTIME; |
| else if (!strcmp(formatString, "long")) format = FORMAT_LONG; |
| else if (!strcmp(formatString, "color")) format = FORMAT_MODIFIER_COLOR; |
| else if (!strcmp(formatString, "colour")) format = FORMAT_MODIFIER_COLOR; |
| else if (!strcmp(formatString, "usec")) format = FORMAT_MODIFIER_TIME_USEC; |
| else if (!strcmp(formatString, "nsec")) format = FORMAT_MODIFIER_TIME_NSEC; |
| else if (!strcmp(formatString, "printable")) format = FORMAT_MODIFIER_PRINTABLE; |
| else if (!strcmp(formatString, "year")) format = FORMAT_MODIFIER_YEAR; |
| else if (!strcmp(formatString, "zone")) format = FORMAT_MODIFIER_ZONE; |
| else if (!strcmp(formatString, "epoch")) format = FORMAT_MODIFIER_EPOCH; |
| else if (!strcmp(formatString, "monotonic")) format = FORMAT_MODIFIER_MONOTONIC; |
| else if (!strcmp(formatString, "uid")) format = FORMAT_MODIFIER_UID; |
| else if (!strcmp(formatString, "descriptive")) format = FORMAT_MODIFIER_DESCRIPT; |
| /* clang-format on */ |
| |
| #ifndef __MINGW32__ |
| else { |
| extern char* tzname[2]; |
| static const char gmt[] = "GMT"; |
| char* cp = getenv(tz); |
| if (cp) { |
| cp = strdup(cp); |
| } |
| setenv(tz, formatString, 1); |
| /* |
| * Run tzset here to determine if the timezone is legitimate. If the |
| * zone is GMT, check if that is what was asked for, if not then |
| * did not match any on the system; report an error to caller. |
| */ |
| tzset(); |
| if (!tzname[0] || |
| ((!strcmp(tzname[0], utc) || !strcmp(tzname[0], gmt)) /* error? */ |
| && strcasecmp(formatString, utc) && |
| strcasecmp(formatString, gmt))) { /* ok */ |
| if (cp) { |
| setenv(tz, cp, 1); |
| } else { |
| unsetenv(tz); |
| } |
| tzset(); |
| format = FORMAT_OFF; |
| } else { |
| format = FORMAT_MODIFIER_ZONE; |
| } |
| free(cp); |
| } |
| #endif |
| |
| return format; |
| } |
| |
| /** |
| * filterExpression: a single filter expression |
| * eg "AT:d" |
| * |
| * returns 0 on success and -1 on invalid expression |
| * |
| * Assumes single threaded execution |
| */ |
| |
| LIBLOG_ABI_PUBLIC int android_log_addFilterRule(AndroidLogFormat* p_format, |
| const char* filterExpression) { |
| size_t tagNameLength; |
| android_LogPriority pri = ANDROID_LOG_DEFAULT; |
| |
| tagNameLength = strcspn(filterExpression, ":"); |
| |
| if (tagNameLength == 0) { |
| goto error; |
| } |
| |
| if (filterExpression[tagNameLength] == ':') { |
| pri = filterCharToPri(filterExpression[tagNameLength + 1]); |
| |
| if (pri == ANDROID_LOG_UNKNOWN) { |
| goto error; |
| } |
| } |
| |
| if (0 == strncmp("*", filterExpression, tagNameLength)) { |
| /* |
| * This filter expression refers to the global filter |
| * The default level for this is DEBUG if the priority |
| * is unspecified |
| */ |
| if (pri == ANDROID_LOG_DEFAULT) { |
| pri = ANDROID_LOG_DEBUG; |
| } |
| |
| p_format->global_pri = pri; |
| } else { |
| /* |
| * for filter expressions that don't refer to the global |
| * filter, the default is verbose if the priority is unspecified |
| */ |
| if (pri == ANDROID_LOG_DEFAULT) { |
| pri = ANDROID_LOG_VERBOSE; |
| } |
| |
| char* tagName; |
| |
| /* |
| * Presently HAVE_STRNDUP is never defined, so the second case is always taken |
| * Darwin doesn't have strndup, everything else does |
| */ |
| #ifdef HAVE_STRNDUP |
| tagName = strndup(filterExpression, tagNameLength); |
| #else |
| /* a few extra bytes copied... */ |
| tagName = strdup(filterExpression); |
| tagName[tagNameLength] = '\0'; |
| #endif /*HAVE_STRNDUP*/ |
| |
| FilterInfo* p_fi = filterinfo_new(tagName, pri); |
| free(tagName); |
| |
| p_fi->p_next = p_format->filters; |
| p_format->filters = p_fi; |
| } |
| |
| return 0; |
| error: |
| return -1; |
| } |
| |
| #ifndef HAVE_STRSEP |
| /* KISS replacement helper for below */ |
| static char* strsep(char** stringp, const char* delim) { |
| char* token; |
| char* ret = *stringp; |
| |
| if (!ret || !*ret) { |
| return NULL; |
| } |
| token = strpbrk(ret, delim); |
| if (token) { |
| *token = '\0'; |
| ++token; |
| } else { |
| token = ret + strlen(ret); |
| } |
| *stringp = token; |
| return ret; |
| } |
| #endif |
| |
| /** |
| * filterString: a comma/whitespace-separated set of filter expressions |
| * |
| * eg "AT:d *:i" |
| * |
| * returns 0 on success and -1 on invalid expression |
| * |
| * Assumes single threaded execution |
| * |
| */ |
| LIBLOG_ABI_PUBLIC int android_log_addFilterString(AndroidLogFormat* p_format, |
| const char* filterString) { |
| char* filterStringCopy = strdup(filterString); |
| char* p_cur = filterStringCopy; |
| char* p_ret; |
| int err; |
| |
| /* Yes, I'm using strsep */ |
| while (NULL != (p_ret = strsep(&p_cur, " \t,"))) { |
| /* ignore whitespace-only entries */ |
| if (p_ret[0] != '\0') { |
| err = android_log_addFilterRule(p_format, p_ret); |
| |
| if (err < 0) { |
| goto error; |
| } |
| } |
| } |
| |
| free(filterStringCopy); |
| return 0; |
| error: |
| free(filterStringCopy); |
| return -1; |
| } |
| |
| /** |
| * Splits a wire-format buffer into an AndroidLogEntry |
| * entry allocated by caller. Pointers will point directly into buf |
| * |
| * Returns 0 on success and -1 on invalid wire format (entry will be |
| * in unspecified state) |
| */ |
| LIBLOG_ABI_PUBLIC int android_log_processLogBuffer(struct logger_entry* buf, |
| AndroidLogEntry* entry) { |
| entry->message = NULL; |
| entry->messageLen = 0; |
| |
| entry->tv_sec = buf->sec; |
| entry->tv_nsec = buf->nsec; |
| entry->uid = -1; |
| entry->pid = buf->pid; |
| entry->tid = buf->tid; |
| |
| /* |
| * format: <priority:1><tag:N>\0<message:N>\0 |
| * |
| * tag str |
| * starts at buf->msg+1 |
| * msg |
| * starts at buf->msg+1+len(tag)+1 |
| * |
| * The message may have been truncated by the kernel log driver. |
| * When that happens, we must null-terminate the message ourselves. |
| */ |
| if (buf->len < 3) { |
| /* |
| * An well-formed entry must consist of at least a priority |
| * and two null characters |
| */ |
| fprintf(stderr, "+++ LOG: entry too small\n"); |
| return -1; |
| } |
| |
| int msgStart = -1; |
| int msgEnd = -1; |
| |
| int i; |
| char* msg = buf->msg; |
| struct logger_entry_v2* buf2 = (struct logger_entry_v2*)buf; |
| if (buf2->hdr_size) { |
| if ((buf2->hdr_size < sizeof(((struct log_msg*)NULL)->entry_v1)) || |
| (buf2->hdr_size > sizeof(((struct log_msg*)NULL)->entry))) { |
| fprintf(stderr, "+++ LOG: entry illegal hdr_size\n"); |
| return -1; |
| } |
| msg = ((char*)buf2) + buf2->hdr_size; |
| if (buf2->hdr_size >= sizeof(struct logger_entry_v4)) { |
| entry->uid = ((struct logger_entry_v4*)buf)->uid; |
| } |
| } |
| for (i = 1; i < buf->len; i++) { |
| if (msg[i] == '\0') { |
| if (msgStart == -1) { |
| msgStart = i + 1; |
| } else { |
| msgEnd = i; |
| break; |
| } |
| } |
| } |
| |
| if (msgStart == -1) { |
| /* +++ LOG: malformed log message, DYB */ |
| for (i = 1; i < buf->len; i++) { |
| /* odd characters in tag? */ |
| if ((msg[i] <= ' ') || (msg[i] == ':') || (msg[i] >= 0x7f)) { |
| msg[i] = '\0'; |
| msgStart = i + 1; |
| break; |
| } |
| } |
| if (msgStart == -1) { |
| msgStart = buf->len - 1; /* All tag, no message, print truncates */ |
| } |
| } |
| if (msgEnd == -1) { |
| /* incoming message not null-terminated; force it */ |
| msgEnd = buf->len - 1; /* may result in msgEnd < msgStart */ |
| msg[msgEnd] = '\0'; |
| } |
| |
| entry->priority = msg[0]; |
| entry->tag = msg + 1; |
| entry->tagLen = msgStart - 1; |
| entry->message = msg + msgStart; |
| entry->messageLen = (msgEnd < msgStart) ? 0 : (msgEnd - msgStart); |
| |
| return 0; |
| } |
| |
| /* |
| * Extract a 4-byte value from a byte stream. |
| */ |
| static inline uint32_t get4LE(const uint8_t* src) { |
| return src[0] | (src[1] << 8) | (src[2] << 16) | (src[3] << 24); |
| } |
| |
| /* |
| * Extract an 8-byte value from a byte stream. |
| */ |
| static inline uint64_t get8LE(const uint8_t* src) { |
| uint32_t low, high; |
| |
| low = src[0] | (src[1] << 8) | (src[2] << 16) | (src[3] << 24); |
| high = src[4] | (src[5] << 8) | (src[6] << 16) | (src[7] << 24); |
| return ((uint64_t)high << 32) | (uint64_t)low; |
| } |
| |
| static bool findChar(const char** cp, size_t* len, int c) { |
| while ((*len) && isspace(*(*cp))) { |
| ++(*cp); |
| --(*len); |
| } |
| if (c == INT_MAX) return *len; |
| if ((*len) && (*(*cp) == c)) { |
| ++(*cp); |
| --(*len); |
| return true; |
| } |
| return false; |
| } |
| |
| /* |
| * Recursively convert binary log data to printable form. |
| * |
| * This needs to be recursive because you can have lists of lists. |
| * |
| * If we run out of room, we stop processing immediately. It's important |
| * for us to check for space on every output element to avoid producing |
| * garbled output. |
| * |
| * Returns 0 on success, 1 on buffer full, -1 on failure. |
| */ |
| enum objectType { |
| TYPE_OBJECTS = '1', |
| TYPE_BYTES = '2', |
| TYPE_MILLISECONDS = '3', |
| TYPE_ALLOCATIONS = '4', |
| TYPE_ID = '5', |
| TYPE_PERCENT = '6', |
| TYPE_MONOTONIC = 's' |
| }; |
| |
| static int android_log_printBinaryEvent(const unsigned char** pEventData, |
| size_t* pEventDataLen, char** pOutBuf, |
| size_t* pOutBufLen, const char** fmtStr, |
| size_t* fmtLen) { |
| const unsigned char* eventData = *pEventData; |
| size_t eventDataLen = *pEventDataLen; |
| char* outBuf = *pOutBuf; |
| char* outBufSave = outBuf; |
| size_t outBufLen = *pOutBufLen; |
| size_t outBufLenSave = outBufLen; |
| unsigned char type; |
| size_t outCount = 0; |
| int result = 0; |
| const char* cp; |
| size_t len; |
| int64_t lval; |
| |
| if (eventDataLen < 1) return -1; |
| |
| type = *eventData++; |
| eventDataLen--; |
| |
| cp = NULL; |
| len = 0; |
| if (fmtStr && *fmtStr && fmtLen && *fmtLen && **fmtStr) { |
| cp = *fmtStr; |
| len = *fmtLen; |
| } |
| /* |
| * event.logtag format specification: |
| * |
| * Optionally, after the tag names can be put a description for the value(s) |
| * of the tag. Description are in the format |
| * (<name>|data type[|data unit]) |
| * Multiple values are separated by commas. |
| * |
| * The data type is a number from the following values: |
| * 1: int |
| * 2: long |
| * 3: string |
| * 4: list |
| * 5: float |
| * |
| * The data unit is a number taken from the following list: |
| * 1: Number of objects |
| * 2: Number of bytes |
| * 3: Number of milliseconds |
| * 4: Number of allocations |
| * 5: Id |
| * 6: Percent |
| * s: Number of seconds (monotonic time) |
| * Default value for data of type int/long is 2 (bytes). |
| */ |
| if (!cp || !findChar(&cp, &len, '(')) { |
| len = 0; |
| } else { |
| char* outBufLastSpace = NULL; |
| |
| findChar(&cp, &len, INT_MAX); |
| while (len && *cp && (*cp != '|') && (*cp != ')')) { |
| if (outBufLen <= 0) { |
| /* halt output */ |
| goto no_room; |
| } |
| outBufLastSpace = isspace(*cp) ? outBuf : NULL; |
| *outBuf = *cp; |
| ++outBuf; |
| ++cp; |
| --outBufLen; |
| --len; |
| } |
| if (outBufLastSpace) { |
| outBufLen += outBuf - outBufLastSpace; |
| outBuf = outBufLastSpace; |
| } |
| if (outBufLen <= 0) { |
| /* halt output */ |
| goto no_room; |
| } |
| if (outBufSave != outBuf) { |
| *outBuf = '='; |
| ++outBuf; |
| --outBufLen; |
| } |
| |
| if (findChar(&cp, &len, '|') && findChar(&cp, &len, INT_MAX)) { |
| static const unsigned char typeTable[] = { |
| EVENT_TYPE_INT, EVENT_TYPE_LONG, EVENT_TYPE_STRING, EVENT_TYPE_LIST, |
| EVENT_TYPE_FLOAT |
| }; |
| |
| if ((*cp >= '1') && |
| (*cp < (char)('1' + (sizeof(typeTable) / sizeof(typeTable[0])))) && |
| (type != typeTable[(size_t)(*cp - '1')])) |
| len = 0; |
| |
| if (len) { |
| ++cp; |
| --len; |
| } else { |
| /* reset the format */ |
| outBuf = outBufSave; |
| outBufLen = outBufLenSave; |
| } |
| } |
| } |
| outCount = 0; |
| lval = 0; |
| switch (type) { |
| case EVENT_TYPE_INT: |
| /* 32-bit signed int */ |
| { |
| int32_t ival; |
| |
| if (eventDataLen < 4) return -1; |
| ival = get4LE(eventData); |
| eventData += 4; |
| eventDataLen -= 4; |
| |
| lval = ival; |
| } |
| goto pr_lval; |
| case EVENT_TYPE_LONG: |
| /* 64-bit signed long */ |
| if (eventDataLen < 8) return -1; |
| lval = get8LE(eventData); |
| eventData += 8; |
| eventDataLen -= 8; |
| pr_lval: |
| outCount = snprintf(outBuf, outBufLen, "%" PRId64, lval); |
| if (outCount < outBufLen) { |
| outBuf += outCount; |
| outBufLen -= outCount; |
| } else { |
| /* halt output */ |
| goto no_room; |
| } |
| break; |
| case EVENT_TYPE_FLOAT: |
| /* float */ |
| { |
| uint32_t ival; |
| float fval; |
| |
| if (eventDataLen < 4) return -1; |
| ival = get4LE(eventData); |
| fval = *(float*)&ival; |
| eventData += 4; |
| eventDataLen -= 4; |
| |
| outCount = snprintf(outBuf, outBufLen, "%f", fval); |
| if (outCount < outBufLen) { |
| outBuf += outCount; |
| outBufLen -= outCount; |
| } else { |
| /* halt output */ |
| goto no_room; |
| } |
| } |
| break; |
| case EVENT_TYPE_STRING: |
| /* UTF-8 chars, not NULL-terminated */ |
| { |
| unsigned int strLen; |
| |
| if (eventDataLen < 4) return -1; |
| strLen = get4LE(eventData); |
| eventData += 4; |
| eventDataLen -= 4; |
| |
| if (eventDataLen < strLen) { |
| result = -1; /* mark truncated */ |
| strLen = eventDataLen; |
| } |
| |
| if (cp && (strLen == 0)) { |
| /* reset the format if no content */ |
| outBuf = outBufSave; |
| outBufLen = outBufLenSave; |
| } |
| if (strLen < outBufLen) { |
| memcpy(outBuf, eventData, strLen); |
| outBuf += strLen; |
| outBufLen -= strLen; |
| } else { |
| if (outBufLen > 0) { |
| /* copy what we can */ |
| memcpy(outBuf, eventData, outBufLen); |
| outBuf += outBufLen; |
| outBufLen -= outBufLen; |
| } |
| if (!result) result = 1; /* if not truncated, return no room */ |
| } |
| eventData += strLen; |
| eventDataLen -= strLen; |
| if (result != 0) goto bail; |
| break; |
| } |
| case EVENT_TYPE_LIST: |
| /* N items, all different types */ |
| { |
| unsigned char count; |
| int i; |
| |
| if (eventDataLen < 1) return -1; |
| |
| count = *eventData++; |
| eventDataLen--; |
| |
| if (outBufLen <= 0) goto no_room; |
| |
| *outBuf++ = '['; |
| outBufLen--; |
| |
| for (i = 0; i < count; i++) { |
| result = android_log_printBinaryEvent( |
| &eventData, &eventDataLen, &outBuf, &outBufLen, fmtStr, fmtLen); |
| if (result != 0) goto bail; |
| |
| if (i < (count - 1)) { |
| if (outBufLen <= 0) goto no_room; |
| *outBuf++ = ','; |
| outBufLen--; |
| } |
| } |
| |
| if (outBufLen <= 0) goto no_room; |
| |
| *outBuf++ = ']'; |
| outBufLen--; |
| } |
| break; |
| default: |
| fprintf(stderr, "Unknown binary event type %d\n", type); |
| return -1; |
| } |
| if (cp && len) { |
| if (findChar(&cp, &len, '|') && findChar(&cp, &len, INT_MAX)) { |
| switch (*cp) { |
| case TYPE_OBJECTS: |
| outCount = 0; |
| /* outCount = snprintf(outBuf, outBufLen, " objects"); */ |
| break; |
| case TYPE_BYTES: |
| if ((lval != 0) && ((lval % 1024) == 0)) { |
| /* repaint with multiplier */ |
| static const char suffixTable[] = { 'K', 'M', 'G', 'T' }; |
| size_t idx = 0; |
| outBuf -= outCount; |
| outBufLen += outCount; |
| do { |
| lval /= 1024; |
| if ((lval % 1024) != 0) break; |
| } while (++idx < |
| ((sizeof(suffixTable) / sizeof(suffixTable[0])) - 1)); |
| outCount = snprintf(outBuf, outBufLen, "%" PRId64 "%cB", lval, |
| suffixTable[idx]); |
| } else { |
| outCount = snprintf(outBuf, outBufLen, "B"); |
| } |
| break; |
| case TYPE_MILLISECONDS: |
| if (((lval <= -1000) || (1000 <= lval)) && |
| (outBufLen || (outBuf[-1] == '0'))) { |
| /* repaint as (fractional) seconds, possibly saving space */ |
| if (outBufLen) outBuf[0] = outBuf[-1]; |
| outBuf[-1] = outBuf[-2]; |
| outBuf[-2] = outBuf[-3]; |
| outBuf[-3] = '.'; |
| while ((outBufLen == 0) || (*outBuf == '0')) { |
| --outBuf; |
| ++outBufLen; |
| } |
| if (*outBuf != '.') { |
| ++outBuf; |
| --outBufLen; |
| } |
| outCount = snprintf(outBuf, outBufLen, "s"); |
| } else { |
| outCount = snprintf(outBuf, outBufLen, "ms"); |
| } |
| break; |
| case TYPE_MONOTONIC: { |
| static const uint64_t minute = 60; |
| static const uint64_t hour = 60 * minute; |
| static const uint64_t day = 24 * hour; |
| |
| /* Repaint as unsigned seconds, minutes, hours ... */ |
| outBuf -= outCount; |
| outBufLen += outCount; |
| uint64_t val = lval; |
| if (val >= day) { |
| outCount = snprintf(outBuf, outBufLen, "%" PRIu64 "d ", val / day); |
| if (outCount >= outBufLen) break; |
| outBuf += outCount; |
| outBufLen -= outCount; |
| val = (val % day) + day; |
| } |
| if (val >= minute) { |
| if (val >= hour) { |
| outCount = snprintf(outBuf, outBufLen, "%" PRIu64 ":", |
| (val / hour) % (day / hour)); |
| if (outCount >= outBufLen) break; |
| outBuf += outCount; |
| outBufLen -= outCount; |
| } |
| outCount = |
| snprintf(outBuf, outBufLen, |
| (val >= hour) ? "%02" PRIu64 ":" : "%" PRIu64 ":", |
| (val / minute) % (hour / minute)); |
| if (outCount >= outBufLen) break; |
| outBuf += outCount; |
| outBufLen -= outCount; |
| } |
| outCount = snprintf(outBuf, outBufLen, |
| (val >= minute) ? "%02" PRIu64 : "%" PRIu64 "s", |
| val % minute); |
| } break; |
| case TYPE_ALLOCATIONS: |
| outCount = 0; |
| /* outCount = snprintf(outBuf, outBufLen, " allocations"); */ |
| break; |
| case TYPE_ID: |
| outCount = 0; |
| break; |
| case TYPE_PERCENT: |
| outCount = snprintf(outBuf, outBufLen, "%%"); |
| break; |
| default: /* ? */ |
| outCount = 0; |
| break; |
| } |
| ++cp; |
| --len; |
| if (outCount < outBufLen) { |
| outBuf += outCount; |
| outBufLen -= outCount; |
| } else if (outCount) { |
| /* halt output */ |
| goto no_room; |
| } |
| } |
| if (!findChar(&cp, &len, ')')) len = 0; |
| if (!findChar(&cp, &len, ',')) len = 0; |
| } |
| |
| bail: |
| *pEventData = eventData; |
| *pEventDataLen = eventDataLen; |
| *pOutBuf = outBuf; |
| *pOutBufLen = outBufLen; |
| if (cp) { |
| *fmtStr = cp; |
| *fmtLen = len; |
| } |
| return result; |
| |
| no_room: |
| result = 1; |
| goto bail; |
| } |
| |
| /** |
| * Convert a binary log entry to ASCII form. |
| * |
| * For convenience we mimic the processLogBuffer API. There is no |
| * pre-defined output length for the binary data, since we're free to format |
| * it however we choose, which means we can't really use a fixed-size buffer |
| * here. |
| */ |
| LIBLOG_ABI_PUBLIC int android_log_processBinaryLogBuffer( |
| struct logger_entry* buf, AndroidLogEntry* entry, |
| const EventTagMap* map __unused, /* only on !__ANDROID__ */ |
| char* messageBuf, int messageBufLen) { |
| size_t inCount; |
| uint32_t tagIndex; |
| const unsigned char* eventData; |
| |
| entry->message = NULL; |
| entry->messageLen = 0; |
| |
| entry->tv_sec = buf->sec; |
| entry->tv_nsec = buf->nsec; |
| entry->priority = ANDROID_LOG_INFO; |
| entry->uid = -1; |
| entry->pid = buf->pid; |
| entry->tid = buf->tid; |
| |
| /* |
| * Pull the tag out, fill in some additional details based on incoming |
| * buffer version (v3 adds lid, v4 adds uid). |
| */ |
| eventData = (const unsigned char*)buf->msg; |
| struct logger_entry_v2* buf2 = (struct logger_entry_v2*)buf; |
| if (buf2->hdr_size) { |
| if ((buf2->hdr_size < sizeof(((struct log_msg*)NULL)->entry_v1)) || |
| (buf2->hdr_size > sizeof(((struct log_msg*)NULL)->entry))) { |
| fprintf(stderr, "+++ LOG: entry illegal hdr_size\n"); |
| return -1; |
| } |
| eventData = ((unsigned char*)buf2) + buf2->hdr_size; |
| if ((buf2->hdr_size >= sizeof(struct logger_entry_v3)) && |
| (((struct logger_entry_v3*)buf)->lid == LOG_ID_SECURITY)) { |
| entry->priority = ANDROID_LOG_WARN; |
| } |
| if (buf2->hdr_size >= sizeof(struct logger_entry_v4)) { |
| entry->uid = ((struct logger_entry_v4*)buf)->uid; |
| } |
| } |
| inCount = buf->len; |
| if (inCount < 4) return -1; |
| tagIndex = get4LE(eventData); |
| eventData += 4; |
| inCount -= 4; |
| |
| entry->tagLen = 0; |
| entry->tag = NULL; |
| #ifdef __ANDROID__ |
| if (map != NULL) { |
| entry->tag = android_lookupEventTag_len(map, &entry->tagLen, tagIndex); |
| } |
| #endif |
| |
| /* |
| * If we don't have a map, or didn't find the tag number in the map, |
| * stuff a generated tag value into the start of the output buffer and |
| * shift the buffer pointers down. |
| */ |
| if (entry->tag == NULL) { |
| size_t tagLen; |
| |
| tagLen = snprintf(messageBuf, messageBufLen, "[%" PRIu32 "]", tagIndex); |
| if (tagLen >= (size_t)messageBufLen) { |
| tagLen = messageBufLen - 1; |
| } |
| entry->tag = messageBuf; |
| entry->tagLen = tagLen; |
| messageBuf += tagLen + 1; |
| messageBufLen -= tagLen + 1; |
| } |
| |
| /* |
| * Format the event log data into the buffer. |
| */ |
| const char* fmtStr = NULL; |
| size_t fmtLen = 0; |
| #ifdef __ANDROID__ |
| if (descriptive_output && map) { |
| fmtStr = android_lookupEventFormat_len(map, &fmtLen, tagIndex); |
| } |
| #endif |
| |
| char* outBuf = messageBuf; |
| size_t outRemaining = messageBufLen - 1; /* leave one for nul byte */ |
| int result = 0; |
| |
| if ((inCount > 0) || fmtLen) { |
| result = android_log_printBinaryEvent(&eventData, &inCount, &outBuf, |
| &outRemaining, &fmtStr, &fmtLen); |
| } |
| if ((result == 1) && fmtStr) { |
| /* We overflowed :-(, let's repaint the line w/o format dressings */ |
| eventData = (const unsigned char*)buf->msg; |
| if (buf2->hdr_size) { |
| eventData = ((unsigned char*)buf2) + buf2->hdr_size; |
| } |
| eventData += 4; |
| outBuf = messageBuf; |
| outRemaining = messageBufLen - 1; |
| result = android_log_printBinaryEvent(&eventData, &inCount, &outBuf, |
| &outRemaining, NULL, NULL); |
| } |
| if (result < 0) { |
| fprintf(stderr, "Binary log entry conversion failed\n"); |
| } |
| if (result) { |
| if (!outRemaining) { |
| /* make space to leave an indicator */ |
| --outBuf; |
| ++outRemaining; |
| } |
| *outBuf++ = (result < 0) ? '!' : '^'; /* Error or Truncation? */ |
| outRemaining--; |
| /* pretend we ate all the data to prevent log stutter */ |
| inCount = 0; |
| if (result > 0) result = 0; |
| } |
| |
| /* eat the silly terminating '\n' */ |
| if (inCount == 1 && *eventData == '\n') { |
| eventData++; |
| inCount--; |
| } |
| |
| if (inCount != 0) { |
| fprintf(stderr, "Warning: leftover binary log data (%zu bytes)\n", inCount); |
| } |
| |
| /* |
| * Terminate the buffer. The NUL byte does not count as part of |
| * entry->messageLen. |
| */ |
| *outBuf = '\0'; |
| entry->messageLen = outBuf - messageBuf; |
| assert(entry->messageLen == (messageBufLen - 1) - outRemaining); |
| |
| entry->message = messageBuf; |
| |
| return result; |
| } |
| |
| /* |
| * One utf8 character at a time |
| * |
| * Returns the length of the utf8 character in the buffer, |
| * or -1 if illegal or truncated |
| * |
| * Open coded from libutils/Unicode.cpp, borrowed from utf8_length(), |
| * can not remove from here because of library circular dependencies. |
| * Expect one-day utf8_character_length with the same signature could |
| * _also_ be part of libutils/Unicode.cpp if its usefullness needs to |
| * propagate globally. |
| */ |
| LIBLOG_WEAK ssize_t utf8_character_length(const char* src, size_t len) { |
| const char* cur = src; |
| const char first_char = *cur++; |
| static const uint32_t kUnicodeMaxCodepoint = 0x0010FFFF; |
| int32_t mask, to_ignore_mask; |
| size_t num_to_read; |
| uint32_t utf32; |
| |
| if ((first_char & 0x80) == 0) { /* ASCII */ |
| return first_char ? 1 : -1; |
| } |
| |
| /* |
| * (UTF-8's character must not be like 10xxxxxx, |
| * but 110xxxxx, 1110xxxx, ... or 1111110x) |
| */ |
| if ((first_char & 0x40) == 0) { |
| return -1; |
| } |
| |
| for (utf32 = 1, num_to_read = 1, mask = 0x40, to_ignore_mask = 0x80; |
| num_to_read < 5 && (first_char & mask); |
| num_to_read++, to_ignore_mask |= mask, mask >>= 1) { |
| if (num_to_read > len) { |
| return -1; |
| } |
| if ((*cur & 0xC0) != 0x80) { /* can not be 10xxxxxx? */ |
| return -1; |
| } |
| utf32 = (utf32 << 6) + (*cur++ & 0b00111111); |
| } |
| /* "first_char" must be (110xxxxx - 11110xxx) */ |
| if (num_to_read >= 5) { |
| return -1; |
| } |
| to_ignore_mask |= mask; |
| utf32 |= ((~to_ignore_mask) & first_char) << (6 * (num_to_read - 1)); |
| if (utf32 > kUnicodeMaxCodepoint) { |
| return -1; |
| } |
| return num_to_read; |
| } |
| |
| /* |
| * Convert to printable from message to p buffer, return string length. If p is |
| * NULL, do not copy, but still return the expected string length. |
| */ |
| static size_t convertPrintable(char* p, const char* message, size_t messageLen) { |
| char* begin = p; |
| bool print = p != NULL; |
| |
| while (messageLen) { |
| char buf[6]; |
| ssize_t len = sizeof(buf) - 1; |
| if ((size_t)len > messageLen) { |
| len = messageLen; |
| } |
| len = utf8_character_length(message, len); |
| |
| if (len < 0) { |
| snprintf(buf, sizeof(buf), |
| ((messageLen > 1) && isdigit(message[1])) ? "\\%03o" : "\\%o", |
| *message & 0377); |
| len = 1; |
| } else { |
| buf[0] = '\0'; |
| if (len == 1) { |
| if (*message == '\a') { |
| strcpy(buf, "\\a"); |
| } else if (*message == '\b') { |
| strcpy(buf, "\\b"); |
| } else if (*message == '\t') { |
| strcpy(buf, "\t"); /* Do not escape tabs */ |
| } else if (*message == '\v') { |
| strcpy(buf, "\\v"); |
| } else if (*message == '\f') { |
| strcpy(buf, "\\f"); |
| } else if (*message == '\r') { |
| strcpy(buf, "\\r"); |
| } else if (*message == '\\') { |
| strcpy(buf, "\\\\"); |
| } else if ((*message < ' ') || (*message & 0x80)) { |
| snprintf(buf, sizeof(buf), "\\%o", *message & 0377); |
| } |
| } |
| if (!buf[0]) { |
| strncpy(buf, message, len); |
| buf[len] = '\0'; |
| } |
| } |
| if (print) { |
| strcpy(p, buf); |
| } |
| p += strlen(buf); |
| message += len; |
| messageLen -= len; |
| } |
| return p - begin; |
| } |
| |
| static char* readSeconds(char* e, struct timespec* t) { |
| unsigned long multiplier; |
| char* p; |
| t->tv_sec = strtoul(e, &p, 10); |
| if (*p != '.') { |
| return NULL; |
| } |
| t->tv_nsec = 0; |
| multiplier = NS_PER_SEC; |
| while (isdigit(*++p) && (multiplier /= 10)) { |
| t->tv_nsec += (*p - '0') * multiplier; |
| } |
| return p; |
| } |
| |
| static struct timespec* sumTimespec(struct timespec* left, |
| struct timespec* right) { |
| left->tv_nsec += right->tv_nsec; |
| left->tv_sec += right->tv_sec; |
| if (left->tv_nsec >= (long)NS_PER_SEC) { |
| left->tv_nsec -= NS_PER_SEC; |
| left->tv_sec += 1; |
| } |
| return left; |
| } |
| |
| static struct timespec* subTimespec(struct timespec* result, |
| struct timespec* left, |
| struct timespec* right) { |
| result->tv_nsec = left->tv_nsec - right->tv_nsec; |
| result->tv_sec = left->tv_sec - right->tv_sec; |
| if (result->tv_nsec < 0) { |
| result->tv_nsec += NS_PER_SEC; |
| result->tv_sec -= 1; |
| } |
| return result; |
| } |
| |
| static long long nsecTimespec(struct timespec* now) { |
| return (long long)now->tv_sec * NS_PER_SEC + now->tv_nsec; |
| } |
| |
| #ifdef __ANDROID__ |
| static void convertMonotonic(struct timespec* result, |
| const AndroidLogEntry* entry) { |
| struct listnode* node; |
| struct conversionList { |
| struct listnode node; /* first */ |
| struct timespec time; |
| struct timespec convert; |
| } * list, *next; |
| struct timespec time, convert; |
| |
| /* If we do not have a conversion list, build one up */ |
| if (list_empty(&convertHead)) { |
| bool suspended_pending = false; |
| struct timespec suspended_monotonic = { 0, 0 }; |
| struct timespec suspended_diff = { 0, 0 }; |
| |
| /* |
| * Read dmesg for _some_ synchronization markers and insert |
| * Anything in the Android Logger before the dmesg logging span will |
| * be highly suspect regarding the monotonic time calculations. |
| */ |
| FILE* p = popen("/system/bin/dmesg", "re"); |
| if (p) { |
| char* line = NULL; |
| size_t len = 0; |
| while (getline(&line, &len, p) > 0) { |
| static const char suspend[] = "PM: suspend entry "; |
| static const char resume[] = "PM: suspend exit "; |
| static const char healthd[] = "healthd"; |
| static const char battery[] = ": battery "; |
| static const char suspended[] = "Suspended for "; |
| struct timespec monotonic; |
| struct tm tm; |
| char *cp, *e = line; |
| bool add_entry = true; |
| |
| if (*e == '<') { |
| while (*e && (*e != '>')) { |
| ++e; |
| } |
| if (*e != '>') { |
| continue; |
| } |
| } |
| if (*e != '[') { |
| continue; |
| } |
| while (*++e == ' ') { |
| ; |
| } |
| e = readSeconds(e, &monotonic); |
| if (!e || (*e != ']')) { |
| continue; |
| } |
| |
| if ((e = strstr(e, suspend))) { |
| e += sizeof(suspend) - 1; |
| } else if ((e = strstr(line, resume))) { |
| e += sizeof(resume) - 1; |
| } else if (((e = strstr(line, healthd))) && |
| ((e = strstr(e + sizeof(healthd) - 1, battery)))) { |
| /* NB: healthd is roughly 150us late, worth the price to |
| * deal with ntp-induced or hardware clock drift. */ |
| e += sizeof(battery) - 1; |
| } else if ((e = strstr(line, suspended))) { |
| e += sizeof(suspended) - 1; |
| e = readSeconds(e, &time); |
| if (!e) { |
| continue; |
| } |
| add_entry = false; |
| suspended_pending = true; |
| suspended_monotonic = monotonic; |
| suspended_diff = time; |
| } else { |
| continue; |
| } |
| if (add_entry) { |
| /* look for "????-??-?? ??:??:??.????????? UTC" */ |
| cp = strstr(e, " UTC"); |
| if (!cp || ((cp - e) < 29) || (cp[-10] != '.')) { |
| continue; |
| } |
| e = cp - 29; |
| cp = readSeconds(cp - 10, &time); |
| if (!cp) { |
| continue; |
| } |
| cp = strptime(e, "%Y-%m-%d %H:%M:%S.", &tm); |
| if (!cp) { |
| continue; |
| } |
| cp = getenv(tz); |
| if (cp) { |
| cp = strdup(cp); |
| } |
| setenv(tz, utc, 1); |
| time.tv_sec = mktime(&tm); |
| if (cp) { |
| setenv(tz, cp, 1); |
| free(cp); |
| } else { |
| unsetenv(tz); |
| } |
| list = calloc(1, sizeof(struct conversionList)); |
| list_init(&list->node); |
| list->time = time; |
| subTimespec(&list->convert, &time, &monotonic); |
| list_add_tail(&convertHead, &list->node); |
| } |
| if (suspended_pending && !list_empty(&convertHead)) { |
| list = node_to_item(list_tail(&convertHead), struct conversionList, |
| node); |
| if (subTimespec(&time, subTimespec(&time, &list->time, &list->convert), |
| &suspended_monotonic) |
| ->tv_sec > 0) { |
| /* resume, what is convert factor before? */ |
| subTimespec(&convert, &list->convert, &suspended_diff); |
| } else { |
| /* suspend */ |
| convert = list->convert; |
| } |
| time = suspended_monotonic; |
| sumTimespec(&time, &convert); |
| /* breakpoint just before sleep */ |
| list = calloc(1, sizeof(struct conversionList)); |
| list_init(&list->node); |
| list->time = time; |
| list->convert = convert; |
| list_add_tail(&convertHead, &list->node); |
| /* breakpoint just after sleep */ |
| list = calloc(1, sizeof(struct conversionList)); |
| list_init(&list->node); |
| list->time = time; |
| sumTimespec(&list->time, &suspended_diff); |
| list->convert = convert; |
| sumTimespec(&list->convert, &suspended_diff); |
| list_add_tail(&convertHead, &list->node); |
| suspended_pending = false; |
| } |
| } |
| pclose(p); |
| } |
| /* last entry is our current time conversion */ |
| list = calloc(1, sizeof(struct conversionList)); |
| list_init(&list->node); |
| clock_gettime(CLOCK_REALTIME, &list->time); |
| clock_gettime(CLOCK_MONOTONIC, &convert); |
| clock_gettime(CLOCK_MONOTONIC, &time); |
| /* Correct for instant clock_gettime latency (syscall or ~30ns) */ |
| subTimespec(&time, &convert, subTimespec(&time, &time, &convert)); |
| /* Calculate conversion factor */ |
| subTimespec(&list->convert, &list->time, &time); |
| list_add_tail(&convertHead, &list->node); |
| if (suspended_pending) { |
| /* manufacture a suspend @ point before */ |
| subTimespec(&convert, &list->convert, &suspended_diff); |
| time = suspended_monotonic; |
| sumTimespec(&time, &convert); |
| /* breakpoint just after sleep */ |
| list = calloc(1, sizeof(struct conversionList)); |
| list_init(&list->node); |
| list->time = time; |
| sumTimespec(&list->time, &suspended_diff); |
| list->convert = convert; |
| sumTimespec(&list->convert, &suspended_diff); |
| list_add_head(&convertHead, &list->node); |
| /* breakpoint just before sleep */ |
| list = calloc(1, sizeof(struct conversionList)); |
| list_init(&list->node); |
| list->time = time; |
| list->convert = convert; |
| list_add_head(&convertHead, &list->node); |
| } |
| } |
| |
| /* Find the breakpoint in the conversion list */ |
| list = node_to_item(list_head(&convertHead), struct conversionList, node); |
| next = NULL; |
| list_for_each(node, &convertHead) { |
| next = node_to_item(node, struct conversionList, node); |
| if (entry->tv_sec < next->time.tv_sec) { |
| break; |
| } else if (entry->tv_sec == next->time.tv_sec) { |
| if (entry->tv_nsec < next->time.tv_nsec) { |
| break; |
| } |
| } |
| list = next; |
| } |
| |
| /* blend time from one breakpoint to the next */ |
| convert = list->convert; |
| if (next) { |
| unsigned long long total, run; |
| |
| total = nsecTimespec(subTimespec(&time, &next->time, &list->time)); |
| time.tv_sec = entry->tv_sec; |
| time.tv_nsec = entry->tv_nsec; |
| run = nsecTimespec(subTimespec(&time, &time, &list->time)); |
| if (run < total) { |
| long long crun; |
| |
| float f = nsecTimespec(subTimespec(&time, &next->convert, &convert)); |
| f *= run; |
| f /= total; |
| crun = f; |
| convert.tv_sec += crun / (long long)NS_PER_SEC; |
| if (crun < 0) { |
| convert.tv_nsec -= (-crun) % NS_PER_SEC; |
| if (convert.tv_nsec < 0) { |
| convert.tv_nsec += NS_PER_SEC; |
| convert.tv_sec -= 1; |
| } |
| } else { |
| convert.tv_nsec += crun % NS_PER_SEC; |
| if (convert.tv_nsec >= (long)NS_PER_SEC) { |
| convert.tv_nsec -= NS_PER_SEC; |
| convert.tv_sec += 1; |
| } |
| } |
| } |
| } |
| |
| /* Apply the correction factor */ |
| result->tv_sec = entry->tv_sec; |
| result->tv_nsec = entry->tv_nsec; |
| subTimespec(result, result, &convert); |
| } |
| #endif |
| |
| /** |
| * Formats a log message into a buffer |
| * |
| * Uses defaultBuffer if it can, otherwise malloc()'s a new buffer |
| * If return value != defaultBuffer, caller must call free() |
| * Returns NULL on malloc error |
| */ |
| |
| LIBLOG_ABI_PUBLIC char* android_log_formatLogLine(AndroidLogFormat* p_format, |
| char* defaultBuffer, |
| size_t defaultBufferSize, |
| const AndroidLogEntry* entry, |
| size_t* p_outLength) { |
| #if !defined(_WIN32) |
| struct tm tmBuf; |
| #endif |
| struct tm* ptm; |
| /* good margin, 23+nul for msec, 26+nul for usec, 29+nul to nsec */ |
| char timeBuf[64]; |
| char prefixBuf[128], suffixBuf[128]; |
| char priChar; |
| int prefixSuffixIsHeaderFooter = 0; |
| char* ret; |
| time_t now; |
| unsigned long nsec; |
| |
| priChar = filterPriToChar(entry->priority); |
| size_t prefixLen = 0, suffixLen = 0; |
| size_t len; |
| |
| /* |
| * Get the current date/time in pretty form |
| * |
| * It's often useful when examining a log with "less" to jump to |
| * a specific point in the file by searching for the date/time stamp. |
| * For this reason it's very annoying to have regexp meta characters |
| * in the time stamp. Don't use forward slashes, parenthesis, |
| * brackets, asterisks, or other special chars here. |
| * |
| * The caller may have affected the timezone environment, this is |
| * expected to be sensitive to that. |
| */ |
| now = entry->tv_sec; |
| nsec = entry->tv_nsec; |
| #if __ANDROID__ |
| if (p_format->monotonic_output) { |
| /* prevent convertMonotonic from being called if logd is monotonic */ |
| if (android_log_clockid() != CLOCK_MONOTONIC) { |
| struct timespec time; |
| convertMonotonic(&time, entry); |
| now = time.tv_sec; |
| nsec = time.tv_nsec; |
| } |
| } |
| #endif |
| if (now < 0) { |
| nsec = NS_PER_SEC - nsec; |
| } |
| if (p_format->epoch_output || p_format->monotonic_output) { |
| ptm = NULL; |
| snprintf(timeBuf, sizeof(timeBuf), |
| p_format->monotonic_output ? "%6lld" : "%19lld", (long long)now); |
| } else { |
| #if !defined(_WIN32) |
| ptm = localtime_r(&now, &tmBuf); |
| #else |
| ptm = localtime(&now); |
| #endif |
| strftime(timeBuf, sizeof(timeBuf), |
| &"%Y-%m-%d %H:%M:%S"[p_format->year_output ? 0 : 3], ptm); |
| } |
| len = strlen(timeBuf); |
| if (p_format->nsec_time_output) { |
| len += snprintf(timeBuf + len, sizeof(timeBuf) - len, ".%09ld", nsec); |
| } else if (p_format->usec_time_output) { |
| len += snprintf(timeBuf + len, sizeof(timeBuf) - len, ".%06ld", |
| nsec / US_PER_NSEC); |
| } else { |
| len += snprintf(timeBuf + len, sizeof(timeBuf) - len, ".%03ld", |
| nsec / MS_PER_NSEC); |
| } |
| if (p_format->zone_output && ptm) { |
| strftime(timeBuf + len, sizeof(timeBuf) - len, " %z", ptm); |
| } |
| |
| /* |
| * Construct a buffer containing the log header and log message. |
| */ |
| if (p_format->colored_output) { |
| prefixLen = snprintf(prefixBuf, sizeof(prefixBuf), "\x1B[38;5;%dm", |
| colorFromPri(entry->priority)); |
| prefixLen = MIN(prefixLen, sizeof(prefixBuf)); |
| suffixLen = snprintf(suffixBuf, sizeof(suffixBuf), "\x1B[0m"); |
| suffixLen = MIN(suffixLen, sizeof(suffixBuf)); |
| } |
| |
| char uid[16]; |
| uid[0] = '\0'; |
| if (p_format->uid_output) { |
| if (entry->uid >= 0) { |
| /* |
| * This code is Android specific, bionic guarantees that |
| * calls to non-reentrant getpwuid() are thread safe. |
| */ |
| #if !defined(__MINGW32__) |
| #if (FAKE_LOG_DEVICE == 0) |
| #ifndef __BIONIC__ |
| #warning \ |
| "This code assumes that getpwuid is thread safe, only true with Bionic!" |
| #endif |
| #endif |
| struct passwd* pwd = getpwuid(entry->uid); |
| if (pwd && (strlen(pwd->pw_name) <= 5)) { |
| snprintf(uid, sizeof(uid), "%5s:", pwd->pw_name); |
| } else |
| #endif |
| { |
| /* Not worth parsing package list, names all longer than 5 */ |
| snprintf(uid, sizeof(uid), "%5d:", entry->uid); |
| } |
| } else { |
| snprintf(uid, sizeof(uid), " "); |
| } |
| } |
| |
| switch (p_format->format) { |
| case FORMAT_TAG: |
| len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen, |
| "%c/%-8.*s: ", priChar, (int)entry->tagLen, entry->tag); |
| strcpy(suffixBuf + suffixLen, "\n"); |
| ++suffixLen; |
| break; |
| case FORMAT_PROCESS: |
| len = snprintf(suffixBuf + suffixLen, sizeof(suffixBuf) - suffixLen, |
| " (%.*s)\n", (int)entry->tagLen, entry->tag); |
| suffixLen += MIN(len, sizeof(suffixBuf) - suffixLen); |
| len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen, |
| "%c(%s%5d) ", priChar, uid, entry->pid); |
| break; |
| case FORMAT_THREAD: |
| len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen, |
| "%c(%s%5d:%5d) ", priChar, uid, entry->pid, entry->tid); |
| strcpy(suffixBuf + suffixLen, "\n"); |
| ++suffixLen; |
| break; |
| case FORMAT_RAW: |
| prefixBuf[prefixLen] = 0; |
| len = 0; |
| strcpy(suffixBuf + suffixLen, "\n"); |
| ++suffixLen; |
| break; |
| case FORMAT_TIME: |
| len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen, |
| "%s %c/%-8.*s(%s%5d): ", timeBuf, priChar, |
| (int)entry->tagLen, entry->tag, uid, entry->pid); |
| strcpy(suffixBuf + suffixLen, "\n"); |
| ++suffixLen; |
| break; |
| case FORMAT_THREADTIME: |
| ret = strchr(uid, ':'); |
| if (ret) { |
| *ret = ' '; |
| } |
| len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen, |
| "%s %s%5d %5d %c %-8.*s: ", timeBuf, uid, entry->pid, |
| entry->tid, priChar, (int)entry->tagLen, entry->tag); |
| strcpy(suffixBuf + suffixLen, "\n"); |
| ++suffixLen; |
| break; |
| case FORMAT_LONG: |
| len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen, |
| "[ %s %s%5d:%5d %c/%-8.*s ]\n", timeBuf, uid, entry->pid, |
| entry->tid, priChar, (int)entry->tagLen, entry->tag); |
| strcpy(suffixBuf + suffixLen, "\n\n"); |
| suffixLen += 2; |
| prefixSuffixIsHeaderFooter = 1; |
| break; |
| case FORMAT_BRIEF: |
| default: |
| len = snprintf(prefixBuf + prefixLen, sizeof(prefixBuf) - prefixLen, |
| "%c/%-8.*s(%s%5d): ", priChar, (int)entry->tagLen, |
| entry->tag, uid, entry->pid); |
| strcpy(suffixBuf + suffixLen, "\n"); |
| ++suffixLen; |
| break; |
| } |
| |
| /* snprintf has a weird return value. It returns what would have been |
| * written given a large enough buffer. In the case that the prefix is |
| * longer then our buffer(128), it messes up the calculations below |
| * possibly causing heap corruption. To avoid this we double check and |
| * set the length at the maximum (size minus null byte) |
| */ |
| prefixLen += len; |
| if (prefixLen >= sizeof(prefixBuf)) { |
| prefixLen = sizeof(prefixBuf) - 1; |
| prefixBuf[sizeof(prefixBuf) - 1] = '\0'; |
| } |
| if (suffixLen >= sizeof(suffixBuf)) { |
| suffixLen = sizeof(suffixBuf) - 1; |
| suffixBuf[sizeof(suffixBuf) - 2] = '\n'; |
| suffixBuf[sizeof(suffixBuf) - 1] = '\0'; |
| } |
| |
| /* the following code is tragically unreadable */ |
| |
| size_t numLines; |
| char* p; |
| size_t bufferSize; |
| const char* pm; |
| |
| if (prefixSuffixIsHeaderFooter) { |
| /* we're just wrapping message with a header/footer */ |
| numLines = 1; |
| } else { |
| pm = entry->message; |
| numLines = 0; |
| |
| /* |
| * The line-end finding here must match the line-end finding |
| * in for ( ... numLines...) loop below |
| */ |
| while (pm < (entry->message + entry->messageLen)) { |
| if (*pm++ == '\n') numLines++; |
| } |
| /* plus one line for anything not newline-terminated at the end */ |
| if (pm > entry->message && *(pm - 1) != '\n') numLines++; |
| } |
| |
| /* |
| * this is an upper bound--newlines in message may be counted |
| * extraneously |
| */ |
| bufferSize = (numLines * (prefixLen + suffixLen)) + 1; |
| if (p_format->printable_output) { |
| /* Calculate extra length to convert non-printable to printable */ |
| bufferSize += convertPrintable(NULL, entry->message, entry->messageLen); |
| } else { |
| bufferSize += entry->messageLen; |
| } |
| |
| if (defaultBufferSize >= bufferSize) { |
| ret = defaultBuffer; |
| } else { |
| ret = (char*)malloc(bufferSize); |
| |
| if (ret == NULL) { |
| return ret; |
| } |
| } |
| |
| ret[0] = '\0'; /* to start strcat off */ |
| |
| p = ret; |
| pm = entry->message; |
| |
| if (prefixSuffixIsHeaderFooter) { |
| strcat(p, prefixBuf); |
| p += prefixLen; |
| if (p_format->printable_output) { |
| p += convertPrintable(p, entry->message, entry->messageLen); |
| } else { |
| strncat(p, entry->message, entry->messageLen); |
| p += entry->messageLen; |
| } |
| strcat(p, suffixBuf); |
| p += suffixLen; |
| } else { |
| do { |
| const char* lineStart; |
| size_t lineLen; |
| lineStart = pm; |
| |
| /* Find the next end-of-line in message */ |
| while (pm < (entry->message + entry->messageLen) && *pm != '\n') pm++; |
| lineLen = pm - lineStart; |
| |
| strcat(p, prefixBuf); |
| p += prefixLen; |
| if (p_format->printable_output) { |
| p += convertPrintable(p, lineStart, lineLen); |
| } else { |
| strncat(p, lineStart, lineLen); |
| p += lineLen; |
| } |
| strcat(p, suffixBuf); |
| p += suffixLen; |
| |
| if (*pm == '\n') pm++; |
| } while (pm < (entry->message + entry->messageLen)); |
| } |
| |
| if (p_outLength != NULL) { |
| *p_outLength = p - ret; |
| } |
| |
| return ret; |
| } |
| |
| /** |
| * Either print or do not print log line, based on filter |
| * |
| * Returns count bytes written |
| */ |
| |
| LIBLOG_ABI_PUBLIC int android_log_printLogLine(AndroidLogFormat* p_format, |
| int fd, |
| const AndroidLogEntry* entry) { |
| int ret; |
| char defaultBuffer[512]; |
| char* outBuffer = NULL; |
| size_t totalLen; |
| |
| outBuffer = android_log_formatLogLine( |
| p_format, defaultBuffer, sizeof(defaultBuffer), entry, &totalLen); |
| |
| if (!outBuffer) return -1; |
| |
| do { |
| ret = write(fd, outBuffer, totalLen); |
| } while (ret < 0 && errno == EINTR); |
| |
| if (ret < 0) { |
| fprintf(stderr, "+++ LOG: write failed (errno=%d)\n", errno); |
| ret = 0; |
| goto done; |
| } |
| |
| if (((size_t)ret) < totalLen) { |
| fprintf(stderr, "+++ LOG: write partial (%d of %d)\n", ret, (int)totalLen); |
| goto done; |
| } |
| |
| done: |
| if (outBuffer != defaultBuffer) { |
| free(outBuffer); |
| } |
| |
| return ret; |
| } |