From 39888aef136da3334dbdd86e18b92733c7795e81 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

(cherry pick from commit f28f6a9ba228803b402ebaccb59f1b2f2fd4af92)

- '-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 3d05d8ffc..54cbc20ee 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 9455d870e..610a6ec70 100644
--- a/logcat/tests/logcat_test.cpp
+++ b/logcat/tests/logcat_test.cpp
@@ -74,6 +74,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;