From f28f6a9ba228803b402ebaccb59f1b2f2fd4af92 Mon Sep 17 00:00:00 2001 From: Mark Salyzyn <salyzyn@google.com> Date: Mon, 31 Aug 2015 08:01:33 -0700 Subject: [PATCH] liblog: logcat: Add year and zone to date on each line - '-v year' modifier adds the four digit year prefix - '-v <timezone>' modifier sets and prints the timezone suffix - Only promise in logcat to support UTC as a timezone since all others are based on the configured environment - '-v zone' modifier toggles the timezone suffix on or off - '-T YYYY-MM-DD HH:MM:SS.mmm...' format is added Bug: 23668700 Change-Id: I7521c1efb7455dc9a25434fce72a69a65dcf72ea --- include/log/logprint.h | 4 +- liblog/logprint.c | 68 +++++++++++++++++++++++++---- logcat/logcat.cpp | 23 ++++++---- logcat/tests/logcat_test.cpp | 84 ++++++++++++++++++++++++++++++++++++ 4 files changed, 162 insertions(+), 17 deletions(-) diff --git a/include/log/logprint.h b/include/log/logprint.h index 4b812cc94..26b1ee5a1 100644 --- a/include/log/logprint.h +++ b/include/log/logprint.h @@ -36,10 +36,12 @@ typedef enum { FORMAT_TIME, FORMAT_THREADTIME, FORMAT_LONG, - /* The following three are modifiers to above formats */ + /* The following are modifiers to above formats */ FORMAT_MODIFIER_COLOR, /* converts priority to color */ FORMAT_MODIFIER_TIME_USEC, /* switches from msec to usec time precision */ FORMAT_MODIFIER_PRINTABLE, /* converts non-printable to printable escapes */ + FORMAT_MODIFIER_YEAR, /* Adds year to date */ + FORMAT_MODIFIER_ZONE, /* Adds zone to date */ } AndroidLogPrintFormat; typedef struct AndroidLogFormat_t AndroidLogFormat; diff --git a/liblog/logprint.c b/liblog/logprint.c index c2f1545eb..97e28fdaf 100644 --- a/liblog/logprint.c +++ b/liblog/logprint.c @@ -48,6 +48,8 @@ struct AndroidLogFormat_t { bool colored_output; bool usec_time_output; bool printable_output; + bool year_output; + bool zone_output; }; /* @@ -192,6 +194,8 @@ AndroidLogFormat *android_log_format_new() p_ret->colored_output = false; p_ret->usec_time_output = false; p_ret->printable_output = false; + p_ret->year_output = false; + p_ret->zone_output = false; return p_ret; } @@ -227,6 +231,12 @@ int android_log_setPrintFormat(AndroidLogFormat *p_format, 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; default: break; } @@ -234,6 +244,9 @@ int android_log_setPrintFormat(AndroidLogFormat *p_format, return 1; } +static const char tz[] = "TZ"; +static const char utc[] = "UTC"; + /** * Returns FORMAT_OFF on invalid string */ @@ -252,7 +265,39 @@ AndroidLogPrintFormat android_log_formatFromString(const char * formatString) else if (strcmp(formatString, "color") == 0) format = FORMAT_MODIFIER_COLOR; else if (strcmp(formatString, "usec") == 0) format = FORMAT_MODIFIER_TIME_USEC; else if (strcmp(formatString, "printable") == 0) format = FORMAT_MODIFIER_PRINTABLE; - else format = FORMAT_OFF; + else if (strcmp(formatString, "year") == 0) format = FORMAT_MODIFIER_YEAR; + else if (strcmp(formatString, "zone") == 0) format = FORMAT_MODIFIER_ZONE; + 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); + } return format; } @@ -887,7 +932,7 @@ char *android_log_formatLogLine ( struct tm tmBuf; #endif struct tm* ptm; - char timeBuf[32]; /* good margin, 23+nul for msec, 26+nul for usec */ + char timeBuf[64]; /* good margin, 23+nul for msec, 26+nul for usec */ char prefixBuf[128], suffixBuf[128]; char priChar; int prefixSuffixIsHeaderFooter = 0; @@ -905,21 +950,28 @@ char *android_log_formatLogLine ( * 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. */ #if !defined(_WIN32) ptm = localtime_r(&(entry->tv_sec), &tmBuf); #else ptm = localtime(&(entry->tv_sec)); #endif - /* strftime(timeBuf, sizeof(timeBuf), "%Y-%m-%d %H:%M:%S", ptm); */ - strftime(timeBuf, sizeof(timeBuf), "%m-%d %H:%M:%S", ptm); + strftime(timeBuf, sizeof(timeBuf), + &"%Y-%m-%d %H:%M:%S"[p_format->year_output ? 0 : 3], + ptm); len = strlen(timeBuf); if (p_format->usec_time_output) { - snprintf(timeBuf + len, sizeof(timeBuf) - len, - ".%06ld", entry->tv_nsec / 1000); + len += snprintf(timeBuf + len, sizeof(timeBuf) - len, + ".%06ld", entry->tv_nsec / 1000); } else { - snprintf(timeBuf + len, sizeof(timeBuf) - len, - ".%03ld", entry->tv_nsec / 1000000); + len += snprintf(timeBuf + len, sizeof(timeBuf) - len, + ".%03ld", entry->tv_nsec / 1000000); + } + if (p_format->zone_output) { + strftime(timeBuf + len, sizeof(timeBuf) - len, " %z", ptm); } /* diff --git a/logcat/logcat.cpp b/logcat/logcat.cpp index e598bb810..9440b6841 100644 --- a/logcat/logcat.cpp +++ b/logcat/logcat.cpp @@ -260,7 +260,7 @@ static void show_help(const char *cmd) " -n <count> Sets max number of rotated logs to <count>, default 4\n" " -v <format> Sets the log print format, where <format> is:\n\n" " brief color long printable process raw tag thread\n" - " threadtime time usec\n\n" + " threadtime time usec UTC year zone\n\n" " -D print dividers between each log buffer\n" " -c clear (flush) the entire log and exit\n" " -d dump the log and then exit (don't block)\n" @@ -268,7 +268,8 @@ static void show_help(const char *cmd) " -t '<time>' print most recent lines since specified time (implies -d)\n" " -T <count> print only the most recent <count> lines (does not imply -d)\n" " -T '<time>' print most recent lines since specified time (not imply -d)\n" - " count is pure numerical, time is 'MM-DD hh:mm:ss.mmm'\n" + " count is pure numerical, time is 'MM-DD hh:mm:ss.mmm...'\n" + " or 'YYYY-MM-DD hh:mm:ss.mmm...' format\n" " -g get the size of the log's ring buffer and exit\n" " -L dump logs from prior to last reboot\n" " -b <buffer> Request alternate ring buffer, 'main', 'system', 'radio',\n" @@ -377,7 +378,14 @@ static void logcat_panic(bool showHelp, const char *fmt, ...) exit(EXIT_FAILURE); } -static const char g_defaultTimeFormat[] = "%m-%d %H:%M:%S.%q"; +static char *parseTime(log_time &t, const char *cp) { + + char *ep = t.strptime(cp, "%m-%d %H:%M:%S.%q"); + if (ep) { + return ep; + } + return t.strptime(cp, "%Y-%m-%d %H:%M:%S.%q"); +} // Find last logged line in gestalt of all matching existing output files static log_time lastLogTime(char *outputFileName) { @@ -423,7 +431,7 @@ static log_time lastLogTime(char *outputFileName) { bool found = false; for (const auto& line : android::base::Split(file, "\n")) { log_time t(log_time::EPOCH); - char *ep = t.strptime(line.c_str(), g_defaultTimeFormat); + char *ep = parseTime(t, line.c_str()); if (!ep || (*ep != ' ')) { continue; } @@ -522,11 +530,10 @@ int main(int argc, char **argv) /* FALLTHRU */ case 'T': if (strspn(optarg, "0123456789") != strlen(optarg)) { - char *cp = tail_time.strptime(optarg, g_defaultTimeFormat); + char *cp = parseTime(tail_time, optarg); if (!cp) { - logcat_panic(false, - "-%c \"%s\" not in \"%s\" time format\n", - ret, optarg, g_defaultTimeFormat); + logcat_panic(false, "-%c \"%s\" not in time format\n", + ret, optarg); } if (*cp) { char c = *cp; diff --git a/logcat/tests/logcat_test.cpp b/logcat/tests/logcat_test.cpp index de2db674d..bcf8d82b6 100644 --- a/logcat/tests/logcat_test.cpp +++ b/logcat/tests/logcat_test.cpp @@ -72,6 +72,90 @@ TEST(logcat, buckets) { EXPECT_EQ(4, count); } +TEST(logcat, year) { + FILE *fp; + + char needle[32]; + time_t now; + time(&now); + struct tm *ptm; +#if !defined(_WIN32) + struct tm tmBuf; + ptm = localtime_r(&now, &tmBuf); +#else + ptm = localtime(&&now); +#endif + strftime(needle, sizeof(needle), "[ %Y-", ptm); + + ASSERT_TRUE(NULL != (fp = popen( + "logcat -v long -v year -b all -t 3 2>/dev/null", + "r"))); + + char buffer[5120]; + + int count = 0; + + while (fgets(buffer, sizeof(buffer), fp)) { + if (!strncmp(buffer, needle, strlen(needle))) { + ++count; + } + } + + pclose(fp); + + ASSERT_EQ(3, count); +} + +TEST(logcat, tz) { + FILE *fp; + + ASSERT_TRUE(NULL != (fp = popen( + "logcat -v long -v America/Los_Angeles -b all -t 3 2>/dev/null", + "r"))); + + char buffer[5120]; + + int count = 0; + + while (fgets(buffer, sizeof(buffer), fp)) { + if ((buffer[0] == '[') && (buffer[1] == ' ') + && isdigit(buffer[2]) && isdigit(buffer[3]) + && (buffer[4] == '-') + && (strstr(buffer, " -0700 ") || strstr(buffer, " -0800 "))) { + ++count; + } + } + + pclose(fp); + + ASSERT_EQ(3, count); +} + +TEST(logcat, ntz) { + FILE *fp; + + ASSERT_TRUE(NULL != (fp = popen( + "logcat -v long -v America/Los_Angeles -v zone -b all -t 3 2>/dev/null", + "r"))); + + char buffer[5120]; + + int count = 0; + + while (fgets(buffer, sizeof(buffer), fp)) { + if ((buffer[0] == '[') && (buffer[1] == ' ') + && isdigit(buffer[2]) && isdigit(buffer[3]) + && (buffer[4] == '-') + && (strstr(buffer, " -0700 ") || strstr(buffer, " -0800 "))) { + ++count; + } + } + + pclose(fp); + + ASSERT_EQ(0, count); +} + TEST(logcat, tail_3) { FILE *fp;