Skip to content

Commit fb43785

Browse files
committed
[ui] report background tasks
1 parent de3be85 commit fb43785

22 files changed

Lines changed: 929 additions & 157 deletions

NEWS.md

Lines changed: 38 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -2,11 +2,38 @@
22
## lnav v0.14.0
33

44
Features:
5-
* Log formats can now specify source file/line and thread
6-
ID with the `src-file-field`, `src-line-field`, and
7-
`thread-id-field` properties. These fields can then be
8-
accessed in the SQL vtables as `log_src_file`,
9-
`log_src_line`, and `log_thread_id`.
5+
* Introducing "Log-Oriented Debugging", a collection of
6+
features to streamline mapping log messages back to
7+
the source code that generated them. For example,
8+
given the log message "Hello, Steve!" and the source
9+
directory containing the log statement. lnav can
10+
find the line of code that generated the message,
11+
such as `logging.info("Hello, %s!", name)`, and
12+
determine the value of the substituted variables
13+
(`name` => `Steve`). This functionality is
14+
implemented using the
15+
[log2src](https://github.com/ttiimm/log2src) project.
16+
The following features have been added in support of
17+
this functionality:
18+
- The `:add-source-path` command was added to specify
19+
the source directories to be scanned for log
20+
statements.
21+
- Log formats can now specify source file/line and
22+
thread ID with the `src-file-field`, `src-line-field`,
23+
and `thread-id-field` properties. These fields can
24+
then be accessed in the SQL vtables as `log_src_file`,
25+
`log_src_line`, and `log_thread_id`.
26+
- The `:breakpoint`, `:toggle-breakpoint`, and
27+
`:clear-breakpoints` commands have been added to
28+
support setting/clearing breakpoints for log messages.
29+
The `CTRL-B` shortcut toggles a breakpoint on the
30+
focused line in the LOG view. Also, if the log
31+
format specifies source file/line fields, the first
32+
character of the source file will be underlined and
33+
can be clicked to toggle a breakpoint. Once
34+
breakpoints have been added, you can press `F7`/`F8`
35+
to move to the previous/next log message that
36+
matches a breakpoint.
1037
* The `all_opids` and `all_thread_ids` virtual tables
1138
have been added to make it simple to discover all of
1239
the operations and threads across all log files.
@@ -28,21 +55,17 @@ Features:
2855
- The `prefers` property is a regular expression that
2956
will be tested against the full path to be opened.
3057
If matched, that editor will be chosen.
31-
* The `:breakpoint`, `:toggle-breakpoint`, and
32-
`:clear-breakpoints` commands have been added to support
33-
setting/clearing breakpoints for log messages. The
34-
`CTRL-B` shortcut toggles a breakpoint on the focused
35-
line in the LOG view. Also, if the log format specifies
36-
source file/line fields, the first character of the
37-
source file will be underlined and can be clicked to
38-
toggle a breakpoint. Once breakpoints have been added,
39-
you can press `F7`/`F8` to move to the previous/next log
40-
message that matches a breakpoint.
4158
* The `:external-access` command has been added to open a
4259
localhost HTTP port that can be used to remotely control
4360
lnav. Requests can be sent to execute commands and poll
4461
for changes in the view state.
4562

63+
Interface changes:
64+
* If there are background tasks, like the processing done
65+
by `:add-source-path`, a panel with progress bars for
66+
each operation will be shown just above the bottom
67+
status bar.
68+
4669
## lnav v0.13.2
4770

4871
Bug Fixes:

src/CMakeLists.txt

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -564,6 +564,7 @@ add_library(
564564
plain_text_source.cc
565565
pretty_printer.cc
566566
preview_status_source.cc
567+
progress_source.cc
567568
pugixml/pugixml.cpp
568569
readline_callbacks.cc
569570
readline_highlighters.cc
@@ -701,6 +702,7 @@ add_library(
701702
plain_text_source.hh
702703
pretty_printer.hh
703704
preview_status_source.hh
705+
progress_source.hh
704706
pugixml/pugiconfig.hpp
705707
pugixml/pugixml.hpp
706708
readline_callbacks.hh

src/Makefile.am

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -346,6 +346,7 @@ noinst_HEADERS = \
346346
pollable.hh \
347347
pretty_printer.hh \
348348
preview_status_source.hh \
349+
progress_source.hh \
349350
ptimec.hh \
350351
ptimec_spec.hh \
351352
readline_callbacks.hh \
@@ -544,6 +545,7 @@ libdiag_a_SOURCES = \
544545
pollable.cc \
545546
pretty_printer.cc \
546547
preview_status_source.cc \
548+
progress_source.cc \
547549
ptimec_rt.cc \
548550
readline_callbacks.cc \
549551
readline_highlighters.cc \

src/base/progress.hh

Lines changed: 50 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -30,13 +30,62 @@
3030
#ifndef lnav_progress_hh
3131
#define lnav_progress_hh
3232

33+
#include <cstdint>
34+
#include <string>
35+
#include <vector>
36+
37+
#include "distributed_slice.hh"
38+
#include "lnav.console.hh"
39+
#include "safe/safe.h"
40+
3341
namespace lnav {
3442

35-
enum class progress_result_t {
43+
enum class progress_result_t : uint8_t {
3644
ok,
3745
interrupt,
3846
};
3947

48+
enum class progress_status_t : uint8_t {
49+
idle,
50+
working,
51+
};
52+
53+
struct task_progress {
54+
std::string tp_id;
55+
progress_status_t tp_status{progress_status_t::idle};
56+
size_t tp_version{0};
57+
std::string tp_step;
58+
size_t tp_completed{0};
59+
size_t tp_total{0};
60+
std::vector<console::user_message> tp_messages;
61+
};
62+
63+
using progress_reporter_t = task_progress(*)();
64+
65+
struct progress_tracker {
66+
using task_container = dist_slice_container<progress_reporter_t>;
67+
68+
using safe_task_container = safe::Safe<task_container*>;
69+
70+
static safe_task_container& get_tasks()
71+
{
72+
static auto pt = progress_tracker();
73+
74+
return pt.pt_tasks;
75+
}
76+
77+
private:
78+
safe_task_container pt_tasks;
79+
80+
progress_tracker()
81+
{
82+
static auto inner
83+
= DIST_SLICE_CONTAINER(progress_reporter_t, prog_reps);
84+
85+
*this->pt_tasks.writeAccess() = &inner;
86+
}
87+
};
88+
4089
} // namespace lnav
4190

4291
#endif

src/cmds.scripting.cc

Lines changed: 62 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -477,8 +477,70 @@ com_sh(exec_context& ec, std::string cmdline, std::vector<std::string>& args)
477477
}
478478

479479
#ifdef HAVE_RUST_DEPS
480+
481+
static lnav::task_progress
482+
ext_prog_rep()
483+
{
484+
auto ext = lnav_rs_ext::get_status();
485+
auto status = ext.status == lnav_rs_ext::Status::idle
486+
? lnav::progress_status_t::idle
487+
: lnav::progress_status_t::working;
488+
std::vector<lnav::console::user_message> msgs_out;
489+
for (const auto& err : ext.messages) {
490+
auto um = lnav::console::user_message::error((std::string) err.error)
491+
.with_reason((std::string) err.source)
492+
.with_help((std::string) err.help);
493+
msgs_out.emplace_back(um);
494+
}
495+
auto retval = lnav::task_progress{
496+
(std::string) ext.id,
497+
status,
498+
ext.version,
499+
(std::string) ext.current_step,
500+
ext.completed,
501+
ext.total,
502+
std::move(msgs_out),
503+
};
504+
505+
return retval;
506+
}
507+
508+
DIST_SLICE(prog_reps) lnav::progress_reporter_t EXT_PROG_REP = ext_prog_rep;
509+
480510
namespace lnav_rs_ext {
481511

512+
LnavLogLevel
513+
get_lnav_log_level()
514+
{
515+
switch (lnav_log_level) {
516+
case lnav_log_level_t::TRACE:
517+
return LnavLogLevel::trace;
518+
case lnav_log_level_t::DEBUG:
519+
return LnavLogLevel::debug;
520+
case lnav_log_level_t::INFO:
521+
return LnavLogLevel::info;
522+
case lnav_log_level_t::WARNING:
523+
return LnavLogLevel::warning;
524+
case lnav_log_level_t::ERROR:
525+
return LnavLogLevel::error;
526+
}
527+
528+
return LnavLogLevel::info;
529+
}
530+
531+
void
532+
log_msg(LnavLogLevel level, ::rust::Str file, uint32_t line, ::rust::Str msg)
533+
{
534+
auto ln_level = static_cast<lnav_log_level_t>(level);
535+
536+
::log_msg(ln_level,
537+
((std::string) file).c_str(),
538+
line,
539+
"%.*s",
540+
msg.size(),
541+
msg.data());
542+
}
543+
482544
::rust::String
483545
version_info()
484546
{

src/command_executor.cc

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -285,6 +285,7 @@ execute_sql(exec_context& ec, const std::string& sql, std::string& alt_msg)
285285
log_info("compiling PRQL: %s", stmt_str.c_str());
286286

287287
#if HAVE_RUST_DEPS
288+
extern rust::Vec<lnav_rs_ext::SourceTreeElement> sqlite_extension_prql;
288289
auto opts = lnav_rs_ext::Options{true, "sql.sqlite", true};
289290

290291
auto tree = sqlite_extension_prql;

src/ext.longpoll.cc

Lines changed: 105 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -32,6 +32,9 @@
3232

3333
#include "ext.longpoll.hh"
3434

35+
#include "base/injector.hh"
36+
#include "base/itertools.enumerate.hh"
37+
#include "base/progress.hh"
3538
#include "config.h"
3639
#include "lnav_rs_ext.cxx.hh"
3740
#include "safe/safe.h"
@@ -51,30 +54,119 @@ using safe_pollers_t = safe::Safe<pollers>;
5154

5255
safe_pollers_t POLLERS;
5356

54-
PollInput
57+
PollResult
5558
longpoll(const PollInput& pi)
5659
{
57-
auto p = POLLERS.writeAccess<std::unique_lock>();
60+
auto pi_retval = PollInput{
61+
0,
62+
};
63+
auto timeout = 10000ms;
5864

59-
if (pi.view_states.log == p->p_latest_state.vs_log
60-
&& pi.view_states.text == p->p_latest_state.vs_text)
6165
{
62-
p->p_pollers.emplace_front(pi);
63-
auto iter = p->p_pollers.begin();
64-
65-
p->p_condvar.wait_for(p.lock, 10s);
66-
p->p_pollers.erase(iter);
66+
auto& bts = lnav::progress_tracker::get_tasks();
67+
68+
for (const auto& bt : **bts.readAccess()) {
69+
auto tp = bt();
70+
if (tp.tp_status == lnav::progress_status_t::working) {
71+
timeout = 333ms;
72+
break;
73+
}
74+
}
6775
}
6876

69-
return PollInput{
70-
0,
71-
ViewStates{
77+
{
78+
auto p = POLLERS.writeAccess<std::unique_lock>();
79+
auto views_are_same = pi.view_states.log == p->p_latest_state.vs_log
80+
&& pi.view_states.text == p->p_latest_state.vs_text;
81+
auto tasks_are_same = true;
82+
83+
{
84+
auto& bts = lnav::progress_tracker::get_tasks();
85+
auto* task_cont = *bts.readAccess();
86+
tasks_are_same = pi.task_states.size() == task_cont->size();
87+
if (tasks_are_same) {
88+
for (size_t lpc = 0; lpc < pi.task_states.size(); lpc++) {
89+
if (lpc >= task_cont->size()) {
90+
continue;
91+
}
92+
93+
auto tp = (*std::next(task_cont->begin(), lpc))();
94+
if (tp.tp_version != pi.task_states[lpc]) {
95+
tasks_are_same = false;
96+
break;
97+
}
98+
}
99+
}
100+
}
101+
102+
if (views_are_same && tasks_are_same) {
103+
p->p_pollers.emplace_front(pi);
104+
auto iter = p->p_pollers.begin();
105+
106+
p->p_condvar.wait_for(p.lock, timeout);
107+
p->p_pollers.erase(iter);
108+
}
109+
pi_retval.view_states = ViewStates{
72110
::rust::String::lossy(p->p_latest_state.vs_log),
73111
::rust::String::lossy(p->p_latest_state.vs_text),
74-
},
112+
};
113+
}
114+
115+
::rust::Vec<ExtProgress> bt_out;
116+
{
117+
auto& bts = lnav::progress_tracker::get_tasks();
118+
for (const auto& [index, bt] :
119+
lnav::itertools::enumerate(**bts.readAccess()))
120+
{
121+
auto tp = bt();
122+
pi_retval.task_states.emplace_back(tp.tp_version);
123+
if (tp.tp_version == 0) {
124+
continue;
125+
}
126+
if (tp.tp_status == lnav::progress_status_t::idle
127+
&& index < pi.task_states.size()
128+
&& pi.task_states[index] == tp.tp_version)
129+
{
130+
continue;
131+
}
132+
133+
::rust::Vec<ExtError> errors_out;
134+
for (const auto& msg : tp.tp_messages) {
135+
errors_out.emplace_back(ExtError{
136+
msg.um_message.al_string,
137+
msg.um_reason.al_string,
138+
msg.um_help.al_string,
139+
});
140+
}
141+
142+
auto ep = ExtProgress{
143+
tp.tp_id,
144+
tp.tp_status == lnav::progress_status_t::idle ? Status::idle
145+
: Status::working,
146+
tp.tp_version,
147+
tp.tp_step,
148+
tp.tp_completed,
149+
tp.tp_total,
150+
};
151+
bt_out.emplace_back(ep);
152+
}
153+
}
154+
155+
return PollResult{
156+
pi_retval,
157+
std::move(bt_out),
75158
};
76159
}
77160

161+
void
162+
notify_pollers()
163+
{
164+
# ifdef HAVE_RUST_DEPS
165+
auto p = POLLERS.writeAccess<std::unique_lock>();
166+
p->p_condvar.notify_all();
167+
# endif
168+
}
169+
78170
} // namespace lnav_rs_ext
79171
#endif
80172

src/ext.longpoll.hh

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -39,6 +39,8 @@ struct view_states {
3939
std::string vs_text;
4040
};
4141

42+
void notify_pollers();
43+
4244
void notify_pollers(const view_states& vs);
4345

4446
} // namespace lnav::ext

0 commit comments

Comments
 (0)