Merge #8729 'log: milliseconds, format'

2 files changed, 21 insertions, 10 deletions

diff --git a/src/nvim/log.c b/src/nvim/log.c
index 7bfe5c4089..e485d4c338 100644
--- a/src/nvim/log.c
+++ b/src/nvim/log.c
@@ -7,6 +7,9 @@
 #include <stdbool.h>
 #include <stdint.h>
 #include <stdio.h>
+#if !defined(WIN32)
+# include <sys/time.h>  // for gettimeofday()
+#endif
 #include <uv.h>
 
 #include "nvim/log.h"
@@ -260,25 +263,33 @@ static bool v_do_log_to_file(FILE *log_file, int log_level,
   };
   assert(log_level >= DEBUG_LOG_LEVEL && log_level <= ERROR_LOG_LEVEL);
 
-  // format current timestamp in local time
+  // Format the timestamp.
   struct tm local_time;
-  if (os_get_localtime(&local_time) == NULL) {
+  if (os_localtime(&local_time) == NULL) {
     return false;
   }
   char date_time[20];
-  if (strftime(date_time, sizeof(date_time), "%Y/%m/%d %H:%M:%S",
+  if (strftime(date_time, sizeof(date_time), "%Y-%m-%dT%H:%M:%S",
                &local_time) == 0) {
     return false;
   }
 
-  // print the log message prefixed by the current timestamp and pid
+  int millis = 0;
+#if !defined(WIN32)
+  struct timeval curtime;
+  if (gettimeofday(&curtime, NULL) == 0) {
+    millis = (int)curtime.tv_usec / 1000;
+  }
+#endif
+
+  // Print the log message.
   int64_t pid = os_get_pid();
   int rv = (line_num == -1 || func_name == NULL)
-    ? fprintf(log_file, "%s %s %" PRId64 " %s", date_time,
-              log_levels[log_level], pid,
+    ? fprintf(log_file, "%s %s.%03d %-5" PRId64 " %s",
+              log_levels[log_level], date_time, millis, pid,
               (context == NULL ? "?:" : context))
-    : fprintf(log_file, "%s %s %" PRId64 " %s%s:%d: ", date_time,
-              log_levels[log_level], pid,
+    : fprintf(log_file, "%s %s.%03d %-5" PRId64 " %s%s:%d: ",
+              log_levels[log_level], date_time, millis, pid,
               (context == NULL ? "" : context),
               func_name, line_num);
   if (rv < 0) {
diff --git a/src/nvim/os/time.c b/src/nvim/os/time.c
index 290d421acc..31ef1a0cd6 100644
--- a/src/nvim/os/time.c
+++ b/src/nvim/os/time.c
@@ -114,12 +114,12 @@ struct tm *os_localtime_r(const time_t *restrict clock,
 #endif
 }
 
-/// Obtains the current Unix timestamp and adjusts it to local time.
+/// Gets the current Unix timestamp and adjusts it to local time.
 ///
 /// @param result Pointer to a 'struct tm' where the result should be placed
 /// @return A pointer to a 'struct tm' in the current time zone (the 'result'
 ///         argument) or NULL in case of error
-struct tm *os_get_localtime(struct tm *result) FUNC_ATTR_NONNULL_ALL
+struct tm *os_localtime(struct tm *result) FUNC_ATTR_NONNULL_ALL
 {
   time_t rawtime = time(NULL);
   return os_localtime_r(&rawtime, result);