From d263b0b1505d4581badc00fea75c6303bc84c825 Mon Sep 17 00:00:00 2001 From: Simon Marchi Date: Fri, 30 Aug 2024 22:39:50 -0400 Subject: [PATCH] Fix: src.ctf.lttng-live: manually clear sessions vector in ~lttng_live_msg_iter() MIME-Version: 1.0 Content-Type: text/plain; charset=utf8 Content-Transfer-Encoding: 8bit Starting with 751aaa6218f ("src.ctf.lttng-live: make lttng_live_msg_iter::sessions an std::vector"), when live message iterator gets destroyed while some stream iterators are still active, we get this assertion: (╯°□°)╯︵ ┻━┻ /home/simark/src/babeltrace/src/plugins/ctf/lttng-live/lttng-live.cpp:153: ~lttng_live_msg_iter(): Assertion `this->active_stream_iter == 0` failed. When a live message iterator completes successfully, by consuming everything the relay has to offer until all stream iterators are ended, there are no more active stream iterators when reaching ~lttng_live_msg_iter() (they all get destroyed by next_stream_iterator_for_trace() when they end). So the `this->active_stream_iter == 0` assertion in the destructor holds. But when an unexpected exit occurs, for instance because of an error or a SIGINT interruption, the message iterator is destroyed while there are still some stream iterators active. Prior to 751aaa6218f, lttng_live_msg_iter_destroy() (which has since been renamed to ~lttng_live_msg_iter()) had: if (lttng_live_msg_iter->sessions) { g_ptr_array_free(lttng_live_msg_iter->sessions, TRUE); } Clearing the `sessions` array caused the `lttng_live_session` objects to be destroyed, which caused the `lttng_live_trace` objects to be destroyed, which caused the stream iterators to be destroyed. When reaching the assertion, the count of active stream iterators was therefore 0. With the refactor introduced by 751aaa6218f, we rely on the destruction of the `sessions` vector for all this to happen, which occurs after the user-specified destructor has run, therefore after the assertion. At the time the assertion is checked, there are still some stream iterators alive. Fix this by manually clearing the sessions vector before the assertion, to mimic the old behavior. Add a test that purposefully sends metadata with a syntax error, which triggers the bug. The change adding the `kill_server_on_cli_failure` parameter to get_cli_output_with_lttng_live_server() is useful to avoid the test script trying to kill the Python live server, in the new test. Since babeltrace successfully connects to the server and the disconnects, the server exits on its own. This would print a "kill 1234 failed: no such process" message. Not fatal, but not welcome either. It's not pretty, but it works. Change-Id: Id777e7ac0294d89ea236dd05651c8fbe708b2be4 Signed-off-by: Simon Marchi Reviewed-on: https://review.lttng.org/c/babeltrace/+/13204 Tested-by: jenkins Reviewed-by: Philippe Proulx --- src/plugins/ctf/lttng-live/lttng-live.cpp | 2 + .../1/live/invalid-metadata/channel0_0 | Bin 0 -> 8192 bytes .../invalid-metadata/index/channel0_0.idx | Bin 0 -> 160 bytes .../1/live/invalid-metadata/metadata | 122 ++++++++++++++++++ .../src.ctf.lttng-live/invalid-metadata.json | 14 ++ tests/plugins/src.ctf.lttng-live/test-live.sh | 64 ++++++++- 6 files changed, 195 insertions(+), 7 deletions(-) create mode 100644 tests/data/ctf-traces/1/live/invalid-metadata/channel0_0 create mode 100644 tests/data/ctf-traces/1/live/invalid-metadata/index/channel0_0.idx create mode 100644 tests/data/ctf-traces/1/live/invalid-metadata/metadata create mode 100644 tests/data/plugins/src.ctf.lttng-live/invalid-metadata.json diff --git a/src/plugins/ctf/lttng-live/lttng-live.cpp b/src/plugins/ctf/lttng-live/lttng-live.cpp index efe51e32..30aff694 100644 --- a/src/plugins/ctf/lttng-live/lttng-live.cpp +++ b/src/plugins/ctf/lttng-live/lttng-live.cpp @@ -147,6 +147,8 @@ lttng_live_session::~lttng_live_session() lttng_live_msg_iter::~lttng_live_msg_iter() { + this->sessions.clear(); + BT_ASSERT(this->lttng_live_comp); BT_ASSERT(this->lttng_live_comp->has_msg_iter); diff --git a/tests/data/ctf-traces/1/live/invalid-metadata/channel0_0 b/tests/data/ctf-traces/1/live/invalid-metadata/channel0_0 new file mode 100644 index 0000000000000000000000000000000000000000..c8e9ddbee8663ae1e1b08cebd00db3b17d43f876 GIT binary patch literal 8192 zcmX>o|K}jH5m-<73nH;8sX>;E%iaWSO-57WuWpi { + struct { + uint27_clock_monotonic_t timestamp; + } compact; + struct { + uint32_t id; + uint64_clock_monotonic_t timestamp; + } extended; + } v; +} align(8); + +struct event_header_large { + enum : uint16_t { compact = 0 ... 65534, extended = 65535 } id; + variant { + struct { + uint32_clock_monotonic_t timestamp; + } compact; + struct { + uint32_t id; + uint64_clock_monotonic_t timestamp; + } extended; + } v; +} align(8); + +stream { + id = 0; + event.header := struct event_header_large; + packet.context := struct packet_context; +}; + +event { + name = "my_app:signe_de_pia$$e"; + id = 0; + stream_id = 0; + loglevel = 13; + fields := struct { + }; +}; + +event { + name = "my_app:signe_de_pia$$e_2"; + id = 1; + stream_id = 0; + loglevel = 13; + fields := struct { + }; +}; diff --git a/tests/data/plugins/src.ctf.lttng-live/invalid-metadata.json b/tests/data/plugins/src.ctf.lttng-live/invalid-metadata.json new file mode 100644 index 00000000..bb0f06b7 --- /dev/null +++ b/tests/data/plugins/src.ctf.lttng-live/invalid-metadata.json @@ -0,0 +1,14 @@ +[ + { + "name": "invalid-metadata", + "id": 0, + "hostname": "hostname", + "live-timer-freq": 1, + "client-count": 0, + "traces": [ + { + "path": "1/live/invalid-metadata/" + } + ] + } +] diff --git a/tests/plugins/src.ctf.lttng-live/test-live.sh b/tests/plugins/src.ctf.lttng-live/test-live.sh index 274302fb..efc8bab7 100755 --- a/tests/plugins/src.ctf.lttng-live/test-live.sh +++ b/tests/plugins/src.ctf.lttng-live/test-live.sh @@ -85,7 +85,8 @@ get_cli_output_with_lttng_live_server() { local cli_stderr_file="$3" local port_file="$4" local trace_path_prefix="$5" - shift 5 + local kill_server_on_cli_failure="$6" + shift 6 local server_args=("$@") local i @@ -138,8 +139,11 @@ get_cli_output_with_lttng_live_server() { if ! bt_cli "$cli_stdout_file" "$cli_stderr_file" "${cli_args[@]}"; then # CLI failed: cancel everything else - kill_lttng_live_server "$server_pid_file" - wait + if [[ $kill_server_on_cli_failure == true ]]; then + kill_lttng_live_server "$server_pid_file" + wait + fi + rm -f "$server_pid_file" rm -f "$server_retcode_file" return 1 @@ -191,8 +195,7 @@ run_test() { port_file="$(mktemp -t test-live-server-port.XXXXXX)" get_cli_output_with_lttng_live_server "$cli_args_template" "$cli_stdout" \ - "$cli_stderr" "$port_file" "$trace_path_prefix" "${server_args[@]}" - port=$(<"$port_file") + "$cli_stderr" "$port_file" "$trace_path_prefix" true "${server_args[@]}" bt_diff "$expected_stdout" "$cli_stdout" ok $? "$test_text - stdout" @@ -204,6 +207,41 @@ run_test() { rm -f "$port_file" } +run_test_fail() { + local test_text="$1" + local cli_args_template="$2" + local expected_stdout="$3" + local expected_stderr_re="$4" + local trace_path_prefix="$5" + shift 5 + local server_args=("$@") + + local cli_stdout + local cli_stderr + local cli_stderr_no_crlf + local port_file + local port + + cli_stdout="$(mktemp -t test-live-stdout.XXXXXX)" + cli_stderr="$(mktemp -t test-live-stderr.XXXXXX)" + cli_stderr_no_crlf="$(mktemp -t test-live-stderr-no-crlf.XXXXXX)" + port_file="$(mktemp -t test-live-server-port.XXXXXX)" + + get_cli_output_with_lttng_live_server "$cli_args_template" "$cli_stdout" \ + "$cli_stderr" "$port_file" "$trace_path_prefix" false "${server_args[@]}" + + bt_diff "$expected_stdout" "$cli_stdout" + ok $? "$test_text - stdout" + + bt_remove_crlf "$cli_stderr" "$cli_stderr_no_crlf" + bt_grep_ok "$expected_stderr_re" "$cli_stderr_no_crlf" "$test_text - stderr" + + rm -f "$cli_stdout" + rm -f "$cli_stderr" + rm -f "$cli_stderr_no_crlf" + rm -f "$port_file" +} + test_list_sessions() { # Test the basic listing of sessions. # Ensure that a multi-domain trace is seen as a single session. @@ -226,7 +264,7 @@ test_list_sessions() { tmp_stdout_expected="$(mktemp -t test-live-list-sessions-stdout-expected.XXXXXX)" get_cli_output_with_lttng_live_server "$cli_args_template" "$cli_stdout" \ - "$cli_stderr" "$port_file" "$trace_dir_native" "${server_args[@]}" + "$cli_stderr" "$port_file" "$trace_dir_native" true "${server_args[@]}" port=$(<"$port_file") # Craft the expected output. This is necessary since the port number @@ -418,7 +456,18 @@ test_live_new_stream_during_inactivity() { rm -rf "$tmp_dir" } -plan_tests 20 +test_invalid_metadata() { + local test_text="invalid metadata sent by the relay" + local cli_args_template="-i lttng-live net://localhost:@PORT@/host/hostname/invalid-metadata" + local server_args=("$test_data_dir/invalid-metadata.json") + local expected_stdout="/dev/null" + + run_test_fail "$test_text" "$cli_args_template" "$expected_stdout" \ + "At line 12 in metadata stream: syntax error, unexpected IDENTIFIER: token=\"perchaude\"" \ + "$trace_dir_native" "${server_args[@]}" +} + +plan_tests 22 test_list_sessions test_base @@ -429,3 +478,4 @@ test_inactivity_discarded_packet test_split_metadata test_stored_values test_live_new_stream_during_inactivity +test_invalid_metadata -- 2.34.1