Format timestamp with 6 decimals

3 files changed, 44 insertions, 54 deletions

diff --git a/jdisc_core/src/main/java/com/yahoo/jdisc/core/ConsoleLogFormatter.java b/jdisc_core/src/main/java/com/yahoo/jdisc/core/ConsoleLogFormatter.java
index efe051a628f..137d0aec26b 100644
--- a/jdisc_core/src/main/java/com/yahoo/jdisc/core/ConsoleLogFormatter.java
+++ b/jdisc_core/src/main/java/com/yahoo/jdisc/core/ConsoleLogFormatter.java
@@ -9,6 +9,7 @@ import org.osgi.service.log.LogService;
 import java.io.PrintWriter;
 import java.io.StringWriter;
 import java.io.Writer;
+import java.time.Instant;
 
 /**
  * @author Simon Thoresen Hult
@@ -44,21 +45,8 @@ class ConsoleLogFormatter {
     // TODO: The non-functional, side effect-laden coding style here is ugly and makes testing hard. See ticket 7128315.
 
     private StringBuilder formatTime(LogEntry entry, StringBuilder out) {
-        String str = Long.toString(Long.MAX_VALUE & entry.getTime()); // remove sign bit for good measure
-        int len = str.length();
-        if (len > 3) {
-            out.append(str, 0, len - 3);
-        } else {
-            out.append('0');
-        }
-        out.append('.');
-        if (len > 2) {
-            out.append(str, len - 3, len);
-        } else if (len == 2) {
-            out.append('0').append(str, len - 2, len); // should never happen
-        } else if (len == 1) {
-            out.append("00").append(str, len - 1, len); // should never happen
-        }
+        Instant instant = Instant.ofEpochMilli(entry.getTime());
+        out.append(String.format("%d.%06d", instant.getEpochSecond(), instant.getNano() / 1000));
         return out;
     }
 
diff --git a/jdisc_core/src/test/java/com/yahoo/jdisc/core/ConsoleLogFormatterTestCase.java b/jdisc_core/src/test/java/com/yahoo/jdisc/core/ConsoleLogFormatterTestCase.java
index 54809897084..402c946b77e 100644
--- a/jdisc_core/src/test/java/com/yahoo/jdisc/core/ConsoleLogFormatterTestCase.java
+++ b/jdisc_core/src/test/java/com/yahoo/jdisc/core/ConsoleLogFormatterTestCase.java
@@ -11,6 +11,7 @@ import org.osgi.service.log.LogService;
 import java.io.PrintWriter;
 import java.io.StringWriter;
 import java.io.Writer;
+import java.time.Instant;
 
 import static org.junit.Assert.assertEquals;
 
@@ -29,89 +30,90 @@ public class ConsoleLogFormatterTestCase {
     public void requireThatMillisecondsArePadded() {
         for (int i = 0; i < 10000; ++i) {
             LogEntry entry = new MyEntry(i, 0, null);
-            assertEquals(String.format("%d.%03d\t-\t-\t-\t-\tunknown\t", i / 1000, i % 1000),
+            Instant instant = Instant.ofEpochMilli(i);
+            assertEquals(String.format("%d.%06d\t-\t-\t-\t-\tunknown\t", instant.getEpochSecond(), instant.getNano() / 1000),
                          SIMPLE_FORMATTER.formatEntry(entry));
         }
     }
 
     @Test
     public void requireThatHostNameIsIncluded() {
-        assertEquals("0.000\thostName\t-\t-\t-\tunknown\t",
+        assertEquals("0.000000\thostName\t-\t-\t-\tunknown\t",
                      new ConsoleLogFormatter("hostName", null, null).formatEntry(SIMPLE_ENTRY));
     }
 
     @Test
     public void requireThatHostNameIsOptional() {
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t",
                      new ConsoleLogFormatter(null, null, null).formatEntry(SIMPLE_ENTRY));
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t",
                      new ConsoleLogFormatter("", null, null).formatEntry(SIMPLE_ENTRY));
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t",
                      new ConsoleLogFormatter(" ", null, null).formatEntry(SIMPLE_ENTRY));
     }
 
     @Test
     public void requireThatProcessIdIsIncluded() {
-        assertEquals("0.000\t-\tprocessId\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\tprocessId\t-\t-\tunknown\t",
                      new ConsoleLogFormatter(null, "processId", null).formatEntry(SIMPLE_ENTRY));
     }
 
     @Test
     public void requireThatProcessIdIsOptional() {
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t",
                      new ConsoleLogFormatter(null, null, null).formatEntry(SIMPLE_ENTRY));
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t",
                      new ConsoleLogFormatter(null, "", null).formatEntry(SIMPLE_ENTRY));
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t",
                      new ConsoleLogFormatter(null, " ", null).formatEntry(SIMPLE_ENTRY));
     }
 
     @Test
     public void requireThatProcessIdIncludesThreadIdWhenAvailable() {
         LogEntry entry = new MyEntry(0, 0, null).putProperty("THREAD_ID", "threadId");
-        assertEquals("0.000\t-\tprocessId/threadId\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\tprocessId/threadId\t-\t-\tunknown\t",
                      new ConsoleLogFormatter(null, "processId", null).formatEntry(entry));
     }
 
     @Test
     public void requireThatServiceNameIsIncluded() {
-        assertEquals("0.000\t-\t-\tserviceName\t-\tunknown\t",
+        assertEquals("0.000000\t-\t-\tserviceName\t-\tunknown\t",
                      new ConsoleLogFormatter(null, null, "serviceName").formatEntry(SIMPLE_ENTRY));
     }
 
     @Test
     public void requireThatServiceNameIsOptional() {
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t",
                      new ConsoleLogFormatter(null, null, null).formatEntry(SIMPLE_ENTRY));
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t",
                      new ConsoleLogFormatter(null, null, "").formatEntry(SIMPLE_ENTRY));
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t",
                      new ConsoleLogFormatter(null, null, " ").formatEntry(SIMPLE_ENTRY));
     }
 
     @Test
     public void requireThatBundleNameIsIncluded() {
         LogEntry entry = new MyEntry(0, 0, null).setBundleSymbolicName("bundleName");
-        assertEquals("0.000\t-\t-\t-\tbundleName\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\tbundleName\tunknown\t",
                      SIMPLE_FORMATTER.formatEntry(entry));
     }
 
     @Test
     public void requireThatBundleNameIsOptional() {
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t",
                      SIMPLE_FORMATTER.formatEntry(SIMPLE_ENTRY));
     }
 
     @Test
     public void requireThatLoggerNameIsIncluded() {
         LogEntry entry = new MyEntry(0, 0, null).putProperty("LOGGER_NAME", "loggerName");
-        assertEquals("0.000\t-\t-\t-\t/loggerName\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\t/loggerName\tunknown\t",
                      SIMPLE_FORMATTER.formatEntry(entry));
     }
 
     @Test
     public void requireThatLoggerNameIsOptional() {
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t",
                      SIMPLE_FORMATTER.formatEntry(SIMPLE_ENTRY));
     }
 
@@ -119,43 +121,43 @@ public class ConsoleLogFormatterTestCase {
     public void requireThatBundleAndLoggerNameIsCombined() {
         LogEntry entry = new MyEntry(0, 0, null).setBundleSymbolicName("bundleName")
                                                 .putProperty("LOGGER_NAME", "loggerName");
-        assertEquals("0.000\t-\t-\t-\tbundleName/loggerName\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\tbundleName/loggerName\tunknown\t",
                      SIMPLE_FORMATTER.formatEntry(entry));
     }
 
     @Test
     public void requireThatLevelNameIsIncluded() {
         ConsoleLogFormatter formatter = SIMPLE_FORMATTER;
-        assertEquals("0.000\t-\t-\t-\t-\terror\t",
+        assertEquals("0.000000\t-\t-\t-\t-\terror\t",
                      formatter.formatEntry(new MyEntry(0, LogService.LOG_ERROR, null)));
-        assertEquals("0.000\t-\t-\t-\t-\twarning\t",
+        assertEquals("0.000000\t-\t-\t-\t-\twarning\t",
                      formatter.formatEntry(new MyEntry(0, LogService.LOG_WARNING, null)));
-        assertEquals("0.000\t-\t-\t-\t-\tinfo\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tinfo\t",
                      formatter.formatEntry(new MyEntry(0, LogService.LOG_INFO, null)));
-        assertEquals("0.000\t-\t-\t-\t-\tdebug\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tdebug\t",
                      formatter.formatEntry(new MyEntry(0, LogService.LOG_DEBUG, null)));
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t",
                      formatter.formatEntry(new MyEntry(0, 69, null)));
     }
 
     @Test
     public void requireThatMessageIsIncluded() {
         LogEntry entry = new MyEntry(0, 0, "message");
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\tmessage",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\tmessage",
                      SIMPLE_FORMATTER.formatEntry(entry));
     }
 
     @Test
     public void requireThatMessageIsOptional() {
         LogEntry entry = new MyEntry(0, 0, null);
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t",
                      SIMPLE_FORMATTER.formatEntry(entry));
     }
 
     @Test
     public void requireThatMessageIsEscaped() {
         LogEntry entry = new MyEntry(0, 0, "\\\n\r\t");
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t\\\\\\n\\r\\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t\\\\\\n\\r\\t",
                      SIMPLE_FORMATTER.formatEntry(entry));
     }
 
@@ -163,7 +165,7 @@ public class ConsoleLogFormatterTestCase {
     public void requireThatExceptionIsIncluded() {
         Throwable t = new Throwable();
         LogEntry entry = new MyEntry(0, 0, null).setException(t);
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t\\n" + formatThrowable(t),
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t\\n" + formatThrowable(t),
                      SIMPLE_FORMATTER.formatEntry(entry));
     }
 
@@ -171,7 +173,7 @@ public class ConsoleLogFormatterTestCase {
     public void requireThatExceptionIsEscaped() {
         Throwable t = new Throwable("\\\n\r\t");
         LogEntry entry = new MyEntry(0, 0, null).setException(t);
-        assertEquals("0.000\t-\t-\t-\t-\tunknown\t\\n" + formatThrowable(t),
+        assertEquals("0.000000\t-\t-\t-\t-\tunknown\t\\n" + formatThrowable(t),
                      SIMPLE_FORMATTER.formatEntry(entry));
     }
 
@@ -179,7 +181,7 @@ public class ConsoleLogFormatterTestCase {
     public void requireThatExceptionIsSimplifiedForInfoEntries() {
         Throwable t = new Throwable("exception");
         LogEntry entry = new MyEntry(0, LogService.LOG_INFO, "entry").setException(t);
-        assertEquals("0.000\t-\t-\t-\t-\tinfo\tentry: exception",
+        assertEquals("0.000000\t-\t-\t-\t-\tinfo\tentry: exception",
                      SIMPLE_FORMATTER.formatEntry(entry));
     }
 
@@ -187,7 +189,7 @@ public class ConsoleLogFormatterTestCase {
     public void requireThatSimplifiedExceptionIsEscaped() {
         Throwable t = new Throwable("\\\n\r\t");
         LogEntry entry = new MyEntry(0, LogService.LOG_INFO, "entry").setException(t);
-        assertEquals("0.000\t-\t-\t-\t-\tinfo\tentry: \\\\\\n\\r\\t",
+        assertEquals("0.000000\t-\t-\t-\t-\tinfo\tentry: \\\\\\n\\r\\t",
                      SIMPLE_FORMATTER.formatEntry(entry));
     }
 
@@ -195,7 +197,7 @@ public class ConsoleLogFormatterTestCase {
     public void requireThatSimplifiedExceptionMessageIsOptional() {
         Throwable t = new Throwable();
         LogEntry entry = new MyEntry(0, LogService.LOG_INFO, "entry").setException(t);
-        assertEquals("0.000\t-\t-\t-\t-\tinfo\tentry: java.lang.Throwable",
+        assertEquals("0.000000\t-\t-\t-\t-\tinfo\tentry: java.lang.Throwable",
                      SIMPLE_FORMATTER.formatEntry(entry));
     }
 
diff --git a/jdisc_core/src/test/java/com/yahoo/jdisc/core/ConsoleLogListenerTestCase.java b/jdisc_core/src/test/java/com/yahoo/jdisc/core/ConsoleLogListenerTestCase.java
index 7bdc3a4b985..4aaa6530030 100644
--- a/jdisc_core/src/test/java/com/yahoo/jdisc/core/ConsoleLogListenerTestCase.java
+++ b/jdisc_core/src/test/java/com/yahoo/jdisc/core/ConsoleLogListenerTestCase.java
@@ -14,7 +14,7 @@ import java.io.PrintStream;
 import static org.junit.Assert.assertEquals;
 
 /**
- * @author <a href="mailto:vikasp@yahoo-inc.com">Vikas Panwar</a>
+ * @author Vikas Panwar
  */
 public class ConsoleLogListenerTestCase {
 
@@ -61,12 +61,12 @@ public class ConsoleLogListenerTestCase {
             listener.logged(new MyEntry(0, i, "message"));
         }
         // TODO: Should use ConsoleLogFormatter.ABSENCE_REPLACEMENT instead of literal '-'. See ticket 7128315.
-        assertEquals("0.000\t" + HOSTNAME + "\t" + PROCESS_ID + "\t-\t-\tunknown\tmessage\n" +
-                     "0.000\t" + HOSTNAME + "\t" + PROCESS_ID + "\t-\t-\terror\tmessage\n" +
-                     "0.000\t" + HOSTNAME + "\t" + PROCESS_ID + "\t-\t-\twarning\tmessage\n" +
-                     "0.000\t" + HOSTNAME + "\t" + PROCESS_ID + "\t-\t-\tinfo\tmessage\n" +
-                     "0.000\t" + HOSTNAME + "\t" + PROCESS_ID + "\t-\t-\tdebug\tmessage\n" +
-                     "0.000\t" + HOSTNAME + "\t" + PROCESS_ID + "\t-\t-\tunknown\tmessage\n",
+        assertEquals("0.000000\t" + HOSTNAME + "\t" + PROCESS_ID + "\t-\t-\tunknown\tmessage\n" +
+                     "0.000000\t" + HOSTNAME + "\t" + PROCESS_ID + "\t-\t-\terror\tmessage\n" +
+                     "0.000000\t" + HOSTNAME + "\t" + PROCESS_ID + "\t-\t-\twarning\tmessage\n" +
+                     "0.000000\t" + HOSTNAME + "\t" + PROCESS_ID + "\t-\t-\tinfo\tmessage\n" +
+                     "0.000000\t" + HOSTNAME + "\t" + PROCESS_ID + "\t-\t-\tdebug\tmessage\n" +
+                     "0.000000\t" + HOSTNAME + "\t" + PROCESS_ID + "\t-\t-\tunknown\tmessage\n",
                      out.toString());
     }