From 71a1850dd31eb523c445f270c17a7d7931c0258d Mon Sep 17 00:00:00 2001 From: Tim Stack Date: Tue, 7 May 2024 21:49:08 -0700 Subject: [PATCH] [demux] some more testing --- src/base/piper.file.hh | 8 +++++ src/file_collection.cc | 6 ---- src/file_format.cc | 2 +- src/logfile.cc | 4 +++ src/piper.looper.cc | 32 +++++++++++++++++-- src/piper.looper.hh | 7 ++++ src/session_data.cc | 6 +++- test/Makefile.am | 1 + test/expected/expected.am | 4 +++ ...d0e59e85769234d589a8a945cf2f80542b7dd1.err | 0 ...d0e59e85769234d589a8a945cf2f80542b7dd1.out | 22 +++++++++++++ ...6b696993549ce6aa0ed6f3c2908f1410a8b467.err | 0 ...6b696993549ce6aa0ed6f3c2908f1410a8b467.out | 2 ++ test/logfile_docker_compose_with_noise.0 | 24 ++++++++++++++ test/test_demux.sh | 6 ++++ 15 files changed, 114 insertions(+), 10 deletions(-) create mode 100644 test/expected/test_demux.sh_7dd0e59e85769234d589a8a945cf2f80542b7dd1.err create mode 100644 test/expected/test_demux.sh_7dd0e59e85769234d589a8a945cf2f80542b7dd1.out create mode 100644 test/expected/test_demux.sh_e36b696993549ce6aa0ed6f3c2908f1410a8b467.err create mode 100644 test/expected/test_demux.sh_e36b696993549ce6aa0ed6f3c2908f1410a8b467.out create mode 100644 test/logfile_docker_compose_with_noise.0 diff --git a/src/base/piper.file.hh b/src/base/piper.file.hh index 99ab0c67..cd53ab9c 100644 --- a/src/base/piper.file.hh +++ b/src/base/piper.file.hh @@ -44,12 +44,20 @@ namespace lnav { namespace piper { +enum class demux_output_t { + not_applicable, + signal, + invalid, +}; + struct header { timeval h_ctime{}; std::string h_name; std::string h_cwd; std::map h_env; std::string h_timezone; + std::string h_mux_id; + demux_output_t h_demux_output{demux_output_t::not_applicable}; std::map h_demux_meta; bool operator<(const header& rhs) const diff --git a/src/file_collection.cc b/src/file_collection.cc index 7dccdd0c..1ff21df5 100644 --- a/src/file_collection.cc +++ b/src/file_collection.cc @@ -557,12 +557,6 @@ file_collection::watch_logfile(const std::string& filename, log_info("loading new file: filename=%s", filename.c_str()); - if (loo.loo_piper && !loo.loo_piper->get_demux_id().empty()) - { - log_info(" treating demuxed file as a log"); - loo.loo_text_format = text_format_t::TF_LOG; - } - auto open_res = logfile::open(filename_to_open, loo); if (open_res.isOk()) { retval.fc_files.push_back(open_res.unwrap()); diff --git a/src/file_format.cc b/src/file_format.cc index b109a4fe..40f3c8cb 100644 --- a/src/file_format.cc +++ b/src/file_format.cc @@ -77,7 +77,7 @@ detect_file_format(const ghc::filesystem::path& filename) lb.set_fd(fd); auto load_res = lb.load_next_line(next_range); - if (load_res.isOk() && lb.is_header_utf8()) { + if (load_res.isOk() && lb.is_header_utf8() && !lb.is_piper()) { auto li = load_res.unwrap(); auto read_res = lb.read_range(li.li_file_range); if (read_res.isOk()) { diff --git a/src/logfile.cc b/src/logfile.cc index 3fe95e21..ee43efbe 100644 --- a/src/logfile.cc +++ b/src/logfile.cc @@ -165,6 +165,10 @@ logfile::open(ghc::filesystem::path filename, phdr.h_name.c_str()); lf->set_filename(phdr.h_name); lf->lf_valid_filename = false; + if (phdr.h_demux_output == lnav::piper::demux_output_t::signal) + { + lf->lf_text_format = text_format_t::TF_LOG; + } lnav::file_options fo; if (!phdr.h_timezone.empty()) { diff --git a/src/piper.looper.cc b/src/piper.looper.cc index ffc667fd..94ddc948 100644 --- a/src/piper.looper.cc +++ b/src/piper.looper.cc @@ -139,6 +139,14 @@ const json_path_container header_demux_handlers = { .for_field(&lnav::piper::header::h_demux_meta), }; +static const json_path_handler_base::enum_value_t demux_output_values[] = { + {"not_applicable", demux_output_t::not_applicable}, + {"signal", demux_output_t::signal}, + {"invalid", demux_output_t::invalid}, + + json_path_handler_base::ENUM_TERMINATOR, +}; + const typed_json_path_container header_handlers = { yajlpp::property_handler("name").for_field(&lnav::piper::header::h_name), yajlpp::property_handler("timezone") @@ -146,6 +154,11 @@ const typed_json_path_container header_handlers = { yajlpp::property_handler("ctime").for_field(&lnav::piper::header::h_ctime), yajlpp::property_handler("cwd").for_field(&lnav::piper::header::h_cwd), yajlpp::property_handler("env").with_children(header_env_handlers), + yajlpp::property_handler("mux_id").for_field( + &lnav::piper::header::h_mux_id), + yajlpp::property_handler("demux_output") + .with_enum_values(demux_output_values) + .for_field(&lnav::piper::header::h_demux_output), yajlpp::property_handler("demux_meta").with_children(header_demux_handlers), }; @@ -237,6 +250,7 @@ looper::loop() off_t os_woff{0}; off_t os_last_woff{0}; std::string os_hash_id; + std::optional os_level; }; robin_hood::unordered_map demux_level; if (curr_demux_def && curr_demux_def->dd_pattern.pp_value ->capture_from(body_sf) @@ -473,8 +489,11 @@ looper::loop() if (muxid_cap_opt && body_cap_opt) { line_muxid_sf = muxid_cap_opt.value(); body_sf = body_cap_opt.value(); + demux_output = demux_output_t::signal; } else { + demux_output = demux_output_t::invalid; line_muxid_sf = OUT_OF_FRAME_ID; + demux_level = LEVEL_ERROR; } if (curr_demux_def->dd_timestamp_capture_index >= 0) { auto ts_cap_opt @@ -484,7 +503,9 @@ looper::loop() } } } else if (curr_demux_def) { + demux_output = demux_output_t::invalid; line_muxid_sf = OUT_OF_FRAME_ID; + demux_level = LEVEL_ERROR; } auto outfds_iter = outfds.find(line_muxid_sf); @@ -495,6 +516,7 @@ looper::loop() outfds_iter = emp_res.first; outfds_iter->second.os_hash_id = hasher().update(line_muxid_sf).to_string(); + outfds_iter->second.os_level = demux_level; } auto& os = outfds_iter->second; if (os.os_woff > os.os_last_woff @@ -535,7 +557,11 @@ looper::loop() this->l_name, this->l_cwd, this->l_env, + "", + line_muxid_sf.to_string(), + demux_output, }; + hdr.h_demux_output = demux_output; if (!line_muxid_sf.empty()) { hdr.h_name = fmt::format( FMT_STRING("{}/{}"), hdr.h_name, line_muxid_sf); @@ -599,8 +625,10 @@ looper::loop() } else { gettimeofday(&line_tv, nullptr); } - wrc = write_line_meta( - os.os_fd.get(), line_tv, cap.cf_level, os.os_woff); + wrc = write_line_meta(os.os_fd.get(), + line_tv, + os.os_level.value_or(cap.cf_level), + os.os_woff); if (wrc == -1) { log_error("unable to write timestamp: %s -- %s", this->l_name.c_str(), diff --git a/src/piper.looper.hh b/src/piper.looper.hh index e0f86836..eac07221 100644 --- a/src/piper.looper.hh +++ b/src/piper.looper.hh @@ -52,8 +52,15 @@ enum class state { using safe_demux_id = safe::Safe; struct options { + bool o_demux{false}; bool o_tail{true}; + options& with_demux(bool v) + { + this->o_demux = v; + return *this; + } + options& with_tail(bool v) { this->o_tail = v; diff --git a/src/session_data.cc b/src/session_data.cc index 064ebc12..6a78860f 100644 --- a/src/session_data.cc +++ b/src/session_data.cc @@ -873,7 +873,11 @@ static const struct json_path_container view_handlers = { if (view_index < LNV__MAX) { return &root->sd_view_states[view_index]; } - return (view_state*) nullptr; + + log_error("unknown view name: %s", + ypc.get_substr("view_name").c_str()); + static view_state dummy; + return &dummy; }) .with_children(view_def_handlers), }; diff --git a/test/Makefile.am b/test/Makefile.am index b300f0db..b7e1f708 100644 --- a/test/Makefile.am +++ b/test/Makefile.am @@ -332,6 +332,7 @@ dist_noinst_DATA = \ logfile_cloudflare.json \ logfile_cxx.0 \ logfile_docker_compose.0 \ + logfile_docker_compose_with_noise.0 \ logfile_docker_compose_with_ts.0 \ logfile_empty.0 \ logfile_epoch.0 \ diff --git a/test/expected/expected.am b/test/expected/expected.am index a9d8d424..42bcd830 100644 --- a/test/expected/expected.am +++ b/test/expected/expected.am @@ -266,12 +266,16 @@ EXPECTED_FILES = \ $(srcdir)/%reldir%/test_config.sh_eec3768ebc201ca63bca1411270965f78db1abfc.out \ $(srcdir)/%reldir%/test_demux.sh_090b34f84229c02aad7ab2f1cea20cfcf94446d5.err \ $(srcdir)/%reldir%/test_demux.sh_090b34f84229c02aad7ab2f1cea20cfcf94446d5.out \ + $(srcdir)/%reldir%/test_demux.sh_7dd0e59e85769234d589a8a945cf2f80542b7dd1.err \ + $(srcdir)/%reldir%/test_demux.sh_7dd0e59e85769234d589a8a945cf2f80542b7dd1.out \ $(srcdir)/%reldir%/test_demux.sh_ac2a283ce1a4a3d99b0a9de4e9b72bbd9637cf61.err \ $(srcdir)/%reldir%/test_demux.sh_ac2a283ce1a4a3d99b0a9de4e9b72bbd9637cf61.out \ $(srcdir)/%reldir%/test_demux.sh_b640a3b46494e680a84cf042514ed465e39d8f38.err \ $(srcdir)/%reldir%/test_demux.sh_b640a3b46494e680a84cf042514ed465e39d8f38.out \ $(srcdir)/%reldir%/test_demux.sh_babab3536a2fc7c2a99847fa355b50d40a51763d.err \ $(srcdir)/%reldir%/test_demux.sh_babab3536a2fc7c2a99847fa355b50d40a51763d.out \ + $(srcdir)/%reldir%/test_demux.sh_e36b696993549ce6aa0ed6f3c2908f1410a8b467.err \ + $(srcdir)/%reldir%/test_demux.sh_e36b696993549ce6aa0ed6f3c2908f1410a8b467.out \ $(srcdir)/%reldir%/test_demux.sh_f8cbb968fccbc0442a831c0f69c6dbdfe5413339.err \ $(srcdir)/%reldir%/test_demux.sh_f8cbb968fccbc0442a831c0f69c6dbdfe5413339.out \ $(srcdir)/%reldir%/test_events.sh_09ba47d70bfca88e89faf29598c1095292cad435.err \ diff --git a/test/expected/test_demux.sh_7dd0e59e85769234d589a8a945cf2f80542b7dd1.err b/test/expected/test_demux.sh_7dd0e59e85769234d589a8a945cf2f80542b7dd1.err new file mode 100644 index 00000000..e69de29b diff --git a/test/expected/test_demux.sh_7dd0e59e85769234d589a8a945cf2f80542b7dd1.out b/test/expected/test_demux.sh_7dd0e59e85769234d589a8a945cf2f80542b7dd1.out new file mode 100644 index 00000000..e622712d --- /dev/null +++ b/test/expected/test_demux.sh_7dd0e59e85769234d589a8a945cf2f80542b7dd1.out @@ -0,0 +1,22 @@ +2013-06-06T19:13:20.123+0000 * Serving Flask app 'app.py' +2013-06-06T19:13:20.123+0000 * Debug mode: on +2013-06-06T19:13:20.123+0000 WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead. +2013-06-06T19:13:20.123+0000 * Running on all addresses (0.0.0.0) +2013-06-06T19:13:20.123+0000 * Running on http://127.0.0.1:5000 +2013-06-06T19:13:20.123+0000 * Running on http://172.18.0.3:5000 +2013-06-06T19:13:20.123+0000 Press CTRL+C to quit +2013-06-06T19:13:20.123+0000 * Restarting with stat +2013-06-06T19:13:20.123+0000 * Debugger is active! +2013-06-06T19:13:20.123+0000 * Debugger PIN: 593-762-075 +1:C 25 Apr 2024 05:32:35.018 * oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo +1:C 25 Apr 2024 05:32:35.018 * Redis version=7.2.0, bits=64, commit=00000000, modified=0, pid=1, just started +1:C 25 Apr 2024 05:32:35.018 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf +1:M 25 Apr 2024 05:32:35.019 * monotonic clock: POSIX clock_gettime +1:M 25 Apr 2024 05:32:35.019 * Running mode=standalone, port=6379. +1:M 25 Apr 2024 05:32:35.020 * Server initialized +1:M 25 Apr 2024 05:32:35.022 * Ready to accept connections tcp +1:signal-handler (25 Apr 2024 05:54:43.000) Received SIGTERM scheduling shutdown... +1:M 25 Apr 2024 05:54:43.946 * User requested shutdown... +1:M 25 Apr 2024 05:54:43.946 * Saving the final RDB snapshot before exiting. +1:M 25 Apr 2024 05:54:43.948 * DB saved on disk +1:M 25 Apr 2024 05:54:43.948 # Redis is now ready to exit, bye bye... diff --git a/test/expected/test_demux.sh_e36b696993549ce6aa0ed6f3c2908f1410a8b467.err b/test/expected/test_demux.sh_e36b696993549ce6aa0ed6f3c2908f1410a8b467.err new file mode 100644 index 00000000..e69de29b diff --git a/test/expected/test_demux.sh_e36b696993549ce6aa0ed6f3c2908f1410a8b467.out b/test/expected/test_demux.sh_e36b696993549ce6aa0ed6f3c2908f1410a8b467.out new file mode 100644 index 00000000..c34ac409 --- /dev/null +++ b/test/expected/test_demux.sh_e36b696993549ce6aa0ed6f3c2908f1410a8b467.out @@ -0,0 +1,2 @@ +out of frame line 1 +out of frame line 2 diff --git a/test/logfile_docker_compose_with_noise.0 b/test/logfile_docker_compose_with_noise.0 new file mode 100644 index 00000000..38f5be42 --- /dev/null +++ b/test/logfile_docker_compose_with_noise.0 @@ -0,0 +1,24 @@ +web-1 | * Serving Flask app 'app.py' +web-1 | * Debug mode: on +web-1 | WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead. +web-1 | * Running on all addresses (0.0.0.0) +web-1 | * Running on http://127.0.0.1:5000 +web-1 | * Running on http://172.18.0.3:5000 +web-1 | Press CTRL+C to quit +web-1 | * Restarting with stat +web-1 | * Debugger is active! +web-1 | * Debugger PIN: 593-762-075 +redis-1 | 1:C 25 Apr 2024 05:32:35.018 * oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo +redis-1 | 1:C 25 Apr 2024 05:32:35.018 * Redis version=7.2.0, bits=64, commit=00000000, modified=0, pid=1, just started +redis-1 | 1:C 25 Apr 2024 05:32:35.018 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf +redis-1 | 1:M 25 Apr 2024 05:32:35.019 * monotonic clock: POSIX clock_gettime +redis-1 | 1:M 25 Apr 2024 05:32:35.019 * Running mode=standalone, port=6379. +redis-1 | 1:M 25 Apr 2024 05:32:35.020 * Server initialized +redis-1 | 1:M 25 Apr 2024 05:32:35.022 * Ready to accept connections tcp +redis-1 | 1:signal-handler (1714024483) Received SIGTERM scheduling shutdown... +redis-1 | 1:M 25 Apr 2024 05:54:43.946 * User requested shutdown... +redis-1 | 1:M 25 Apr 2024 05:54:43.946 * Saving the final RDB snapshot before exiting. +redis-1 | 1:M 25 Apr 2024 05:54:43.948 * DB saved on disk +out of frame line 1 +out of frame line 2 +redis-1 | 1:M 25 Apr 2024 05:54:43.948 # Redis is now ready to exit, bye bye... diff --git a/test/test_demux.sh b/test/test_demux.sh index 77d614b6..3d9fb0a0 100644 --- a/test/test_demux.sh +++ b/test/test_demux.sh @@ -16,3 +16,9 @@ run_cap_test ${lnav_test} -n ${test_dir}/logfile_mux_zookeeper.0 run_cap_test ${lnav_test} -n \ -c ';SELECT * FROM lnav_file_demux_metadata' \ ${test_dir}/logfile_mux_zookeeper.0 + +run_cap_test ${lnav_test} -n ${test_dir}/logfile_docker_compose_with_noise.0 + +run_cap_test ${lnav_test} -n \ + -c ':switch-to-view text' \ + ${test_dir}/logfile_docker_compose_with_noise.0