[nav] add "opid" support with a hotkey

This commit is contained in:
Timothy Stack 2015-11-24 20:59:24 -08:00
parent 885f65f402
commit 91406be91e
13 changed files with 210 additions and 16 deletions

8
NEWS
View File

@ -1,4 +1,12 @@
lnav v0.8.1:
Interface Changes:
* The 'o/O' hotkeys have been reassigned to navigate through log
messages that have a matching "opid" field. The old action of
moving forward and backward by 60 minutes can be simulated by
using the ':goto' command with a relative time and the 'r/R'
hotkeys.
lnav v0.8.0:
Features:
* Integration with "papertrailapp.com" for querying and tailing

10
README
View File

@ -51,9 +51,17 @@ You can view all the syslog messages by running:
$ lnav /var/log/messages*
SUPPORT
-------
The lnav mailing list can be reached at:
lnav@googlegroups.com
SEE ALSO
--------
Lnav website:
The lnav website:
http://lnav.org

View File

@ -90,6 +90,12 @@ fields:
:body-field: The name of the field that contains the main body of the
message. Defaults to "body".
:opid-field: The name of the field that contains the "operation ID" of the
message. An "operation ID" establishes a thread of messages that might
correspond to a particular operation/request/transaction. The user can
press the 'o' or 'Shift+O' hotkeys to move forward/backward through the
list of messages that have the same operation ID.
:module-field: The name of the field that contains the module identifier
that distinguishes messages from one log source from another. This field
should be used if this message format can act as a container for other

View File

@ -115,6 +115,9 @@ Spatial Navigation
- |ks| Shift |ke| + |ks| u |ke|
-
- Next/previous bookmark
* - |ks| o |ke|
- |ks| Shift |ke| + |ks| o |ke|
- Forward/backward through log messages with a matching "opid" field
* - |ks| y |ke|
- |ks| Shift |ke| + |ks| y |ke|
-
@ -134,9 +137,6 @@ Chronological Navigation
* - Keypress
-
- Command
* - |ks| o |ke|
- |ks| Shift |ke| + |ks| o |ke|
- Forward/backward 60 minutes
* - |ks| d |ke|
- |ks| Shift |ke| + |ks| d |ke|
- Forward/backward 24 hours

View File

@ -23,6 +23,7 @@
"level" : {
"error" : "^[^123].*"
},
"opid-field" : "c_ip",
"value" : {
"c_ip" : {
"kind" : "string",
@ -256,6 +257,11 @@
"pattern" : "^(?<timestamp>\\d{4}-\\d{2}-\\d{2}T\\d{2}:\\d{2}:\\d{2}\\.\\d{6}Z) (?<elb>[^ ]+) (?<client_ip>[\\w\\.:]+):(?<client_port>\\d+) (?<backend_ip>[\\w\\.:]+):(?<backend_port>\\d+) (?<request_processing_time>\\d+(\\.\\d+)?) (?<backend_processing_time>\\d+(\\.\\d+)?) (?<response_processing_time>\\d+(\\.\\d+)?) (?<elb_status_code>\\d+|-) (?<backend_status_code>\\d+|-) (?<received_bytes>\\d+) (?<sent_bytes>\\d+) \"(?:\\-|(?<cs_method>\\w+|-) (?<cs_uri_stem>[^ \\?]+)(?:\\?(?<cs_uri_query>[^ ]*))? (?<cs_version>[\\w/\\.]+|-)\\s*)\" \"(?<user_agent>[^\"]+)\" (?<ssl_cipher>[\\w-]+) (?<ssl_protocol>[\\w\\.-]+)(?<body>.*)"
}
},
"level-field": "elb_status_code",
"level" : {
"error" : "^[^123].*"
},
"opid-field" : "client_ip",
"value" : {
"elb" : {
"kind" : "string",
@ -356,6 +362,7 @@
"pattern" : "^(?<timestamp>.+) (?<level>.+) \\[(?<logger>.+)\\] \\((?<tid>.+)\\) (?<body>(?:-|\\n)*)"
}
},
"opid-field" : "tid",
"value" : {
"tid" : {
"kind" : "string",
@ -440,6 +447,7 @@
"critical" : "C",
"fatal" : "F"
},
"opid-field" : "thread",
"value" : {
"thread" : {
"kind" : "integer",
@ -953,6 +961,7 @@
"error" : "(?:(?:(?<![a-zA-Z]))(?:(?i)error(?:s)?)(?:(?![a-zA-Z]))|failed|failure)",
"warning" : "(?:(?:(?i)warn)|not responding|init: cannot execute)"
},
"opid-field" : "log_pid",
"module-field" : "log_procname",
"value" : {
"log_hostname" : {
@ -1062,6 +1071,7 @@
"level" : {
"error" : "^[^123]"
},
"opid-field" : "s_pid",
"value" : {
"s_pid" : {
"kind" : "string",
@ -1248,6 +1258,7 @@
"warning" : "warning",
"trace" : "verbose"
},
"opid-field" : "opid",
"value" : {
"prc" : {
"kind" : "string",

View File

@ -193,8 +193,8 @@ through the file.
from the terminal without picking up any of the extra
decorations.
o/O Move forward/backward 60 minutes from the current
position in the log file.
o/O Move forward/backward to the log message with a matching
'operation ID' (opid) field.
d/D Move forward/backward 24 hours from the current
position in the log file.
@ -776,3 +776,15 @@ search string (i.e. "pt:").
Only one papertrail search can be active at a time. So, if an ':open'
is done with a new query, the previous query will be closed first.
CONTACT
-------
For more information, visit the lnav website at:
http://lnav.org
For support questions, email:
lnav@googlegroups.com

View File

@ -48,6 +48,51 @@ using namespace std;
static bookmark_type_t BM_EXAMPLE("");
class logline_helper {
public:
logline_helper(logfile_sub_source &lss) : lh_sub_source(lss) {
};
logline &move_to_msg_start() {
content_line_t cl = this->lh_sub_source.at(this->lh_current_line);
logfile *lf = this->lh_sub_source.find(cl);
logfile::iterator ll = lf->begin() + cl;
while (ll->is_continued()) {
--ll;
--this->lh_current_line;
}
return (*lf)[cl];
};
void annotate() {
this->lh_string_attrs.clear();
this->lh_line_values.clear();
content_line_t cl = this->lh_sub_source.at(this->lh_current_line);
logfile *lf = this->lh_sub_source.find(cl);
logfile::iterator ll = lf->begin() + cl;
log_format *format = lf->get_format();
lf->read_full_message(ll, this->lh_msg_buffer);
format->annotate(this->lh_msg_buffer,
this->lh_string_attrs,
this->lh_line_values);
};
std::string to_string(const struct line_range &lr) {
const char *start = this->lh_msg_buffer.get_data();
return string(&start[lr.lr_start], lr.length());
}
logfile_sub_source &lh_sub_source;
vis_line_t lh_current_line;
shared_buffer_ref lh_msg_buffer;
string_attrs_t lh_string_attrs;
vector<logline_value> lh_line_values;
};
/* XXX For one, this code is kinda crappy. For two, we should probably link
* directly with X so we don't need to have xclip installed and it'll work if
* we're ssh'd into a box.
@ -687,7 +732,6 @@ void handle_paging_key(int ch)
break;
case 'D':
case 'O':
if (tc->get_top() == 0) {
alerter::singleton().chime();
}
@ -706,7 +750,6 @@ void handle_paging_key(int ch)
break;
case 'd':
case 'o':
if (lss) {
int step = ch == 'd' ? (24 * 60 * 60) : (60 * 60);
vis_line_t line =
@ -718,6 +761,72 @@ void handle_paging_key(int ch)
}
break;
case 'o':
case 'O':
if (lss) {
logline_helper start_helper(*lss);
start_helper.lh_current_line = tc->get_top();
logline &start_line = start_helper.move_to_msg_start();
start_helper.annotate();
struct line_range opid_range = find_string_attr_range(
start_helper.lh_string_attrs, &logline::L_OPID);
if (!opid_range.is_valid()) {
alerter::singleton().chime();
lnav_data.ld_rl_view->set_value("Log message does not contain an opid");
} else {
unsigned int opid_hash = start_line.get_opid();
logline_helper next_helper(*lss);
bool found = false;
next_helper.lh_current_line = start_helper.lh_current_line;
while (true) {
if (ch == 'o') {
if (++next_helper.lh_current_line >= tc->get_inner_height()) {
break;
}
}
else {
if (--next_helper.lh_current_line <= 0) {
break;
}
}
logline &next_line = next_helper.move_to_msg_start();
if (next_line.is_continued()) {
continue;
}
if (next_line.get_opid() != opid_hash) {
continue;
}
next_helper.annotate();
struct line_range opid_next_range = find_string_attr_range(
next_helper.lh_string_attrs, &logline::L_OPID);
if (opid_range.length() != opid_next_range.length() ||
memcmp(start_helper.lh_msg_buffer.get_data(),
next_helper.lh_msg_buffer.get_data(),
opid_range.length()) != 0) {
continue;
}
found = true;
break;
}
if (found) {
lnav_data.ld_rl_view->set_value("");
tc->set_top(next_helper.lh_current_line);
}
else {
string opid_str = start_helper.to_string(opid_range);
lnav_data.ld_rl_view->set_value(
"No more messages found with opid: " + opid_str);
alerter::singleton().chime();
}
}
}
break;
case ':':
if (lnav_data.ld_views[LNV_LOG].get_inner_height() > 0) {
logfile_sub_source &lss = lnav_data.ld_log_source;

View File

@ -137,4 +137,6 @@ private:
const intern_string *ist_interned_string;
};
unsigned long hash_str(const char *str, size_t len);
#endif

View File

@ -1,5 +1,5 @@
/**
* Copyright (c) 2007-2012, Timothy Stack
* Copyright (c) 2007-2015, Timothy Stack
*
* All rights reserved.
*
@ -63,6 +63,7 @@ string_attr_type logline::L_TIMESTAMP;
string_attr_type logline::L_FILE;
string_attr_type logline::L_PARTITION;
string_attr_type logline::L_MODULE;
string_attr_type logline::L_OPID;
const char *logline::level_names[LEVEL__MAX + 1] = {
"unknown",
@ -677,13 +678,14 @@ bool external_log_format::scan(std::vector<logline> &dst,
pcre_context::capture_t *ts = pc[fpat->p_timestamp_field_index];
pcre_context::capture_t *level_cap = pc[fpat->p_level_field_index];
pcre_context::capture_t *mod_cap = pc[fpat->p_module_field_index];
pcre_context::capture_t *opid_cap = pc[fpat->p_opid_field_index];
pcre_context::capture_t *body_cap = pc[fpat->p_body_field_index];
const char *ts_str = pi.get_substr_start(ts);
const char *last;
struct exttm log_time_tm;
struct timeval log_tv;
logline::level_t level = logline::LEVEL_INFO;
uint8_t mod_index = 0;
uint8_t mod_index = 0, opid = 0;
if ((last = this->lf_date_time.scan(ts_str,
ts->length(),
@ -715,6 +717,10 @@ bool external_log_format::scan(std::vector<logline> &dst,
this->check_for_new_year(dst, log_time_tm, log_tv);
}
if (opid_cap != NULL) {
opid = hash_str(pi.get_substr_start(opid_cap), opid_cap->length());
}
if (mod_cap != NULL) {
intern_string_t mod_name = intern_string::lookup(
pi.get_substr_start(mod_cap), mod_cap->length());
@ -728,7 +734,7 @@ bool external_log_format::scan(std::vector<logline> &dst,
}
}
dst.push_back(logline(offset, log_tv, level, mod_index));
dst.push_back(logline(offset, log_tv, level, mod_index, opid));
this->lf_fmt_lock = curr_fmt;
retval = true;
@ -821,6 +827,13 @@ void external_log_format::annotate(shared_buffer_ref &line,
sa.push_back(string_attr(lr, &logline::L_MODULE));
}
}
cap = pc[pat.p_opid_field_index];
if (cap != NULL && cap->is_valid()) {
lr.lr_start = cap->c_begin;
lr.lr_end = cap->c_end;
sa.push_back(string_attr(lr, &logline::L_OPID));
}
}
body_cap = pc[pat.p_body_field_index];
@ -1215,6 +1228,9 @@ void external_log_format::build(std::vector<std::string> &errors)
if (name == this->elf_module_id_field) {
pat.p_module_field_index = name_iter->index();
}
if (name == this->elf_opid_field) {
pat.p_opid_field_index = name_iter->index();
}
if (name == this->elf_body_field) {
pat.p_body_field_index = name_iter->index();
}

View File

@ -67,6 +67,7 @@ public:
static string_attr_type L_FILE;
static string_attr_type L_PARTITION;
static string_attr_type L_MODULE;
static string_attr_type L_OPID;
/**
* The logging level identifiers for a line(s).
@ -116,10 +117,12 @@ public:
time_t t,
uint16_t millis,
level_t l,
uint8_t mod = 0)
uint8_t mod = 0,
uint8_t opid = 0)
: ll_offset(off),
ll_time(t),
ll_millis(millis),
ll_opid(opid),
ll_sub_offset(0),
ll_level(l),
ll_module_id(mod)
@ -130,8 +133,10 @@ public:
logline(off_t off,
const struct timeval &tv,
level_t l,
uint8_t mod = 0)
uint8_t mod = 0,
uint8_t opid = 0)
: ll_offset(off),
ll_opid(opid),
ll_sub_offset(0),
ll_level(l),
ll_module_id(mod)
@ -211,6 +216,10 @@ public:
return this->ll_module_id;
};
uint8_t get_opid(void) const {
return this->ll_opid;
};
/**
* @return True if there is a schema value set for this log line.
*/
@ -267,7 +276,8 @@ public:
private:
off_t ll_offset;
time_t ll_time;
uint16_t ll_millis;
unsigned int ll_millis : 10;
unsigned int ll_opid : 6;
uint16_t ll_sub_offset;
uint8_t ll_level;
uint8_t ll_module_id;
@ -749,6 +759,7 @@ public:
p_timestamp_field_index(-1),
p_level_field_index(-1),
p_module_field_index(-1),
p_opid_field_index(-1),
p_body_field_index(-1),
p_timestamp_end(-1),
p_module_format(false) {
@ -762,6 +773,7 @@ public:
int p_timestamp_field_index;
int p_level_field_index;
int p_module_field_index;
int p_opid_field_index;
int p_body_field_index;
int p_timestamp_end;
bool p_module_format;
@ -898,6 +910,7 @@ public:
intern_string_t elf_level_field;
intern_string_t elf_body_field;
intern_string_t elf_module_id_field;
intern_string_t elf_opid_field;
std::map<logline::level_t, level_pattern> elf_level_patterns;
bool elf_multiline;
bool elf_container;

View File

@ -187,6 +187,9 @@ static int read_format_field(yajlpp_parse_context *ypc, const unsigned char *str
elf->elf_module_id_field = intern_string::lookup(value);
elf->elf_container = true;
}
else if (field_name == "opid-field") {
elf->elf_opid_field = intern_string::lookup(value);
}
return 1;
}
@ -417,7 +420,7 @@ static struct json_path_handler format_handlers[] = {
.add_cb(read_format_int),
json_path_handler("^/\\w+/(file-pattern|level-field|timestamp-field|"
"body-field|url|url#|title|description|"
"timestamp-format#|module-field)$",
"timestamp-format#|module-field|opid-field)$",
read_format_field),
json_path_handler("^/\\w+/level/"
"(trace|debug\\d*|info|stats|warning|error|critical|fatal)$",

View File

@ -210,6 +210,7 @@ void logfile::process_prefix(off_t offset, shared_buffer_ref &sbr)
logline::level_t last_level = logline::LEVEL_UNKNOWN;
time_t last_time = this->lf_index_time;
short last_millis = 0;
uint8_t last_mod = 0, last_opid = 0;
if (!this->lf_index.empty()) {
logline &ll = this->lf_index.back();
@ -224,11 +225,15 @@ void logfile::process_prefix(off_t offset, shared_buffer_ref &sbr)
last_level = (logline::level_t)
(ll.get_level() | logline::LEVEL_CONTINUED);
}
last_mod = ll.get_module_id();
last_opid = ll.get_opid();
}
this->lf_index.push_back(logline(offset,
last_time,
last_millis,
last_level));
last_level,
last_mod,
last_opid));
}
}

View File

@ -540,4 +540,5 @@ private:
index_delegate *lss_index_delegate;
size_t lss_longest_line;
};
#endif