[overlay] fix actual time

Author: tstack

src/field_overlay_source.cc

@@ -193,27 +193,24 @@ field_overlay_source::build_field_lines(const listview_curses& lv,
     time_line.with_attr(
         string_attr(time_lr, VC_STYLE.value(text_attrs::with_bold())));
 
-    auto time_range = find_string_attr_range(
-        this->fos_log_helper.ldh_line_attrs, &L_TIMESTAMP);
+    auto ts_sf = this->fos_log_helper.ldh_line_values.lvv_time_value;
 
     curr_tv = this->fos_log_helper.ldh_line->get_timeval();
-    if (ll->is_time_skewed() && time_range.lr_end != -1) {
-        const char* time_src
-            = this->fos_log_helper.ldh_line_values.lvv_sbr.get_data()
-            + time_range.lr_start;
+    if (ll->is_time_skewed() && ts_sf) {
         timeval actual_tv;
         date_time_scanner dts;
         exttm tm;
 
         dts.set_base_time(format->lf_date_time.dts_base_time,
                           format->lf_date_time.dts_base_tm.et_tm);
         dts.dts_zoned_to_local = format->lf_date_time.dts_zoned_to_local;
-        if (format->lf_date_time.scan(time_src,
-                                      time_range.length(),
+        if (format->lf_date_time.scan(ts_sf->data(),
+                                      ts_sf->length(),
                                       format->get_timestamp_formats(),
                                       &tm,
                                       actual_tv)
-            || dts.scan(time_src, time_range.length(), nullptr, &tm, actual_tv))
+            || dts.scan(
+                ts_sf->data(), ts_sf->length(), nullptr, &tm, actual_tv))
         {
             sql_strftime(
                 orig_timestamp, sizeof(orig_timestamp), actual_tv, 'T');
@@ -843,8 +840,8 @@ field_overlay_source::build_meta_line(const listview_curses& lv,
 
         al.with_string(" \u2514");
         for (const auto& entry : line_meta.bm_tags) {
-            al.append(1, ' ').append(entry.te_tag,
-                                     VC_STYLE.value(vc.attrs_for_ident(entry.te_tag)));
+            al.append(1, ' ').append(
+                entry.te_tag, VC_STYLE.value(vc.attrs_for_ident(entry.te_tag)));
         }
 
         al.insert(0, filename_width, ' ');

src/formats/cloudflare_log.json

@@ -12,6 +12,8 @@
             "info": "hit",
             "warning": "miss"
         },
+        "duration-field": "OriginResponseDurationMs",
+        "duration-divisor": 1000,
         "line-format": [
             {
                 "field": "ClientIP",
@@ -53,6 +55,7 @@
             }
         ],
         "timestamp-field": "EdgeStartTimestamp",
+        "timestamp-divisor": 1000000000,
         "opid": {
             "description": {
                 "std": {

src/lnav.prompt.cc

@@ -267,6 +267,7 @@ prompt::refresh_sql_expr_completions(textview_curses& tc)
         ":log_src_file",
         ":log_src_line",
         ":log_thread_id",
+        ":log_duration",
     };
 
     this->insert_sql_completion("log_line", sql_format_column_t{});

src/log.watch.cc

@@ -256,6 +256,17 @@ eval_with(logfile& lf, logfile::iterator ll)
                 bind_to_sqlite(stmt, lpc + 1, values.lvv_thread_id_value);
                 continue;
             }
+            if (strcmp(name, ":log_duration") == 0) {
+                if (values.lvv_duration_value) {
+                    bind_to_sqlite(
+                        stmt,
+                        lpc + 1,
+                        values.lvv_duration_value->count() / 1000000.0);
+                } else {
+                    sqlite3_bind_null(stmt, lpc + 1);
+                }
+                continue;
+            }
             if (strcmp(name, ":log_raw_text") == 0) {
                 auto res = lf.read_raw_message(ll);
 

src/log_format.cc

@@ -713,6 +713,8 @@ logline_value_vector::clear()
 {
     this->lvv_values.clear();
     this->lvv_sbr.disown();
+    this->lvv_time_value = std::nullopt;
+    this->lvv_time_exttm = std::nullopt;
     this->lvv_opid_value = std::nullopt;
     this->lvv_opid_provenance = opid_provenance::none;
     this->lvv_thread_id_value = std::nullopt;
@@ -723,6 +725,8 @@ logline_value_vector::clear()
 
 logline_value_vector::logline_value_vector(const logline_value_vector& other)
     : lvv_sbr(other.lvv_sbr.clone()), lvv_values(other.lvv_values),
+      lvv_time_value(other.lvv_time_value),
+      lvv_time_exttm(other.lvv_time_exttm),
       lvv_opid_value(other.lvv_opid_value),
       lvv_opid_provenance(other.lvv_opid_provenance),
       lvv_thread_id_value(
@@ -740,6 +744,8 @@ logline_value_vector::operator=(const logline_value_vector& other)
 {
     this->lvv_sbr = other.lvv_sbr.clone();
     this->lvv_values = other.lvv_values;
+    this->lvv_time_value = other.lvv_time_value;
+    this->lvv_time_exttm = other.lvv_time_exttm;
     this->lvv_opid_value = other.lvv_opid_value;
     this->lvv_opid_provenance = other.lvv_opid_provenance;
     this->lvv_thread_id_value
@@ -2407,6 +2413,7 @@ external_log_format::annotate(logfile* lf,
     auto ts_cap = md[pat.p_timestamp_field_index];
     if (ts_cap) {
         sa.emplace_back(to_line_range(ts_cap.value()), L_TIMESTAMP.value());
+        values.lvv_time_value = ts_cap;
     }
 
     auto opid_cap = md[pat.p_opid_field_index];
@@ -2859,6 +2866,7 @@ rewrite_json_field(yajlpp_parse_context* ypc,
             sql_strftime(
                 time_buf, sizeof(time_buf), jlu->jlu_line->get_timeval(), 'T');
         }
+        jlu->jlu_format->jlf_line_values.lvv_time_value = frag;
         jlu->jlu_format->jlf_line_values.lvv_values.emplace_back(
             jlu->jlu_format->get_value_meta(field_name,
                                             value_kind_t::VALUE_TEXT),
@@ -3025,7 +3033,7 @@ external_log_format::get_subline(const log_format_file_state& lffs,
         } else {
             std::vector<logline_value>::iterator lv_iter;
             bool used_values[this->jlf_line_values.lvv_values.size()];
-            struct line_range lr;
+            line_range lr;
 
             memset(used_values, 0, sizeof(used_values));
             for (lv_iter = this->jlf_line_values.lvv_values.begin();
@@ -3034,6 +3042,9 @@ external_log_format::get_subline(const log_format_file_state& lffs,
             {
                 lv_iter->lv_meta.lvm_format = this;
             }
+            if (!this->jlf_line_values.lvv_time_value) {
+                this->jlf_line_values.lvv_time_exttm = jlu.jlu_exttm;
+            }
 
             if (jlu.jlu_tid_number) {
                 char tid_buf[128];

src/log_format_fwd.hh

@@ -712,6 +712,8 @@ struct logline_value_vector {
     ArenaAlloc::Alloc<char> lvv_allocator{8 * 1024};
     shared_buffer_ref lvv_sbr;
     std::vector<logline_value> lvv_values;
+    std::optional<string_fragment> lvv_time_value;
+    std::optional<exttm> lvv_time_exttm;
     std::optional<std::string> lvv_opid_value;
     opid_provenance lvv_opid_provenance{opid_provenance::none};
     std::optional<string_fragment> lvv_thread_id_value;

src/logfile_sub_source.cc

@@ -2224,6 +2224,16 @@ logfile_sub_source::eval_sql_filter(sqlite3_stmt* stmt,
             bind_to_sqlite(stmt, lpc + 1, values.lvv_thread_id_value);
             continue;
         }
+        if (strcmp(name, ":log_duration") == 0) {
+            if (values.lvv_duration_value) {
+                bind_to_sqlite(stmt,
+                               lpc + 1,
+                               values.lvv_duration_value->count() / 1000000.0);
+            } else {
+                sqlite3_bind_null(stmt, lpc + 1);
+            }
+            continue;
+        }
         for (const auto& lv : values.lvv_values) {
             if (lv.lv_meta.lvm_name != &name[1]) {
                 continue;
@@ -3245,8 +3255,7 @@ logfile_sub_source::clear_bookmark_metadata()
             }
             auto tag_iter = meta.bm_tags.begin();
             while (tag_iter != meta.bm_tags.end()) {
-                if (tag_iter->te_source
-                    == bookmark_metadata::meta_source::user)
+                if (tag_iter->te_source == bookmark_metadata::meta_source::user)
                 {
                     tag_iter = meta.bm_tags.erase(tag_iter);
                 } else {