From 7ef92dab79877f184622f9d33b9dc8b41248b303 Mon Sep 17 00:00:00 2001 From: Timothy Stack Date: Sat, 11 Jul 2015 16:32:48 -0700 Subject: [PATCH] [format] try to validate formats against a given file --- NEWS | 2 ++ TESTS_ENVIRONMENT.in | 4 +++ lnav.1 | 4 ++- src/default-log-formats.json | 4 +++ src/lnav.cc | 60 +++++++++++++++++++++++++++++------ src/log_format.cc | 30 ++++++++++++++++-- src/log_format.hh | 14 ++++++-- src/log_format_loader.cc | 4 ++- src/logfile.cc | 1 - test/Makefile.am | 2 ++ test/logfile_bad_access_log.0 | 3 ++ test/logfile_bad_syslog.0 | 4 +++ test/test_logfile.sh | 16 ++++++++++ 13 files changed, 131 insertions(+), 17 deletions(-) create mode 100644 test/logfile_bad_access_log.0 create mode 100644 test/logfile_bad_syslog.0 diff --git a/NEWS b/NEWS index 27a7c6ee..7ce4a064 100644 --- a/NEWS +++ b/NEWS @@ -6,6 +6,8 @@ lnav v0.7.4: Shift+Left/Shift+Right). * A color-coded bar has been added to the left side to show where messages from one file stop and messages from another file start. + * The '-C' option will now try to check any specified log files to + make sure the format(s) match all of the lines. Fixes: * Nested fields in JSON logs are now supported for levels, bodies, etc... diff --git a/TESTS_ENVIRONMENT.in b/TESTS_ENVIRONMENT.in index 6d89228a..5c2a8057 100644 --- a/TESTS_ENVIRONMENT.in +++ b/TESTS_ENVIRONMENT.in @@ -82,6 +82,10 @@ check_output() { test_num=`expr ${test_num} \+ 1` } +test_err_filename() { + echo ${test_file_base}_${test_num}.err +} + check_error_output() { diff -w -u - ${test_file_base}_${test_num}.err \ > ${test_file_base}_${test_num}.err.diff diff --git a/lnav.1 b/lnav.1 index 175a8084..494f2ac6 100644 --- a/lnav.1 +++ b/lnav.1 @@ -57,7 +57,9 @@ Install the given format files in the $HOME/.lnav/formats/installed directory and exit. .TP \fB\-C\fR -Check the configuration and exit. +Check the configuration and exit. The log format files will be loaded and +checked. Any files given on the command-line will be loaded checked to make +sure they match a log format. .TP \fB\-d\fR file Write debug messages to the given file. diff --git a/src/default-log-formats.json b/src/default-log-formats.json index 3db5920b..91bfc9e2 100644 --- a/src/default-log-formats.json +++ b/src/default-log-formats.json @@ -3,6 +3,7 @@ "title" : "Common Access Log", "description" : "The default web access log format for servers like Apache.", "url" : "http://en.wikipedia.org/wiki/Common_Log_Format", + "multiline" : false, "regex" : { "ts-first-noquotes" : { "pattern" : "^(?\\d{4}-\\d{2}-\\d{2}T\\d{2}:\\d{2}:\\d{2}(?:\\.\\d{3})?) (?[^ ]+) (?[^ ]+) (?[A-Z]+) (?[^ \\?]+)(?:\\?(?[^ ]*))? (?:-1|\\d+) (?\\d+) \\d+" @@ -567,6 +568,7 @@ "title" : "CUPS Page Log", "description" : "The CUPS server log of printed pages.", "url" : "http://www.cups.org/documentation.php/doc-1.7/ref-page_log.html", + "multiline" : false, "regex" : { "pre-1.7" : { "pattern" : "^(?[\\w_\\-\\.]+) (?[\\w\\.\\-]+) (?\\d+) \\[(?[^\\]]+)\\] (?total|\\d+) (?\\d+) (?[^ ]+) (?[\\w\\.:\\-]+)$" @@ -747,6 +749,7 @@ "title" : "Strace", "description" : "The strace output format.", "url" : "http://en.wikipedia.org/wiki/Strace", + "multiline" : false, "regex" : { "std" : { "pattern" : "^(?\\d{2}:\\d{2}:\\d{2}\\.\\d{6}) (?\\w+)\\((?.*)\\)\\s+=\\s+(?[-\\w]+)(?: (?\\w+) \\([^\\)]+\\))?(?: <(?\\d+\\.\\d+)>)?$" @@ -897,6 +900,7 @@ "uwsgi_log" : { "title" : "Uwsgi Log", "description" : "The uwsgi log format.", + "multiline" : false, "regex" : { "std" : { "pattern" : "^\\[pid: (?\\d+)\\|app: (?[\\-\\d]+)\\|req: (?[\\-\\d]+)/(?\\d+)\\] (?[^ ]+) \\((?[^\\)]*)\\) \\{(?\\d+) vars in (?\\d+) bytes\\} \\[(?[^\\]]+)\\] (?[A-Z]+) (?[^ \\?]+)(?:\\?(?[^ ]*))? => generated (?\\d+) bytes in (?\\d+) (?\\w+) \\((?[^ ]+) (?\\d+)\\) (?\\d+) headers in (?\\d+) bytes \\((?\\d+) switches on core (?\\d+)\\)" diff --git a/src/lnav.cc b/src/lnav.cc index 316a4705..328b112d 100644 --- a/src/lnav.cc +++ b/src/lnav.cc @@ -343,7 +343,7 @@ public: { static sig_atomic_t index_counter = 0; - if (lnav_data.ld_flags & LNF_HEADLESS) { + if (lnav_data.ld_flags & (LNF_HEADLESS|LNF_CHECK_CONFIG)) { return; } @@ -2371,10 +2371,6 @@ int main(int argc, char *argv[]) return EXIT_FAILURE; } - if (lnav_data.ld_flags & LNF_CHECK_CONFIG) { - return EXIT_SUCCESS; - } - /* If we statically linked against an ncurses library that had a non- * standard path to the terminfo database, we need to set this variable * so that it will try the default path. @@ -2431,10 +2427,14 @@ int main(int argc, char *argv[]) } } - DEFAULT_FILES.insert(make_pair(LNF_SYSLOG, string("var/log/messages"))); - DEFAULT_FILES.insert(make_pair(LNF_SYSLOG, string("var/log/system.log"))); - DEFAULT_FILES.insert(make_pair(LNF_SYSLOG, string("var/log/syslog"))); - DEFAULT_FILES.insert(make_pair(LNF_SYSLOG, string("var/log/syslog.log"))); + if (!(lnav_data.ld_flags & LNF_CHECK_CONFIG)) { + DEFAULT_FILES.insert(make_pair(LNF_SYSLOG, string("var/log/messages"))); + DEFAULT_FILES.insert( + make_pair(LNF_SYSLOG, string("var/log/system.log"))); + DEFAULT_FILES.insert(make_pair(LNF_SYSLOG, string("var/log/syslog"))); + DEFAULT_FILES.insert( + make_pair(LNF_SYSLOG, string("var/log/syslog.log"))); + } init_lnav_commands(lnav_commands); @@ -2577,7 +2577,47 @@ int main(int argc, char *argv[]) } } - if (!(lnav_data.ld_flags & LNF_HEADLESS) && !isatty(STDOUT_FILENO)) { + if (lnav_data.ld_flags & LNF_CHECK_CONFIG) { + rescan_files(true); + for (list::iterator file_iter = lnav_data.ld_files.begin(); + file_iter != lnav_data.ld_files.end(); + ++file_iter) { + logfile *lf = (*file_iter); + + lf->rebuild_index(); + + lf->rebuild_index(); + log_format *fmt = lf->get_format(); + if (fmt == NULL) { + fprintf(stderr, "error:%s:no format found for file\n", + lf->get_filename().c_str()); + retval = EXIT_FAILURE; + continue; + } + for (logfile::iterator line_iter = lf->begin(); + line_iter != lf->end(); + ++line_iter) { + if (!line_iter->is_continued()) { + continue; + } + + shared_buffer_ref sbr; + + lf->read_line(line_iter, sbr); + if (fmt->scan_for_partial(sbr)) { + long line_number = distance(lf->begin(), line_iter); + fprintf(stderr, + "error:%s:%ld:line did not match format %s\n", + lf->get_filename().c_str(), line_number, + fmt->get_pattern_name().c_str()); + retval = EXIT_FAILURE; + } + } + } + return retval; + } + + if (!(lnav_data.ld_flags & (LNF_HEADLESS|LNF_CHECK_CONFIG)) && !isatty(STDOUT_FILENO)) { fprintf(stderr, "error: stdout is not a tty.\n"); retval = EXIT_FAILURE; } diff --git a/src/log_format.cc b/src/log_format.cc index d1bfea8c..d8f8aef0 100644 --- a/src/log_format.cc +++ b/src/log_format.cc @@ -575,6 +575,28 @@ static struct json_path_handler json_log_rewrite_handlers[] = { json_path_handler() }; +bool external_log_format::scan_for_partial(shared_buffer_ref &sbr) +{ + if (this->jlf_json) { + return false; + } + + if (!this->elf_multiline) { + return true; + } + + pattern *pat = this->elf_pattern_order[this->lf_fmt_lock]; + + if (pat->p_timestamp_end == -1 || pat->p_timestamp_end > sbr.length()) { + return false; + } + + pcre_input pi(sbr.get_data(), 0, pat->p_timestamp_end); + pcre_context_static<128> pc; + + return pat->p_pcre->match(pc, pi, PCRE_PARTIAL); +} + bool external_log_format::scan(std::vector &dst, off_t offset, shared_buffer_ref &sbr) @@ -1200,14 +1222,18 @@ void external_log_format::build(std::vector &errors) } if (pat.p_pcre->match(pc, pi)) { - const char *ts = pi.get_substr_start( - pc[this->lf_timestamp_field.get()]); + pcre_context::capture_t *ts_cap = + pc[this->lf_timestamp_field.get()]; + const char *ts = pi.get_substr_start(ts_cap); ssize_t ts_len = pc[this->lf_timestamp_field.get()]->length(); const char *const *custom_formats = this->get_timestamp_formats(); date_time_scanner dts; struct timeval tv; struct exttm tm; + if (ts_cap->c_begin == 0) { + pat.p_timestamp_end = ts_cap->c_end; + } found = true; if (ts_len == -1 || dts.scan(ts, ts_len, custom_formats, &tm, tv) == NULL) { errors.push_back("error:" + diff --git a/src/log_format.hh b/src/log_format.hh index e4b448e8..3d3084ca 100644 --- a/src/log_format.hh +++ b/src/log_format.hh @@ -537,6 +537,7 @@ public: log_format() : lf_fmt_lock(-1), lf_timestamp_field(intern_string::lookup("timestamp", -1)) { }; + virtual ~log_format() { }; virtual void clear(void) @@ -567,6 +568,10 @@ public: off_t offset, shared_buffer_ref &sbr) = 0; + virtual bool scan_for_partial(shared_buffer_ref &sbr) { + return false; + }; + /** * Remove redundant data from the log line string. * @@ -694,12 +699,13 @@ public: }; struct pattern { - pattern() : p_pcre(NULL) { }; + pattern() : p_pcre(NULL), p_timestamp_end(-1) { }; std::string p_config_path; std::string p_string; pcrepp *p_pcre; std::vector p_value_by_index; + int p_timestamp_end; }; struct level_pattern { @@ -715,6 +721,7 @@ public: elf_column_count(0), elf_timestamp_divisor(1.0), elf_body_field(intern_string::lookup("body", -1)), + elf_multiline(true), jlf_json(false), jlf_hide_extra(false), jlf_cached_offset(-1), @@ -737,7 +744,9 @@ public: bool scan(std::vector &dst, off_t offset, shared_buffer_ref &sbr); - + + bool scan_for_partial(shared_buffer_ref &sbr); + void annotate(shared_buffer_ref &line, string_attrs_t &sa, std::vector &values) const; @@ -837,6 +846,7 @@ public: intern_string_t elf_body_field; int elf_body_field_index; std::map elf_level_patterns; + bool elf_multiline; enum json_log_field { JLF_CONSTANT, diff --git a/src/log_format_loader.cc b/src/log_format_loader.cc index e3b9554b..3bb83c7c 100644 --- a/src/log_format_loader.cc +++ b/src/log_format_loader.cc @@ -99,6 +99,8 @@ static int read_format_bool(yajlpp_parse_context *ypc, int val) elf->jlf_json = val; else if (field_name == "hide-extra") elf->jlf_hide_extra = val; + else if (field_name == "multiline") + elf->elf_multiline = val; return 1; } @@ -378,7 +380,7 @@ static int read_json_variable_num(yajlpp_parse_context *ypc, long long val) static struct json_path_handler format_handlers[] = { json_path_handler("^/\\w+/regex/[^/]+/pattern$", read_format_regex), - json_path_handler("^/\\w+/(json|convert-to-local-time|epoch-timestamp|hide-extra)$", read_format_bool), + json_path_handler("^/\\w+/(json|convert-to-local-time|epoch-timestamp|hide-extra|multiline)$", read_format_bool), json_path_handler("^/\\w+/timestamp-divisor$", read_format_double) .add_cb(read_format_int), json_path_handler("^/\\w+/(file-pattern|level-field|timestamp-field|" diff --git a/src/logfile.cc b/src/logfile.cc index e33135b1..3878fe55 100644 --- a/src/logfile.cc +++ b/src/logfile.cc @@ -324,7 +324,6 @@ void logfile::read_line(logfile::iterator ll, string &line_out) if (this->lf_line_buffer.read_line(off, sbr)) { if (this->lf_format.get() != NULL) { this->lf_format->get_subline(*ll, sbr); - } line_out.append(sbr.get_data(), sbr.length()); } diff --git a/test/Makefile.am b/test/Makefile.am index b3b513b1..895643a5 100644 --- a/test/Makefile.am +++ b/test/Makefile.am @@ -214,6 +214,8 @@ dist_noinst_DATA = \ listview_output.6 \ logfile_access_log.0 \ logfile_access_log.1 \ + logfile_bad_access_log.0 \ + logfile_bad_syslog.0 \ logfile_blued.0 \ logfile_empty.0 \ logfile_epoch.0 \ diff --git a/test/logfile_bad_access_log.0 b/test/logfile_bad_access_log.0 new file mode 100644 index 00000000..d48df45b --- /dev/null +++ b/test/logfile_bad_access_log.0 @@ -0,0 +1,3 @@ +192.168.202.254 - - [20/Jul/2009:22:59:26 +0000] "GET /vmw/cgi/tramp HTTP/1.0" 200 134 "-" "gPXE/0.9.7" +192.168.202.254 [20/Jul/2009:22:59:29 +0000] "GET /vmw/vSphere/default/vmkboot.gz HTTP/1.0" 404 46210 "-" "gPXE/0.9.7" +192.168.202.254 - - [20/Jul/2009:22:59:29 +0000] "GET /vmw/vSphere/default/vmkernel.gz HTTP/1.0" 200 78929 "-" "gPXE/0.9.7" diff --git a/test/logfile_bad_syslog.0 b/test/logfile_bad_syslog.0 new file mode 100644 index 00000000..af65a10b --- /dev/null +++ b/test/logfile_bad_syslog.0 @@ -0,0 +1,4 @@ +Nov 3 09:23:38 veridian automount[7998]: lookup(file): lookup for foobar failed +Nov 3 09:23:38 veridian automount[16442]: attempting to mount entry /auto/opt +Nov 3 09:23:38 veridian lookup for opt failed +Nov 3 09:47:02 veridian sudo: timstack : TTY=pts/6 ; PWD=/auto/wstimstack/rpms/lbuild/test ; USER=root ; COMMAND=/usr/bin/tail /var/log/messages diff --git a/test/test_logfile.sh b/test/test_logfile.sh index 0370a2ea..abafdac0 100644 --- a/test/test_logfile.sh +++ b/test/test_logfile.sh @@ -236,3 +236,19 @@ check_output "piping to stdin is not working?" <