From ae64b599bd8342a077722d04659a1b4081e18420 Mon Sep 17 00:00:00 2001 From: Timothy Stack Date: Fri, 10 Apr 2015 19:50:05 -0700 Subject: [PATCH] [format] add more log levels and fix some more pretty-printer glitches Fixes #212 --- NEWS | 1 + TESTS_ENVIRONMENT.in | 4 +-- docs/source/formats.rst | 2 +- src/lnav.cc | 12 ++++----- src/log_format.cc | 22 +++++++++++++-- src/log_format.hh | 7 ++++- src/log_format_loader.cc | 5 ++-- src/pretty_printer.hh | 15 ++++++++--- test/logfile_json.json | 11 ++++++++ test/logfile_pretty.0 | 1 + test/test_cmds.sh | 6 +++++ test/test_json_format.sh | 37 ++++++++++++++++++++++++- test/test_logfile.sh | 58 ++++++++++++++++++++-------------------- 13 files changed, 133 insertions(+), 48 deletions(-) diff --git a/NEWS b/NEWS index 6d88cef3..ebbe0eee 100644 --- a/NEWS +++ b/NEWS @@ -37,6 +37,7 @@ lnav v0.7.3: how each format matches each other formats sample lines. * Command files (i.e. those executed via the '-f' flag) now support commands/queries that span more than one line. + * Added more log levels: stats, debug2 - debug5. lnav v0.7.2: * Added log formats for vdsm, openstack, and the vmkernel. diff --git a/TESTS_ENVIRONMENT.in b/TESTS_ENVIRONMENT.in index 6849d808..6d89228a 100644 --- a/TESTS_ENVIRONMENT.in +++ b/TESTS_ENVIRONMENT.in @@ -72,7 +72,7 @@ run_test() { # EOF # check_output() { - diff -w -u ${test_file_base}_${test_num}.tmp - > ${test_file_base}_${test_num}.diff + diff -w -u - ${test_file_base}_${test_num}.tmp > ${test_file_base}_${test_num}.diff if test $? -ne 0; then echo $LAST_TEST echo $1 @@ -83,7 +83,7 @@ check_output() { } check_error_output() { - diff -w -u ${test_file_base}_${test_num}.err - \ + diff -w -u - ${test_file_base}_${test_num}.err \ > ${test_file_base}_${test_num}.err.diff if test $? -ne 0; then echo $LAST_TEST diff --git a/docs/source/formats.rst b/docs/source/formats.rst index 27b7bef4..66f3ae60 100644 --- a/docs/source/formats.rst +++ b/docs/source/formats.rst @@ -84,7 +84,7 @@ fields: checked against each of these regexes. Once a match is found, the log message level will set to the corresponding level. The available levels, in order of severity, are: **fatal**, **critical**, **error**, - **warning**, **info**, **debug**, **trace**. + **warning**, **stats**, **info**, **debug**, **debug2-5**, **trace**. :value: This object contains the definitions for the values captured by the regexes. diff --git a/src/lnav.cc b/src/lnav.cc index 71449da3..750460b4 100644 --- a/src/lnav.cc +++ b/src/lnav.cc @@ -1,5 +1,5 @@ /** - * Copyright (c) 2007-2012, Timothy Stack + * Copyright (c) 2007-2015, Timothy Stack * * All rights reserved. * @@ -1237,7 +1237,7 @@ static void open_pretty_view(void) pretty_printer pp(&ds); // TODO: dump more details of the line in the output. - stream << pp.print() << endl; + stream << trim(pp.print()) << endl; first_line = false; } pretty_tc->set_sub_source(new plain_text_source(stream.str())); @@ -1653,10 +1653,10 @@ static void handle_paging_key(int ch) HELP_MSG_1(c, "to copy marked lines to the clipboard; ") HELP_MSG_1(C, "to clear marked lines")); - user_top = next_cluster(&bookmark_vector::next, + user_top = next_cluster(&bookmark_vector::next, &textview_curses::BM_USER, tc->get_top()); - part_top = next_cluster(&bookmark_vector::next, + part_top = next_cluster(&bookmark_vector::next, &textview_curses::BM_PARTITION, tc->get_top()); if (part_top == -1 && user_top == -1) { @@ -1677,10 +1677,10 @@ static void handle_paging_key(int ch) case 'U': { vis_line_t user_top, part_top; - user_top = next_cluster(&bookmark_vector::prev, + user_top = next_cluster(&bookmark_vector::prev, &textview_curses::BM_USER, tc->get_top()); - part_top = next_cluster(&bookmark_vector::prev, + part_top = next_cluster(&bookmark_vector::prev, &textview_curses::BM_PARTITION, tc->get_top()); if (part_top == -1 && user_top == -1) { diff --git a/src/log_format.cc b/src/log_format.cc index bbf0cd73..b53575d7 100644 --- a/src/log_format.cc +++ b/src/log_format.cc @@ -66,8 +66,13 @@ string_attr_type logline::L_PARTITION; const char *logline::level_names[LEVEL__MAX + 1] = { "unknown", "trace", + "debug5", + "debug4", + "debug3", + "debug2", "debug", "info", + "stats", "warning", "error", "critical", @@ -77,7 +82,7 @@ const char *logline::level_names[LEVEL__MAX + 1] = { }; static pcrepp LEVEL_RE( - "(?i)(TRACE|VERBOSE|DEBUG|INFO|WARN(?:ING)?|ERROR|CRITICAL|SEVERE|FATAL)"); + "^(?i)(TRACE|DEBUG\\d*|INFO|STATS|WARN(?:ING)?|ERROR|CRITICAL|SEVERE|FATAL)$"); logline::level_t logline::string2level(const char *levelstr, ssize_t len, bool exact) { @@ -113,15 +118,28 @@ logline::level_t logline::abbrev2level(const char *levelstr, ssize_t len) return LEVEL_TRACE; case 'D': case 'V': + if (len > 1) { + switch (levelstr[len - 1]) { + case '2': + return LEVEL_DEBUG2; + case '3': + return LEVEL_DEBUG3; + case '4': + return LEVEL_DEBUG4; + case '5': + return LEVEL_DEBUG5; + } + } return LEVEL_DEBUG; case 'I': return LEVEL_INFO; + case 'S': + return LEVEL_STATS; case 'W': return LEVEL_WARNING; case 'E': return LEVEL_ERROR; case 'C': - case 'S': return LEVEL_CRITICAL; case 'F': return LEVEL_FATAL; diff --git a/src/log_format.hh b/src/log_format.hh index b45072c9..148214f6 100644 --- a/src/log_format.hh +++ b/src/log_format.hh @@ -71,8 +71,13 @@ public: typedef enum { LEVEL_UNKNOWN, LEVEL_TRACE, + LEVEL_DEBUG5, + LEVEL_DEBUG4, + LEVEL_DEBUG3, + LEVEL_DEBUG2, LEVEL_DEBUG, LEVEL_INFO, + LEVEL_STATS, LEVEL_WARNING, LEVEL_ERROR, LEVEL_CRITICAL, @@ -184,7 +189,7 @@ public: const char *get_level_name() const { - return level_names[this->ll_level & 0x0f]; + return level_names[this->ll_level & ~LEVEL__FLAGS]; }; bool is_continued(void) const { diff --git a/src/log_format_loader.cc b/src/log_format_loader.cc index 6c9ba6e9..1b7d8ab1 100644 --- a/src/log_format_loader.cc +++ b/src/log_format_loader.cc @@ -156,7 +156,8 @@ static int read_levels(yajlpp_parse_context *ypc, const unsigned char *str, size { external_log_format *elf = ensure_format(ypc); string regex = string((const char *)str, len); - logline::level_t level = logline::string2level(ypc->get_path_fragment(2).c_str()); + string level_name_or_number = ypc->get_path_fragment(2); + logline::level_t level = logline::string2level(level_name_or_number.c_str()); elf->elf_level_patterns[level].lp_regex = regex; @@ -376,7 +377,7 @@ static struct json_path_handler format_handlers[] = { json_path_handler("^/\\w+/(file-pattern|level-field|timestamp-field|body-field|url|url#|title|description)$", read_format_field), json_path_handler("^/\\w+/level/" - "(trace|debug|info|warning|error|critical|fatal)$", + "(trace|debug\\d*|info|stats|warning|error|critical|fatal)$", read_levels), json_path_handler("^/\\w+/value/\\w+/(kind|collate|unit/field)$", read_value_def), json_path_handler("^/\\w+/value/\\w+/(identifier|foreign-key|hidden)$", read_value_bool), diff --git a/src/pretty_printer.hh b/src/pretty_printer.hh index 2ec97745..aa90cb18 100644 --- a/src/pretty_printer.hh +++ b/src/pretty_printer.hh @@ -87,12 +87,14 @@ public: continue; case DT_LCURLY: case DT_LSQUARE: + case DT_LPAREN: this->flush_values(true); this->pp_values.push_back(el); this->descend(); continue; case DT_RCURLY: case DT_RSQUARE: + case DT_RPAREN: this->flush_values(); if (this->pp_body_lines.top()) { this->start_new_line(); @@ -168,10 +170,15 @@ private: } void ascend() { - int lines = this->pp_body_lines.top(); - this->pp_depth -= 1; - this->pp_body_lines.pop(); - this->pp_body_lines.top() += lines; + if (this->pp_depth > 0) { + int lines = this->pp_body_lines.top(); + this->pp_depth -= 1; + this->pp_body_lines.pop(); + this->pp_body_lines.top() += lines; + } + else { + this->pp_body_lines.top() = 0; + } } void start_new_line() { diff --git a/test/logfile_json.json b/test/logfile_json.json index 740db393..42a6024f 100644 --- a/test/logfile_json.json +++ b/test/logfile_json.json @@ -1,2 +1,13 @@ +{"ts": "2013-09-06T20:00:48.124817Z", "lvl": "TRACE", "msg": "trace test"} {"ts": "2013-09-06T20:00:49.124817Z", "lvl": "INFO", "msg": "Starting up service"} {"ts": "2013-09-06T22:00:49.124817Z", "lvl": "INFO", "msg": "Shutting down service", "user": "steve@example.com"} +{"ts": "2013-09-06T22:00:59.124817Z", "lvl": "DEBUG5", "msg": "Details..."} +{"ts": "2013-09-06T22:00:59.124817Z", "lvl": "DEBUG4", "msg": "Details..."} +{"ts": "2013-09-06T22:00:59.124817Z", "lvl": "DEBUG3", "msg": "Details..."} +{"ts": "2013-09-06T22:00:59.124817Z", "lvl": "DEBUG2", "msg": "Details..."} +{"ts": "2013-09-06T22:00:59.124817Z", "lvl": "DEBUG", "msg": "Details..."} +{"ts": "2013-09-06T22:01:49.124817Z", "lvl": "STATS", "msg": "1 beat per second"} +{"ts": "2013-09-06T22:01:49.124817Z", "lvl": "WARNING", "msg": "not looking good"} +{"ts": "2013-09-06T22:01:49.124817Z", "lvl": "ERROR", "msg": "looking bad"} +{"ts": "2013-09-06T22:01:49.124817Z", "lvl": "CRITICAL", "msg": "sooo bad"} +{"ts": "2013-09-06T22:01:49.124817Z", "lvl": "FATAL", "msg": "shoot"} diff --git a/test/logfile_pretty.0 b/test/logfile_pretty.0 index 56badd99..f91b0544 100644 --- a/test/logfile_pretty.0 +++ b/test/logfile_pretty.0 @@ -20,3 +20,4 @@ Apr 7 07:31:56 Tim-Stacks-iMac.local VirtualBox[36403]: WARNING: The Gestalt se Call location: Apr 7 07:31:56 Tim-Stacks-iMac.local VirtualBox[36403]: 0 CarbonCore 0x00007fff8a9b3d9b ___Gestalt_SystemVersion_block_invoke + 113 Apr 7 07:31:56 Tim-Stacks-iMac.local VirtualBox[36403]: 1 libdispatch.dylib 0x00007fff8bc84c13 _dispatch_client_callout + 8 +Apr 7 07:32:56 Tim-Stacks-iMac.local logger[234]: Bad data { abc, 123, 456 )}] diff --git a/test/test_cmds.sh b/test/test_cmds.sh index 943558b9..b0513639 100644 --- a/test/test_cmds.sh +++ b/test/test_cmds.sh @@ -437,6 +437,12 @@ Apr 7 07:31:56 Tim-Stacks-iMac.local VirtualBox[36403]: WARNING: The Gestalt se Call location: Apr 7 07:31:56 Tim-Stacks-iMac.local VirtualBox[36403]: 0 CarbonCore 0x00007fff8a9b3d9b ___Gestalt_SystemVersion_block_invoke + 113 Apr 7 07:31:56 Tim-Stacks-iMac.local VirtualBox[36403]: 1 libdispatch.dylib 0x00007fff8bc84c13 _dispatch_client_callout + 8 +Apr 7 07:32:56 Tim-Stacks-iMac.local logger[234]: Bad data { + abc, + 123, + 456 +) +}] EOF diff --git a/test/test_json_format.sh b/test/test_json_format.sh index 619e42ca..a2edbfda 100644 --- a/test/test_json_format.sh +++ b/test/test_json_format.sh @@ -8,15 +8,50 @@ run_test ${lnav_test} -n \ ${test_dir}/logfile_json.json check_output "json log format is not working" < +1,p.0,2013-09-06 20:00:49.124,1000,info,0, +2,p.0,2013-09-06 22:00:49.124,7200000,info,0,steve@example.com +4,p.0,2013-09-06 22:00:59.124,10000,debug5,0, +5,p.0,2013-09-06 22:00:59.124,0,debug4,0, +6,p.0,2013-09-06 22:00:59.124,0,debug3,0, +7,p.0,2013-09-06 22:00:59.124,0,debug2,0, +8,p.0,2013-09-06 22:00:59.124,0,debug,0, +9,p.0,2013-09-06 22:01:49.124,50000,stats,0, +10,p.0,2013-09-06 22:01:49.124,0,warning,0, +11,p.0,2013-09-06 22:01:49.124,0,error,0, +12,p.0,2013-09-06 22:01:49.124,0,critical,0, +13,p.0,2013-09-06 22:01:49.124,0,fatal,0, EOF run_test ${lnav_test} -n \ -I ${test_dir} \ - -c ":goto 1" \ + -c ":goto 2" \ -c ":pipe-line-to sed -e 's/2013//g'" \ -c ":switch-to-view text" \ ${test_dir}/logfile_json.json diff --git a/test/test_logfile.sh b/test/test_logfile.sh index 674b3449..5808b7dd 100644 --- a/test/test_logfile.sh +++ b/test/test_logfile.sh @@ -118,41 +118,41 @@ EOF run_test ./drive_logfile -v -f syslog_log ${srcdir}/logfile_syslog.0 check_output "Syslog level interpreted incorrectly?" <