diff --git a/src/base/intern_string.hh b/src/base/intern_string.hh index 8d429a67..37ccc362 100644 --- a/src/base/intern_string.hh +++ b/src/base/intern_string.hh @@ -62,6 +62,12 @@ struct string_fragment { return string_fragment{str, 0, str != nullptr ? (int) strlen(str) : 0}; } + static string_fragment from_c_str(const unsigned char* str) + { + return string_fragment{ + str, 0, str != nullptr ? (int) strlen((char*) str) : 0}; + } + template static string_fragment from_const(const T (&str)[N]) { @@ -277,6 +283,18 @@ struct string_fragment { this->sf_string, this->sf_begin + begin, this->sf_begin + end}; } + size_t count(char ch) const { + size_t retval = 0; + + for (int lpc = this->sf_begin; lpc < this->sf_end; lpc++) { + if (this->sf_string[lpc] == ch) { + retval += 1; + } + } + + return retval; + } + nonstd::optional find(char ch) const { for (int lpc = this->sf_begin; lpc < this->sf_end; lpc++) { diff --git a/src/log_format.cc b/src/log_format.cc index 3d40ebba..d97c713b 100644 --- a/src/log_format.cc +++ b/src/log_format.cc @@ -708,8 +708,21 @@ external_log_format::scan(logfile& lf, scan_batch_context& sbc) { if (this->elf_type == elf_type_t::ELF_TYPE_JSON) { - yajlpp_parse_context& ypc = *(this->jlf_parse_context); logline ll(li.li_file_range.fr_offset, 0, 0, LEVEL_INFO); + auto line_frag = sbr.to_string_fragment(); + + if (!line_frag.startswith("{")) { + if (!this->lf_specialized) { + return log_format::SCAN_NO_MATCH; + } + + ll.set_time(dst.back().get_timeval()); + ll.set_level(LEVEL_INVALID); + dst.emplace_back(ll); + return log_format::SCAN_MATCH; + } + + auto& ypc = *(this->jlf_parse_context); yajl_handle handle = this->jlf_yajl_handle.get(); json_log_userdata jlu(sbr, &sbc); @@ -750,10 +763,10 @@ external_log_format::scan(logfile& lf, ll.set_ignore(true); dst.emplace_back(ll); return log_format::SCAN_MATCH; - } else { - log_debug("no match! %.*s", sbr.length(), line_data); - return log_format::SCAN_NO_MATCH; } + + log_debug("no match! %.*s", sbr.length(), line_data); + return log_format::SCAN_NO_MATCH; } jlu.jlu_sub_line_count += this->jlf_line_format_init_count; @@ -772,11 +785,11 @@ external_log_format::scan(logfile& lf, msg = yajl_get_error( handle, 1, (const unsigned char*) sbr.get_data(), sbr.length()); if (msg != nullptr) { + auto msg_frag = string_fragment::from_c_str(msg); log_debug("Unable to parse line at offset %d: %s", li.li_file_range.fr_offset, msg); - line_count - = std::count(msg, msg + strlen((char*) msg), '\n') + 1; + line_count = msg_frag.count('\n') + 1; yajl_free_error(handle, msg); } if (!this->lf_specialized) { @@ -785,7 +798,7 @@ external_log_format::scan(logfile& lf, for (int lpc = 0; lpc < line_count; lpc++) { log_level_t level = LEVEL_INVALID; - ll.set_time(dst.back().get_time()); + ll.set_time(dst.back().get_timeval()); if (lpc > 0) { level = (log_level_t) (level | LEVEL_CONTINUED); } @@ -1018,7 +1031,8 @@ external_log_format::module_scan(string_fragment body_cap, int curr_fmt = -1, fmt_lock = -1; while (::next_format(elf->elf_pattern_order, curr_fmt, fmt_lock)) { - static thread_local auto md = lnav::pcre2pp::match_data::unitialized(); + static thread_local auto md + = lnav::pcre2pp::match_data::unitialized(); auto& fpat = elf->elf_pattern_order[curr_fmt]; auto& pat = fpat->p_pcre; @@ -1389,7 +1403,7 @@ external_log_format::get_subline(const logline& ll, if (this->jlf_cached_offset != ll.get_offset() || this->jlf_cached_full != full_message) { - yajlpp_parse_context& ypc = *(this->jlf_parse_context); + auto& ypc = *(this->jlf_parse_context); yajl_handle handle = this->jlf_yajl_handle.get(); json_log_userdata jlu(sbr, nullptr); @@ -1399,6 +1413,26 @@ external_log_format::get_subline(const logline& ll, this->jlf_line_offsets.clear(); this->jlf_line_attrs.clear(); + auto line_frag = sbr.to_string_fragment(); + + if (!line_frag.startswith("{")) { + this->jlf_cached_line.resize(line_frag.length()); + memcpy(this->jlf_cached_line.data(), + line_frag.data(), + line_frag.length()); + this->jlf_line_values.clear(); + sbr.share(this->jlf_share_manager, + &this->jlf_cached_line[0], + this->jlf_cached_line.size()); + this->jlf_line_values.lvv_sbr = sbr; + this->jlf_line_attrs.emplace_back( + line_range{0, -1}, + SA_INVALID.value(fmt::format( + FMT_STRING("line at offset {} is not a JSON-line"), + ll.get_offset()))); + return; + } + yajl_reset(handle); ypc.set_static_handler(json_log_rewrite_handlers.jpc_children[0]); ypc.ypc_userdata = &jlu; diff --git a/test/Makefile.am b/test/Makefile.am index 7229d77d..913d5966 100644 --- a/test/Makefile.am +++ b/test/Makefile.am @@ -304,6 +304,7 @@ dist_noinst_DATA = \ logfile_haproxy.0 \ logfile_invalid_json.json \ logfile_invalid_json2.json \ + logfile_mixed_json2.json \ logfile_journald.json \ logfile_json.json \ logfile_json2.json \ diff --git a/test/expected/expected.am b/test/expected/expected.am index 15f62438..6d4d0a01 100644 --- a/test/expected/expected.am +++ b/test/expected/expected.am @@ -272,6 +272,8 @@ EXPECTED_FILES = \ $(srcdir)/%reldir%/test_json_format.sh_84a71e94dc34661a70bb9015b67ba00e93e9cfb5.out \ $(srcdir)/%reldir%/test_json_format.sh_85d03b1b41a7f819af135d2521a8f2c59418e907.err \ $(srcdir)/%reldir%/test_json_format.sh_85d03b1b41a7f819af135d2521a8f2c59418e907.out \ + $(srcdir)/%reldir%/test_json_format.sh_8f2ebcd319afc7966ef11e31f9dd646bf6f001dd.err \ + $(srcdir)/%reldir%/test_json_format.sh_8f2ebcd319afc7966ef11e31f9dd646bf6f001dd.out \ $(srcdir)/%reldir%/test_json_format.sh_952297a90e312d2184fe3e4df795ddc731b096c9.err \ $(srcdir)/%reldir%/test_json_format.sh_952297a90e312d2184fe3e4df795ddc731b096c9.out \ $(srcdir)/%reldir%/test_json_format.sh_989e52d167582648b73c5d025cc0e814c642b3c8.err \ diff --git a/test/expected/test_json_format.sh_80959e2bb6a7fdf938c2e4dbd7d7c81eb84fa072.out b/test/expected/test_json_format.sh_80959e2bb6a7fdf938c2e4dbd7d7c81eb84fa072.out index 63376a40..bae2626a 100644 --- a/test/expected/test_json_format.sh_80959e2bb6a7fdf938c2e4dbd7d7c81eb84fa072.out +++ b/test/expected/test_json_format.sh_80959e2bb6a7fdf938c2e4dbd7d7c81eb84fa072.out @@ -1,6 +1,6 @@ -2013-09-06T20:00:48.124 TRACE trace test +2013-09-06T20:00:48.124 abc 48 def info - - @fields: { "lvl": "TRACE", "msg": "trace test"} -2013-09-06T20:00:49.124 INFO Starting up service +2013-09-06T20:00:49.124 abc 49 def info - - @fields: { "lvl": "INFO", "msg": "Starting up service"} [offset: 186] {"ts": "2013-09-06T22:00:49.124817Z", "@fields": { "lvl": "INFO", "msg": parse error: premature EOF diff --git a/test/expected/test_json_format.sh_8f2ebcd319afc7966ef11e31f9dd646bf6f001dd.err b/test/expected/test_json_format.sh_8f2ebcd319afc7966ef11e31f9dd646bf6f001dd.err new file mode 100644 index 00000000..e69de29b diff --git a/test/expected/test_json_format.sh_8f2ebcd319afc7966ef11e31f9dd646bf6f001dd.out b/test/expected/test_json_format.sh_8f2ebcd319afc7966ef11e31f9dd646bf6f001dd.out new file mode 100644 index 00000000..338bca95 --- /dev/null +++ b/test/expected/test_json_format.sh_8f2ebcd319afc7966ef11e31f9dd646bf6f001dd.out @@ -0,0 +1,21 @@ +2013-09-06T20:00:48.124 abc 48 def TRACE - trace test +2013-09-06T20:00:49.124 abc 49 def INFO - Starting up service +2013-09-06T22:00:49.124 abc 49 def INFO - Shutting down service + user: steve@example.com +timestamp="2013-09-06T22:00:50.123000Z" level="INFO" msg="Hello, World" +panic: foo bar failed baz + level1.py:10034 + level2.py:100 + level3.py:42 +2013-09-06T22:00:59.124 abc 59 def DEBUG5 - Details... +2013-09-06T22:00:59.124 abc 59 def DEBUG4 - Details... +2013-09-06T22:00:59.124 abc 59 def DEBUG3 - Details... +2013-09-06T22:00:59.124 abc 59 def DEBUG2 - Details... +2013-09-06T22:00:59.124 abc 59 def DEBUG - Details... +2013-09-06T22:01:49.124 abc 49 def STATS - 1 beat per second +2013-09-06T22:01:49.124 abc 49 def WARNING - not looking good +2013-09-06T22:01:49.124 abc 49 def ERROR - looking bad +2013-09-06T22:01:49.124 abc 49 def CRITICAL - sooo bad +2013-09-06T22:01:49.124 abc 49 def FATAL - shoot + obj: { "field1" : "hi", "field2": 2 } + arr: ["hi", {"sub1": true}] diff --git a/test/formats/jsontest2/format.json b/test/formats/jsontest2/format.json index 95781f7f..167aa0ff 100644 --- a/test/formats/jsontest2/format.json +++ b/test/formats/jsontest2/format.json @@ -3,7 +3,7 @@ "json_log2": { "title": "Test JSON Log with integer levels", "json": true, - "file-pattern": "logfile_json2\\.json", + "file-pattern": "logfile_.*json2\\.json", "description": "Test config", "line-format": [ { @@ -15,26 +15,34 @@ "timestamp-format": "abc %S def" }, " ", - { "field" : "lvl", "min-width": 5 }, + { + "field": "lvl", + "min-width": 5 + }, " ", - { "field" : "cl", "max-width": 5}, + { + "field": "cl", + "max-width": 5 + }, " ", - { "field" : "msg" } + { + "field": "msg" + } ], - "level-field" : "lvl", - "level" : { - "info" : 0, - "error" : 10 + "level-field": "lvl", + "level": { + "info": 0, + "error": 10 }, "timestamp-field": "ts", - "body-field" : "msg", - "value" : { - "user" : { - "kind" : "string", - "identifier" : true + "body-field": "msg", + "value": { + "user": { + "kind": "string", + "identifier": true }, - "cl" : { - "kind" : "string" + "cl": { + "kind": "string" } } } diff --git a/test/formats/jsontest3/format.json b/test/formats/jsontest3/format.json index 519cc407..63cc2a6b 100644 --- a/test/formats/jsontest3/format.json +++ b/test/formats/jsontest3/format.json @@ -3,7 +3,7 @@ "json_log3": { "title": "Test JSON Log Format", "description": "Test JSON Log Format", - "file-pattern": "logfile_json3\\.json", + "file-pattern": "logfile_.*json3\\.json", "json": true, "hide-extra": true, "convert-to-local-time": true, diff --git a/test/logfile_mixed_json2.json b/test/logfile_mixed_json2.json new file mode 100644 index 00000000..6ddcb81d --- /dev/null +++ b/test/logfile_mixed_json2.json @@ -0,0 +1,18 @@ +{"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"} +timestamp="2013-09-06T22:00:50.123000Z" level="INFO" msg="Hello, World" +panic: foo bar failed baz + level1.py:10034 + level2.py:100 + level3.py:42 +{"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", "obj": { "field1" : "hi", "field2": 2 }, "arr" : ["hi", {"sub1": true}]} diff --git a/test/test_json_format.sh b/test/test_json_format.sh index 06051832..1ef206a8 100644 --- a/test/test_json_format.sh +++ b/test/test_json_format.sh @@ -131,3 +131,7 @@ run_cap_test ${lnav_test} -n \ -d /tmp/lnav.err \ -I ${test_dir} \ ${test_dir}/logfile_invalid_json2.json + +run_cap_test ${lnav_test} -n \ + -I ${test_dir} \ + ${test_dir}/logfile_mixed_json2.json