[search-table] some more enhancements to search-tables

NEWS

@@ -70,7 +70,8 @@ lnav v0.10.2:
        the entire message string.
      * Search tables defined in formats are now constrained to only
        match log messages that are in that log format instead of all
-       log messages.
+       log messages.  As a benefit, the search table now includes
+       the columns that are defined as part of the format.
 
      Fixes:
      * Toggling enabled/disabled filters when there is a SQL expression

src/breadcrumb_curses.cc

@@ -218,6 +218,22 @@ breadcrumb_curses::handle_key(int ch)
     bool retval = false;
 
     switch (ch) {
+        case KEY_CTRL_A:
+            if (this->bc_selected_crumb) {
+                this->bc_selected_crumb = 0;
+                this->bc_current_search.clear();
+                this->reload_data();
+            }
+            retval = true;
+            break;
+        case KEY_CTRL_E:
+            if (this->bc_selected_crumb) {
+                this->bc_selected_crumb = this->bc_focused_crumbs.size() - 1;
+                this->bc_current_search.clear();
+                this->reload_data();
+            }
+            retval = true;
+            break;
         case KEY_BTAB:
         case KEY_LEFT:
             if (this->bc_selected_crumb) {

src/formats/vmw_log.json

@@ -95,8 +95,14 @@
         },
         "search-table": {
             "vpxd_session_stats": {
-                "pattern": "/SessionStats/SessionPool/Session/Id='(?<Id>[^']+)'/Username='(?<Username>[^']+)'/ClientIP='(?<ClientIP>[^']+)'(?<ProfileKey>[^ ]+) (?<ProfileValue>[^\\n]+)",
+                "pattern": "/SessionStats/SessionPool/Session/Id='(?<SessionId>[^']+)'/Username='(?<Username>[^']+)'/ClientIP='(?<ClientIP>[^']+)'(?<ProfileKey>[^ ]+) (?<ProfileValue>[^\\n]+)",
                 "glob": "*/vpxd-profile*"
+            },
+            "vpx_lro_begin": {
+                "pattern": "\\[VpxLRO\\] -- BEGIN (?<lro_id>\\S+) -- (?<entity>\\S*) -- (?<operation>\\S*) -- (?:(?<SessionId>[0-9a-f]{8}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{12})(?:\\((?<SessionSubId>[0-9a-f]{8}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{12})\\))?)?"
+            },
+            "vpx_lro_finish": {
+                "pattern": "\\[VpxLRO\\] -- FINISH (?<lro_id>\\S+)"
             }
         },
         "sample": [

src/hotkeys.cc

@@ -231,8 +231,8 @@ handle_paging_key(int ch)
             if (lnav_data.ld_last_view == nullptr) {
                 alerter::singleton().chime();
             } else {
-                textview_curses* tc = lnav_data.ld_last_view;
+                auto* tc = lnav_data.ld_last_view;
-                textview_curses* top_tc = *lnav_data.ld_view_stack.top();
+                auto* top_tc = *lnav_data.ld_view_stack.top();
                 auto* dst_view
                     = dynamic_cast<text_time_translator*>(tc->get_sub_source());
                 auto* src_view = dynamic_cast<text_time_translator*>(
@@ -243,7 +243,7 @@ handle_paging_key(int ch)
                     src_view->time_for_row(top_tc->get_top()) |
                         [dst_view, tc](auto top_time) {
                             dst_view->row_for_time(top_time) |
-                                [tc](auto row) { tc->set_top(row); };
+                                [tc](auto row) { tc->set_selection(row); };
                         };
                 }
                 ensure_view(tc);

src/log_format.cc

@@ -2730,5 +2730,17 @@ logline_value_stats::add_value(double value)
     this->lvs_total += value;
 }
 
+std::vector<logline_value_meta>
+external_log_format::get_value_metadata() const
+{
+    std::vector<logline_value_meta> retval;
+
+    for (const auto& vd : this->elf_value_def_order) {
+        retval.emplace_back(vd->vd_meta);
+    }
+
+    return retval;
+}
+
 /* XXX */
 #include "log_format_impls.cc"

src/log_format.hh

@@ -114,7 +114,9 @@ struct logline_value_meta {
                        int col = -1,
                        const nonstd::optional<log_format*>& format
                        = nonstd::nullopt)
-        : lvm_name(name), lvm_kind(kind), lvm_column(col), lvm_format(format){};
+        : lvm_name(name), lvm_kind(kind), lvm_column(col), lvm_format(format)
+    {
+    }
 
     bool is_hidden() const
     {
@@ -437,6 +439,11 @@ public:
         return "";
     }
 
+    virtual std::vector<logline_value_meta> get_value_metadata() const
+    {
+        return {};
+    }
+
     struct pattern_for_lines {
         pattern_for_lines(uint32_t pfl_line, uint32_t pfl_pat_index);
 

src/log_format_ext.hh

@@ -195,7 +195,7 @@ public:
         }
 
         return retval;
-    };
+    }
 
     void get_subline(const logline& ll,
                      shared_buffer_ref& sbr,
@@ -220,6 +220,8 @@ public:
         return this->elf_source_path;
     }
 
+    std::vector<logline_value_meta> get_value_metadata() const;
+
     enum class json_log_field {
         CONSTANT,
         VARIABLE

src/log_search_table.cc

@@ -35,20 +35,35 @@
 
 const static std::string MATCH_INDEX = "match_index";
 static auto match_index_name = intern_string::lookup("match_index");
-static auto match_index_meta
-    = logline_value_meta(match_index_name, value_kind_t::VALUE_INTEGER, 0);
 
 log_search_table::log_search_table(pcrepp pattern, intern_string_t table_name)
     : log_vtab_impl(table_name), lst_regex(std::move(pattern))
 {
-    this->get_columns_int(this->lst_cols);
 }
 
 void
-log_search_table::get_columns_int(std::vector<vtab_column>& cols)
+log_search_table::get_columns_int(std::vector<vtab_column>& cols) const
 {
     column_namer cn{column_namer::language::SQL};
 
+    if (this->lst_format != nullptr) {
+        this->lst_column_metas = this->lst_format->get_value_metadata();
+        this->lst_format_column_count = this->lst_column_metas.size();
+        cols.resize(this->lst_column_metas.size());
+        for (const auto& meta : this->lst_column_metas) {
+            if (meta.lvm_column == -1) {
+                continue;
+            }
+            auto type_pair
+                = log_vtab_impl::logline_value_to_sqlite_type(meta.lvm_kind);
+            cols[meta.lvm_column].vc_name = meta.lvm_name.to_string();
+            cols[meta.lvm_column].vc_type = type_pair.first;
+            cols[meta.lvm_column].vc_subtype = type_pair.second;
+        }
+    }
+
+    this->lst_column_metas.emplace_back(
+        match_index_name, value_kind_t::VALUE_INTEGER, cols.size());
     cols.emplace_back(MATCH_INDEX, SQLITE_INTEGER);
     for (int lpc = 0; lpc < this->lst_regex.get_capture_count(); lpc++) {
         std::string collator;
@@ -100,6 +115,9 @@ log_search_table::get_foreign_keys(std::vector<std::string>& keys_inout) const
 bool
 log_search_table::next(log_cursor& lc, logfile_sub_source& lss)
 {
+    this->vi_attrs.clear();
+    this->lst_line_values_cache.clear();
+
     if (this->lst_match_index >= 0) {
         this->lst_input.pi_offset = this->lst_input.pi_next_offset;
         if (this->lst_regex.match(
@@ -133,12 +151,12 @@ log_search_table::next(log_cursor& lc, logfile_sub_source& lss)
         return false;
     }
 
-    string_attrs_t sa;
-    std::vector<logline_value> line_values;
-
     lf->read_full_message(lf_iter, this->lst_current_line);
-    lf->get_format()->annotate(
+    lf->get_format()->annotate(cl,
-        cl, this->lst_current_line, sa, line_values, false);
+                               this->lst_current_line,
+                               this->vi_attrs,
+                               this->lst_line_values_cache,
+                               false);
     this->lst_input.reset(
         this->lst_current_line.get_data(), 0, this->lst_current_line.length());
 
@@ -159,12 +177,15 @@ log_search_table::extract(logfile* lf,
                           shared_buffer_ref& line,
                           std::vector<logline_value>& values)
 {
-    values.emplace_back(match_index_meta, this->lst_match_index);
+    values = this->lst_line_values_cache;
+    values.emplace_back(this->lst_column_metas[this->lst_format_column_count],
+                        this->lst_match_index);
     for (int lpc = 0; lpc < this->lst_regex.get_capture_count(); lpc++) {
         const auto* cap = this->lst_match_context[lpc];
-        values.emplace_back(this->lst_column_metas[lpc],
+        values.emplace_back(
-                            line,
+            this->lst_column_metas[this->lst_format_column_count + 1 + lpc],
-                            line_range{cap->c_begin, cap->c_end});
+            line,
+            line_range{cap->c_begin, cap->c_end});
     }
 }
 

src/log_search_table.hh

@@ -47,12 +47,14 @@ public:
 
     void get_primary_keys(std::vector<std::string>& keys_out) const override;
 
-    void get_columns_int(std::vector<vtab_column>& cols);
+    void get_columns_int(std::vector<vtab_column>& cols) const;
 
     void get_columns(std::vector<vtab_column>& cols) const override
     {
+        this->get_columns_int(this->lst_cols);
         cols = this->lst_cols;
     }
+
     void filter(log_cursor& lc, logfile_sub_source& lss) override;
 
     void get_foreign_keys(std::vector<std::string>& keys_inout) const override;
@@ -66,13 +68,15 @@ public:
 
     pcrepp lst_regex;
     log_format* lst_format{nullptr};
+    mutable size_t lst_format_column_count{0};
     std::string lst_log_path_glob;
     shared_buffer_ref lst_current_line;
     pcre_input lst_input{""};
     pcre_context_static<128> lst_match_context;
-    std::vector<logline_value_meta> lst_column_metas;
+    mutable std::vector<logline_value_meta> lst_column_metas;
     int64_t lst_match_index{-1};
-    std::vector<vtab_column> lst_cols;
+    mutable std::vector<vtab_column> lst_cols;
+    std::vector<logline_value> lst_line_values_cache;
 };
 
 #endif

src/spectro_impls.cc

@@ -32,7 +32,9 @@
 #include "lnav.hh"
 #include "logfile_sub_source.hh"
 
-class filtered_sub_source : public text_sub_source {
+class filtered_sub_source
+    : public text_sub_source
+    , public text_time_translator {
 public:
     size_t text_line_count() override { return this->fss_lines.size(); }
 
@@ -61,6 +63,19 @@ public:
             tc, this->fss_lines[line], value_out);
     }
 
+    nonstd::optional<vis_line_t> row_for_time(
+        struct timeval time_bucket) override
+    {
+        return dynamic_cast<text_time_translator*>(this->fss_delegate)
+            ->row_for_time(time_bucket);
+    }
+
+    nonstd::optional<struct timeval> time_for_row(vis_line_t row) override
+    {
+        return dynamic_cast<text_time_translator*>(this->fss_delegate)
+            ->time_for_row(this->fss_lines[row]);
+    }
+
     text_sub_source* fss_delegate;
     std::vector<vis_line_t> fss_lines;
 };

src/spectro_source.cc

@@ -77,7 +77,7 @@ spectrogram_source::list_input_handle_key(listview_curses& lv, int ch)
             width -= 2;
 
             auto& sb = this->ss_cached_bounds;
-            auto begin_time_opt = this->time_for_row(sel);
+            auto begin_time_opt = this->time_for_row_int(sel);
             if (!begin_time_opt) {
                 return true;
             }
@@ -102,6 +102,24 @@ spectrogram_source::list_input_handle_key(listview_curses& lv, int ch)
             return true;
         }
 
+        case KEY_CTRL_A: {
+            if (this->ss_value_source != nullptr) {
+                this->ss_cursor_column = 0;
+                this->text_selection_changed((textview_curses&) lv);
+                lv.set_needs_update();
+            }
+            return true;
+        }
+
+        case KEY_CTRL_E: {
+            if (this->ss_value_source != nullptr) {
+                this->ss_cursor_column = INT_MAX;
+                this->text_selection_changed((textview_curses&) lv);
+                lv.set_needs_update();
+            }
+            return true;
+        }
+
         case KEY_LEFT:
         case KEY_RIGHT: {
             auto sel = lv.get_selection();
@@ -302,6 +320,21 @@ spectrogram_source::text_line_width(textview_curses& tc)
 
 nonstd::optional<struct timeval>
 spectrogram_source::time_for_row(vis_line_t row)
+{
+    if (this->ss_details_source != nullptr) {
+        auto* details_tss = dynamic_cast<text_time_translator*>(
+            this->ss_details_source.get());
+
+        if (details_tss != nullptr) {
+            return details_tss->time_for_row(this->ss_details_view->get_top());
+        }
+    }
+
+    return this->time_for_row_int(row);
+}
+
+nonstd::optional<struct timeval>
+spectrogram_source::time_for_row_int(vis_line_t row)
 {
     struct timeval retval {
         0, 0
@@ -326,11 +359,13 @@ spectrogram_source::row_for_time(struct timeval time_bucket)
     int retval;
 
     this->cache_bounds();
-    if (time_bucket.tv_sec < this->ss_cached_bounds.sb_begin_time) {
+    auto grain_begin_time
+        = rounddown(this->ss_cached_bounds.sb_begin_time, this->ss_granularity);
+    if (time_bucket.tv_sec < grain_begin_time) {
         return 0_vl;
     }
 
-    diff = time_bucket.tv_sec - this->ss_cached_bounds.sb_begin_time;
+    diff = time_bucket.tv_sec - grain_begin_time;
     retval = diff / this->ss_granularity;
 
     return vis_line_t(retval);
@@ -346,7 +381,7 @@ spectrogram_source::text_value_for_line(textview_curses& tc,
     char tm_buffer[128];
     struct tm tm;
 
-    auto row_time_opt = this->time_for_row(vis_line_t(row));
+    auto row_time_opt = this->time_for_row_int(vis_line_t(row));
     if (!row_time_opt) {
         value_out.clear();
         return;

src/spectro_source.hh

@@ -167,6 +167,8 @@ public:
 
     void cache_bounds();
 
+    nonstd::optional<struct timeval> time_for_row_int(vis_line_t row);
+
     const spectrogram_row& load_row(const listview_curses& lv, int row);
 
     textview_curses* ss_details_view;

src/view_curses.hh

@@ -69,6 +69,8 @@
 #include "optional.hpp"
 #include "styling.hh"
 
+#define KEY_CTRL_A 0x01
+#define KEY_CTRL_E 0x05
 #define KEY_CTRL_G 7
 #define KEY_CTRL_L 12
 #define KEY_CTRL_P 16

test/Makefile.am

@@ -317,6 +317,7 @@ dist_noinst_DATA = \
 	logfile_uwsgi.0 \
 	logfile_vami.0 \
 	logfile_vdsm.0 \
+	logfile_vpxd.0 \
 	logfile_w3c.0 \
 	logfile_w3c.1 \
 	logfile_w3c.2 \

test/expected/expected.am

@@ -680,6 +680,8 @@ EXPECTED_FILES = \
     $(srcdir)/%reldir%/test_sql_json_func.sh_f34f5dfa938a1ac7721f924beb16bbceec127a1b.out \
     $(srcdir)/%reldir%/test_sql_search_table.sh_df0fd242f57a96d40f466493938cda0789a094fa.err \
     $(srcdir)/%reldir%/test_sql_search_table.sh_df0fd242f57a96d40f466493938cda0789a094fa.out \
+    $(srcdir)/%reldir%/test_sql_search_table.sh_ef9373a76853f345d06234f6e0fe11b5d40da27b.err \
+    $(srcdir)/%reldir%/test_sql_search_table.sh_ef9373a76853f345d06234f6e0fe11b5d40da27b.out \
     $(srcdir)/%reldir%/test_sql_str_func.sh_005b9365ac99596e539f47c9fe432668c209b21f.err \
     $(srcdir)/%reldir%/test_sql_str_func.sh_005b9365ac99596e539f47c9fe432668c209b21f.out \
     $(srcdir)/%reldir%/test_sql_str_func.sh_04712488fe50554eb36d3ced80f9a033602f3daa.err \

test/expected/test_sql_search_table.sh_ef9373a76853f345d06234f6e0fe11b5d40da27b.out

@@ -0,0 +1,6 @@
+log_line log_part        log_time         log_idle_msecs log_level log_mark log_comment log_tags log_filters  comp             opid              tid   user   item  prc  reason       src        sub    line   file  match_index   lro_id         entity                       operation                              SessionId                           SessionSubId                                                                     log_body                                                         
+       0   <NULL> 2022-06-02 11:58:12.193              0 info             0      <NULL>   <NULL>      <NULL> <NULL> 7e1280cf                    45715 <NULL> <NULL> vpxd <NULL> Originator@6876 vpxLro <NULL> <NULL>           0 lro-846063 SessionManager     vim.SessionManager.sessionIsActive        528e6e0c-246d-58b5-3234-278c6e0c5d0d 52c289ac-2563-48d5-8a8e-f178da022c0d [VpxLRO] -- BEGIN lro-846063 -- SessionManager -- vim.Sessio⋯8b5-3234-278c6e0c5d0d(52c289ac-2563-48d5-8a8e-f178da022c0d) 
+       2   <NULL> 2022-06-02 11:58:12.376            182 info             0      <NULL>   <NULL>      <NULL> <NULL> e3979f6                     45709 <NULL> <NULL> vpxd <NULL> Originator@6876 vpxLro <NULL> <NULL>           0 lro-846064 SessionManager     vim.SessionManager.sessionIsActive        52626140-422b-6287-b4e4-344192c6a01d 523e0a4b-6e83-6bcd-9342-22502dd89866 [VpxLRO] -- BEGIN lro-846064 -- SessionManager -- vim.Sessio⋯287-b4e4-344192c6a01d(523e0a4b-6e83-6bcd-9342-22502dd89866) 
+       4   <NULL> 2022-06-02 11:58:12.623            246 info             0      <NULL>   <NULL>      <NULL> <NULL> l3wrhr4o-cbf-h5:70001034-60 47524 <NULL> <NULL> vpxd <NULL> Originator@6876 vpxLro <NULL> <NULL>           0 lro-846066 ChangeLogCollector vim.cdc.ChangeLogCollector.waitForChanges 526861fc-0c28-1930-ae5e-d8c2772bf8c2 52a7a308-9646-c054-f1e7-16131c1a7db6 [VpxLRO] -- BEGIN lro-846066 -- ChangeLogCollector -- vim.c⋯1930-ae5e-d8c2772bf8c2(52a7a308-9646-c054-f1e7-16131c1a7db6) 
+       6   <NULL> 2022-06-02 11:58:12.736            113 info             0      <NULL>   <NULL>      <NULL> <NULL> 499b440                     48432 <NULL> <NULL> vpxd <NULL> Originator@6876 vpxLro <NULL> <NULL>           0 lro-846067 SessionManager     vim.SessionManager.sessionIsActive        521fe9f6-d061-11a2-ac86-badb3c071373 524cba9b-2cc4-9b70-32e4-421452a404d7 [VpxLRO] -- BEGIN lro-846067 -- SessionManager -- vim.Sessio⋯1a2-ac86-badb3c071373(524cba9b-2cc4-9b70-32e4-421452a404d7) 
+       8   <NULL> 2022-06-02 11:58:12.740              4 info             0      <NULL>   <NULL>      <NULL> <NULL> 55a419df                    48035 <NULL> <NULL> vpxd <NULL> Originator@6876 vpxLro <NULL> <NULL>           0 lro-846068 SessionManager     vim.SessionManager.sessionIsActive        52585600-b0bc-76b1-c4d5-4d7708671c5e 523b68ba-e312-9909-a3ca-39cc86aaf206 [VpxLRO] -- BEGIN lro-846068 -- SessionManager -- vim.Sessio⋯6b1-c4d5-4d7708671c5e(523b68ba-e312-9909-a3ca-39cc86aaf206) 

test/logfile_vpxd.0

@@ -0,0 +1,12 @@
+2022-06-02T11:58:12.193Z info vpxd[45715] [Originator@6876 sub=vpxLro opID=7e1280cf] [VpxLRO] -- BEGIN lro-846063 -- SessionManager -- vim.SessionManager.sessionIsActive -- 528e6e0c-246d-58b5-3234-278c6e0c5d0d(52c289ac-2563-48d5-8a8e-f178da022c0d)
+2022-06-02T11:58:12.194Z info vpxd[45715] [Originator@6876 sub=vpxLro opID=7e1280cf] [VpxLRO] -- FINISH lro-846063
+2022-06-02T11:58:12.376Z info vpxd[45709] [Originator@6876 sub=vpxLro opID=e3979f6] [VpxLRO] -- BEGIN lro-846064 -- SessionManager -- vim.SessionManager.sessionIsActive -- 52626140-422b-6287-b4e4-344192c6a01d(523e0a4b-6e83-6bcd-9342-22502dd89866)
+2022-06-02T11:58:12.377Z info vpxd[45709] [Originator@6876 sub=vpxLro opID=e3979f6] [VpxLRO] -- FINISH lro-846064
+2022-06-02T11:58:12.623Z info vpxd[47524] [Originator@6876 sub=vpxLro opID=l3wrhr4o-cbf-h5:70001034-60] [VpxLRO] -- BEGIN lro-846066 -- ChangeLogCollector -- vim.cdc.ChangeLogCollector.waitForChanges -- 526861fc-0c28-1930-ae5e-d8c2772bf8c2(52a7a308-9646-c054-f1e7-16131c1a7db6)
+2022-06-02T11:58:12.623Z info vpxd[47524] [Originator@6876 sub=vpxLro opID=l3wrhr4o-cbf-h5:70001034-60] [VpxLRO] -- FINISH lro-846066
+2022-06-02T11:58:12.736Z info vpxd[48432] [Originator@6876 sub=vpxLro opID=499b440] [VpxLRO] -- BEGIN lro-846067 -- SessionManager -- vim.SessionManager.sessionIsActive -- 521fe9f6-d061-11a2-ac86-badb3c071373(524cba9b-2cc4-9b70-32e4-421452a404d7)
+2022-06-02T11:58:12.736Z info vpxd[48432] [Originator@6876 sub=vpxLro opID=499b440] [VpxLRO] -- FINISH lro-846067
+2022-06-02T11:58:12.740Z info vpxd[48035] [Originator@6876 sub=vpxLro opID=55a419df] [VpxLRO] -- BEGIN lro-846068 -- SessionManager -- vim.SessionManager.sessionIsActive -- 52585600-b0bc-76b1-c4d5-4d7708671c5e(523b68ba-e312-9909-a3ca-39cc86aaf206)
+2022-06-02T11:58:12.740Z info vpxd[48035] [Originator@6876 sub=vpxLro opID=55a419df] [VpxLRO] -- FINISH lro-846068
+2022-06-02T11:58:12.796Z info vpxd[47240] [Originator@6876 sub=MoCluster opID=HB-host-363@2022-389ab9b1] Host [vim.HostSystem:host-363,esx-2-121.vlcm.com] has 1 HDCS resources
+2022-06-02T11:58:12.914Z info vpxd[47370] [Originator@6876 sub=MoCluster opID=HB-host-493@2000-2922fd96] Host [vim.HostSystem:host-493,esx-2-192.vlcm.com] has 1 HDCS resources

test/test_sql_search_table.sh

@@ -5,3 +5,7 @@ export YES_COLOR=1
 run_cap_test ${lnav_test} -n \
     -c ';SELECT * FROM procstate_procs' \
     ${test_dir}/logfile_procstate.0
+
+run_cap_test ${lnav_test} -n \
+    -c ';SELECT *,log_body FROM vpx_lro_begin' \
+    ${test_dir}/logfile_vpxd.0