liblog/logprint.c

/*
**
** 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);
    LOG_ALWAYS_FATAL_IF(node == list_head(&convertHead), "corrupted list");
    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;
}