From ddea51954259597ce5efd03d3de34fd0fa91d1d3 Mon Sep 17 00:00:00 2001 From: "Justin M. Keyes" Date: Wed, 11 Jul 2018 22:20:32 +0200 Subject: rename: os_get_localtime => os_localtime --- src/nvim/log.c | 2 +- src/nvim/os/time.c | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) (limited to 'src') diff --git a/src/nvim/log.c b/src/nvim/log.c index 7bfe5c4089..ef5b7699af 100644 --- a/src/nvim/log.c +++ b/src/nvim/log.c @@ -262,7 +262,7 @@ static bool v_do_log_to_file(FILE *log_file, int log_level, // format current timestamp in local time struct tm local_time; - if (os_get_localtime(&local_time) == NULL) { + if (os_localtime(&local_time) == NULL) { return false; } char date_time[20]; 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); -- cgit From 4d6a1e5566b73c938e4db35432bc975ca9389deb Mon Sep 17 00:00:00 2001 From: "Justin M. Keyes" Date: Wed, 11 Jul 2018 22:48:53 +0200 Subject: log.c: message format MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - Log-level name (INFO/ERROR/…) should be in the first column, so that filtering by log-level is maximally trivial. - Use 2-digit year. 4-digit year is useless, logs don't survive for decades without context. Before: 2018/07/05 17:49:41 INFO 27596 on_process_exit:393: foo After: INFO 180705.174941 27596 on_process_exit:393: foo --- src/nvim/log.c | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) (limited to 'src') diff --git a/src/nvim/log.c b/src/nvim/log.c index ef5b7699af..3d689db117 100644 --- a/src/nvim/log.c +++ b/src/nvim/log.c @@ -260,25 +260,25 @@ 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_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%d.%H%M%S", &local_time) == 0) { return false; } - // print the log message prefixed by the current timestamp and pid + // 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 %" PRId64 " %s", log_levels[log_level], + date_time, 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 %" PRId64 " %s%s:%d: ", log_levels[log_level], + date_time, pid, (context == NULL ? "" : context), func_name, line_num); if (rv < 0) { -- cgit From 3258c6a2f48b9d290f9a1830766fcf32874f9149 Mon Sep 17 00:00:00 2001 From: "Justin M. Keyes" Date: Wed, 11 Jul 2018 23:50:35 +0200 Subject: log.c: include milliseconds closes #8727 Before: INFO 180711.233956 11124 main:560: starting main loop After: INFO 180711.233956.807 11124 main:560: starting main loop Note: - Can't use uv_hrtime() nor uv_now(), they are not "since the epoch". Also, log.c can't assume a loop exists. --- src/nvim/log.c | 19 +++++++++++++++---- 1 file changed, 15 insertions(+), 4 deletions(-) (limited to 'src') diff --git a/src/nvim/log.c b/src/nvim/log.c index 3d689db117..a83db725ff 100644 --- a/src/nvim/log.c +++ b/src/nvim/log.c @@ -7,6 +7,9 @@ #include #include #include +#if !defined(WIN32) +# include // for gettimeofday() +#endif #include #include "nvim/log.h" @@ -271,14 +274,22 @@ static bool v_do_log_to_file(FILE *log_file, int log_level, return false; } + 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", log_levels[log_level], - date_time, pid, + ? fprintf(log_file, "%s %s.%-3d %" PRId64 " %s", + log_levels[log_level], date_time, millis, pid, (context == NULL ? "?:" : context)) - : fprintf(log_file, "%s %s %" PRId64 " %s%s:%d: ", log_levels[log_level], - date_time, pid, + : fprintf(log_file, "%s %s.%-3d %" PRId64 " %s%s:%d: ", + log_levels[log_level], date_time, millis, pid, (context == NULL ? "" : context), func_name, line_num); if (rv < 0) { -- cgit From ef86aad8783b7e38e0dfa4c6d4e3f652206ab22b Mon Sep 17 00:00:00 2001 From: "Justin M. Keyes" Date: Tue, 17 Jul 2018 22:05:21 +0200 Subject: log.c: ISO 8601 date/time After: INFO 2018-07-17T22:05:46.175 656 main:560: starting main loop --- src/nvim/log.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'src') diff --git a/src/nvim/log.c b/src/nvim/log.c index a83db725ff..289b95b227 100644 --- a/src/nvim/log.c +++ b/src/nvim/log.c @@ -269,7 +269,7 @@ static bool v_do_log_to_file(FILE *log_file, int log_level, 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; } -- cgit From 27dc42160fa2acbc3e5894068f28808c70ca3f44 Mon Sep 17 00:00:00 2001 From: "Justin M. Keyes" Date: Wed, 25 Jul 2018 15:29:57 +0200 Subject: log.c: format: padding - milliseconds: leading zeroes - PID: whitespace padding --- src/nvim/log.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'src') diff --git a/src/nvim/log.c b/src/nvim/log.c index 289b95b227..e485d4c338 100644 --- a/src/nvim/log.c +++ b/src/nvim/log.c @@ -285,10 +285,10 @@ static bool v_do_log_to_file(FILE *log_file, int log_level, // Print the log message. int64_t pid = os_get_pid(); int rv = (line_num == -1 || func_name == NULL) - ? fprintf(log_file, "%s %s.%-3d %" PRId64 " %s", + ? 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.%-3d %" PRId64 " %s%s:%d: ", + : 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); -- cgit