diff --git a/src/formats/engine_log.json b/src/formats/engine_log.json index 18f4fee0..7ad7f2a5 100644 --- a/src/formats/engine_log.json +++ b/src/formats/engine_log.json @@ -5,7 +5,7 @@ "description": "The log format for the engine.log files from RHEV/oVirt", "regex": { "std": { - "pattern": "^(?.+) (?.+) \\[(?.+)\\] \\((?.+)\\) (?(?:-|\\n)*)" + "pattern": "^(?\\d{4}-\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2},\\d{3}+)\\s+(?\\w+)\\s+\\[(?[^\\]]+)\\]\\s+\\((?[^\\)]+)\\)\\s+(?(?:-|\\n)*)" } }, "opid-field": "tid", diff --git a/src/formats/openstack_log.json b/src/formats/openstack_log.json index a7213ad6..b517bb04 100644 --- a/src/formats/openstack_log.json +++ b/src/formats/openstack_log.json @@ -34,10 +34,6 @@ "logger": { "kind": "string", "identifier": true - }, - "body": { - "kind": "string", - "identifier": false } }, "sample": [ diff --git a/src/log_data_helper.hh b/src/log_data_helper.hh index 5dc059d2..dcffdf30 100644 --- a/src/log_data_helper.hh +++ b/src/log_data_helper.hh @@ -97,7 +97,7 @@ public: this->ldh_line_attrs.clear(); this->ldh_line_values.clear(); this->ldh_file->read_full_message(ll, this->ldh_msg); - format->annotate(this->ldh_line_index, this->ldh_msg, sa, this->ldh_line_values, false); + format->annotate(this->ldh_line_index, this->ldh_msg, sa, this->ldh_line_values); body = find_string_attr_range(sa, &SA_BODY); if (body.lr_start == -1) { diff --git a/src/log_format.cc b/src/log_format.cc index ecfe6933..e47346be 100644 --- a/src/log_format.cc +++ b/src/log_format.cc @@ -766,10 +766,35 @@ log_format::scan_result_t external_log_format::scan(logfile &lf, if (mod_iter == MODULE_FORMATS.end()) { mod_index = module_scan(pi, body_cap, mod_name); + mod_iter = MODULE_FORMATS.find(mod_name); } else if (mod_iter->second.mf_mod_format) { mod_index = mod_iter->second.mf_mod_format->lf_mod_index; } + + if (mod_index && level_cap && body_cap) { + auto mod_elf = dynamic_pointer_cast( + mod_iter->second.mf_mod_format); + + if (mod_elf) { + pcre_context_static<128> mod_pc; + shared_buffer_ref body_ref; + + body_cap->ltrim(sbr.get_data()); + + pcre_input mod_pi(pi.get_substr_start(body_cap), + 0, + body_cap->length()); + int mod_pat_index = mod_elf->last_pattern_index(); + pattern &mod_pat = *mod_elf->elf_pattern_order[mod_pat_index]; + + if (mod_pat.p_pcre->match(mod_pc, mod_pi)) { + auto mod_level_cap = mod_pc[mod_pat.p_level_field_index]; + + level = mod_elf->convert_level(mod_pi, mod_level_cap); + } + } + } } for (auto value_index : fpat->p_numeric_value_indexes) { @@ -928,7 +953,7 @@ void external_log_format::annotate(uint64_t line_number, shared_buffer_ref &line if (pat.p_module_field_index != -1) { module_cap = pc[pat.p_module_field_index]; - if (module_cap != NULL && module_cap->is_valid()) { + if (module_cap != nullptr && module_cap->is_valid()) { lr.lr_start = module_cap->c_begin; lr.lr_end = module_cap->c_end; sa.emplace_back(lr, &logline::L_MODULE); @@ -936,7 +961,7 @@ void external_log_format::annotate(uint64_t line_number, shared_buffer_ref &line } cap = pc[pat.p_opid_field_index]; - if (cap != NULL && cap->is_valid()) { + if (cap != nullptr && cap->is_valid()) { lr.lr_start = cap->c_begin; lr.lr_end = cap->c_end; sa.emplace_back(lr, &logline::L_OPID); @@ -944,15 +969,6 @@ void external_log_format::annotate(uint64_t line_number, shared_buffer_ref &line } body_cap = pc[pat.p_body_field_index]; - if (body_cap != NULL && body_cap->c_begin != -1) { - lr.lr_start = body_cap->c_begin; - lr.lr_end = body_cap->c_end; - } - else { - lr.lr_start = line.length(); - lr.lr_end = line.length(); - } - sa.emplace_back(lr, &SA_BODY); for (size_t lpc = 0; lpc < pat.p_value_by_index.size(); lpc++) { const indexed_value_def &ivd = pat.p_value_by_index[lpc]; @@ -983,8 +999,12 @@ void external_log_format::annotate(uint64_t line_number, shared_buffer_ref &line } else { values.emplace_back(vd.vd_meta); } + if (pat.p_module_format) { + values.back().lv_meta.lvm_from_module = true; + } } + bool did_mod_annotate_body = false; if (annotate_module && module_cap != nullptr && body_cap != nullptr && body_cap->is_valid()) { intern_string_t mod_name = intern_string::lookup( @@ -992,21 +1012,35 @@ void external_log_format::annotate(uint64_t line_number, shared_buffer_ref &line auto mod_iter = MODULE_FORMATS.find(mod_name); if (mod_iter != MODULE_FORMATS.end() && - mod_iter->second.mf_mod_format != nullptr) { + mod_iter->second.mf_mod_format != nullptr) { module_format &mf = mod_iter->second; shared_buffer_ref body_ref; body_cap->ltrim(line.get_data()); body_ref.subset(line, body_cap->c_begin, body_cap->length()); + + auto pre_mod_values_size = values.size(); + auto pre_mod_sa_size = sa.size(); mf.mf_mod_format->annotate(line_number, body_ref, sa, values, false); - for (auto &value : values) { - if (!value.lv_meta.lvm_from_module) { - continue; - } - value.lv_origin.lr_start += body_cap->c_begin; - value.lv_origin.lr_end += body_cap->c_begin; + for (size_t lpc = pre_mod_values_size; lpc < values.size(); lpc++) { + values[lpc].lv_origin.shift(0, body_cap->c_begin); } + for (size_t lpc = pre_mod_sa_size; lpc < sa.size(); lpc++) { + sa[lpc].sa_range.shift(0, body_cap->c_begin); + } + did_mod_annotate_body = true; + } + } + if (!did_mod_annotate_body) { + if (body_cap != nullptr && body_cap->is_valid()) { + lr.lr_start = body_cap->c_begin; + lr.lr_end = body_cap->c_end; } + else { + lr.lr_start = line.length(); + lr.lr_end = line.length(); + } + sa.emplace_back(lr, &SA_BODY); } } diff --git a/src/logfile_sub_source.cc b/src/logfile_sub_source.cc index e04029e7..cdf4cd6c 100644 --- a/src/logfile_sub_source.cc +++ b/src/logfile_sub_source.cc @@ -208,9 +208,7 @@ void logfile_sub_source::text_value_for_line(textview_curses &tc, line_range{0, (int) this->lss_token_value.length()}, &SA_BODY); } else { - format->annotate(line, sbr, this->lss_token_attrs, - this->lss_token_values, - false); + format->annotate(line, sbr, this->lss_token_attrs, this->lss_token_values); } if (this->lss_token_line->get_sub_offset() != 0) { this->lss_token_attrs.clear(); diff --git a/test/CMakeLists.txt b/test/CMakeLists.txt index 6c3a645b..2d4d614a 100644 --- a/test/CMakeLists.txt +++ b/test/CMakeLists.txt @@ -41,5 +41,8 @@ add_test(NAME test_abbrev COMMAND test_abbrev) add_executable(drive_sql_anno drive_sql_anno.cc) target_link_libraries(drive_sql_anno diag PkgConfig::libpcre) +add_executable(drive_data_scanner drive_data_scanner.cc) +target_link_libraries(drive_data_scanner diag PkgConfig::libpcre) + add_executable(scripty scripty.cc) target_link_libraries(scripty diag PkgConfig::ncursesw) diff --git a/test/drive_data_scanner.cc b/test/drive_data_scanner.cc index eee81301..39542c97 100644 --- a/test/drive_data_scanner.cc +++ b/test/drive_data_scanner.cc @@ -152,8 +152,8 @@ int main(int argc, char *argv[]) if (is_log) { for (iter = root_formats.begin(); - iter != root_formats.end() && !found; - ++iter) { + iter != root_formats.end() && !found; + ++iter) { line_info li = { {13}}; logfile *lf = nullptr; // XXX @@ -163,6 +163,11 @@ int main(int argc, char *argv[]) found = true; } } + + if (!found) { + fprintf(stderr, "error: log sample does not match\n"); + return EXIT_FAILURE; + } } vector ll_values; diff --git a/test/log-samples/sample-27353a72ba4025448f261dcfa6ea16e474187795.txt b/test/log-samples/sample-27353a72ba4025448f261dcfa6ea16e474187795.txt index 314d9a63..3a7277b0 100644 --- a/test/log-samples/sample-27353a72ba4025448f261dcfa6ea16e474187795.txt +++ b/test/log-samples/sample-27353a72ba4025448f261dcfa6ea16e474187795.txt @@ -1,30 +1,4 @@ Jun 3 07:00:23 Tim-Stacks-iMac.local sudo[2326]: stack : TTY=ttys002 ; PWD=/ ; USER=root ; COMMAND=/bin/ls - key 53:53 ^ -word 53:58 ^---^ stack - val 53:58 ^---^ stack -pair 53:58 ^---^ stack - key 61:64 ^-^ TTY - sym 65:72 ^-----^ ttys002 - val 65:72 ^-----^ ttys002 -pair 61:72 ^---------^ TTY=ttys002 - key 75:78 ^-^ PWD -path 79:80 ^ / - val 79:80 ^ / -pair 75:80 ^---^ PWD=/ - key 83:87 ^--^ USER -word 88:92 ^--^ root - val 88:92 ^--^ root -pair 83:92 ^-------^ USER=root - key 95:102 ^-----^ COMMAND -path 103:110 ^-----^ /bin/ls - val 103:110 ^-----^ /bin/ls -pair 95:110 ^-------------^ COMMAND=/bin/ls -msg : stack : TTY=ttys002 ; PWD=/ ; USER=root ; COMMAND=/bin/ls -format : # : TTY=# ; PWD=# ; USER=# ; COMMAND=# -{ - "col_0": "stack", - "TTY": "ttys002", - "PWD": "/", - "USER": "root", - "COMMAND": "/bin/ls" -} +msg : +format : +null diff --git a/test/log-samples/sample-70c906b3c1a1cf03f15bde92ee78edfa6f9b7960.txt b/test/log-samples/sample-70c906b3c1a1cf03f15bde92ee78edfa6f9b7960.txt index a4a6fba9..9d80bf95 100644 --- a/test/log-samples/sample-70c906b3c1a1cf03f15bde92ee78edfa6f9b7960.txt +++ b/test/log-samples/sample-70c906b3c1a1cf03f15bde92ee78edfa6f9b7960.txt @@ -1,35 +1,4 @@ Jun 3 07:02:37 Tim-Stacks-iMac.local sudo[2717]: stack : TTY=ttys002 ; PWD=/ ; USER=root ; COMMAND=/usr/bin/env VAR1=foo ls - key 53:53 ^ -word 53:58 ^---^ stack - val 53:58 ^---^ stack -pair 53:58 ^---^ stack - key 61:64 ^-^ TTY - sym 65:72 ^-----^ ttys002 - val 65:72 ^-----^ ttys002 -pair 61:72 ^---------^ TTY=ttys002 - key 75:78 ^-^ PWD -path 79:80 ^ / - val 79:80 ^ / -pair 75:80 ^---^ PWD=/ - key 83:87 ^--^ USER -word 88:92 ^--^ root - val 88:92 ^--^ root -pair 83:92 ^-------^ USER=root - key 95:102 ^-----^ COMMAND -path 103:115 ^----------^ /usr/bin/env -wspc 115:116 ^ - sym 116:120 ^--^ VAR1 -word 121:124 ^-^ foo -wspc 124:125 ^ -word 125:127 ^^ ls - val 103:127 ^----------------------^ /usr/bin/env VAR1=foo ls -pair 95:127 ^------------------------------^ COMMAND=/usr/bin/env VAR1=foo ls -msg : stack : TTY=ttys002 ; PWD=/ ; USER=root ; COMMAND=/usr/bin/env VAR1=foo ls -format : # : TTY=# ; PWD=# ; USER=# ; COMMAND=# -{ - "col_0": "stack", - "TTY": "ttys002", - "PWD": "/", - "USER": "root", - "COMMAND": "/usr/bin/env VAR1=foo ls" -} +msg : +format : +null diff --git a/test/logfile_syslog_with_access_log.0 b/test/logfile_syslog_with_access_log.0 index acb72b6a..2ec28da4 100644 --- a/test/logfile_syslog_with_access_log.0 +++ b/test/logfile_syslog_with_access_log.0 @@ -1,4 +1,5 @@ Jan 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 Mar 24 14:02:50 bigproduct-web1 tomcat.log: 127.0.0.1 - - "GET /includes/js/combined-javascript.js HTTP/1.1" 200 65508 4.386 +Mar 24 14:02:50 bigproduct-web1 tomcat.log: 127.0.0.1 - - "GET /bad.foo HTTP/1.1" 404 65508 4.386 Mar 24 14:02:51 bigproduct-web1 automount[7999]: lookup(file): lookup for opt failed Mar 24 14:26:01 --- last message repeated 2 times --- diff --git a/test/test_sql.sh b/test/test_sql.sh index 35312852..c7480ecc 100644 --- a/test/test_sql.sh +++ b/test/test_sql.sh @@ -1107,7 +1107,7 @@ unset LNAVSECURE touch -t 201503240923 ${test_dir}/logfile_syslog_with_access_log.0 -run_test ${lnav_test} -n \ +run_test ${lnav_test} -n -d /tmp/lnav.err \ -c ";select * from access_log" \ -c ':write-csv-to -' \ ${test_dir}/logfile_syslog_with_access_log.0 @@ -1115,6 +1115,7 @@ run_test ${lnav_test} -n \ check_output "access_log not found within syslog file" <,2015-03-24 14:02:50.000,6927348000,info,0,,,,127.0.0.1,GET,,,/includes/js/combined-javascript.js,,-,HTTP/1.1,65508,200, +2,,2015-03-24 14:02:50.000,0,error,0,,,,127.0.0.1,GET,,,/bad.foo,,-,HTTP/1.1,65508,404, EOF