From d82140de52a11378af352900aca30e5b46a71975 Mon Sep 17 00:00:00 2001 From: Timothy Stack Date: Mon, 4 Apr 2022 09:14:57 -0700 Subject: [PATCH] [date-time-scanner] fix generating with a user-defined format Fixes #967 --- NEWS | 2 ++ src/base/date_time_scanner.cc | 44 ++++++++++++++++++++++++++++++---- src/base/date_time_scanner.hh | 5 +++- src/base/time_util.hh | 6 +++++ src/logfile_sub_source.cc | 28 +++++++++++++++------- test/test_date_time_scanner.cc | 23 ++++++++++++++++-- test/test_logfile.sh | 9 +++++++ 7 files changed, 101 insertions(+), 16 deletions(-) diff --git a/NEWS b/NEWS index 4d159f26..9706864a 100644 --- a/NEWS +++ b/NEWS @@ -7,6 +7,8 @@ lnav v0.10.2: * Added a 'language' column to the lnav_view_filters table that specifies the language of the 'pattern' column, either 'regex' or 'sql'. + * Timestamps that do not have a day or month are rewritten to a + full timestamp like YYYY-MM-DD HH:MM:SS. Fixes: * Toggling enabled/disabled filters when there is a SQL expression diff --git a/src/base/date_time_scanner.cc b/src/base/date_time_scanner.cc index ef05558a..889bf0f5 100644 --- a/src/base/date_time_scanner.cc +++ b/src/base/date_time_scanner.cc @@ -35,11 +35,29 @@ #include "ptimec.hh" size_t -date_time_scanner::ftime(char* dst, size_t len, const exttm& tm) const +date_time_scanner::ftime(char* dst, + size_t len, + const char* const time_fmt[], + const exttm& tm) const { off_t off = 0; - PTIMEC_FORMATS[this->dts_fmt_lock].pf_ffunc(dst, off, len, tm); + if (time_fmt == nullptr) { + PTIMEC_FORMATS[this->dts_fmt_lock].pf_ffunc(dst, off, len, tm); + if (tm.et_flags & ETF_MILLIS_SET) { + dst[off++] = '.'; + ftime_L(dst, off, len, tm); + } else if (tm.et_flags & ETF_MICROS_SET) { + dst[off++] = '.'; + ftime_f(dst, off, len, tm); + } else if (tm.et_flags & ETF_NANOS_SET) { + dst[off++] = '.'; + ftime_N(dst, off, len, tm); + } + dst[off] = '\0'; + } else { + off = ftime_fmt(dst, len, time_fmt[this->dts_fmt_lock], tm); + } return (size_t) off; } @@ -196,13 +214,29 @@ date_time_scanner::scan(const char* time_dest, if (retval[0] == '.' || retval[0] == ',') { off_t off = (retval - time_dest) + 1; - if (ptime_f(tm_out, time_dest, off, time_len)) { - tv_out.tv_usec = tm_out->et_nsec / 1000; + if (ptime_N(tm_out, time_dest, off, time_len)) { + tv_out.tv_usec + = std::chrono::duration_cast( + std::chrono::nanoseconds{tm_out->et_nsec}) + .count(); + this->dts_fmt_len += 10; + tm_out->et_flags |= ETF_NANOS_SET; + retval += 10; + } else if (ptime_f(tm_out, time_dest, off, time_len)) { + tv_out.tv_usec + = std::chrono::duration_cast( + std::chrono::nanoseconds{tm_out->et_nsec}) + .count(); this->dts_fmt_len += 7; + tm_out->et_flags |= ETF_MICROS_SET; retval += 7; } else if (ptime_L(tm_out, time_dest, off, time_len)) { - tv_out.tv_usec = tm_out->et_nsec / 1000; + tv_out.tv_usec + = std::chrono::duration_cast( + std::chrono::nanoseconds{tm_out->et_nsec}) + .count(); this->dts_fmt_len += 4; + tm_out->et_flags |= ETF_MILLIS_SET; retval += 4; } } diff --git a/src/base/date_time_scanner.hh b/src/base/date_time_scanner.hh index 64da04b2..536ec235 100644 --- a/src/base/date_time_scanner.hh +++ b/src/base/date_time_scanner.hh @@ -103,7 +103,10 @@ struct date_time_scanner { struct timeval& tv_out, bool convert_local = true); - size_t ftime(char* dst, size_t len, const struct exttm& tm) const; + size_t ftime(char* dst, + size_t len, + const char* const time_fmt[], + const struct exttm& tm) const; bool convert_to_timeval(const char* time_src, ssize_t time_len, diff --git a/src/base/time_util.hh b/src/base/time_util.hh index 9fcb0386..4b5c1bc6 100644 --- a/src/base/time_util.hh +++ b/src/base/time_util.hh @@ -75,6 +75,9 @@ enum exttm_bits_t { ETB_DAY_SET, ETB_MACHINE_ORIENTED, ETB_EPOCH_TIME, + ETB_MILLIS_SET, + ETB_MICROS_SET, + ETB_NANOS_SET, }; enum exttm_flags_t { @@ -83,6 +86,9 @@ enum exttm_flags_t { ETF_DAY_SET = (1UL << ETB_DAY_SET), ETF_MACHINE_ORIENTED = (1UL << ETB_MACHINE_ORIENTED), ETF_EPOCH_TIME = (1UL << ETB_EPOCH_TIME), + ETF_MILLIS_SET = (1UL << ETB_MILLIS_SET), + ETF_MICROS_SET = (1UL << ETB_MICROS_SET), + ETF_NANOS_SET = (1UL << ETB_NANOS_SET), }; struct exttm { diff --git a/src/logfile_sub_source.cc b/src/logfile_sub_source.cc index 738bfce5..a8b84ff3 100644 --- a/src/logfile_sub_source.cc +++ b/src/logfile_sub_source.cc @@ -40,7 +40,6 @@ #include "command_executor.hh" #include "config.h" #include "k_merge_tree.h" -#include "lnav_util.hh" #include "log_accel.hh" #include "relative_time.hh" #include "sql_util.hh" @@ -119,7 +118,7 @@ logfile_sub_source::find(const char* fn, content_line_t& line_base) iter++) { auto& ld = *(*iter); - auto lf = ld.get_file_ptr(); + auto* lf = ld.get_file_ptr(); if (lf == nullptr) { continue; @@ -233,7 +232,9 @@ logfile_sub_source::text_value_for_line(textview_curses& tc, } if ((this->lss_token_file->is_time_adjusted() - || format->lf_timestamp_flags & ETF_MACHINE_ORIENTED) + || format->lf_timestamp_flags & ETF_MACHINE_ORIENTED + || !(format->lf_timestamp_flags & ETF_DAY_SET) + || !(format->lf_timestamp_flags & ETF_MONTH_SET)) && format->lf_date_time.dts_fmt_lock != -1) { auto time_attr @@ -246,7 +247,10 @@ logfile_sub_source::text_value_for_line(textview_curses& tc, const char* fmt; ssize_t len; - if (format->lf_timestamp_flags & ETF_MACHINE_ORIENTED) { + if (format->lf_timestamp_flags & ETF_MACHINE_ORIENTED + || !(format->lf_timestamp_flags & ETF_DAY_SET) + || !(format->lf_timestamp_flags & ETF_MONTH_SET)) + { format->lf_date_time.convert_to_timeval( &this->lss_token_value.c_str()[time_range.lr_start], time_range.length(), @@ -254,14 +258,23 @@ logfile_sub_source::text_value_for_line(textview_curses& tc, adjusted_time); fmt = "%Y-%m-%d %H:%M:%S.%f"; gmtime_r(&adjusted_time.tv_sec, &adjusted_tm.et_tm); - adjusted_tm.et_nsec = adjusted_time.tv_usec * 1000; + adjusted_tm.et_nsec + = std::chrono::duration_cast( + std::chrono::microseconds{adjusted_time.tv_usec}) + .count(); len = ftime_fmt(buffer, sizeof(buffer), fmt, adjusted_tm); } else { adjusted_time = this->lss_token_line->get_timeval(); gmtime_r(&adjusted_time.tv_sec, &adjusted_tm.et_tm); - adjusted_tm.et_nsec = adjusted_time.tv_usec * 1000; + adjusted_tm.et_nsec + = std::chrono::duration_cast( + std::chrono::microseconds{adjusted_time.tv_usec}) + .count(); len = format->lf_date_time.ftime( - buffer, sizeof(buffer), adjusted_tm); + buffer, + sizeof(buffer), + format->get_timestamp_formats(), + adjusted_tm); } value_out.replace( @@ -585,7 +598,6 @@ logfile_sub_source::text_attrs_for_line(textview_curses& lv, auto sql_filter_opt = this->get_sql_filter(); if (sql_filter_opt) { auto* sf = (sql_filter*) sql_filter_opt.value().get(); - log_debug("eval sql %p %p", &this->tss_filters, sf); auto eval_res = this->eval_sql_filter(sf->sf_filter_stmt.in(), this->lss_token_file_data, this->lss_token_line); diff --git a/test/test_date_time_scanner.cc b/test/test_date_time_scanner.cc index 40fe9e20..8a85993b 100644 --- a/test/test_date_time_scanner.cc +++ b/test/test_date_time_scanner.cc @@ -39,6 +39,7 @@ static const char* GOOD_TIMES[] = { "May 01 00:00:01", "May 10 12:00:01", "2014-02-11 16:12:34", + "2014-02-11 16:12:34.123", "05/18/2018 12:00:53 PM", "05/18/2018 12:00:53 AM", }; @@ -70,7 +71,7 @@ main(int argc, char* argv[]) char ts[64]; gmtime_r(&tv.tv_sec, &tm.et_tm); - dts.ftime(ts, sizeof(ts), tm); + dts.ftime(ts, sizeof(ts), nullptr, tm); printf("orig %s\n", good_time); printf("loop %s\n", ts); assert(strcmp(ts, good_time) == 0); @@ -85,7 +86,7 @@ main(int argc, char* argv[]) auto rc = dts.scan(OLD_TIME, strlen(OLD_TIME), nullptr, &tm, tv); assert(rc != nullptr); char ts[64]; - dts.ftime(ts, sizeof(ts), tm); + dts.ftime(ts, sizeof(ts), nullptr, tm); assert(strcmp(ts, "05/18/1980 12:00:53 AM") == 0); } @@ -145,6 +146,24 @@ main(int argc, char* argv[]) } } + { + const char* ts = "22:46:03.471"; + const char* fmt[] = { + "%H:%M:%S.%L", + nullptr, + }; + char buf[64]; + date_time_scanner dts; + struct exttm tm; + struct timeval tv; + + const auto* ts_end = dts.scan(ts, strlen(ts), fmt, &tm, tv); + assert(ts_end - ts == 12); + auto rc = dts.ftime(buf, sizeof(buf), fmt, tm); + assert(rc == 12); + assert(strcmp(ts, buf) == 0); + } + { const char* epoch_str = "ts 1428721664 ]"; struct exttm tm; diff --git a/test/test_logfile.sh b/test/test_logfile.sh index 465f64d2..5817a885 100644 --- a/test/test_logfile.sh +++ b/test/test_logfile.sh @@ -325,6 +325,15 @@ Apr 06 10:30:11 2014 -- 474 Apr 06 11:01:11 2014 -- 475 EOF +run_test ${lnav_test} -n ${srcdir}/logfile_tcf.1 + +check_output "timestamps with no dates are not rewritten?" < C 2 RunControl getChildren null +TCF 2014-04-06 11:01:11.475000: 0: <--- R 2 ["P1"] +EOF + + # The TCSH format converts to local time, so we need to specify a TZ export TZ="UTC" run_test ./drive_logfile -t -f tcsh_history ${srcdir}/logfile_tcsh_history.0