From e3dc4a0a40490e69ffb74ccc8b48039057f82361 Mon Sep 17 00:00:00 2001
From: Dima Kogan <Dmitriy.Kogan@jpl.nasa.gov>
Date: Tue, 18 Jul 2023 17:23:25 -0700
Subject: [PATCH] EVR output: we print 6 digits worth of microseconds

This avoids a pernicious behavior where EVR timestamps lie about their
sub-second values. I have this test program:

  #include <stdio.h>
  #include <inttypes.h>
  void main(void)
  {
      printf("%02d:%02d:%02d.%03" PRIu32 "\n", 1,2,3, 12);
      printf("%02d:%02d:%02d.%03" PRIu32 "\n", 1,2,3, 123);
      printf("%02d:%02d:%02d.%03" PRIu32 "\n", 1,2,3, 1234);
      printf("%02d:%02d:%02d.%03" PRIu32 "\n", 1,2,3, 12356);
      printf("%02d:%02d:%02d.%03" PRIu32 "\n", 1,2,3, 123456);
  }

It produces this output:

  01:02:03.012
  01:02:03.123
  01:02:03.1234
  01:02:03.12356
  01:02:03.123456

so prior to this patch, if we were 1 hour, 2 minutes, 3 seconds, 123
microseconds past midnight, this was printed as "01:02:03.123" instead of
"01:02:03.000123". Any reasonable human looking at "01:02:03.123" would see a
value of "123000" microseconds.
---
 Svc/ActiveTextLogger/ActiveTextLoggerImpl.cpp | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/Svc/ActiveTextLogger/ActiveTextLoggerImpl.cpp b/Svc/ActiveTextLogger/ActiveTextLoggerImpl.cpp
index 5daa9318e0..0961813ea1 100644
--- a/Svc/ActiveTextLogger/ActiveTextLoggerImpl.cpp
+++ b/Svc/ActiveTextLogger/ActiveTextLoggerImpl.cpp
@@ -94,7 +94,7 @@ namespace Svc {
 
             (void) snprintf(textStr,
                             FW_INTERNAL_INTERFACE_STRING_MAX_SIZE,
-                            "EVENT: (%" PRI_FwEventIdType ") (%04d-%02d-%02dT%02d:%02d:%02d.%03" PRIu32 ") %s: %s\n",
+                            "EVENT: (%" PRI_FwEventIdType ") (%04d-%02d-%02dT%02d:%02d:%02d.%06" PRIu32 ") %s: %s\n",
                             id, tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday, tm.tm_hour,
                             tm.tm_min,tm.tm_sec,timeTag.getUSeconds(),
                             severityString,text.toChar());