Fix: sessiond: preserve jul/log4j domain loglevels

Issue observed
==============

Following dcd24bbf7dbc74e3584d1d0d52715e749023c452, the
lttng-ust-java-tests started failing with a number of errors such as
the following [1]:

```
org.opentest4j.AssertionFailedError: expected: java.util.Collections$SingletonList@3270d194<[Event name = eventA, Log level selector = (LTTNG_EVENT_LOGLEVEL_ALL), Filter string = logger_name == "eventA"]> but was: java.util.ArrayList@235834f2<[Event name = eventA, Log level selector = (LTTNG_EVENT_LOGLEVEL_ALL), Filter string = logger_name == "eventA"]>
	at org.lttng.ust.agent.integration.client.TcpClientIT.testEnableEvent(TcpClientIT.java:187
```
While the assertion failure print out looks like the events are the
same, there is a difference in between the objects which is not
printed: the loglevel integer value. For example:

```
eventA [level -2147483648, type 0]: logger_name == "eventA"
eventB [level -2147483648, type 0]: logger_name == "eventB"

eventA [level -1, type 0]: logger_name == "eventA"
eventB [level -1, type 0]: logger_name == "eventB"
```

Cause
=====

When events are created from payloads in
`src/common/event.cpp:lttng_event_create_from_payload`, the loglevel
value is coerced to `-1` when the loglevel_type is
LTTNG_EVENT_LOGLEVEL_ALL.

Consider the event created in `lttng enable-event --jul
eventName`. The loglevel_type and loglevel will be set as follows:

* loglevel_type: LTTNG_EVENT_LOGLEVEL_ALL (0)
* loglevel: LTTNG_EVENT_LOGLEVEL_JUL_ALL (-2147483648)

The event created is then serialized and sent to the sessiond which
recreates it from the payload removing the value set initially.

The normalization performed in `src/bin/lttng-sessiond/cmd.cpp` has
the same effect.

Solution
========

Remove the normalization of the the loglevel to -1 when events with
loglevel_type LTTNG_EVENT_LOGLEVEL_ALL are created from payloads or
processed via `_cmd_enable_event`.

A test has been added to confirm that the modification doesn't regress
on the issue flagged in https://bugs.lttng.org/issues/1373 which lead
to the normalization changes being made.

This change isn't an exhaustive audit of the packet outputs which may
or may not leak the '-1' "unset" value. One potential change to the
normalization may be to have the normalization be domain-aware and
always default to the domain's "ALL" value. Note that not all domains
have the concept of an "unset" level.

References
==========

[1] https://ci.lttng.org/job/lttng-ust-java-tests_master_build/java_version=java-11-openjdk,platform=bionic-amd64/3302/consoleFull

Refs: #1373

Signed-off-by: Kienan Stewart <kstewart@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: Iac653157190b61b44d5ff18ac968fef58330a106

diff --git a/configure.ac b/configure.ac
index dbba02672ad0ac17afedadef75d421efefa59aef..43d9d3933890d9bdac225f4bb33c4c165952624c 100644 (file)
--- a/configure.ac
+++ b/configure.ac
@@ -1158,6 +1158,7 @@ AC_CONFIG_FILES([
        tests/regression/tools/mi/Makefile
        tests/regression/tools/wildcard/Makefile
        tests/regression/tools/channel/Makefile
+       tests/regression/tools/client/Makefile
        tests/regression/tools/crash/Makefile
        tests/regression/tools/regen-metadata/Makefile
        tests/regression/tools/regen-statedump/Makefile

diff --git a/tests/regression/Makefile.am b/tests/regression/Makefile.am
index 7ac7e0974106f4a79417ed1d527660a37a9de549..e556223d8d39909f32167d40e5c8e7ceef32c0f3 100644 (file)
--- a/tests/regression/Makefile.am
+++ b/tests/regression/Makefile.am
@@ -55,7 +55,8 @@ TESTS = tools/base-path/test_ust \
        tools/trigger/test_list_triggers_cli \
        tools/trigger/test_remove_trigger_cli \
        tools/trigger/name/test_trigger_name_backwards_compat \
-       tools/trigger/hidden/test_hidden_trigger
+       tools/trigger/hidden/test_hidden_trigger \
+       tools/client/test_bug1373_events_differ_only_by_loglevel
 
 if HAVE_LIBLTTNG_UST_CTL
 SUBDIRS += ust

diff --git a/tests/regression/tools/Makefile.am b/tests/regression/tools/Makefile.am
index fc39333c01a9a8bdcb500db222069bc79638c517..153dc036fcb2bac0e416b13d7f5ba10746c370e9 100644 (file)
--- a/tests/regression/tools/Makefile.am
+++ b/tests/regression/tools/Makefile.am
@@ -3,6 +3,7 @@
 SUBDIRS = base-path \
        channel \
        clear \
+       client \
        crash \
        exclusion \
        filtering \

diff --git a/tests/regression/tools/client/Makefile.am b/tests/regression/tools/client/Makefile.am
new file mode 100644 (file)
index 0000000..ee3ee0a
--- /dev/null
+++ b/tests/regression/tools/client/Makefile.am
@@ -0,0 +1,18 @@
+# SPDX-License-Identifier: GPL-2.0-only
+
+noinst_SCRIPTS = test_bug1373_events_differ_only_by_loglevel
+EXTRA_DIST = test_bug1373_events_differ_only_by_loglevel
+
+all-local:
+       @if [ x"$(srcdir)" != x"$(builddir)" ]; then \
+               for script in $(EXTRA_DIST); do \
+                       cp -f $(srcdir)/$$script $(builddir); \
+               done; \
+       fi
+
+clean-local:
+       @if [ x"$(srcdir)" != x"$(builddir)" ]; then \
+               for script in $(EXTRA_DIST); do \
+                       rm -f $(builddir)/$$script; \
+               done; \
+       fi

diff --git a/tests/regression/tools/client/test_bug1373_events_differ_only_by_loglevel b/tests/regression/tools/client/test_bug1373_events_differ_only_by_loglevel
new file mode 100755 (executable)
index 0000000..1508583
--- /dev/null
+++ b/tests/regression/tools/client/test_bug1373_events_differ_only_by_loglevel
@@ -0,0 +1,60 @@
+#!/bin/bash
+#
+# Copyright (C) 2023 Kienan Stewart <kstewart@efficios.com>
+#
+# SPDX-License-Identifier: LGPL-2.1-only
+#
+
+TEST_DESC="lttng-sessiond should not crash when activating rules that different by loglevel only"
+
+CURDIR=$(dirname "$0")
+TESTDIR=$(realpath "${CURDIR}/../../../")
+
+# Test app for ust event
+TESTAPP_PATH="${TESTDIR}/utils/testapp"
+TESTAPP_NAME="gen-ust-events"
+TESTAPP_BIN="${TESTAPP_PATH}/${TESTAPP_NAME}/${TESTAPP_NAME}"
+NR_USEC_WAIT=1
+NR_ITER=100000
+
+SESSION_NAME="test_session"
+CHANNEL_NAME="test_channel"
+EVENT_NAME="'l*'"
+
+OUTPUT_DIR=$(mktemp -d -t tmp.test_events_differ_only_by_loglevels.XXXXXX)
+
+NUM_TESTS=9
+
+# shellcheck source-path=SCRIPTDIR/../../../
+source "${TESTDIR}/utils/utils.sh"
+
+if [ ! -x "${TESTAPP_BIN}" ] ; then
+    BAIL_OUT "No UST events binary detected"
+fi
+
+plan_tests "${NUM_TESTS}"
+print_test_banner "${TEST_DESC}"
+bail_out_if_no_babeltrace
+
+# shellcheck disable=SC2119
+start_lttng_sessiond
+
+"${TESTAPP_BIN}" -i "${NR_ITER}" -w "${NR_USEC_WAIT}" &
+ TESTAPP_PID="${!}"
+
+create_lttng_session_ok "${SESSION_NAME}" "${OUTPUT_DIR}"
+enable_ust_lttng_channel_ok "${SESSION_NAME}" "${CHANNEL_NAME}"
+start_lttng_tracing_ok "${SESSION_NAME}"
+enable_ust_lttng_event_loglevel "${SESSION_NAME}" "${EVENT_NAME}" TRACE_DEBUG_LINE "${CHANNEL_NAME}"
+enable_ust_lttng_event_loglevel_only "${SESSION_NAME}" "${EVENT_NAME}" TRACE_DEBUG_LINE "${CHANNEL_NAME}"
+
+sleep 1
+
+stop_lttng_tracing_ok "${SESSION_NAME}"
+destroy_lttng_session_ok "${SESSION_NAME}"
+
+# shellcheck disable=SC2119
+stop_lttng_sessiond
+
+kill "${TESTAPP_PID}"
+rm -rf "${OUTPUT_DIR}"

diff --git a/tests/utils/utils.sh b/tests/utils/utils.sh
index 949ed131138865dc5c45e28be0e3984e28d110fe..3c6455e2c4d7ae1e0d7026c1d1798ae1c08ca6b4 100644 (file)
--- a/tests/utils/utils.sh
+++ b/tests/utils/utils.sh
@@ -1485,8 +1485,13 @@ function enable_ust_lttng_event_loglevel()
        local sess_name="$1"
        local event_name="$2"
        local loglevel="$3"
+       local channel_name="$4"
+       local chan=()
+       if [ -n "${channel_name}" ] ; then
+               chan=('-c' "${channel_name}")
+       fi
 
-       $TESTDIR/../src/bin/lttng/$LTTNG_BIN enable-event "$event_name" -s $sess_name -u --loglevel $loglevel 1> $OUTPUT_DEST 2> $ERROR_OUTPUT_DEST
+       $TESTDIR/../src/bin/lttng/$LTTNG_BIN enable-event "${chan[@]}" "$event_name" -s $sess_name -u --loglevel $loglevel 1> $OUTPUT_DEST 2> $ERROR_OUTPUT_DEST
        ok $? "Enable event $event_name with loglevel $loglevel"
 }
 
@@ -1495,8 +1500,13 @@ function enable_ust_lttng_event_loglevel_only()
        local sess_name="$1"
        local event_name="$2"
        local loglevel="$3"
+       local channel_name="$4"
+       local chan=()
+       if [ -n "${channel_name}" ] ; then
+               chan=('-c' "${channel_name}")
+       fi
 
-       $TESTDIR/../src/bin/lttng/$LTTNG_BIN enable-event "$event_name" -s $sess_name -u --loglevel-only $loglevel 1> $OUTPUT_DEST 2> $ERROR_OUTPUT_DEST
+       $TESTDIR/../src/bin/lttng/$LTTNG_BIN enable-event "${chan[@]}" "$event_name" -s $sess_name -u --loglevel-only $loglevel 1> $OUTPUT_DEST 2> $ERROR_OUTPUT_DEST
        ok $? "Enable event $event_name with loglevel-only $loglevel"
 }