diff --git a/docs/source/intro.rst b/docs/source/intro.rst index 96b06121..bdc1f667 100644 --- a/docs/source/intro.rst +++ b/docs/source/intro.rst @@ -11,6 +11,12 @@ navigate through your logs using a variety of :ref:`hotkeys`. for doing things like applying filters, tagging messages, and more. You can then analyze your log messages using the :ref:`sql-ext`. +.. figure:: lnav-intro-screen.png + :align: center + :alt: Screenshot of lnav showing a mix of syslog and web access_log messages. + + Screenshot of **lnav** viewing syslog and web access_log messages. + Development ----------- diff --git a/docs/source/lnav-gantt-1.png b/docs/source/lnav-gantt-1.png new file mode 100644 index 00000000..306187c4 Binary files /dev/null and b/docs/source/lnav-gantt-1.png differ diff --git a/docs/source/lnav-gantt-2.png b/docs/source/lnav-gantt-2.png new file mode 100644 index 00000000..90bf8c15 Binary files /dev/null and b/docs/source/lnav-gantt-2.png differ diff --git a/docs/source/lnav-intro-screen.png b/docs/source/lnav-intro-screen.png new file mode 100644 index 00000000..39d8129a Binary files /dev/null and b/docs/source/lnav-intro-screen.png differ diff --git a/docs/source/ui.rst b/docs/source/ui.rst index e6ca1667..2b68132f 100644 --- a/docs/source/ui.rst +++ b/docs/source/ui.rst @@ -301,6 +301,13 @@ GANTT .. note:: This feature is available in v0.12.0+. +.. figure:: lnav-gantt-1.png + :align: center + + Screenshot of the Gantt chart view when viewing logs from the + VMWare Update Manager. Most rows show API requests as they + are received and processed. + The Gantt Chart view visualizes operations over time. The operations are identified by the "opid" field defined in the log format. In the view, there is a header that shows the overall time span, the @@ -322,7 +329,27 @@ focused time span will be adjusted to keep the preceding and following five operations within the span. The preview panel at the bottom of the display will show the -messages associated with the operation. +messages associated with the focused operation. + +The following hotkeys can be useful in this view: + +* :kbd:`p` -- If the log format defined sub-operations with the + :code:`opid/subid` property, this will toggle an overlay panel + that displays the sub-operation descriptions. + + .. figure:: lnav-gantt-2.png + :align: center + + Screenshot showing the same log as above after pressing + :kbd:`p`. The overlay panel shows a breakdown of + sub-operations performed while processing the main operation. + +* :kbd:`Shift` + :kbd:`q` -- Return to the previous view and change + its focused line to match the time that was focused in the gantt + view. +* :kbd:`Shift` + :kbd:`a` -- After leaving the gantt view, pressing + these keys will return to the Gantt view while keeping the focused + time in sync. PRETTY ^^^^^^ diff --git a/release/loggen.py b/release/loggen.py index 5e0bbbb5..556991cc 100755 --- a/release/loggen.py +++ b/release/loggen.py @@ -131,7 +131,7 @@ TEST_AGENTS = [ "Roku4640X/DVP-7.70 (297.70E04154A)", ] -START_TIME = datetime.datetime.fromtimestamp(1641898727) +START_TIME = datetime.datetime.fromtimestamp(1692700000) ACCESS_LOG_CURR_TIME = START_TIME SYSLOG_LOG_CURR_TIME = START_TIME @@ -139,7 +139,7 @@ SYSLOG_LOG_CURR_TIME = START_TIME def access_log_msgs(): global ACCESS_LOG_CURR_TIME while True: - ACCESS_LOG_CURR_TIME += datetime.timedelta(seconds=random.randrange(1, 3)) + ACCESS_LOG_CURR_TIME += datetime.timedelta(seconds=random.randrange(1, 5)) yield '%s - %s [%s +0000] "%s %s %s" %s %s "%s" "%s"\n' % ( random.choice(TEST_ADDRESSES), random.choice(TEST_USERNAMES), @@ -181,7 +181,7 @@ TEST_MSGS = [ def syslog_msgs(): global SYSLOG_LOG_CURR_TIME while True: - SYSLOG_LOG_CURR_TIME += datetime.timedelta(seconds=random.randrange(1, 3)) + SYSLOG_LOG_CURR_TIME += datetime.timedelta(seconds=random.randrange(1, 5)) yield '%s frontend3 %s: %s\n' % ( SYSLOG_LOG_CURR_TIME.strftime(SYSLOG_DATE_FMT), random.choice(TEST_PROCS), diff --git a/src/formats/procstate_log.json b/src/formats/procstate_log.json index 0c409167..c6fe7277 100644 --- a/src/formats/procstate_log.json +++ b/src/formats/procstate_log.json @@ -15,7 +15,7 @@ ], "search-table": { "procstate_procs": { - "pattern": "^(?\\S+)\\s+(?:(?\\d+)\\s+)?(?\\d+)\\s+(?\\d+(?:\\.\\d+)?)\\s+(?\\d+(?:\\.\\d+)?)\\s+(?\\d+)\\s+(?\\d+)\\s(?\\S+)\\s+(?\\S+)\\s+(?\\S+)\\s+(?\\S+)\\s+(?(?[^ \\n]+)(?: (?[^\\n]+))?)$" + "pattern": "^(?\\S+)\\s+(?:(?\\d+)\\s+)?(?\\d+)\\s+(?\\d+(?:\\.\\d+)?)\\s+(?\\d+(?:\\.\\d+)?)\\s+(?\\d+)\\s+(?\\d+)\\s(?\\S+)\\s+(?\\S+)\\s+(?\\S+)\\s+(?\\S+)(?:\\s+(?\\d+)\\s+(?\\d+))?\\s+(?(?[^ \\n]+)(?: (?[^\\n]+))?)$" } } } diff --git a/src/spectro_source.cc b/src/spectro_source.cc index 6a098da4..0fefd48b 100644 --- a/src/spectro_source.cc +++ b/src/spectro_source.cc @@ -132,6 +132,7 @@ spectrogram_source::list_input_handle_key(listview_curses& lv, int ch) this->text_attrs_for_line((textview_curses&) lv, sel, sa); if (sa.empty()) { + this->ss_details_source.reset(); this->ss_cursor_column = nonstd::nullopt; return true; } @@ -165,6 +166,7 @@ spectrogram_source::list_input_handle_key(listview_curses& lv, int ch) } } this->ss_cursor_column = current->sa_range.lr_start; + this->ss_details_source.reset(); lv.reload_data(); @@ -526,12 +528,14 @@ spectrogram_source::text_selection_changed(textview_curses& tc) { if (this->ss_value_source == nullptr || this->text_line_count() == 0) { this->ss_cursor_column = nonstd::nullopt; + this->ss_details_source.reset(); return; } const auto& s_row = this->load_row(tc, tc.get_selection()); this->ss_cursor_column = s_row.nearest_column(this->ss_cursor_column.value_or(0)); + this->ss_details_source.reset(); } bool diff --git a/test/expected/test_sql_search_table.sh_5aaae556ecb1661602f176215e28f661d3404032.out b/test/expected/test_sql_search_table.sh_5aaae556ecb1661602f176215e28f661d3404032.out index 927666fa..20c213a0 100644 --- a/test/expected/test_sql_search_table.sh_5aaae556ecb1661602f176215e28f661d3404032.out +++ b/test/expected/test_sql_search_table.sh_5aaae556ecb1661602f176215e28f661d3404032.out @@ -1,4 +1,4 @@ -log_line log_part  log_time log_idle_msecs log_level log_mark log_comment log_tags log_annotations log_filters match_index user  ppid pid cpu_pct mem_pct vsz rss tty stat start_time cpu_time  cmd  cmd_name cmd_args  - 0 2022-06-02 00:01:01.000  0 info 0 1 root 2  0  0  0  0 ? S Jun01 0:00 [kthreadd] [kthreadd] - 12   2022-06-02 00:02:01.000  60000 info   0          1 root   2  0  0  0  0 ?  S  Jun01  0:00  [kthreadd] [kthreadd]  - 30   2022-06-02 00:03:01.000  60000 info   0          1 root   2  0  0  0  0 ?  S  Jun01  0:00  [kthreadd] [kthreadd]   +log_line log_part  log_time log_idle_msecs log_level log_mark log_comment log_tags log_annotations log_filters match_index user  ppid pid cpu_pct mem_pct vsz rss tty stat start_time cpu_time maj_flt min_flt  cmd  cmd_name cmd_args  + 0 2022-06-02 00:01:01.000  0 info 0 1 root 2  0  0  0  0 ? S Jun01 0:00 [kthreadd] [kthreadd] + 12   2022-06-02 00:02:01.000  60000 info   0          1 root   2  0  0  0  0 ?  S  Jun01  0:00      [kthreadd] [kthreadd]  + 30   2022-06-02 00:03:01.000  60000 info   0          1 root   2  0  0  0  0 ?  S  Jun01  0:00      [kthreadd] [kthreadd]   diff --git a/test/expected/test_sql_search_table.sh_df0fd242f57a96d40f466493938cda0789a094fa.out b/test/expected/test_sql_search_table.sh_df0fd242f57a96d40f466493938cda0789a094fa.out index 22cd3f38..62071ed6 100644 --- a/test/expected/test_sql_search_table.sh_df0fd242f57a96d40f466493938cda0789a094fa.out +++ b/test/expected/test_sql_search_table.sh_df0fd242f57a96d40f466493938cda0789a094fa.out @@ -1,24 +1,24 @@ -log_line log_part  log_time log_idle_msecs log_level log_mark log_comment log_tags log_annotations log_filters match_index user  ppid pid cpu_pct mem_pct  vsz rss tty stat start_time cpu_time  cmd  cmd_name  cmd_args  - 0   2022-06-02 00:01:01.000  0 info   0          0 root   1  0  0 158392 7792 ?  Ss  Jun01  0:14  /lib/systemd/systemd --switched-root --system --deserialize 16 /lib/systemd/systemd --switched-root --system --deserialize 16 - 0 2022-06-02 00:01:01.000  0 info 0 1 root 2  0  0  0  0 ? S Jun01 0:00 [kthreadd] [kthreadd] - 0  <NULL> 2022-06-02 00:01:01.000  0 info   0  <NULL>  <NULL>  <NULL>  <NULL>  2 root <NULL>  3  0  0  0  0 ?  I<  Jun01  0:00  [rcu_gp]  [rcu_gp]  <NULL>  - 0  <NULL> 2022-06-02 00:01:01.000  0 info   0  <NULL>  <NULL>  <NULL>  <NULL>  3 root <NULL>  4  0  0  0  0 ?  I<  Jun01  0:00  [rcu_par_gp]  [rcu_par_gp]  <NULL>  - 0 2022-06-02 00:01:01.000  0 info 0 4 root 6  0  0  0  0 ? I< Jun01 0:00 [kworker/0:0H-kblockd] [kworker/0:0H-kblockd] - 12   2022-06-02 00:02:01.000  60000 info   0          0 root   1  0  0 158392 7792 ?  Ss  Jun01  0:14  /lib/systemd/systemd --switched-root --system --deserialize 16 /lib/systemd/systemd  --switched-root --system --deserialize 16 - 12   2022-06-02 00:02:01.000  60000 info   0    <NULL>  <NULL>  <NULL>  1 root <NULL>  2  0  0  0  0 ?  S  Jun01  0:00  [kthreadd]  [kthreadd]  <NULL>  - 12   2022-06-02 00:02:01.000  60000 info   0    <NULL>  <NULL>  <NULL>  2 root <NULL>  3  0  0  0  0 ?  I<  Jun01  0:00  [rcu_gp]  [rcu_gp]  <NULL>  - 12   2022-06-02 00:02:01.000  60000 info   0    3 root 4  0  0  0  0 ? I< Jun01 0:00 [rcu_par_gp] [rcu_par_gp] - 12   2022-06-02 00:02:01.000  60000 info   0    4 root 6  0  0  0  0 ? I< Jun01 0:00 [kworker/0:0H-kblockd] [kworker/0:0H-kblockd] - 12   2022-06-02 00:02:01.000  60000 info   0    <NULL>  <NULL>  <NULL>  5 root <NULL>  8  0  0  0  0 ?  I<  Jun01  0:00  [mm_percpu_wq]  [mm_percpu_wq]  <NULL>  - 12   2022-06-02 00:02:01.000  60000 info   0    <NULL>  <NULL>  <NULL>  6 root <NULL>  9  0  0  0  0 ?  S  Jun01  0:00  [ksoftirqd/0]  [ksoftirqd/0]  <NULL>  - 12   2022-06-02 00:02:01.000  60000 info   0    7 root 10  0  0  0  0 ? I Jun01 0:23 [rcu_sched] [rcu_sched] - 12   2022-06-02 00:02:01.000  60000 info   0    8 root 11  0  0  0  0 ? I Jun01 0:00 [rcu_bh] [rcu_bh] - 12   2022-06-02 00:02:01.000  60000 info   0    <NULL>  <NULL>  <NULL>  9 root <NULL>  12  0  0  0  0 ?  S  Jun01  0:00  [migration/0]  [migration/0]  <NULL>  - 12   2022-06-02 00:02:01.000  60000 info   0    <NULL>  <NULL>  <NULL>  10 root <NULL>  14  0  0  0  0 ?  S  Jun01  0:00  [cpuhp/0]  [cpuhp/0]  <NULL>  - 30   2022-06-02 00:03:01.000  60000 info   0          0 root   1  0  0 158392 7792 ?  Ss  Jun01  0:14  /lib/systemd/systemd --switched-root --system --deserialize 16 /lib/systemd/systemd  --switched-root --system --deserialize 16 - 30   2022-06-02 00:03:01.000  60000 info   0    1 root 2  0  0  0  0 ? S Jun01 0:00 [kthreadd] [kthreadd] - 30   2022-06-02 00:03:01.000  60000 info   0    <NULL>  <NULL>  <NULL>  2 root <NULL>  3  0  0  0  0 ?  I<  Jun01  0:00  [rcu_gp]  [rcu_gp]  <NULL>  - 30   2022-06-02 00:03:01.000  60000 info   0    <NULL>  <NULL>  <NULL>  3 root <NULL>  4  0  0  0  0 ?  I<  Jun01  0:00  [rcu_par_gp]  [rcu_par_gp]  <NULL>  - 30   2022-06-02 00:03:01.000  60000 info   0    4 root 6  0  0  0  0 ? I< Jun01 0:00 [kworker/0:0H-kblockd] [kworker/0:0H-kblockd] - 30   2022-06-02 00:03:01.000  60000 info   0    5 root 8  0  0  0  0 ? I< Jun01 0:00 [mm_percpu_wq] [mm_percpu_wq] - 30   2022-06-02 00:03:01.000  60000 info   0    <NULL>  <NULL>  <NULL>  6 root <NULL>  9  0  0  0  0 ?  S  Jun01  0:00  [ksoftirqd/0]  [ksoftirqd/0]  <NULL>  +log_line log_part  log_time log_idle_msecs log_level log_mark log_comment log_tags log_annotations log_filters match_index user  ppid pid cpu_pct mem_pct  vsz rss tty stat start_time cpu_time maj_flt min_flt  cmd  cmd_name  cmd_args  + 0   2022-06-02 00:01:01.000  0 info   0          0 root   1  0  0 158392 7792 ?  Ss  Jun01  0:14      /lib/systemd/systemd --switched-root --system --deserialize 16 /lib/systemd/systemd --switched-root --system --deserialize 16 + 0 2022-06-02 00:01:01.000  0 info 0 1 root 2  0  0  0  0 ? S Jun01 0:00 [kthreadd] [kthreadd] + 0  <NULL> 2022-06-02 00:01:01.000  0 info   0  <NULL>  <NULL>  <NULL>  <NULL>  2 root <NULL>  3  0  0  0  0 ?  I<  Jun01  0:00   <NULL>  <NULL> [rcu_gp]  [rcu_gp]  <NULL>  + 0  <NULL> 2022-06-02 00:01:01.000  0 info   0  <NULL>  <NULL>  <NULL>  <NULL>  3 root <NULL>  4  0  0  0  0 ?  I<  Jun01  0:00   <NULL>  <NULL> [rcu_par_gp]  [rcu_par_gp]  <NULL>  + 0 2022-06-02 00:01:01.000  0 info 0 4 root 6  0  0  0  0 ? I< Jun01 0:00 [kworker/0:0H-kblockd] [kworker/0:0H-kblockd] + 12   2022-06-02 00:02:01.000  60000 info   0          0 root   1  0  0 158392 7792 ?  Ss  Jun01  0:14      /lib/systemd/systemd --switched-root --system --deserialize 16 /lib/systemd/systemd  --switched-root --system --deserialize 16 + 12   2022-06-02 00:02:01.000  60000 info   0      <NULL>  <NULL>  1 root <NULL>  2  0  0  0  0 ?  S  Jun01  0:00   <NULL>  <NULL> [kthreadd]  [kthreadd]  <NULL>  + 12   2022-06-02 00:02:01.000  60000 info   0      <NULL>  <NULL>  2 root <NULL>  3  0  0  0  0 ?  I<  Jun01  0:00   <NULL>  <NULL> [rcu_gp]  [rcu_gp]  <NULL>  + 12   2022-06-02 00:02:01.000  60000 info   0    3 root 4  0  0  0  0 ? I< Jun01 0:00 [rcu_par_gp] [rcu_par_gp] + 12   2022-06-02 00:02:01.000  60000 info   0    4 root 6  0  0  0  0 ? I< Jun01 0:00 [kworker/0:0H-kblockd] [kworker/0:0H-kblockd] + 12   2022-06-02 00:02:01.000  60000 info   0      <NULL>  <NULL>  5 root <NULL>  8  0  0  0  0 ?  I<  Jun01  0:00   <NULL>  <NULL> [mm_percpu_wq]  [mm_percpu_wq]  <NULL>  + 12   2022-06-02 00:02:01.000  60000 info   0      <NULL>  <NULL>  6 root <NULL>  9  0  0  0  0 ?  S  Jun01  0:00   <NULL>  <NULL> [ksoftirqd/0]  [ksoftirqd/0]  <NULL>  + 12   2022-06-02 00:02:01.000  60000 info   0    7 root 10  0  0  0  0 ? I Jun01 0:23 [rcu_sched] [rcu_sched] + 12   2022-06-02 00:02:01.000  60000 info   0    8 root 11  0  0  0  0 ? I Jun01 0:00 [rcu_bh] [rcu_bh] + 12   2022-06-02 00:02:01.000  60000 info   0      <NULL>  <NULL>  9 root <NULL>  12  0  0  0  0 ?  S  Jun01  0:00   <NULL>  <NULL> [migration/0]  [migration/0]  <NULL>  + 12   2022-06-02 00:02:01.000  60000 info   0      <NULL>  <NULL>  10 root <NULL>  14  0  0  0  0 ?  S  Jun01  0:00   <NULL>  <NULL> [cpuhp/0]  [cpuhp/0]  <NULL>  + 30   2022-06-02 00:03:01.000  60000 info   0          0 root   1  0  0 158392 7792 ?  Ss  Jun01  0:14      /lib/systemd/systemd --switched-root --system --deserialize 16 /lib/systemd/systemd  --switched-root --system --deserialize 16 + 30   2022-06-02 00:03:01.000  60000 info   0    1 root 2  0  0  0  0 ? S Jun01 0:00 [kthreadd] [kthreadd] + 30   2022-06-02 00:03:01.000  60000 info   0      <NULL>  <NULL>  2 root <NULL>  3  0  0  0  0 ?  I<  Jun01  0:00   <NULL>  <NULL> [rcu_gp]  [rcu_gp]  <NULL>  + 30   2022-06-02 00:03:01.000  60000 info   0      <NULL>  <NULL>  3 root <NULL>  4  0  0  0  0 ?  I<  Jun01  0:00   <NULL>  <NULL> [rcu_par_gp]  [rcu_par_gp]  <NULL>  + 30   2022-06-02 00:03:01.000  60000 info   0    4 root 6  0  0  0  0 ? I< Jun01 0:00 [kworker/0:0H-kblockd] [kworker/0:0H-kblockd] + 30   2022-06-02 00:03:01.000  60000 info   0    5 root 8  0  0  0  0 ? I< Jun01 0:00 [mm_percpu_wq] [mm_percpu_wq] + 30   2022-06-02 00:03:01.000  60000 info   0      <NULL>  <NULL>  6 root <NULL>  9  0  0  0  0 ?  S  Jun01  0:00   <NULL>  <NULL> [ksoftirqd/0]  [ksoftirqd/0]  <NULL>