[demux] some more testing

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<std::string, std::string> h_env;
     std::string h_timezone;
+    std::string h_mux_id;
+    demux_output_t h_demux_output{demux_output_t::not_applicable};
     std::map<std::string, std::string> h_demux_meta;
 
     bool operator<(const header& rhs) const

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());

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()) {

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()) {

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<lnav::piper::header> 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<lnav::piper::header> 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<log_level_t> os_level;
     };
     robin_hood::unordered_map<string_fragment,
                               out_state,
@@ -437,6 +451,7 @@ looper::loop()
                     break;
                 }
 
+                auto demux_output = demux_output_t::not_applicable;
                 auto sbr = read_result.unwrap();
                 auto line_muxid_sf = DEFAULT_ID;
                 auto body_sf = sbr.to_string_fragment();
@@ -459,6 +474,7 @@ looper::loop()
                     }
                     demux_attempted = true;
                 }
+                std::optional<log_level_t> 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(),

src/piper.looper.hh

@@ -52,8 +52,15 @@ enum class state {
 using safe_demux_id = safe::Safe<std::string>;
 
 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;

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),
 };

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 \

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 \

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...

test/expected/test_demux.sh_e36b696993549ce6aa0ed6f3c2908f1410a8b467.out

@@ -0,0 +1,2 @@
+out of frame line 1
+out of frame line 2

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...

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