Skip to content

Commit 3e9e2df

Browse files
tstacktstack
committed
[timeline] create ranges out of tags
1 parent 2c59660 commit 3e9e2df

8 files changed

Lines changed: 118 additions & 28 deletions

‎NEWS.md‎

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -103,6 +103,16 @@ Bug Fixes:
103103
check is only done on files that contain at least
104104
100 lines and those lines are checked to see if
105105
they have the same timestamp/file-offset.
106+
* In the TIMELINE view, tags whose names start or end
107+
with "stop", "stopped", "end", "ended", "finish", or
108+
"finished" (case-insensitive) are now paired with
109+
matching "start", "started", or "begin" tags that
110+
share the same base name (for example, `#start-foo`
111+
is paired with `#stop-foo`). The start tag's row
112+
spans from the start time to the stop time, and the
113+
stop tag is no longer shown as a separate row. Tags
114+
without a base name (such as a bare `#start`) are
115+
not paired.
106116

107117

108118
## lnav v0.14.0

‎src/logfile.cc‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1827,7 +1827,9 @@ logfile::rebuild_index(std::optional<ui_clock::time_point> deadline)
18271827
std::distance(this->begin(), curr_ll));
18281828

18291829
this->lf_bookmark_metadata[line_number].add_tag(
1830-
td->ftd_name,
1830+
tag_md.get_count() > 1
1831+
? td->ftd_name + tag_md.to_string()
1832+
: td->ftd_name,
18311833
bookmark_metadata::meta_source::format);
18321834
}
18331835
}

‎src/timeline_source.cc‎

Lines changed: 78 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -1036,37 +1036,86 @@ timeline_source::rebuild_indexes()
10361036
this->ts_index_progress(std::nullopt);
10371037
}
10381038

1039+
std::set<string_fragment> consumed_tag_keys;
10391040
{
1040-
static const auto START_RE = lnav::pcre2pp::code::from_const(
1041-
R"(^(?:start(?:ed)?|begin)|\b(?:start(?:ed)?|begin)$)",
1041+
static const auto START_PREFIX_RE = lnav::pcre2pp::code::from_const(
1042+
R"(^#(?:start(?:ed)?|begin)[-_:.]?(.*)$)", PCRE2_CASELESS);
1043+
static const auto START_SUFFIX_RE = lnav::pcre2pp::code::from_const(
1044+
R"(^(.*?)(?:[-_:.])?\b(?:start(?:ed)?|begin)$)", PCRE2_CASELESS);
1045+
static const auto STOP_PREFIX_RE = lnav::pcre2pp::code::from_const(
1046+
R"(^#(?:stop(?:ped)?|end(?:ed)?|finish(?:ed)?)[-_:.]?(.*)$)",
1047+
PCRE2_CASELESS);
1048+
static const auto STOP_SUFFIX_RE = lnav::pcre2pp::code::from_const(
1049+
R"(^(.*?)(?:[-_:.])?\b(?:stop(?:ped)?|end(?:ed)?|finish(?:ed)?)$)",
10421050
PCRE2_CASELESS);
10431051

1044-
std::vector<opid_row*> start_tags;
1052+
struct span_event {
1053+
bool se_is_start;
1054+
std::chrono::microseconds se_time;
1055+
opid_row* se_row;
1056+
string_fragment se_key;
1057+
};
1058+
std::map<string_fragment, std::vector<span_event>> events_by_base;
1059+
thread_local auto md = lnav::pcre2pp::match_data::unitialized();
10451060
for (auto& pair : this->ts_active_opids) {
10461061
if (pair.second.or_type != row_type::tag) {
10471062
continue;
10481063
}
1049-
if (START_RE.find_in(pair.second.or_name).ignore_error()) {
1050-
start_tags.emplace_back(&pair.second);
1064+
auto tag = pair.second.or_name;
1065+
std::optional<bool> is_start;
1066+
std::optional<string_fragment> base;
1067+
if (START_PREFIX_RE.capture_from(tag).into(md).found_p()) {
1068+
is_start = true;
1069+
base = md[1];
1070+
} else if (START_SUFFIX_RE.capture_from(tag).into(md).found_p()) {
1071+
is_start = true;
1072+
base = md[1];
1073+
} else if (STOP_PREFIX_RE.capture_from(tag).into(md).found_p()) {
1074+
is_start = false;
1075+
base = md[1];
1076+
} else if (STOP_SUFFIX_RE.capture_from(tag).into(md).found_p()) {
1077+
is_start = false;
1078+
base = md[1];
10511079
}
1080+
if (!is_start.has_value()) {
1081+
continue;
1082+
}
1083+
if (base->empty()) {
1084+
continue;
1085+
}
1086+
events_by_base[base.value()].push_back({
1087+
is_start.value(),
1088+
pair.second.or_value.otr_range.tr_begin,
1089+
&pair.second,
1090+
pair.first,
1091+
});
10521092
}
1053-
std::stable_sort(start_tags.begin(),
1054-
start_tags.end(),
1055-
[](const auto* lhs, const auto* rhs) {
1056-
if (lhs->or_name == rhs->or_name) {
1057-
return lhs->or_value.otr_range.tr_begin
1058-
< rhs->or_value.otr_range.tr_begin;
1059-
}
1060-
return lhs->or_name < rhs->or_name;
1061-
});
1062-
for (size_t i = 0; i < start_tags.size(); i++) {
1063-
if (i + 1 < start_tags.size()
1064-
&& start_tags[i]->or_name == start_tags[i + 1]->or_name)
1065-
{
1066-
start_tags[i]->or_value.otr_range.tr_end
1067-
= start_tags[i + 1]->or_value.otr_range.tr_begin - 1us;
1068-
} else {
1069-
start_tags[i]->or_value.otr_range.tr_end = last_log_time;
1093+
1094+
for (auto& base_pair : events_by_base) {
1095+
auto& events = base_pair.second;
1096+
std::stable_sort(
1097+
events.begin(), events.end(), [](const auto& l, const auto& r) {
1098+
if (l.se_time != r.se_time) {
1099+
return l.se_time < r.se_time;
1100+
}
1101+
return l.se_is_start && !r.se_is_start;
1102+
});
1103+
opid_row* current_start = nullptr;
1104+
for (const auto& evt : events) {
1105+
if (evt.se_is_start) {
1106+
if (current_start != nullptr) {
1107+
current_start->or_value.otr_range.tr_end
1108+
= evt.se_time - 1us;
1109+
}
1110+
current_start = evt.se_row;
1111+
} else if (current_start != nullptr) {
1112+
current_start->or_value.otr_range.tr_end = evt.se_time;
1113+
consumed_tag_keys.insert(evt.se_key);
1114+
current_start = nullptr;
1115+
}
1116+
}
1117+
if (current_start != nullptr) {
1118+
current_start->or_value.otr_range.tr_end = last_log_time;
10701119
}
10711120
}
10721121
}
@@ -1080,10 +1129,10 @@ timeline_source::rebuild_indexes()
10801129
next_iter = std::next(next_iter);
10811130
}
10821131

1083-
auto part_key = fmt::format(
1084-
FMT_STRING("{}@{}"), part_name, begin_time.count());
1085-
auto part_key_sf = string_fragment::from_str(part_key).to_owned(
1086-
this->ts_allocator);
1132+
auto part_key
1133+
= fmt::format(FMT_STRING("{}@{}"), part_name, begin_time.count());
1134+
auto part_key_sf
1135+
= string_fragment::from_str(part_key).to_owned(this->ts_allocator);
10871136
auto part_name_sf
10881137
= string_fragment::from_str(part_name).to_owned(this->ts_allocator);
10891138
auto part_otr = opid_time_range{};
@@ -1120,6 +1169,9 @@ timeline_source::rebuild_indexes()
11201169
this->ts_time_order.clear();
11211170
this->ts_time_order.reserve(this->ts_active_opids.size());
11221171
for (auto& pair : this->ts_active_opids) {
1172+
if (consumed_tag_keys.count(pair.first) > 0) {
1173+
continue;
1174+
}
11231175
opid_row& row = pair.second;
11241176
opid_time_range& otr = pair.second.or_value;
11251177
std::string full_desc;

‎test/expected/Makefile.am‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1624,6 +1624,8 @@ dist_noinst_DATA = \
16241624
test_sql_views_vtab.sh_45dbef06572b43cb997682436e753a13e003f792.out \
16251625
test_sql_views_vtab.sh_485a6ac7c69bd4b5d34d3399a9c17f6a2dc89ad3.err \
16261626
test_sql_views_vtab.sh_485a6ac7c69bd4b5d34d3399a9c17f6a2dc89ad3.out \
1627+
test_sql_views_vtab.sh_4af3a57478faa9f206e90bb0500abbad566d534c.err \
1628+
test_sql_views_vtab.sh_4af3a57478faa9f206e90bb0500abbad566d534c.out \
16271629
test_sql_views_vtab.sh_5a1bca0859a81a5206bc95872f262a0568949f51.err \
16281630
test_sql_views_vtab.sh_5a1bca0859a81a5206bc95872f262a0568949f51.out \
16291631
test_sql_views_vtab.sh_62d15cb9d5a9259f198aa01ca8ed200d6da38d68.err \
@@ -1826,6 +1828,8 @@ dist_noinst_DATA = \
18261828
test_timeline.sh_0b9d98b7ae18fc6bb61ddff4e698b365c8352723.out \
18271829
test_timeline.sh_183e441e1ec6d1207c6cdbcc1d13dc9b812ea4f5.err \
18281830
test_timeline.sh_183e441e1ec6d1207c6cdbcc1d13dc9b812ea4f5.out \
1831+
test_timeline.sh_1858be38a9d8d6e74b2ae8e73e1c805118ee6b77.err \
1832+
test_timeline.sh_1858be38a9d8d6e74b2ae8e73e1c805118ee6b77.out \
18291833
test_timeline.sh_18f6dd738d8daece3db6e25e99322209dea604af.err \
18301834
test_timeline.sh_18f6dd738d8daece3db6e25e99322209dea604af.out \
18311835
test_timeline.sh_1a611c8752ca85361f436768a9982051530a5d2a.err \

‎test/expected/test_sessions.sh_639b83ce8f67975dfdc7086946ec287b43b6fa8c.out‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
"top_meta": {
44
"time": "2009-07-20 22:59:29.000000",
55
"file": "{test_dir}/logfile_access_log.0",
6-
"anchor": "#middle",
6+
"anchor": "#msg00046f2b171e9640-v1:b05c1bdfe75cde41e151c89087e31951",
77
"breadcrumbs": [
88
{
99
"display_value": "⊑ middle",

‎test/expected/test_timeline.sh_1858be38a9d8d6e74b2ae8e73e1c805118ee6b77.err‎

Whitespace-only changes.

‎test/expected/test_timeline.sh_1858be38a9d8d6e74b2ae8e73e1c805118ee6b77.out‎

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,11 @@
1+
 Duration | ✘▲ | Item | 70us |140us
2+
   █  🧵 1952452992 
3+
  144us ▄▁ 📄 logfile_glog.0 
4+
  118us    🏷 #start-query 
5+
      🧵 952452992 
6+
      🧵 52452992 
7+
    █ 🧵 2452992 
8+
      🧵 452992 
9+
  8us    🏷 #begin-backup 
10+
      🧵 52992 
11+
   █  🧵 2992 

‎test/test_timeline.sh‎

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -199,3 +199,14 @@ run_cap_test ${lnav_test} -n \
199199
run_cap_test ${lnav_test} -n \
200200
-c ':switch-to-view timeline' \
201201
${test_dir}/logfile_uwsgi.0
202+
203+
# start/stop tag pairing: a "stop" tag with the same base name as a
204+
# preceding "start" tag should consume the stop and extend the start
205+
# row's span to the stop time
206+
run_cap_test ${lnav_test} -n \
207+
-c ";UPDATE all_logs SET log_tags = json_array('#start-query') WHERE log_line = 1" \
208+
-c ";UPDATE all_logs SET log_tags = json_array('#stop-query') WHERE log_line = 4" \
209+
-c ";UPDATE all_logs SET log_tags = json_array('#begin-backup') WHERE log_line = 5" \
210+
-c ";UPDATE all_logs SET log_tags = json_array('#end-backup') WHERE log_line = 6" \
211+
-c ':switch-to-view timeline' \
212+
${test_dir}/logfile_glog.0

0 commit comments

Comments
 (0)