lttng-tools.git
7 months agoUpdate version to v2.13.13 v2.13.13
Jérémie Galarneau [Fri, 5 Apr 2024 19:10:37 +0000 (15:10 -0400)] 
Update version to v2.13.13

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
7 months agoFix: consumerd: leak of tracing buffers on relayd connectivity issue
Jérémie Galarneau [Thu, 21 Mar 2024 20:55:08 +0000 (16:55 -0400)] 
Fix: consumerd: leak of tracing buffers on relayd connectivity issue

Observed issue
==============

A leak of the tracing buffers can be noticed when the relay daemon is
terminated following the creation of a live session, but prior to the
initiation of any applications.

The issue can be reproduced with the following steps:
  # Create a live session
  $ lttng create --live

  # Kill the relay daemon before the allocation of the buffers
  $ killall lttng-relayd
  $ lttng enable-event --userspace --all
  $ lttng start

  # Launch an instrumented application
  $ ./my_app

  # Destroy all sessions
  $ lttng destroy --all

  # List the open file descriptors of the lttng-consumerd process
  # and notice how the tracing buffer are still visible.
  $ ls -lah /proc/$pid_of_lttng_consumerd/fd

[...]
lrwx------ 1 root root   64 Mar 19 19:50 987 -> '/dev/shm/shm-ust-consumer-358446 (deleted)'
lrwx------ 1 root root   64 Mar 19 19:50 988 -> '/dev/shm/shm-ust-consumer-358446 (deleted)'
lrwx------ 1 root root   64 Mar 19 19:50 989 -> '/dev/shm/shm-ust-consumer-358446 (deleted)'
[...]

Cause
=====

The consumer daemon allocates recording channels and their tracing
buffers in a two-step process.

First, the session daemon emits an `ASK_CHANNEL_CREATION` command, which
results in the allocation of the internal consumer channel structures
and of the actual tracing buffers. The channel's unique key is returned
to the session daemon.

After this command, the channel temporarily holds a list of streams
which are waiting to be sent to the session and relay daemons as a
result of the `GET_CHANNEL` command.

At this moment, the channel's reference count is one over the number of
streams as they all hold a back-reference to their parent channel and
there is a global reference held by the session daemon.

The session daemon uses the key it received to emit the `GET_CHANNEL`
command. When executing this command, the consumer daemon attempts to
send the streams to the relay daemon.

On failure to do so, the session daemon is informed of the connection
error. The consumer daemon then omits a step of the command: the streams
are never handed-off from the channel's internal list to the
consumption/monitoring thread. This hand-off is what is internally
referred-to as making the streams "globally visible".

The session daemon, upon receiving the failure error code of the
GET_CHANNEL command, tears down its internal ust_app channel structures.
As part of that process, it emits the `DESTROY_CHANNEL` command to
reclaim the channel on the consumer daemon's end. This command is
deferred to the channel poll thread as the `CHANNEL_DEL`
internal command.

As part of this internal command, the channel poll thread cleans the
channel's stream list to clean-up any streams that are not "globally
visible": all of them, in our case.

Then, the session daemon's global reference is released which should
normally result in the reclamation of the channel itself.

While reproducing the problem, we noted that channel wasn't reclaimed
and that its reference count matched the number of CPUs on the system at
the time the `CHANNEL_DEL` command completed.

This hinted at the streams holding a reference to the channel even after
the completion of the reclamation command.

Looking at clean_channel_stream_list(), which cleans up the channel's
temporary stream list, we note that the streams' monitor property is
overridden to `false` just before the call to consumer_stream_destroy().

This is strange and a comment (added as part of 212d67a2 in 2014) hints
at a locking problem that was being worked-around. In all likelihood,
this no longer applies as the locking strategies used have evolved quite
a bit since then.

Still, setting the monitor property to `false` is problematic as, in
that mode (say, channels that are used to record a snapshot), streams do
not hold a reference to their parent channel. This causes the clean-up
code to forego the clean-up of the channel, resulting in its leak.

Since the channel ultimately owns the 'stream_fds' which represent the
shared memory files, those files (and associated memory) are also leaked
(they are closed during the execution of lttng_ustconsumer_del_channel()).

Solution
========

We simply remove the stream monitor mode override to leave it in its
appropriate state. The clean-up then proceeds normally, ensuring the
tracing buffers are properly reclaimed.

Known drawbacks
===============

None.

Fixes #1411

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

7 months agoFix: consumerd: wrong timer mentioned in error logging
Jérémie Galarneau [Wed, 15 Mar 2023 20:42:27 +0000 (16:42 -0400)] 
Fix: consumerd: wrong timer mentioned in error logging

As its name indicates, consumer_timer_monitor_stop() stops the _monitor_
timer; not the live timer. This is most likely a copy-paste error.

The error logging is fixed to mention the appropriate timer.

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

7 months agoFix: consumerd: type confusion in lttng_consumer_send_error
Jérémie Galarneau [Tue, 7 Mar 2023 19:38:32 +0000 (14:38 -0500)] 
Fix: consumerd: type confusion in lttng_consumer_send_error

lttng_consumer_send_error sends an lttcomm_return_code to the session
daemon. However, the size of lttcomm_sessiond_command was used.

This was probably missed since the function accepts an integer instead
of a proper enum type.

The size accepted by the function is changed to use lttcomm_return_code
and the size of a fixed-size type is used to send the error code to the
session daemon.

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

7 months agoUpdate version to v2.13.12 v2.13.12
Jérémie Galarneau [Thu, 28 Mar 2024 20:02:31 +0000 (16:02 -0400)] 
Update version to v2.13.12

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
8 months agoFix: baddr-statedump: use $(LIBTOOL) --mode=execute
orbea [Fri, 8 Mar 2024 16:17:37 +0000 (08:17 -0800)] 
Fix: baddr-statedump: use $(LIBTOOL) --mode=execute

GNU libtool inconsistently places the compiled executable in the source
directory or in the .libs directory where a libtool wrapper script is
placed in the source directory.

While slibtool will always place the compiled executable in the .libs
directory and a wrapper script in the source directory.

This will result with a build error when using slibtool since objcopy
needs the executable and not the shell wrapper script, but this can be
solved for both implementations by using $(LIBTOOL) --mode=execute on all
commands that operate on the libtool compiled executables.

Gentoo issue: https://bugs.gentoo.org/858095

The GNU libtool --mode=excute is documented upstream.

https://www.gnu.org/software/libtool/manual/html_node/Execute-mode.html
https://www.gnu.org/software/libtool/manual/html_node/Debugging-executables.html

And the GNU libtool behavior of when to create a wrapper script is
documented in the 'Linking Executables' section.

  "Notice that the executable, hell, was actually created in the .libs
  subdirectory. Then, a wrapper script (or, on certain platforms, a
  wrapper executable see Wrapper executables) was created in the current
  directory.

  Since libtool created a wrapper script, you should use libtool to
  install it and debug it too. However, since the program does not depend
  on any uninstalled libtool library, it is probably usable even without
  the wrapper script."

https://www.gnu.org/software/libtool/manual/html_node/Linking-executables.html

And the inconsistency between GNU libtool and slibtool is documented at
the Gentoo wiki.

  "One difference between GNU libtool and slibtool is that the former will
  conditionally place the compiled executable or a shell wrapper script in
  the build directory, depending on whether or not the executable depends
  on a build-local libtool library (e.g. libfoo.la). Where slibtool will
  always place a compatible wrapper script in the build directory where
  GNU libtool would have conditionally placed the executable. When the
  wrapper script is created both GNU libtool and slibtool will place the
  executable in the .libs directory within the build directory.
  Consequently build systems, ebuilds, and other users should take care to
  avoid scenarios like installing the wrapper script to the system instead
  of the executable. In these cases ideally the executable would be
  installed by the same libtool implementation that compiled it."

https: //wiki.gentoo.org/wiki/Slibtool#Installing_or_using_binaries_created_by_libtool_manually
Signed-off-by: orbea <orbea@riseup.net>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I03102ed78af835daa9b9a5836c2979a5f5d4bd8c

8 months agoFix: relayd: live client not notified of inactive streams
Jérémie Galarneau [Fri, 15 Dec 2023 16:44:34 +0000 (11:44 -0500)] 
Fix: relayd: live client not notified of inactive streams

Observed issue
--------------

Some LTTng-tools live tests failures appear to show babeltrace2
hanging (failing to print expected events). The problem is intermittent,
but Kienan was able to develop a test case that's reproducible for him.

The test case performs the following steps:
  - Start a ust application and leave it running
  - Configure and then start an lttng live session
  - Connect a live viewer (babeltrace)
  - Run a second ust application
  - Wait for the expected number of events
    - In the failing case, no events are seen by babeltrace

Using per-uid buffers, the test typically completes normally. With
per-pid buffers the test fails, hanging indefinitely if waiting for the
specified number of events. While "hanging", babeltrace2 is polling the
relayd.

This affects for babeltrace2 stable-2.0 and master while using
lttng-tools master.

For more information, see the description of bug #1406[1]

Cause
-----

When consuming a live trace captured in per-PID mode, Babeltrace
periodically requests the index of the next packet it should consume.

As part of the reply, it gets a 'flags' field which is used to announce
that new streams, or new metadata, are available to the viewer.
Unfortunately, these 'flags' are only set when the relay daemon has new
tracing data to deliver. It is not set when the relay daemon indicates
that the stream is inactive (see LTTNG_VIEWER_INDEX_INACTIVE).

In the average case where an application is spawned while others are
actively emiting events, a request for new data will result in a reply
that returns an index entry (code LTTNG_VIEWER_INDEX_OK) for an
available packet accompanied by the LTTNG_VIEWER_FLAG_NEW_STREAM flag.

This flag indicates to the viewer that it should request new
streams (using the LTTNG_VIEWER_GET_NEW_STREAMS live protocol command)
before consuming the new data.

In the cases where we observe a hang, an application is running but not
emiting new events. As such, the relay daemon periodically emits "live
beacons" to indicate that the session's streams are inactive up to a
given time 'T'.

Since the existing application remains inactive and the viewer is never
notified that new streams are available, the viewer effectively remains
"stuck" and never notices the new application being traced.

The LTTNG_VIEWER_FLAG_NEW_METADATA communicates a similar semantic with
regards to the metadata. However, ignoring it for inactive streams isn't
as deleterious: the same information is made available to the viewer the
next time it will successfully request a new index to the relay daemon.

This would only become a problem if the tracers start to express
non-layout data (like supplemental environment information, but I don't
see a real use-case) as part of the metadata stream that should be made
available downstream even during periods of inactivity.

Note that the same problem most likely affects the per-UID buffer
allocation mode when multiple users are being traced.

Solution
--------

On the producer end, LTTNG_VIEWER_FLAG_NEW_STREAM is set even when
returning an inactivity index.

Note that to preserve compatibility with older live consumers that don't
expect this flag in non-OK response, the LTTNG_VIEWER_FLAG_NEW_STREAM
notification is repeated until the next LTTNG_VIEWER_GET_NEW_STREAMS
command that returns LTTNG_VIEWER_INDEX_OK.

The 'new_streams' state is no longer cleared from relay sessions during
the processing of the LTTNG_VIEWER_GET_NEXT_INDEX commands. Instead, it
is cleared when the viewer requests new streams.

On Babeltrace's end, the handler of the LTTNG_VIEWER_GET_NEXT_INDEX
command (lttng_live_get_next_index) is modified to expect
LTTNG_VIEWER_FLAG_NEW_STREAM in the cases where the command returns:
  - LTTNG_VIEWER_INDEX_OK (as done previously),
  - LTTNG_VIEWER_INDEX_HUP (new),
  - LTTNG_VIEWER_INDEX_INACTIVE (new).

Drawbacks
---------

This is arguably a protocol change as none of the producers ever set the
NEW_METADATA/NEW_STREAM flags when indicating an inactive stream.

References
----------

[1] https://bugs.lttng.org/issues/1406

Fixes #1406

Change-Id: I84f53f089597ac7b22ce8bd0962d4b28112b7ab6
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
8 months agoFix: relayd: live: dispose of zombie viewer metadata stream
Jérémie Galarneau [Sat, 17 Feb 2024 13:57:47 +0000 (08:57 -0500)] 
Fix: relayd: live: dispose of zombie viewer metadata stream

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

In the CI, builds on SLES15SP5 frequently experience timeouts. From
prior inspections, there are hangs during
tests/regression/tools/clear/test_ust while waiting for babeltrace to
exit.

It is possible to reproduce the problem fairly easily:

  $ lttng create --live
  $ lttng enable-event --userspace --all
  $ lttng start

  # Launch an application that emits a couple of events
  $ ./my_app
  $ lttng stop

  # Clear the data, this eventually results in the deletion of all
  # trace files on the relay daemon's end.
  $ lttng clear

  # Attach to the live session from another terminal
  $ babeltrace -i lttng-live net://...

  # The 'destroy' command completes, but the viewer never exits.
  $ lttng destroy

Cause
=====

After the clear command completes, the relay daemon no longer has any
data to serve. We notice that the live client loops endlessly repeatably
sending GET_METADATA requests. In response, the relay daemon replies
with the NO_NEW_METADATA status.

In concrete terms, the viewer_get_metadata() function short-circuits to
send that reply when it sees that the metadata stream has no active
trace chunk (i.e., there are no backing files from which to read the
data at the moment).

This situation is not abnormal in itself: it is legitimate for a client
to wait for the metadata to become available again. For example, in the
reproducer above, it would be possible for the user to restart the
tracing (lttng start), which would create a new trace chunk and make the
metadata stream available. New events could also be emitted following
this restart.

However, when a session's connection is closed, there is no hope that
the metadata stream will ever transition back to an active trace chunk.

Solution
========

When the metadata stream has no active chunk and the corresponding
consumerd-side connection has been closed, there is no way the relay
daemon will be able to serve the metadata contents to the client.

As such, the viewer stream can be disposed-of since it will no longer be
of any use to the client. Since some client implementations expect at
least one GET_METADATA command to result in NO_NEW_METADATA, that status
code is initially returned.

Later, when the client emits a follow-up GET_METADATA request for that
same stream, it will receive an "error" status indicating that the
stream no longer exists. This situation is not treated as an error by
the clients. For instance, babeltrace2 will simply close the
corresponding trace and indicate it ended.

The 'no_new_metadata_notified' flag doesn't appear to be necessary to
implement the behaviour expected by the clients (seeing at least one
NO_NEW_METADATA status reply for every metadata stream). The
viewer_get_metadata() function is refactored a bit to drop the global
reference to the viewer metadata stream as it exits, while still
returning the NO_NEW_METADATA status code.

Known drawbacks
===============

None.

Note
====

The commit message of e8b269fa provides more details behind the
intention of the 'no_new_metadata_notified' flag.

Change-Id: Ib1b80148d7f214f7aed221d3559e479b69aedd82
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
8 months agotests: Fix typo in tests/regression/kernel/test_ns_contexts
Kienan Stewart [Wed, 20 Dec 2023 15:58:42 +0000 (10:58 -0500)] 
tests: Fix typo in tests/regression/kernel/test_ns_contexts

Change-Id: I50e6027f87b6d4a08a61337782356f8fbc6a64ae
Signed-off-by: Kienan Stewart <kstewart@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
8 months agoFix: sessiond: freeze on channel creation on restart
Jérémie Galarneau [Tue, 12 Dec 2023 21:54:41 +0000 (16:54 -0500)] 
Fix: sessiond: freeze on channel creation on restart

Issue observed
--------------

When using lttng via a script, the session and consumer daemons appear
to completely lock up when we request that a channel be created. The
conditions for this lockup seem to be created by destroying a sessiond
and then creating a sessiond in quick sequence.

This can be reproduced, on some systems, by launching a session daemon
and running the following commands:
  $ sudo killall lttng-sessiond
  $ sudo lttng-sessiond --daemonize
  $ lttng create my_session --snapshot --output /tmp/demo-output
  $ lttng enable-channel --kernel my_channel

Note that 'killall' above is racy as it does not wait for the session
daemon to be killed. Hence, it is not unexpected for the incoming
session daemon to see the smoldering ashes of the "outgoing" session
daemon. However, it would be helpful if the second session daemon
instance warned the user of the existing session daemon instance.

From the logs captured from both instances of the lttng-sessiond (the
outgoing and incoming instances), there appears to be a time period
during which both session daemons are active at once.

This behaviour is unexpected as the session daemon guards itself (in
theory) from running multiple conflicting instances.

The guarding mechanism works in two steps (see the implementation of
`check_existing_daemon` @ src/bin/lttng-sessiond/main.cpp:926)

When a session daemon is launched, it attempts to connect to any active
session daemon's 'client' endpoint (a UNIX socket, the same used by
liblttng-ctl to communicate with the session daemon).

If the daemon receives a reply, it can assume that another session
daemon instance is already active and abort its launch. Conversely, when
no reply is received, it uses a "lock file" mechanism to check for other
running instances.

The lock file-based check creates a file (typically
/var/run/lttng/lttng-sessiond.lck in the case of a root session daemon)
and acquires an exclusive (write) POSIX lock on it [1]. The assumption
is that any other instance would own the lock and cause the operation to
fail.

On a reproducer system, we could notice that the client thread of the
outgoing sessiond daemon was torn down before the launch of the
initialization of the incoming session daemon. This caused the incoming
session daemon to not receive a reply to its connection attempt and
fall-back to the lock file-based mechanism.

Surprinsingly, it appears that the lock file checks succeeds even though
the outgoing session daemon still holds the lock file according to its
log.

See the original bug report for more information about the investigation
and how to reproduce the problem.

Cause
-----

The POSIX file locking API has a number of surprising behaviours[2] that
have seen it being superseded by platform-specific APIs. In our case,
the one that bit us is that any file lock held by a process is
automatically released when any of the file descriptors that reference
the file's description is released.

In practical terms, if a process forks and its child dies, it loses its
file lock since the child's file descriptors are closed on exit.

The LWN article linked below describes a similar scenario:

  It's common to have a library routine that opens a file, reads or
  writes to it, and then closes it again, without the calling
  application ever being aware that has occurred. If the application
  happens to be holding a lock on the file when that occurs, it can lose
  that lock without ever being aware of it.

The problem affects any use of the --background/--daemonize options
since, as part of the daemonization process (which occurs after the lock
file acquisition), the session daemon forks and its parent process
exits. This causes one of the descriptors pointing to the lock file to
be closed and the lock to be released.

After that point, any other instance of the session daemon process would
succeed in acquiring the lock file and assume it is the sole instance on
the system.

Solution
--------

The lock file code is modified to use the non-POSIX `flock`[3]
interface which is available on Linux and some BSDs[4]. `flock` provides
us with the guarantee we thought we had: that the file lock is only
released when _all_ file descriptors pointing to a given file
description are closed.

Drawbacks
---------

As a fallback, platforms that don't support `flock` will use the original
locking mechanism. Since this is a "hint" to warn users when erroneously
launch a second privileged session daemon, it seems acceptable for it
to not be completely reliable on secondary platforms.

References
----------

[1] https://man7.org/linux/man-pages/man2/fcntl.2.html (see F_SETLK)
[2] https://lwn.net/Articles/586904/
[3] https://linux.die.net/man/2/flock
[4] https://man.freebsd.org/cgi/man.cgi?query=flock&sektion=2

Fixes #1405

Reported-by: Erica Bugden <ebugden@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: Ic505ff0671c321f808050831ef2b7152cdbf4b8a

8 months agocommon: move utils_create_lock_file to its own file
Jérémie Galarneau [Tue, 12 Dec 2023 21:13:59 +0000 (16:13 -0500)] 
common: move utils_create_lock_file to its own file

A follow-up change introduces platform-specific implementations of this
functions. Moving the function to a separate file makes it possible to
add other implementations without polluting utils.c with more
platform-specific code.

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

8 months agotests: tools/clear/test_ust wait for specific test app pid
Kienan Stewart [Tue, 19 Dec 2023 19:01:47 +0000 (14:01 -0500)] 
tests: tools/clear/test_ust wait for specific test app pid

Observed issue
==============

When debugging failing tests manually, one step that is sometimes done
is to quickly swap the commands that start the relay or sessiond in
`tests/utils/utils.sh` (eg. in `start_lttng_relayd_opt`) for the version
which uses a verbose output to a logfile.

When doing this, the `relayd` wasn't using the background
`process_mode`, and was a child of the running test.

This caused `test_ust_local_snapshot_per_pid` in
`tests/regression/tools/clear/test_ust` to hang as it waited for all
child processes to terminate.

Solution
========

The test has been updated to wait for only the specific test application
pid.

Known drawbacks
===============

None.

Change-Id: I8761649a52fceda92a5545c71818dc2eb027bfcf
Signed-off-by: Kienan Stewart <kstewart@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
11 months agoFix: sessiond: crash when sending data_pending to an active session
Kienan Stewart [Thu, 13 Jul 2023 19:13:12 +0000 (15:13 -0400)] 
Fix: sessiond: crash when sending data_pending to an active session

Observed Issue
==============

When a data_pending command is sent to an active session, the sessiond
crashes with the following assert

```
lttng-sessiond: client.cpp:2647: void* thread_manage_clients(void*): Assertion `cmd_ctx.reply_payload.buffer.size >= sizeof(*llm)' failed.
Error: 1 trace chunks are leaked by lttng-consumerd. This can be caused by an internal error of the session daemon.
```

Cause
=====

When a session is active, cmd.cpp:cmd_data_pending() returns
LTTNG_ERR_SESSION_STARTED. In client.cpp:process_client_msg(), this
return value causes the execution to go the the setup_error label. In
the setup_error label, no default LLM header is added to the reply,
meaning the reply has a zero size and triggering the assert above.

Solution
========

When cmd_data_pending() returns a value that is neither 0 nor 1, the
return code is set appropriately as follows:

  * when the return value is outside the range of lttng error codes,
  LTTNG_ERR_UNK is used
  * otherwise, the return value is used

The execution then jumps to the error label so that the default LLM
message header can be added.

Known Drawbacks
===============

None.

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

14 months agoTests: fix: list_triggers_cli: kallsyms contains prefixed symbols
Jérémie Galarneau [Thu, 13 Apr 2023 19:50:57 +0000 (15:50 -0400)] 
Tests: fix: list_triggers_cli: kallsyms contains prefixed symbols

The test_list_triggers_cli test fails with:

  # Listing event-rule-matches kernel probe
  ./tests/regression/tools/trigger/test_list_triggers_cli: line 808: [[: 0xffffffffc1fca020
  ffffffffc1fca030: syntax error in expression (error token is "ffffffffc1fca030")
  ./tests/regression/tools/trigger/test_list_triggers_cli: line 813: 0xffffffffc1fca020
  ffffffffc1fca030 - 0xffffffffc1fca0c0
  ffffffffc1fca0b0 : syntax error in expression (error token is "ffffffffc1fca030 - 0xffffffffc1fca0c0
  ffffffffc1fca0b0 ")

This is due to the fact that /proc/kallsyms now contains prefixed
symbols (e.g. `__pfx_lttng_channel_enable`) which cause the test to fail
since the grep invocation doesn't expect more than one match.

Matching the begin/end of the "word" (or rather, function name) allows
us to check for exact matches only.

https://github.com/torvalds/linux/commit/9f2899fe36a623885d8576604cb582328ad32b3c

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

15 months agoLicense: common: error_query: fix typo in SPDX specifier
Jérémie Galarneau [Thu, 24 Aug 2023 17:33:44 +0000 (13:33 -0400)] 
License: common: error_query: fix typo in SPDX specifier

The error-query API files were erroneously licensed under "GPL-2.1", a
license which doesn't exist.

As the author of those files, I hereby confirm that the intention was to
license these files under LGPL-2.1 as evidenced by their presence in the
libcommon_lgpl internal library.

Reported-by: Christophe Bedard <christophe.bedard@apex.ai>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I0d56372ca009e44732e0737bd8f10ad4a4d000c5

15 months agoUpdate version to v2.13.11 v2.13.11
Jérémie Galarneau [Mon, 21 Aug 2023 18:32:07 +0000 (14:32 -0400)] 
Update version to v2.13.11

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
15 months agoTests: use CPU ids from online ranges
Kienan Stewart [Tue, 15 Aug 2023 15:50:16 +0000 (11:50 -0400)] 
Tests: use CPU ids from online ranges

test_tracefile_count could fail randomly on systems where there are CPUs
present but not online. For example:

  $ cat /sys/devices/system/cpu/online
  0-7
  $ cat /sys/devices/system/cpu/present
  0-39

When a CPU is present, it will have an entry in
/sys/devices/system/cpu/cpuX for it's ID, and thus the test may pick
that CPU's ID. However, a present CPU which is not online is not a valid
target for taskset.

In cases where `get_any_available_cpu` is used with task set, the tests
could fail for a similar reason. This case can be somewhat less common,
because it would return the numerically lowest CPU first; however, with
online as follows cpu 0 isn't available and taskset fails.

  $ cat /sys/devices/system/cpu/online
  18-19,135,142
  $ cat /sys/devices/system/cpu/present
  0-167

Change-Id: I06ac2e67495552f54765794b154acc9e8e9990ec
Signed-off-by: Kienan Stewart <kstewart@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
15 months agodocs: fix: Match stated automake requirement
Erica Bugden [Mon, 14 Aug 2023 20:31:36 +0000 (16:31 -0400)] 
docs: fix: Match stated automake requirement

to the applied requirement. Previously, the README stated the minimum
required version of automake was 1.10. However, since commit 343a7a984
(Require automake >= 1.12), the configuration script (configure.ac)
actually enforced a minimum of 1.12:

AM_INIT_AUTOMAKE([1.12 foreign dist-bzip2 no-dist-gzip tar-pax ...

Change-Id: I5056e3a4098418c2537d56830ef1e1808db14d8b
Signed-off-by: Erica Bugden <ebugden@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
15 months agoDocs: Fix broken reference in lttng-add-trigger
Kienan Stewart [Thu, 29 Jun 2023 14:32:59 +0000 (10:32 -0400)] 
Docs: Fix broken reference in lttng-add-trigger

Change-Id: I4068570d188fbf75e402898234944b6e21cfa2a1
Signed-off-by: Kienan Stewart <kstewart@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
15 months agoDocs: Fix broken reference to lttng-concepts(7) man page
Kienan Stewart [Thu, 6 Jul 2023 20:20:24 +0000 (16:20 -0400)] 
Docs: Fix broken reference to lttng-concepts(7) man page

Change-Id: Iaa700e06ec98a3a451f10b4e287c7b28e6ff4524
Signed-off-by: Kienan Stewart <kstewart@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
15 months agoTests: Preemptively fail infinite blocking tests when low on disk space
Kienan Stewart [Wed, 21 Jun 2023 13:39:06 +0000 (09:39 -0400)] 
Tests: Preemptively fail infinite blocking tests when low on disk space

In the system tests run by LAVA, the infinite blocking tests were
hanging when the system under test ran out of disk space. This is the
expected behaviour of the failing test, but the condition can be
detected and the tests preemptively failed with a clear error of what
needs to be addressed in the system being tested.

Change-Id: I9e6126408b57c2cd5aa64c2e360e0672f9eb2314
Signed-off-by: Kienan Stewart <kstewart@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
15 months agoFix: lttng-add-context: leak of application context parameters
Jérémie Galarneau [Thu, 27 Jul 2023 18:59:40 +0000 (14:59 -0400)] 
Fix: lttng-add-context: leak of application context parameters

This commit backports 37d11aa60 and ca400a290, see their respective
messages.

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

15 months agoFix: sessiond: bad fd used while rotating exiting app's buffers
Jérémie Galarneau [Wed, 17 May 2023 17:41:03 +0000 (13:41 -0400)] 
Fix: sessiond: bad fd used while rotating exiting app's buffers

Issue observed
--------------

From bug #1372:

We are observing seemingly random crashes in the LTTng consumer daemon
when tracing a C++ application with LTTng-UST. Our workload has a single
printf-like tracepoint, where each string is in the order of 1kb and the
total output is around 30MB/s.

LTTng is set up with a single session and channel enabling this
tracepoint, and we enabled rotation with a maximum size of 100MB or
every 30 seconds. We are periodically starting new traced processes and
the system runs close to 100% CPU load. This ran on an AWS
Graviton2 (ARM) instance with CentOS 7 and a 5.4 kernel, using LTTng-UST
2.13.5 and LTTng-tools 2.13.8.

The first reported error is a write to a bad file descriptor (-1),
apparently when waking up the metadata poll thread during a rotation.

Cause
-----

Inspecting the logs, we see that the metadata channel with key 574 has a
negative poll fd write end which causes the write in
consumer_metadata_wakeup_pipe to fail because of an invalid file
descriptor:

  DBG1 - 15:12:13.271001175 [6593/6605]: Waking up metadata poll thread (writing to pipe): channel name = 'metadata', channel key = 574 (in consumer_metadata_wakeup_pipe() at consumer.c:888)
  DBG3 - 15:12:13.271010093 [6593/6605]: write() fd = -1 (in consumer_metadata_wakeup_pipe() at consumer.c:892)
  PERROR - 15:12:13.271014655 [6593/6605]: Failed to write to UST metadata pipe while attempting to wake-up the metadata poll thread: Bad file descriptor (in consumer_metadata_wakeup_pipe() at consumer.c:907)
  Error: Failed to dump the metadata cache
  Error: Rotate channel failed

Meanwhile, a lot of applications seem to be unregistering. Notably, the
application associated with that metadata channel is being torn down.

Leading up to the use of a bad file descriptor, the chain of events is:

1) The "rotation" thread starts to issue "Consumer rotate channel" on
   key 574 (@ `15:12:12.865621802`), but blocks on the consumer socket
   lock. We can deduce this from the fact that thread "6605" in the
   consumer wakes up to process an unrelated command originating from the
   same socket.

   We don't see that command being issued by the session daemon, most
   likely because it occurs just before the captured logs start. All
   call sites that use this socket take the socket lock, issue their
   command, wait for a reply, and release the socket lock.

2) The application unregisters (@ `15:12:13.269722736`). The
   `registry_session`, which owns the metadata contents, is destroyed
   during `delete_ust_app_session` which is done directly as a consequence
   of the app unregistration (through a deferred RCU call), see
   `ust_app_unregister`.

   This is problematic since the consumer will request the metadata during
   the rotation of the metadata channel. In the logs, we can see that
   the "close_metadata" command blocks on the consumer socket lock.
   However, the problem occurs when the `manage-apps` acquires the lock
   before the "rotation" thread. In this instance, the "close-metadata"
   command is performed by the consumer daemon, closing the metadata
   poll file descriptor.

3) As the "close_metadata" command completes, the rotation thread
   successfully acquires the socket lock. It is not aware of the
   unregistration of the application and of the subsequent tear-down of the
   application, registry, and channels since it was already iterating on
   the application's channels.

   The consumer starts to process the channel rotation command (@
   `15:12:13.270633213`) which fails on the metadata poll fd.

Essentially, we must ensure that the lifetime of metadata
channel/streams exceeds any ongoing rotation, and prevent a rotation
from being launched when an application is being torn-down in per-PID
buffering mode.

The problem is fairly hard to reproduce as it requires threads to
wake-up in the problematic order described above. I don't have a
straight-forward reproducer for the moment.

Solution
--------

During the execution of a rotation on a per-pid session, the session
daemon iterates on all applications to rotate their data and metadata
channels.

The `ust_app` itself is correctly protected: it is owned by an RCU HT
(`ust_app_ht`) and the RCU read lock is acquired as required to protect
the lifetime of the storage of `ust_app`. However, there is no way to
lock an `ust_app` instance itself.

The rotation command assumes that if it finds the `ust_app`, it will be
able to rotate all of its channels. This isn't true: the `ust_app` can
be unregistered by the `manage-applications` thread which monitors the
application sockets for their deaths in order to teardown the
applications.

The `ust_app` doesn't directly own its channels; they are owned by an
`ust_app_session` which, itself, has a `lock` mutex. Also, the metadata
of the application is owned by the "session registry", which itself can
also be locked.

At a high-level, we want to ensure that the metadata isn't closed while
a rotation is being setup. The registry lock could provide this
guarantee. However, it currently needs to remain unlocked during the
setup of the rotation as it is used when providing the metadata to the
consumer daemon.

Taking the registry lock over the duration of the setup would result in
a deadlock like so:

- the consumer buffer consumption thread consumed a data buffer and attempts
  a metadata sync,
- the command handling thread of the consumer daemon attempts to rotate
  any stream that is already at its rotation position and locks on the
  channel lock held by the consumption thread,
- the metadata sync launches a metadata request against the session
  daemon which attempts to refresh the metadata contents through the
  command socket,
- the command handling thread never services the metadata "refresh" sent
  by the session daemon since it is locked against the same channel as
  the buffer consumption thread, resulting in a deadlock.

Instead, a different approach is required: extending the lifetime of the
application's channels over the duration of the setup of a rotation.

To do so, the `ust_app` structure (which represents a registered
application) is now reference-counted. A reference is acquired over the
duration of the rotation's setup phase. This reference transitively
holds a reference the application's tracing buffers.

Note that taking a reference doesn't prevent applications from
unregistering; it simply defers the reclamation of their buffers to the
end of the rotation setup.

As the rotation completes its setup phase, the references to the
application (and thus, its tracing buffers) are released, allowing the
reclamation of all buffering ressources.

Note that the setup phase of the rotation doesn't last long so it
shouldn't significantly change the observable behaviour in terms of
memory usage. The setup phase mostly consists in sampling the
consumption/production positions of all buffers in order to establish a
switch-over point between the old and new files.

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

15 months agoFix: consumerd: slow metadata push slows down application registration
Jérémie Galarneau [Thu, 29 Jun 2023 18:04:37 +0000 (14:04 -0400)] 
Fix: consumerd: slow metadata push slows down application registration

Issue observed
--------------

When rotating the channels of a session configured with a "per-pid"
buffer sharing policy, applications with a long registration
timeout (e.g. LTTNG_UST_REGISTER_TIMEOUT=-1, see LTTNG-UST(3)) sometimes
experience long start-up times.

Cause
-----

The session list lock is held during the registration of an application
and during the setup of a rotation.

While setting up a rotation in the userspace domain, the session daemon
flushes its metadata cache to the userspace consumer daemon and waits
for a confirmation that all metadata emitted before that point in time
has been serialized (whether on disk or sent through a network output).

As the consumer daemon waits for the metadata to be consumed, it
periodically checks the metadata stream's output position with a 200ms
delay (see DEFAULT_METADATA_AVAILABILITY_WAIT_TIME).

In practice, in per-uid mode, this delay is seldomly encountered since
the metadata has already been pushed by the consumption thread.
Moreover, if it was not, a single polling iteration will typically
suffice.

However, in per-pid buffering mode and with a sustained "heavy" data
production rate, this delay becomes problematic since:
  - metadata is pushed for every application,
  - the delay is hit almost systematically as the consumption thread
    is busy and has to catch up to consume the most recent metadata.

Hence, some rotation setups can easily take multiple seconds (at least
200ms per application). This makes the locking scheme employed on that
path unsuitable as it blocks some operations (like application
registrations) for an extended period of time.

Solution
--------

The polling "back-off" delay is eliminated by using a waiter that allows
the consumer daemon thread that runs the metadata push command to
wake-up whenever the criteria used to evaluate the "pushed" metadata
position are changed.

Those criteria are:
  - the metadata stream's pushed position
  - the lifetime of the metadata channel's stream
  - the status of the session's endpoint

Whenever those states are affected, the waiters are woken-up to force a
re-evaluation of the metadata cache flush position and, eventually,
cause the metadata push command to complete.

Note
----

The waiter queue is adapted from urcu-wait.h of liburcu (also LGPL
licensed).

Change-Id: Ib86c2e878abe205c73f930e6de958c0b10486a37
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
16 months agoevent-rule: set event rule loglevel to domain specific value when unset
Jérémie Galarneau [Fri, 14 Jul 2023 21:26:26 +0000 (17:26 -0400)] 
event-rule: set event rule loglevel to domain specific value when unset

The various domains that support log levels define different values for
ALL/UNSET that are not -1. Using these domain values makes reasoning
about the code simpler as -1 does not necessarily have a defined meaning
in all domains.

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

16 months agoFix: sessiond: preserve jul/log4j domain loglevels
Kienan Stewart [Wed, 28 Jun 2023 15:28:55 +0000 (11:28 -0400)] 
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

16 months agoFix: sessiond: crash enabling event rules that differ only by loglevel type
Jérémie Galarneau [Mon, 17 Jul 2023 19:48:51 +0000 (15:48 -0400)] 
Fix: sessiond: crash enabling event rules that differ only by loglevel type

Issue observed
--------------

Summarizing bug #1373, an assertion fails when enabling two event-rules
that only differ by their log level selection type (all, range, or
single).

This issue can be reproduced by launching an instrumented
application (which remains active over the duration of this test) and
running:
  $ lttng create test_session
  $ lttng enable-channel --userspace test_channel
  $ lttng start test_session
  $ lttng enable-event --userspace --session test_session --channel test_channel 'l*' --loglevel-only=TRACE_DEBUG_LINE
  $ lttng enable-event --userspace --session test_session --channel test_channel 'l*' --loglevel=TRACE_DEBUG_LINE

Cause
-----

A number of sites conflate log level values and type. A clean-up had
been performed previously as of 2106efa08 and through follow-up commits.
However, some instances were apparently missed at the time.

As such, add_unique_ust_app_event mixed loglevel values and types when
initializing the key used for the unique insertion. The log level type,
for its part, is completely ignored.

Going back to the reproducer above, the first insertion succeeds as
expected. The second insertion fails since there is already an app event
rule with the `TRACE_DEBUG_LINE` log level type.

Moreover, the matching function only matches on the log level
type (which is really the value), which is also a bug.

The "matching" function is invoked on the key of the second event rule
and the first event rule since the hashing is only performed on the
event-rule's name pattern, resulting in a collision.

Solution
--------

Both the log level value and log level types are used to perform the
matching within the ust-app module. This implies extending the
ust_app_ht_key to store the log level value.

To simplify the matching logic (which attempted to handle 0 and -1
having the same meaning when the "ALL" log level type was used), the log
level value is normalized to '-1' throughout.

Fixes #1373
Reported-by: Bogdan Codres <bogdan.codres@windriver.com>
Change-Id: Id8090156646e4ef2011738623e0bfee1f400dced
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
17 months agoUpdate version to v2.13.10 v2.13.10
Jérémie Galarneau [Tue, 20 Jun 2023 19:06:38 +0000 (15:06 -0400)] 
Update version to v2.13.10

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
17 months agoFix: sessiond: incorrect use of exclusions array leads to crash
Jérémie Galarneau [Tue, 23 May 2023 23:35:10 +0000 (19:35 -0400)] 
Fix: sessiond: incorrect use of exclusions array leads to crash

Issue observed
--------------

When using the CLI to list the configuration of a session that has an
event rule which makes use of multiple exclusions, the session daemon
crashes with the following stack trace:

  (gdb) bt
  #0  0x00007fa9ed401445 in ?? () from /usr/lib/libc.so.6
  #1  0x0000560cd5fc5199 in lttng_strnlen (str=0x615f6f6c6c6568 <error: Cannot access memory at address 0x615f6f6c6c6568>, max=256) at ../../src/common/compat/string.h:19
  #2  0x0000560cd5fc6b39 in lttng_event_serialize (event=0x7fa9cc01d8b0, exclusion_count=2, exclusion_list=0x7fa9cc011794, filter_expression=0x0, bytecode_len=0, bytecode=0x0, payload=0x7fa9d3ffda88) at event.c:767
  #3  0x0000560cd5f380b5 in list_lttng_ust_global_events (nb_events=<synthetic pointer>, reply_payload=0x7fa9d3ffda88, ust_global=<optimized out>, channel_name=<optimized out>) at cmd.c:472
  #4  cmd_list_events (domain=<optimized out>, session=<optimized out>, channel_name=<optimized out>, reply_payload=0x7fa9d3ffda88) at cmd.c:3860
  #5  0x0000560cd5f6d76a in process_client_msg (cmd_ctx=0x7fa9d3ffa710, sock=0x7fa9d3ffa5b0, sock_error=0x7fa9d3ffa5b4) at client.c:1890
  #6  0x0000560cd5f6f876 in thread_manage_clients (data=0x560cd7879490) at client.c:2629
  #7  0x0000560cd5f65a54 in launch_thread (data=0x560cd7879500) at thread.c:66
  #8  0x00007fa9ed32d44b in ?? () from /usr/lib/libc.so.6
  #9  0x00007fa9ed3b0e40 in ?? () from /usr/lib/libc.so.6

Cause
-----

lttng_event_serialize expects a `char **` list of exclusion names, as
provided by the other callsite in liblttng-ctl. However, the callsite in
list_lttng_ust_global_events passes pointer to the exclusions as stored
in lttng_event_exclusion.

lttng_event_exclusion contains an array of fixed-length strings (with a
stride of 256 bytes) which isn't an expected layout for
lttng_event_serialize.

Solution
--------

A temporary array of pointers is constructed before invoking
lttng_event_serialize to construct a list of exclusions with the layout
that lttng_event_serialize expects.

The array itself is reused for all events, limiting the number of
allocations.

Note
----

None.

Change-Id: I266a1cc9e9f18e0476177a0047b1d8f468110575
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
17 months agoTests fix: test_callstack: output of addr2line incorrectly parsed
Jérémie Galarneau [Thu, 25 May 2023 23:15:20 +0000 (19:15 -0400)] 
Tests fix: test_callstack: output of addr2line incorrectly parsed

Issue observed
--------------

The test_callstack test fails with GCC 13.1 with the following output:

  Traceback (most recent call last):
  File "/usr/lib/lttng-tools/ptest/tests/regression/././kernel//../../utils/parse-callstack.py", line 160, in <module>
  main()
  File "/usr/lib/lttng-tools/ptest/tests/regression/././kernel//../../utils/parse-callstack.py", line 155, in main
  raise Exception('Expected function name not found in recorded callstack')
  Exception: Expected function name not found in recorded callstack
  ok 10 - Destroy session callstack
  PASS: kernel/test_callstack 10 - Destroy session callstack
  not ok 11 - Validate userspace callstack
  FAIL: kernel/test_callstack 11 - Validate userspace callstack

Cause
-----

parse-callstack.py uses 'split()' to split the lines of addr2line's
output. By default, 'split()' splits a string on any whitespace.
Typically this was fine as addr2line's output doesn't contain spaces and
the function then splits on new lines.

Typical output of addr2line:

  $ addr2line -e ./tests/regression/kernel//../../utils/testapp/gen-syscall-events-callstack/gen-syscall-events-callstack --functions --addresses 0x40124B
  0x000000000040124b
  my_gettid
  /tmp/test-callstack-master/src/lttng-tools/tests/utils/testapp/gen-syscall-events-callstack/gen-syscall-events-callstack.c:40

However, with the test app compiled using gcc 13.1, a "discriminator"
annotation is present:

  0x0000000000401279
  fct_b
  /tmp/test-callstack-master/src/lttng-tools/tests/utils/testapp/gen-syscall-events-callstack/gen-syscall-events-callstack.c:58 (discriminator 1)

Hence, by selecting the second to last element (-2, with negative
indexing), the addr2line function returns '(discriminator' as the
function name.

Solution
--------

The parsing code is changed to simply iterate on groups of 3 lines,
following addr2line's output format.

Fixes #1377

Change-Id: I8c1eab97e84ca7cad171904bed6660540061cf08
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
17 months agoFix: sessiond: silent kernel notifier registration error
Jérémie Galarneau [Fri, 14 Apr 2023 18:39:05 +0000 (14:39 -0400)] 
Fix: sessiond: silent kernel notifier registration error

When a kernel notifier fails to be registered, the error is silently
ignored because of a missing jump to the error label.

This was noticed while debugging an unrelated problem where the kernel
tracer would fail to add a userspace probe to a semaphore-protected SDT
probe.

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

17 months agoFix: sessiond: size-based notification occasionally not triggered
Jérémie Galarneau [Tue, 4 Apr 2023 15:03:03 +0000 (11:03 -0400)] 
Fix: sessiond: size-based notification occasionally not triggered

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

When tracing to multiple sessions with scheduled size-based rotations
that occur simultaneously (typically because they trace the same events
and use the same rotation schedule configuration), the start of some
rotations seems to be delayed indefinitely.

Cause
=====

The size-based rotations are implemented by piggy-backing onto the
channel monitoring facilities.

Essentially, a per-channel timer samples a number of statistics on the
consumer daemon end, which transmits them to the session daemon.

The session daemon's notification subsystem evaluates the statistics
against the various registered triggers bound to the channels being
monitored when a statistics sample is received.

To implement size-based rotations, internal triggers are registered with
the "consumed size" condition set to a given threshold. A session
rotation management thread (which also performs other tasks) uses a
notification channel to wait for sessions to reach their target size,
starts rotations as needed, and sets a new threshold according to the
sessions' configured rotation schedule.

The rotation thread uses liblttng-ctl's API to consume notifications
from a notification channel.

At any time, a notification channel may have multiple notifications
queued-up internally in its buffers. This is because a notification
channel multiplexes command replies and notifications over the same UNIX
socket. The current protocol specifies that multiple notifications can
be received before the reply to a command.

In such cases, the notification channel client implementation internally
queues them and provides them on the next calls to
lttng_notification_channel_get_next_notification().

This is correct with respect to the public API, which is intended to be
used in "blocking mode". However, this internal user uses the
notification channel's raw file descriptor to wake-up when a
notification is available.

This is problematic because notifications may be queued by the
notification channel (and thus removed from the socket) while waiting
for command replies (subscribing and unsubscribing from notification
conditions). In such a case, a notification is available but the
rotation thread does not wake-up to consume it as nothing is available
in the socket's buffer.

When this happens, a session that is supposed to rotate automatically
appears to grow indefinitely. It will typically eventually rotate as new
notifications become available and cause the rotation thread to wake-up.
However, a "lag" builds up as the notification that caused the wake-up
is not consumed. Instead, the last buffered notification is provided to
the rotation thread.

Solution
========

Use an event_fd to wake-up the rotation thread whenever a command
completes on the notification channel. This ensures that any
notification that was queued while waiting for a reply to the command is
eventually consumed.

Known drawbacks
===============

None.

Note
====

The use of C++ features is kept to a minimum in this patch in order to
make it easier to backport to the stable releases. A clean-up patch
follows and makes the code conform to the coding standards.

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

17 months agoFix: adding a user space probe fails on thumb functions
Olivier Dion [Wed, 22 Feb 2023 20:19:14 +0000 (15:19 -0500)] 
Fix: adding a user space probe fails on thumb functions

On some architectures, calling convention details are embedded in the
symbol addresses. Uprobe requires a "clean" symbol offset (or at least,
an address where an instruction boundary would be legal) to add
instrumentation. sanitize_uprobe_offset implements that sanitization
logic on a per-architecture basis.

The least significant bit is used when branching to switch to thumb ISA.
However, it's an invalid address for us; mask the least significant bit.

We were not masking the thumb bit, thus using the wrong address offset
by one.

Change-Id: Iaff8ccea3a319f9d9ad80501f1beccd74d1ef56d
Signed-off-by: Olivier Dion <odion@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
17 months agoFix: Tests that assume CPU 0 is present
Olivier Dion [Thu, 16 Feb 2023 20:34:26 +0000 (15:34 -0500)] 
Fix: Tests that assume CPU 0 is present

Add util_event_generator.sh to shellcheck test while at it.

Change-Id: I261452496827a5b9fc08b39a1132b13a39d0a7f5
Signed-off-by: Olivier Dion <odion@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
17 months agoFix: Wrong assumption about possible CPUs
Olivier Dion [Tue, 14 Feb 2023 19:35:34 +0000 (14:35 -0500)] 
Fix: Wrong assumption about possible CPUs

cpuset is not necessary contiguous.  Thus, we need to parse
/sys/devices/system/cpu/posssible correctly.

Also, the `get_exposed_cpus_list' utility functions is required for
taskset-ting on the correct CPUs available to the test environment.

Change-Id: I062ce8d311ff0e8c4b757fe6f36387e3007cfa27
Signed-off-by: Olivier Dion <odion@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
17 months agoTests: fix: parse-callback reports missing addr2line
Olivier Dion [Fri, 10 Mar 2023 18:17:46 +0000 (13:17 -0500)] 
Tests: fix: parse-callback reports missing addr2line

addr2line from binutils is required for this script to work correctly.
However, it silently fails. Fix this by using `subprocess.run' with
`check=True' instead of `subprocess.getoutput'. That way, an exception
is raised if an error occurs.

Fix the shebang by not assuming where python is installed while at it.

Change-Id: I5157b3dbccf6bfbe08a6b6840b38f5db9010fe96
Signed-off-by: Olivier Dion <odion@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
17 months agoFix: lttng remove-trigger -h fails
Olivier Dion [Wed, 22 Feb 2023 21:45:27 +0000 (16:45 -0500)] 
Fix: lttng remove-trigger -h fails

The error was that `argv' was incremented before passing it to
`argpar_iter_create'. However, the macro `SHOW_HELP' implicitly
deferences `argv[0]' to determine the command name.

Fix this by introducing a new variable `args' leaving `argv' untouched.

Change-Id: Id50fa2424550280a1e5e207429d643f5e8e00396
Signed-off-by: Olivier Dion <odion@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
17 months agoTests: snapshot tests complain that nothing is output
Jérémie Galarneau [Mon, 13 Feb 2023 20:43:18 +0000 (15:43 -0500)] 
Tests: snapshot tests complain that nothing is output

The user space snapshot tests invoke a common script that runs the
actual tests. In doing so, the parent script's tap generator isn't
involved in the production of the tests' tap output and outputs an error
message as diagnostic.

  ok 134 - Wait after kill session daemon
  # Looks like your test died before it could output anything.

`exec`-ing the common script sidesteps the problem by replacing the
shell entirely.

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

17 months agoTests: Test snapshot maximum size correctly
Olivier Dion [Wed, 1 Feb 2023 22:11:02 +0000 (17:11 -0500)] 
Tests: Test snapshot maximum size correctly

The minimum size for a channel is determined by:

  sub-buffer-size * sub-buffer-count * possible-cpus

where sub-buffer-size is the system page size and sub-buffer-count is 2.

We set a snapshot with a maximum size of the minimum size. From there,
we need to spam that amount of events, assuming each event to be one
byte, on every online CPUs. We can then ensure that the total snapshot's
size is equal to the minimum size for a channel. However, there's a
little bias if the number of possible cores is greater than the number
of online cores. In that case, the bias is one sub-buffer for each extra
ring buffer.

Change-Id: I4718e134684463789b4f7be9b12c9bf3d6cfec20
Signed-off-by: Olivier Dion <odion@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
17 months agoTests: Add get_possible_cpus_count utility
Olivier Dion [Wed, 1 Feb 2023 21:04:14 +0000 (16:04 -0500)] 
Tests: Add get_possible_cpus_count utility

lttng-ust uses the possible number of CPUs to allocate its ring buffers.
Certain tests have to take that into consideration in their calculation
instead of relying on online processors.

Thus, add the same logic for calculating the possible CPUs on the
system.

Change-Id: I9f14afba3e4adad9547cbd9386f8e1b1b55a3253
Signed-off-by: Olivier Dion <odion@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
17 months agoFix: ini parser: truncation of value name
Jérémie Galarneau [Mon, 16 Jan 2023 19:19:20 +0000 (14:19 -0500)] 
Fix: ini parser: truncation of value name

clang 14 reports the following:

  ini-config/ini.cpp:88:16: warning: 'char* strncpy(char*, const char*, size_t)' output may be truncated copying 49 bytes from a string of length 199 [-Wstringop-truncation]
     88 |         strncpy(dest, src, size - 1);
        |         ~~~~~~~^~~~~~~~~~~~~~~~~~~~~

Indeed, a silent truncation of `name` occurs whenever it is longer than
prev_name (49 characters, excluding the terminator).

Report an error when this condition occurs.

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

19 months agoFix: truncated len in lttng_event_rule_user_tracepoint_serialize()
Michael Jeanson [Thu, 23 Mar 2023 16:45:18 +0000 (12:45 -0400)] 
Fix: truncated len in lttng_event_rule_user_tracepoint_serialize()

Observed issue
==============

On 64-bit big-endian platforms, the serialization/deserialization tests
of tracepoint event rules fail since the length of individual exclusions
is truncated in lttng_event_rule_user_tracepoint_serialize and appear as
"0" on the receiving end.

Cause
=====

The length of the exclusion name string is stored in a variable of type
`size_t`. However, since the protocol expects it to be expressed as a
uint32_t, the value is added to the payload by copying the first 4 bytes
of the value.

On a 32-bit system this would be fine since `sizeof(size_t) == 4`. Even
worse, it would work most of the time (assuming an exclusion name string
< 4GiB) on a little-endian 64-bit system as the least significant bits
would be copied and correctly express the length of the string.

On a big-endian 64-bit platform, the most-significant 4 bytes are copied
to the payload buffer thus making the string length appear as "0".

Solution
========

A temporary variable is used to hold the "casted" value and make it safe
to copy to the payload buffer regardless of the platform's endianness.

Known drawbacks
===============

None.

Change-Id: I64c03345fff7ffea2f8fcb84692a085da31c421b
Signed-off-by: Michael Jeanson <mjeanson@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
19 months agoTests: remove leftover debug printing in test_add_trigger_cli
Michael Jeanson [Wed, 22 Mar 2023 19:08:10 +0000 (15:08 -0400)] 
Tests: remove leftover debug printing in test_add_trigger_cli

Change-Id: Ie5d0cc18ae35ff5848008fae5942d93eac5f2f70
Signed-off-by: Michael Jeanson <mjeanson@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
22 months agoUpdate version to v2.13.9 v2.13.9
Jérémie Galarneau [Fri, 6 Jan 2023 03:13:30 +0000 (22:13 -0500)] 
Update version to v2.13.9

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
22 months agoFix: lttng: poptGetArg doesn't provide string ownership
Michael Jeanson [Mon, 31 Oct 2022 19:52:46 +0000 (15:52 -0400)] 
Fix: lttng: poptGetArg doesn't provide string ownership

The string returned by poptGetArg() is 'const' because it is owned by
the popt librairy and is free'd by it when poptFreeContext() is called.
Copy those strings when we need to alter them to maintain proper
ownership.

The latest release of popt (v1.19) introduced a breaking
change (changing the ownership of left-over command line arguments) that
can cause double free()-s.

This is ultimately due to this upstream commit in popt 1.19:
https://github.com/rpm-software-management/popt/commit/7182e4618ad5a0186145fc2aa4a98c2229afdfa8

which is derived from a package patch:
https://src.fedoraproject.org/rpms/babeltrace/c/d48452beff87b145c038f070e7182358db04336c?branch=rawhide

Change-Id: Id2535d1534c0e47cc0747968d6dd60a587f0b810
Signed-off-by: Michael Jeanson <mjeanson@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
22 months agoFix: relayd: missing space in trace creation logging statement
Jérémie Galarneau [Fri, 2 Dec 2022 22:11:00 +0000 (17:11 -0500)] 
Fix: relayd: missing space in trace creation logging statement

A missing space results in hard to read logging statements when a
ctf_trace is created:

[...] Created ctf_trace 15of session "hello" [...]

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

22 months agoFix: event field value: assertion fails on empty string
Mathieu Desnoyers [Mon, 26 Sep 2022 17:36:38 +0000 (13:36 -0400)] 
Fix: event field value: assertion fails on empty string

When converting msgpack objects to their event_field_value equivalent,
the following assertion fails: LTTNG_ASSERT(val);

 #4  0x00007f1f65349486 in __assert_fail () from /usr/lib/libc.so.6
 #5  0x00007f1f65584da7 in lttng_event_field_value_string_create_with_size (val=0x0, size=0) at event-field-value.cpp:186
 #6  0x00007f1f65576a1a in event_field_value_from_obj (obj=0x557f597ccdb8, field_val=0x7ffcc9675dd0)
     at conditions/event-rule-matches.cpp:1120
 #7  0x00007f1f65577176 in event_field_value_from_capture_payload (condition=0x557f597c8520,
     capture_payload=0x557f597c825b "\221\240", capture_payload_size=2) at conditions/event-rule-matches.cpp:1340
 #8  0x00007f1f655772ea in lttng_evaluation_event_rule_matches_create (condition=0x557f597c8520,
     capture_payload=0x557f597c825b "\221\240", capture_payload_size=2, decode_capture_payload=true)
     at conditions/event-rule-matches.cpp:1398
 #9  0x00007f1f655765fc in lttng_evaluation_event_rule_matches_create_from_payload (condition=0x557f597c8520,
     view=0x7ffcc9675ff0, _evaluation=0x7ffcc9676080) at conditions/event-rule-matches.cpp:990
 #10 0x00007f1f6557f273 in lttng_evaluation_create_from_payload (condition=0x557f597c8520, src_view=0x7ffcc9676100,
     evaluation=0x7ffcc9676080) at evaluation.cpp:120
 #11 0x00007f1f6559ba36 in lttng_notification_create_from_payload (src_view=0x7ffcc9676190, notification=0x7ffcc9676180)
     at notification.cpp:123
 #12 0x00007f1f65552577 in create_notification_from_current_message (channel=0x557f597c8ee0) at channel.cpp:124
 #13 0x00007f1f6555298c in lttng_notification_channel_get_next_notification (channel=0x557f597c8ee0, _notification=0x7ffcc9676280)
     at channel.cpp:292

The msgpack API represents string as p-style while the implementation of
event_field_value relies on null-terminated strings. When an empty
string is captured by a tracer, it is decoded as a msgpack_object with
`str = {size = 0, ptr = 0x0}`.

lttng_event_field_value_string_create_with_size does not require a
null-terminated string since it also receives the length. Hence, this
fix causes lttng_event_field_value_string_create_with_size to accept
null strings when their length is zero. A copy of an empty string is
made to accomodate the null-termination convention used by the rest of
that API.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I7c3a839dbbeeb95a1b3bf6ddc3205a2f6b4538e3

22 months agoBuild fix: rpath of test libraries results in non-reproducible build
Jérémie Galarneau [Mon, 24 Oct 2022 14:53:40 +0000 (10:53 -0400)] 
Build fix: rpath of test libraries results in non-reproducible build

Yocto has trouble making LTTng-tools builds reproducibile since
abs_builddir is used as the rpath of the test libraries under
tests/regression/ust/ust-dl/.

From their commit message:
  Specifing abs_builddir as an RPATH is plain wrong when cross
  compiling. Sadly, removing the rpath makes libtool/automake do weird
  things and breaks the build as shared libs are no longer generated.

  We already try and delete the RPATH at do_install with chrpath however
  that does leave the path in the string table so it doesn't help us
  with reproducibility.

Their fix consists in hardcoding /usr/lib as the rpath of those
libraries. As mentionned, the rpath doesn't matter; it's used to
workaround libtool's behaviour.

This fix uses `$libdir`, which takes the user's specified prefix into
account to generate an rpath that is consistent with the one inserted in
the other artifacts.

Note that the change in the notification tests is a bit more involved
since we have to bypass libtool to instrument a test application with
uprobes.

Fixes #1361

Change-Id: I7739956f8bc8571ef90802c3b37a4e1f21352385
Reported-by: Alexander Kanavin <alex.kanavin@gmail.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
22 months agoFix: never use 'no' in a command variable
Michael Jeanson [Tue, 18 Oct 2022 15:10:46 +0000 (11:10 -0400)] 
Fix: never use 'no' in a command variable

Command variable may be used in the Makefiles and tests, when not found,
set them to an empty string instead of trying to execute the command
'no'.

Change-Id: I5429bb96599e3b7f166e52545269cd99eed758ae
Reported-by: Heng Guo <heng.guo@windriver.com>
Signed-off-by: Michael Jeanson <mjeanson@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
22 months agoFix: sessiond: abort called on undefined client command
Jérémie Galarneau [Thu, 13 Oct 2022 13:28:59 +0000 (14:28 +0100)] 
Fix: sessiond: abort called on undefined client command

Issue observed
--------------

When running in verbose mode, the session daemon calls abort()
when it receives an unknown client command:

 #1  0x00007f66ffd69958 in raise () from /usr/lib/libc.so.6
 #2  0x00007f66ffd5353d in abort () from /usr/lib/libc.so.6
 #3  0x000055a671a6f6bd in lttcomm_sessiond_command_str (cmd=1633771873)
     at ../../../src/common/sessiond-comm/sessiond-comm.hpp:199
 #4  0x000055a671a73897 in process_client_msg (cmd_ctx=0x7f66f5ff6d10,
     sock=0x7f66f5ff6c34, sock_error=0x7f66f5ff6c38) at client.cpp:1006
 #5  0x000055a671a777fc in thread_manage_clients (data=0x55a673956100)
     at client.cpp:2622
 #6  0x000055a671a6d290 in launch_thread (data=0x55a673956170) at thread.cpp:68

Cause
-----

process_client_msg() logs the client command on entry. While it
previously logged the numerical value, it now provides the string-ified
version of the command id (since 19f912db8).

The lttcomm_sessiond_command_str() function aborts when it encounters an
unknown command id. This is reasonable (in so far that it is how we
handle these situations, typically). However, the validity of the
command must be checked beforehand as it comes from an
external (untrusted) source.

Solution
--------

Add lttcomm_sessiond_command_is_valid and tombstone command IDs to
lttcomm_sessiond_command to ensure only valid command ids are passed
to lttcomm_sessiond_command_str when logging.

Drawbacks
---------

None

Reported-by: Michael Jeanson <mjeanson@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: Ibd36f1e69da984c7f27b55ec68e5e3fe06d7ac91

22 months agoFix: consumer: snapshot: assertion on subsequent snapshot
Jonathan Rajotte [Wed, 1 Jun 2022 19:20:55 +0000 (15:20 -0400)] 
Fix: consumer: snapshot: assertion on subsequent snapshot

Observed issue
==============

While a snapshot is being taken, the containing folder can disappear
unexpectedly. This can lead to the following errors, which are expected
and mostly handled fine:

PERROR - 14:47:32.002564464 [2922498/2922507]: Failed to open file relative to trace chunk file_path = "channel0_0", flags = 577, mode = 432: No such file or directory (in _lttng_trace_chunk_open_fs_handle_locked() at trace-chunk.cpp:1411)
Error: Failed to open stream file "channel0_0"
Error: Snapshot channel failed

The problem happens on the subsequent snapshot for the session:

 #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 #1  0x00007fbbdadb3859 in __GI_abort () at abort.c:79
 #2  0x00007fbbdadb3729 in __assert_fail_base (fmt=0x7fbbdaf49588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55c4212cfbb5 "!stream->trace_chunk", file=0x55c4212cf820 "kernel-co
 #3  0x00007fbbdadc5006 in __GI___assert_fail (assertion=0x55c4212cfbb5 "!stream->trace_chunk", file=0x55c4212cf820 "kernel-consumer/kernel-consumer.cpp", line=188, function=0x55c4212cfb00 "
 #4  0x000055c421268cc6 in lttng_kconsumer_snapshot_channel (channel=0x7fbbc4000b60, key=1, path=0x7fbbd37f8fd4 "", relayd_id=18446744073709551615, nb_packets_per_stream=0) at kernel-consume
 #5  0x000055c42126b39d in lttng_kconsumer_recv_cmd (ctx=0x55c421b80a90, sock=31, consumer_sockpoll=0x7fbbd37fd280) at kernel-consumer/kernel-consumer.cpp:986
 #6  0x000055c4212546d1 in lttng_consumer_recv_cmd (ctx=0x55c421b80a90, sock=31, consumer_sockpoll=0x7fbbd37fd280) at consumer/consumer.cpp:2090
 #7  0x000055c421259963 in consumer_thread_sessiond_poll (data=0x55c421b80a90) at consumer/consumer.cpp:3281
 #8  0x00007fbbdaf8b609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #9  0x00007fbbdaeb0163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

How to reproduce:

 1. Setting a breakpoint on snapshot_channel() inside
    src/common/ust-consumer/ust-consumer.cpp
 2. When the breakpoint hits, remove the the complete lttng directory
    containing the session data.
 3. Continue the lttng_consumerd process from gdb.
 4. In that case you see a negative return value -1 from
    consumer_stream_create_output_files() inside snapshot_channel().
 5. Take another snapshot and lttng_consumerd crashes because
    of the `assert(!stream->trace_chunk)` in snapshot_channel().

    This last action does not require any breakpoint intervention.

Cause
=====

During the snapshot, the stream is assigned the channel current chunk.
It is expected that the stream does not have a chunk at this point.

The error handling is faulty here, the stream chunk must be
invalidated/reset on error to allow its reuse later on.

The problem exists for both consumer domains (user/kernel).

Solution
========

For the ust consumer, we can directly use the `error_close_stream`
label.

For the kernel consumer, the code path is slightly different since it
does not uses `consumer_stream_close`. Note that `consumer_stream_close`
cannot be used as is for the kernel consumer. The current implementation
partially resembles `consumer_stream_close` at the end of the iteration.
It is extracted to its own function for easier reuse from the new
`error_finalize_stream` label.

Known drawbacks
=========

None.

Fixes: #1352
Signed-off-by: Marcel Hamer <marcel.hamer@windriver.com>
Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I9fc81917b19aa436ed8e8679672648f2d5baf41a

22 months agoFix: sessiond: instance uuid is not sufficiently unique
Jérémie Galarneau [Tue, 3 Jan 2023 23:41:23 +0000 (18:41 -0500)] 
Fix: sessiond: instance uuid is not sufficiently unique

Observed issue
==============

Tracing a cluster of machines -- all launched simultaneously -- to the
same relay daemon occasionally produces corrupted traces.

The size of packets received (as seen from the relay daemon logs) and
that of those present in the on-disk stream occasionally didn't match.

The traces were observed to all relate to the same trace UUID, but
present packet begin timestamps that were not monotonic for a given
stream.

This causes both Babeltrace 1.x and 2.x to fail to open the traces with
different error messages related to clocks.

Cause
=====

On start, the session daemon generates a UUID to uniquely identify the
sessiond instance. Since the UUID generation utils use time() to seed
the random number generator, two session daemons launched within the
same second can end up with the same instance UUID.

Since the relay daemon relies on this UUID to uniquely identify a
session daemon accross its various connections, identifier clashes can
cause streams from the same `uid` or `pid` to become scrambled resulting
in corrupted traces.

Solution
========

The UUID utils now initializes its random seed using the getrandom() API
in non-blocking mode. If that fails -- most likely because the random
pool is depleted or the syscall is not available on the platform -- it
falls back to using a hash of two time readings (with nanosecond
precision), of the hostname, and the PID.

Known drawbacks
===============

This fix implements many fallbacks, each with their own caveats and we
don't have full test coverage for all of those for the moment.

This article presents the different drawbacks of using /dev/urandom vs
getrandom().

https://lwn.net/Articles/884875/

As for the pseudo-random time and configuration based fallback, it is
meant as a last resort for platforms or configurations where both
getrandom() (old kernels or non-Linux platforms) and /dev/urandom (e.g.
locked-down container) are not be available. I haven't done a formal
analysis of the entropy of this home-grown method. The practical
use-case we want to enable is launching multiple virtual machines (or
containers) at roughly the same time and ensure that they don't end up
using the same sessiond UUID.

In that respect, having a different host name and minute timing changes
seem enough to prevent a UUID clash.

Using the PID as part of the hash also helps when launching multiple
session daemons simultaneously for different users.

Change-Id: I320fff7bc52752ff504643569e49fa3c02472ec2
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
2 years agoUpdate version to v2.13.8 v2.13.8
Jérémie Galarneau [Mon, 22 Aug 2022 18:45:38 +0000 (14:45 -0400)] 
Update version to v2.13.8

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
2 years agoFix: waiter: futex wait: handle spurious futex wakeups
Mathieu Desnoyers [Thu, 23 Jun 2022 20:27:41 +0000 (16:27 -0400)] 
Fix: waiter: futex wait: handle spurious futex wakeups

Observed issue
==============

The waiter lttng_waiter_wait() implements a futex wait/wakeup
scheme similar to the liburcu workqueue code, which has an issue with
spurious wakeups.

A spurious wakeup on lttng_waiter_wait can cause
lttng_waiter_wait to reach label skip_futex_wait with a
waiter->state state of WAITER_WAITING, which is unexpected. It would
cause busy-waiting on WAITER_TEARDOWN state to start early. The
wait-teardown stage is done with WAIT_ATTEMPTS active attempts,
following by attempts spaced by 10ms sleeps. I do not expect that these
spurious wakeups will cause user-observable effects other than being
slightly less efficient that it should be.

This issue will cause spurious unexpected high CPU use, but will not
lead to data corruption.

Cause
=====

From futex(5):

       FUTEX_WAIT
              Returns 0 if the caller was woken up.  Note that a  wake-up  can
              also  be caused by common futex usage patterns in unrelated code
              that happened to have previously used the  futex  word's  memory
              location  (e.g., typical futex-based implementations of Pthreads
              mutexes can cause this under some conditions).  Therefore, call‐
              ers should always conservatively assume that a return value of 0
              can mean a spurious wake-up, and  use  the  futex  word's  value
              (i.e.,  the user-space synchronization scheme) to decide whether
              to continue to block or not.

Solution
========

We therefore need to validate whether the value differs from
WAITER_WAITING in user-space after the call to FUTEX_WAIT returns 0.

Known drawbacks
===============

None.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: Ida9905d1f0b5d9543c8b85ecbd7d748a6f7c1c97

2 years agoFix: futex wait: handle spurious futex wakeups
Mathieu Desnoyers [Thu, 23 Jun 2022 20:15:51 +0000 (16:15 -0400)] 
Fix: futex wait: handle spurious futex wakeups

Observed issue
==============

The futex futex_nto1_wait() implements a futex wait/wakeup scheme
identical to the liburcu workqueue code, which has an issue with
spurious wakeups.

A spurious wakeup on futex_nto1_wait can cause futex_nto1_wait to return
with a futex state of -1, which is unexpected.

futex_nto1_wait is used by the relayd live dispatcher thread, by the
relayd main dispatcher thread, as well as by the sessiond dispatcher
thread.

Given that following a futex_nto1_wait returning due to a spurious
wakeup futex_nto1_prepare will set the futex value to -1, things go
back to normal for the following futex_nto1_wait calls.

Therefore, the only impact of this issue is to spuriously use slightly
more CPU time than strictly required.

The effect is even shorter-lasting that in the liburcu counterparts
because futex_nto1_prepare explicitly sets the futex state to -1 rather
than use an atomic decrement, which immediately sets to state back to
a consistent state.

Cause
=====

From futex(5):

       FUTEX_WAIT
              Returns 0 if the caller was woken up.  Note that a  wake-up  can
              also  be caused by common futex usage patterns in unrelated code
              that happened to have previously used the  futex  word's  memory
              location  (e.g., typical futex-based implementations of Pthreads
              mutexes can cause this under some conditions).  Therefore, call‐
              ers should always conservatively assume that a return value of 0
              can mean a spurious wake-up, and  use  the  futex  word's  value
              (i.e.,  the user-space synchronization scheme) to decide whether
              to continue to block or not.

Solution
========

We therefore need to validate whether the value differs from -1 in
user-space after the call to FUTEX_WAIT returns 0.

Known drawbacks
===============

None.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I8a1b6aaf77b6a2f941fd4f89b61bed71cf17906b

2 years agoFix: utils: unhandled close return value
Jérémie Galarneau [Mon, 22 Aug 2022 15:25:21 +0000 (11:25 -0400)] 
Fix: utils: unhandled close return value

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

2 years agoFix: agent port file is o+w when launching as root
Jonathan Rajotte [Thu, 21 Jul 2022 13:30:27 +0000 (09:30 -0400)] 
Fix: agent port file is o+w when launching as root

Observed issue
==============

When starting as root, the following permissions are observed:

[-rw-rw-rw-]  agent.port
[-rw-r--r--]  lttng-sessiond.pid

When starting as user:

[-rw-rw----]  agent.port
[-rw-rw-r--]  lttng-sessiond.pid

Note that despite being created by the same function,
`utils_create_pid_file`, the permissions are not the same.

Cause
=====

`get_wait_shm` manipulates the umask and does not restore it, thus
influencing the outcome of following file creations that don't enforce
specific permissions (using chmod).

Also `fopen` defaults to mode `0666 & ~umask`, thus resulting in
unnecessarily lax permissions when the session daemon is started as a
non-privileged user (umask = 0002, most of the time).

Solution
========

Mimic other call sites of umask(), modify then revert the umask.

Open the pid and agent port files as 0644 letting the umask to do its
job as necessary for those files.

Remove unnecessary umask() usage when chmod is directly used.

Known drawbacks
===============

Use of umask in a multi-threaded process is not recommended. Still our
current usage is limited and mostly happens during the initialization
phase. The usage of umask() is required for the `wait_shm` since on
FreeBSD it is not possible to chmod an shm file descriptor. The default
umask would interfere here.

Discussion
==========

The usage in run-as is valid even when in no-clone mode (valgrind) since
it is the sole user of umask() following the initialization phase. When
spawned as a separate process the clearing of umask is totally valid
even if it is not ideal since we are ignoring any umask set by the user.

It seems like the current usage is the lesser evil here.

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: Ie224d254714fff05f4bced471ebfa8f19eede26a

2 years agoFix: tests: don't assume sequential cpuids
Michael Jeanson [Tue, 9 Aug 2022 15:38:16 +0000 (15:38 +0000)] 
Fix: tests: don't assume sequential cpuids

On Linux CPU ids aren't sequential if a CPU is offlined or unplugged.
Get the list of currently available CPU ids from sysfs and pick a random
one, if sysfs is not available use the previous behavior.

Signed-off-by: Michael Jeanson <mjeanson@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: Ibdb63c7d036389104ac2f629827a6dce59e06983

2 years agoFix: sessiond: handle empty scheduled rotations
Jérémie Galarneau [Wed, 6 Jul 2022 16:09:41 +0000 (12:09 -0400)] 
Fix: sessiond: handle empty scheduled rotations

A number of error codes were added to cmd_rotate_session since the
implementation of size-based rotations. The rotation thread doesn't
expect LTTNG_ERR_ROTATION_MULTIPLE_AFTER_STOP and
LTTNG_ERR_ROTATION_AFTER_STOP_CLEAR which are not fatal failures.

These rotations would simply result in an empty trace archive and are,
therefore, not produced. In both cases, it is safe to wait for the next
size cycle.

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

2 years agoFix: sessiond: report client list allocation failure as a fatal error
Jérémie Galarneau [Thu, 30 Jun 2022 16:03:23 +0000 (12:03 -0400)] 
Fix: sessiond: report client list allocation failure as a fatal error

Report the failure to allocate a notification client list as a fatal
notification thread error.

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

2 years agoFix: ust-consumerd: set `hangup_flush_done` in a locked context
Jérémie Galarneau [Tue, 21 Jun 2022 20:21:17 +0000 (16:21 -0400)] 
Fix: ust-consumerd: set `hangup_flush_done` in a locked context

hangup_flush_done is updated after releasing the stream lock. This
doesn't appear to be a problem right now since this attribute is
apparently always accessed by the same thread, but it is conceptually
sus.

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

2 years agoFix: sessiond: size-based rotations never trigger
Jérémie Galarneau [Fri, 17 Jun 2022 20:53:53 +0000 (16:53 -0400)] 
Fix: sessiond: size-based rotations never trigger

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

Size-based scheduled rotations have no effect.

Cause
=====

Since c08136a3f, the rotation thread's handle_condition() checks that
the notification received matches the trigger that was registered.

As part of the equality check, the triggers' credentials are compared.

This checks fails systematically since the group id of a trigger's
credentials is not transported by the serialize/create_from functions.
The trigger that is received through the notification thus has an unset
group id, while the rotation trigger of the `ltt_session` has a group id
set; it was not stripped by the communication layer.

The check also fails since the trigger registered for the size-based
rotation is "hidden". This internal attribute is not propagated through
the communication layer, which causes the comparison to fail.

Solution
========

Since triggers only use the 'uid' part of lttng_credentials, we ensure
that lttng_trigger_set_credentials only sets this part of the structure.

Also, the `is_hidden` attribute of a trigger is now propagated through
the communication layer. This has no effect for external applications
since this attribute is not exposed through the API. However, it is
useful for internal triggers which use the same communication
facilities.

This allows the equality check in rotation-thread.cpp to go through as
expected.

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

2 years agoFix: lttng-snapshot: use after free of max size argument
Jérémie Galarneau [Tue, 17 May 2022 17:41:49 +0000 (13:41 -0400)] 
Fix: lttng-snapshot: use after free of max size argument

gcc 12.1.0 reports:

commands/snapshot.cpp: In function ‘int cmd_snapshot(int, const char**)’:
../../../src/common/error.hpp:139:32: error: pointer ‘max_size_arg’ may be used after ‘void free(void*)’ [-Werror=use-after-free]

free max_size_arg on both paths.

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

2 years agoFix: lttng: snapshot: add-output: leak of max size parameter
Jérémie Galarneau [Fri, 15 Apr 2022 06:09:53 +0000 (02:09 -0400)] 
Fix: lttng: snapshot: add-output: leak of max size parameter

==1920281==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 6 byte(s) in 1 object(s) allocated from:
    #0 0x7fa95633add9 in __interceptor_malloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:145
    #1 0x7fa955e90c09  (/usr/lib/libpopt.so.0+0x3c09)

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

2 years agoTests: fix: lttng-create: leaked command parameter
Jérémie Galarneau [Fri, 15 Apr 2022 05:55:45 +0000 (01:55 -0400)] 
Tests: fix: lttng-create: leaked command parameter

==1853705==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 3 byte(s) in 1 object(s) allocated from:
    #0 0x7fb67ee0edd9 in __interceptor_malloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:145
    #1 0x7fb67e964c09  (/usr/lib/libpopt.so.0+0x3c09)

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

2 years agoFix: sessiond: rotation trigger leak
Jérémie Galarneau [Fri, 15 Apr 2022 05:30:50 +0000 (01:30 -0400)] 
Fix: sessiond: rotation trigger leak

==1801304==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 224 byte(s) in 2 object(s) allocated from:
    #0 0x7fe0f4e73fb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x559fbeb64175 in zmalloc_internal ../../src/common/macros.hpp:60
    #2 0x559fbeb6a291 in lttng_trigger* zmalloc<lttng_trigger>() ../../src/common/macros.hpp:89
    #3 0x559fbeb64aa6 in lttng_trigger_create /home/jgalar/EfficiOS/src/lttng-tools/src/common/trigger.cpp:58
    #4 0x559fbe9dc417 in subscribe_session_consumed_size_rotation(ltt_session*, unsigned long, notification_thread_handle*) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/rotate.cpp:87
    #5 0x559fbe995d6f in cmd_rotation_set_schedule(ltt_session*, bool, lttng_rotation_schedule_type, unsigned long, notification_thread_handle*) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/cmd.cpp:5993
    #6 0x559fbe9fe559 in process_client_msg /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/client.cpp:2246
    #7 0x559fbea01378 in thread_manage_clients /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/client.cpp:2624
    #8 0x559fbe9ea642 in launch_thread /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/thread.cpp:68
    #9 0x7fe0f44935c1 in start_thread (/usr/lib/libc.so.6+0x8d5c1)

Indirect leak of 208 byte(s) in 2 object(s) allocated from:
    #0 0x7fe0f4e73fb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x559fbeb16e21 in zmalloc_internal ../../src/common/macros.hpp:60
    #2 0x559fbeb16e31 in lttng_action_notify* zmalloc<lttng_action_notify>() ../../src/common/macros.hpp:89
    #3 0x559fbeb168a0 in lttng_action_notify_create actions/notify.cpp:135
    #4 0x559fbe9dc34b in subscribe_session_consumed_size_rotation(ltt_session*, unsigned long, notification_thread_handle*) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/rotate.cpp:80
    #5 0x559fbe995d6f in cmd_rotation_set_schedule(ltt_session*, bool, lttng_rotation_schedule_type, unsigned long, notification_thread_handle*) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/cmd.cpp:5993
    #6 0x559fbe9fe559 in process_client_msg /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/client.cpp:2246
    #7 0x559fbea01378 in thread_manage_clients /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/client.cpp:2624
    #8 0x559fbe9ea642 in launch_thread /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/thread.cpp:68
    #9 0x7fe0f44935c1 in start_thread (/usr/lib/libc.so.6+0x8d5c1)

Indirect leak of 160 byte(s) in 2 object(s) allocated from:
    #0 0x7fe0f4e73fb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x559fbeb3d7a1 in zmalloc_internal ../../src/common/macros.hpp:60
    #2 0x559fbeb3fa35 in lttng_condition_session_consumed_size* zmalloc<lttng_condition_session_consumed_size>() ../../src/common/macros.hpp:89
    #3 0x559fbeb3e6fd in lttng_condition_session_consumed_size_create conditions/session-consumed-size.cpp:206
    #4 0x559fbe9dc0f1 in subscribe_session_consumed_size_rotation(ltt_session*, unsigned long, notification_thread_handle*) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/rotate.cpp:54
    #5 0x559fbe995d6f in cmd_rotation_set_schedule(ltt_session*, bool, lttng_rotation_schedule_type, unsigned long, notification_thread_handle*) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/cmd.cpp:5993
    #6 0x559fbe9fe559 in process_client_msg /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/client.cpp:2246
    #7 0x559fbea01378 in thread_manage_clients /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/client.cpp:2624
    #8 0x559fbe9ea642 in launch_thread /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/thread.cpp:68
    #9 0x7fe0f44935c1 in start_thread (/usr/lib/libc.so.6+0x8d5c1)

Indirect leak of 112 byte(s) in 2 object(s) allocated from:
    #0 0x7fe0f4e73fb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x559fbeb242ad in zmalloc_internal ../../src/common/macros.hpp:60
    #2 0x559fbeb27062 in zmalloc<(anonymous namespace)::lttng_rate_policy_every_n> ../../src/common/macros.hpp:89
    #3 0x559fbeb25e9f in lttng_rate_policy_every_n_create actions/rate-policy.cpp:492
    #4 0x559fbeb168b9 in lttng_action_notify_create actions/notify.cpp:141
    #5 0x559fbe9dc34b in subscribe_session_consumed_size_rotation(ltt_session*, unsigned long, notification_thread_handle*) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/rotate.cpp:80
    #6 0x559fbe995d6f in cmd_rotation_set_schedule(ltt_session*, bool, lttng_rotation_schedule_type, unsigned long, notification_thread_handle*) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/cmd.cpp:5993
    #7 0x559fbe9fe559 in process_client_msg /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/client.cpp:2246
    #8 0x559fbea01378 in thread_manage_clients /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/client.cpp:2624
    #9 0x559fbe9ea642 in launch_thread /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/thread.cpp:68
    #10 0x7fe0f44935c1 in start_thread (/usr/lib/libc.so.6+0x8d5c1)

Indirect leak of 34 byte(s) in 2 object(s) allocated from:
    #0 0x7fe0f4e19319 in __interceptor_strdup /usr/src/debug/gcc/libsanitizer/asan/asan_interceptors.cpp:454
    #1 0x559fbeb3f603 in lttng_condition_session_consumed_size_set_session_name conditions/session-consumed-size.cpp:442
    #2 0x559fbe9dc2c4 in subscribe_session_consumed_size_rotation(ltt_session*, unsigned long, notification_thread_handle*) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/rotate.cpp:71
    #3 0x559fbe995d6f in cmd_rotation_set_schedule(ltt_session*, bool, lttng_rotation_schedule_type, unsigned long, notification_thread_handle*) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/cmd.cpp:5993
    #4 0x559fbe9fe559 in process_client_msg /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/client.cpp:2246
    #5 0x559fbea01378 in thread_manage_clients /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/client.cpp:2624
    #6 0x559fbe9ea642 in launch_thread /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/thread.cpp:68
    #7 0x7fe0f44935c1 in start_thread (/usr/lib/libc.so.6+0x8d5c1)

The rotation trigger of a session (used for size-based rotations) is
never cleaned-up. It is now cleaned up every time its condition is
hit and whenever the session is destroyed.

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

2 years agoTests: fix: schedule api: leak of rotation schedule list
Jérémie Galarneau [Fri, 15 Apr 2022 05:34:54 +0000 (01:34 -0400)] 
Tests: fix: schedule api: leak of rotation schedule list

==1769573==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 24 byte(s) in 1 object(s) allocated from:
    #0 0x7fef37a29fb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x7fef37792f2f in zmalloc_internal ../../../src/common/macros.hpp:60
    #2 0x7fef3779573a in lttng_rotation_schedules* zmalloc<lttng_rotation_schedules>() ../../../src/common/macros.hpp:89
    #3 0x7fef377947cc in lttng_rotation_schedules_create /home/jgalar/EfficiOS/src/lttng-tools/src/lib/lttng-ctl/rotate.cpp:353
    #4 0x7fef37794aa0 in get_schedules /home/jgalar/EfficiOS/src/lttng-tools/src/lib/lttng-ctl/rotate.cpp:392
    #5 0x7fef377956dc in lttng_session_list_rotation_schedules /home/jgalar/EfficiOS/src/lttng-tools/src/lib/lttng-ctl/rotate.cpp:665
    #6 0x5646131713f2 in test_add_list_remove_schedule /home/jgalar/EfficiOS/src/lttng-tools/tests/regression/tools/rotation/schedule_api.c:252
    #7 0x56461317157b in test_add_list_remove_size_schedule /home/jgalar/EfficiOS/src/lttng-tools/tests/regression/tools/rotation/schedule_api.c:270
    #8 0x564613171680 in main /home/jgalar/EfficiOS/src/lttng-tools/tests/regression/tools/rotation/schedule_api.c:307
    #9 0x7fef373ae30f in __libc_start_call_main (/usr/lib/libc.so.6+0x2d30f)

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

2 years agoFix: lttng: enable-rotation: leak of command parameter
Jérémie Galarneau [Fri, 15 Apr 2022 05:29:46 +0000 (01:29 -0400)] 
Fix: lttng: enable-rotation: leak of command parameter

==1759491==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 6 byte(s) in 1 object(s) allocated from:
    #0 0x7fdbdc94add9 in __interceptor_malloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:145
    #1 0x7fdbdc4a0c09  (/usr/lib/libpopt.so.0+0x3c09)

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

2 years agoFix: lttng: track: leaked command parameter
Jérémie Galarneau [Fri, 15 Apr 2022 04:35:35 +0000 (00:35 -0400)] 
Fix: lttng: track: leaked command parameter

==1676099==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 5 byte(s) in 1 object(s) allocated from:
    #0 0x7f19429d9dd9 in __interceptor_malloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:145
    #1 0x7f19425342ad in poptGetNextOpt (/usr/lib/libpopt.so.0+0x82ad)

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

2 years agoFix: lttng: add-trigger: leak of parser context on capture
Jérémie Galarneau [Fri, 15 Apr 2022 03:43:10 +0000 (23:43 -0400)] 
Fix: lttng: add-trigger: leak of parser context on capture

==1501334==ERROR: LeakSanitizer: detected memory leaks

Indirect leak of 16386 byte(s) in 1 object(s) allocated from:
    #0 0x7f95efc3cdd9 in __interceptor_malloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:145
    #1 0x55acb0681ed3 in lttng_filter_yyalloc(unsigned long, void*) filter/filter-lexer.cpp:2511
    #2 0x55acb067f2f2 in lttng_filter_yy_create_buffer(_IO_FILE*, int, void*) filter/filter-lexer.cpp:1895
    #3 0x55acb067ea44 in yyrestart(_IO_FILE*, void*) filter/filter-lexer.cpp:1824
    #4 0x55acb0649a43 in filter_parser_ctx_alloc(_IO_FILE*) filter/filter-parser.ypp:271
    #5 0x55acb0649e7f in filter_parser_ctx_create_from_filter_expression(char const*, filter_parser_ctx**) filter/filter-parser.ypp:332
    #6 0x55acb058ee89 in parse_event_rule commands/add_trigger.cpp:783
    #7 0x55acb05920c0 in handle_condition_event commands/add_trigger.cpp:1361
    #8 0x55acb0592739 in parse_condition commands/add_trigger.cpp:1457
    #9 0x55acb0596b56 in cmd_add_trigger(int, char const**) commands/add_trigger.cpp:2304
    #10 0x55acb05a5b80 in handle_command /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng/lttng.cpp:238
    #11 0x55acb05a6643 in parse_args /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng/lttng.cpp:427
    #12 0x55acb05a694a in main /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng/lttng.cpp:476
    #13 0x7f95ef28730f in __libc_start_call_main (/usr/lib/libc.so.6+0x2d30f)

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

2 years agoTests: fix: leak of trigger in trigger listing tests
Jérémie Galarneau [Fri, 15 Apr 2022 03:26:12 +0000 (23:26 -0400)] 
Tests: fix: leak of trigger in trigger listing tests

==1480456==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 112 byte(s) in 1 object(s) allocated from:
    #0 0x7fdb9260cfb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x7fdb9242348d in zmalloc_internal ../../src/common/macros.hpp:60
    #2 0x7fdb924295a9 in lttng_trigger* zmalloc<lttng_trigger>() ../../src/common/macros.hpp:89
    #3 0x7fdb92423dbe in lttng_trigger_create /home/jgalar/EfficiOS/src/lttng-tools/src/common/trigger.cpp:58
    #4 0x56304832331f in register_trigger /home/jgalar/EfficiOS/src/lttng-tools/tests/regression/tools/trigger/utils/register-some-triggers.cpp:24
    #5 0x5630483233f1 in register_trigger_action_list_notify /home/jgalar/EfficiOS/src/lttng-tools/tests/regression/tools/trigger/utils/register-some-triggers.cpp:46
    #6 0x5630483239a0 in test_session_rotation_conditions /home/jgalar/EfficiOS/src/lttng-tools/tests/regression/tools/trigger/utils/register-some-triggers.cpp:246
    #7 0x563048323d4d in main /home/jgalar/EfficiOS/src/lttng-tools/tests/regression/tools/trigger/utils/register-some-triggers.cpp:309
    #8 0x7fdb91c6630f in __libc_start_call_main (/usr/lib/libc.so.6+0x2d30f)

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

2 years agoFix: action error query: leak of action path
Jérémie Galarneau [Fri, 15 Apr 2022 03:21:27 +0000 (23:21 -0400)] 
Fix: action error query: leak of action path

==1429021==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 8 byte(s) in 1 object(s) allocated from:
    #0 0x7fe305f031b2 in __interceptor_realloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:164
    #1 0x559f1b022238 in lttng_dynamic_buffer_set_capacity(lttng_dynamic_buffer*, unsigned long) /home/jgalar/EfficiOS/src/lttng-tools/src/common/dynamic-buffer.cpp:159
    #2 0x559f1b021d9f in lttng_dynamic_buffer_append(lttng_dynamic_buffer*, void const*, unsigned long) /home/jgalar/EfficiOS/src/lttng-tools/src/common/dynamic-buffer.cpp:52
    #3 0x559f1b02144a in lttng_dynamic_array_add_element(lttng_dynamic_array*, void const*) /home/jgalar/EfficiOS/src/lttng-tools/src/common/dynamic-array.cpp:58
    #4 0x559f1b07d07b in lttng_action_path_copy(lttng_action_path const*, lttng_action_path*) actions/path.cpp:116
    #5 0x559f1b02383f in lttng_error_query_action_create /home/jgalar/EfficiOS/src/lttng-tools/src/common/error-query.cpp:232
    #6 0x559f1b02760e in lttng_error_query_create_from_payload(lttng_payload_view*, lttng_error_query**) /home/jgalar/EfficiOS/src/lttng-tools/src/common/error-query.cpp:911
    #7 0x559f1af5c361 in receive_lttng_error_query /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/client.cpp:740
    #8 0x559f1af64eba in process_client_msg /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/client.cpp:2336
    #9 0x559f1af67378 in thread_manage_clients /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/client.cpp:2624
    #10 0x559f1af50642 in launch_thread /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/thread.cpp:68
    #11 0x7fe3055225c1 in start_thread (/usr/lib/libc.so.6+0x8d5c1)

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

2 years agoFix: lttng: enable-channel: leak of popt arguments
Jérémie Galarneau [Fri, 15 Apr 2022 00:22:03 +0000 (20:22 -0400)] 
Fix: lttng: enable-channel: leak of popt arguments

==1245463==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 5 byte(s) in 1 object(s) allocated from:
    #0 0x7fe7c494fdd9 in __interceptor_malloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:145
    #1 0x7fe7c44a5c09  (/usr/lib/libpopt.so.0+0x3c09)

Arguments obtained with poptGetOptArg() must be free'd.

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

2 years agoTests: clean-up: rate policy: remove stale comment
Jérémie Galarneau [Fri, 15 Apr 2022 00:09:58 +0000 (20:09 -0400)] 
Tests: clean-up: rate policy: remove stale comment

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

2 years agoTests: fix: leak of rate policy in rate policy unit tests
Jérémie Galarneau [Fri, 15 Apr 2022 00:09:24 +0000 (20:09 -0400)] 
Tests: fix: leak of rate policy in rate policy unit tests

==1198508==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 56 byte(s) in 1 object(s) allocated from:
    #0 0x7f8b62634fb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x557871869adb in zmalloc_internal ../../src/common/macros.hpp:60
    #2 0x55787186c8a0 in zmalloc<(anonymous namespace)::lttng_rate_policy_once_after_n> ../../src/common/macros.hpp:89
    #3 0x55787186c173 in lttng_rate_policy_once_after_n_create actions/rate-policy.cpp:707
    #4 0x55787186a368 in lttng_rate_policy_once_after_n_create_from_payload actions/rate-policy.cpp:183
    #5 0x55787186ad02 in lttng_rate_policy_create_from_payload(lttng_payload_view*, lttng_rate_policy**) actions/rate-policy.cpp:287
    #6 0x557871865b5b in test_rate_policy_once_after_n /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_rate_policy.cpp:231
    #7 0x557871865dc9 in main /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_rate_policy.cpp:250
    #8 0x7f8b61c7130f in __libc_start_call_main (/usr/lib/libc.so.6+0x2d30f)

Direct leak of 56 byte(s) in 1 object(s) allocated from:
    #0 0x7f8b62634fb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x557871869adb in zmalloc_internal ../../src/common/macros.hpp:60
    #2 0x55787186c890 in zmalloc<(anonymous namespace)::lttng_rate_policy_every_n> ../../src/common/macros.hpp:89
    #3 0x55787186b6cd in lttng_rate_policy_every_n_create actions/rate-policy.cpp:492
    #4 0x55787186a699 in lttng_rate_policy_every_n_create_from_payload actions/rate-policy.cpp:220
    #5 0x55787186ad02 in lttng_rate_policy_create_from_payload(lttng_payload_view*, lttng_rate_policy**) actions/rate-policy.cpp:287
    #6 0x557871864cae in test_rate_policy_every_n /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_rate_policy.cpp:122
    #7 0x557871865dc4 in main /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_rate_policy.cpp:249
    #8 0x7f8b61c7130f in __libc_start_call_main (/usr/lib/libc.so.6+0x2d30f)

SUMMARY: AddressSanitizer: 112 byte(s) leaked in 2 allocation(s).

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

2 years agoTests: fix: leak of payload in serdes test of log level rule
Jérémie Galarneau [Fri, 15 Apr 2022 00:06:19 +0000 (20:06 -0400)] 
Tests: fix: leak of payload in serdes test of log level rule

==1190137==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 8 byte(s) in 1 object(s) allocated from:
    #0 0x7f40a9d4c1b2 in __interceptor_realloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:164
    #1 0x55ab716e1def in lttng_dynamic_buffer_set_capacity(lttng_dynamic_buffer*, unsigned long) /home/jgalar/EfficiOS/src/lttng-tools/src/common/dynamic-buffer.cpp:159
    #2 0x55ab716e1956 in lttng_dynamic_buffer_append(lttng_dynamic_buffer*, void const*, unsigned long) /home/jgalar/EfficiOS/src/lttng-tools/src/common/dynamic-buffer.cpp:52
    #3 0x55ab716ca64e in lttng_log_level_rule_serialize(lttng_log_level_rule const*, lttng_payload*) /home/jgalar/EfficiOS/src/lttng-tools/src/common/log-level-rule.cpp:177
    #4 0x55ab716c760f in test_log_level_rule_serialize_deserialize /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_log_level_rule.cpp:60
    #5 0x55ab716c8457 in test_log_level_rule_at_least_as_severe_as /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_log_level_rule.cpp:177
    #6 0x55ab716c84d3 in main /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_log_level_rule.cpp:185
    #7 0x7f40a938830f in __libc_start_call_main (/usr/lib/libc.so.6+0x2d30f)

Direct leak of 8 byte(s) in 1 object(s) allocated from:
    #0 0x7f40a9d4c1b2 in __interceptor_realloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:164
    #1 0x55ab716e1def in lttng_dynamic_buffer_set_capacity(lttng_dynamic_buffer*, unsigned long) /home/jgalar/EfficiOS/src/lttng-tools/src/common/dynamic-buffer.cpp:159
    #2 0x55ab716e1956 in lttng_dynamic_buffer_append(lttng_dynamic_buffer*, void const*, unsigned long) /home/jgalar/EfficiOS/src/lttng-tools/src/common/dynamic-buffer.cpp:52
    #3 0x55ab716ca64e in lttng_log_level_rule_serialize(lttng_log_level_rule const*, lttng_payload*) /home/jgalar/EfficiOS/src/lttng-tools/src/common/log-level-rule.cpp:177
    #4 0x55ab716c760f in test_log_level_rule_serialize_deserialize /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_log_level_rule.cpp:60
    #5 0x55ab716c8135 in test_log_level_rule_exactly /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_log_level_rule.cpp:154
    #6 0x55ab716c84ce in main /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_log_level_rule.cpp:184
    #7 0x7f40a938830f in __libc_start_call_main (/usr/lib/libc.so.6+0x2d30f)

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

2 years agoTests: fix: leak of some attributes of ltt_ust_session
Jérémie Galarneau [Fri, 15 Apr 2022 00:02:18 +0000 (20:02 -0400)] 
Tests: fix: leak of some attributes of ltt_ust_session

==1175545==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 8696 byte(s) in 1 object(s) allocated from:
    #0 0x7efed0f39fb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x55707ddc6004 in zmalloc_internal ../../../src/common/macros.hpp:60
    #2 0x55707ddceb17 in ltt_ust_session* zmalloc<ltt_ust_session>() ../../../src/common/macros.hpp:89
    #3 0x55707ddc81e7 in trace_ust_create_session(unsigned long) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/trace-ust.cpp:274
    #4 0x55707ddc2bea in test_create_one_ust_session /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_ust_data.cpp:63
    #5 0x55707ddc4941 in main /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_ust_data.cpp:283
    #6 0x7efed04f930f in __libc_start_call_main (/usr/lib/libc.so.6+0x2d30f)

Indirect leak of 24672 byte(s) in 1 object(s) allocated from:
    #0 0x7efed0f39fb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x55707dee4ec1 in zmalloc_internal ../../../src/common/macros.hpp:60
    #2 0x55707def774e in consumer_output* zmalloc<consumer_output>() ../../../src/common/macros.hpp:89
    #3 0x55707dee90df in consumer_create_output(consumer_dst_type) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/consumer.cpp:523
    #4 0x55707ddc8821 in trace_ust_create_session(unsigned long) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/trace-ust.cpp:321
    #5 0x55707ddc2bea in test_create_one_ust_session /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_ust_data.cpp:63
    #6 0x55707ddc4941 in main /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_ust_data.cpp:283
    #7 0x7efed04f930f in __libc_start_call_main (/usr/lib/libc.so.6+0x2d30f)

Indirect leak of 1024 byte(s) in 1 object(s) allocated from:
    #0 0x7efed0f39fb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x7efed0bf985f in alloc_split_items_count /home/jgalar/EfficiOS/src/userspace-rcu/src/rculfhash.c:688
    #2 0x7efed0bf985f in _cds_lfht_new /home/jgalar/EfficiOS/src/userspace-rcu/src/rculfhash.c:1642

Indirect leak of 656 byte(s) in 1 object(s) allocated from:
    #0 0x7efed0f39fb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x7efed0bfac68 in __default_alloc_cds_lfht ../src/rculfhash-internal.h:172
    #2 0x7efed0bfac68 in alloc_cds_lfht /home/jgalar/EfficiOS/src/userspace-rcu/src/rculfhash-mm-order.c:81

Indirect leak of 48 byte(s) in 2 object(s) allocated from:
    #0 0x7efed0f39fb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x7efed0bfabd4 in cds_lfht_alloc_bucket_table /home/jgalar/EfficiOS/src/userspace-rcu/src/rculfhash-mm-order.c:35
    #2 0x7efed0bfabd4 in cds_lfht_alloc_bucket_table /home/jgalar/EfficiOS/src/userspace-rcu/src/rculfhash-mm-order.c:28

Indirect leak of 24 byte(s) in 1 object(s) allocated from:
    #0 0x7efed0f39fb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x55707de3a9af in zmalloc_internal ../../src/common/macros.hpp:60
    #2 0x55707de3a9bf in lttng_ht* zmalloc<lttng_ht>() ../../src/common/macros.hpp:89
    #3 0x55707de38461 in lttng_ht_new(unsigned long, lttng_ht_type) hashtable/hashtable.cpp:113
    #4 0x55707dee9340 in consumer_create_output(consumer_dst_type) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/consumer.cpp:535
    #5 0x55707ddc8821 in trace_ust_create_session(unsigned long) /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng-sessiond/trace-ust.cpp:321
    #6 0x55707ddc2bea in test_create_one_ust_session /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_ust_data.cpp:63
    #7 0x55707ddc4941 in main /home/jgalar/EfficiOS/src/lttng-tools/tests/unit/test_ust_data.cpp:283
    #8 0x7efed04f930f in __libc_start_call_main (/usr/lib/libc.so.6+0x2d30f)

Indirect leak of 16 byte(s) in 1 object(s) allocated from:
    #0 0x7efed0f39fb9 in __interceptor_calloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:154
    #1 0x7efed0bfac15 in cds_lfht_alloc_bucket_table /home/jgalar/EfficiOS/src/userspace-rcu/src/rculfhash-mm-order.c:31

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

2 years agoFix: liblttng-ctl: leak of payload on field listing
Jérémie Galarneau [Thu, 14 Apr 2022 23:45:28 +0000 (19:45 -0400)] 
Fix: liblttng-ctl: leak of payload on field listing

LeakSanitizer reports the following leak:

==974957==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 32 byte(s) in 1 object(s) allocated from:
    #0 0x7fdb86fcd1b2 in __interceptor_realloc /usr/src/debug/gcc/libsanitizer/asan/asan_malloc_linux.cpp:164
    #1 0x7fdb86d7c296 in lttng_dynamic_buffer_set_capacity(lttng_dynamic_buffer*, unsigned long) /home/jgalar/EfficiOS/src/lttng-tools/src/common/dynamic-buffer.cpp:159
    #2 0x7fdb86d7c060 in lttng_dynamic_buffer_set_size(lttng_dynamic_buffer*, unsigned long) /home/jgalar/EfficiOS/src/lttng-tools/src/common/dynamic-buffer.cpp:112
    #3 0x7fdb86d2589a in recv_payload_sessiond /home/jgalar/EfficiOS/src/lttng-tools/src/lib/lttng-ctl/lttng-ctl.cpp:230
    #4 0x7fdb86d26fa5 in lttng_ctl_ask_sessiond_payload(lttng_payload_view*, lttng_payload*) /home/jgalar/EfficiOS/src/lttng-tools/src/lib/lttng-ctl/lttng-ctl.cpp:662
    #5 0x7fdb86d2cd8d in lttng_list_tracepoint_fields /home/jgalar/EfficiOS/src/lttng-tools/src/lib/lttng-ctl/lttng-ctl.cpp:1767
    #6 0x56481623cb4c in list_ust_event_fields commands/list.cpp:850
    #7 0x5648162448d9 in cmd_list(int, char const**) commands/list.cpp:2394
    #8 0x56481628fb3e in handle_command /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng/lttng.cpp:238
    #9 0x564816290601 in parse_args /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng/lttng.cpp:427
    #10 0x564816290908 in main /home/jgalar/EfficiOS/src/lttng-tools/src/bin/lttng/lttng.cpp:476
    #11 0x7fdb8661730f in __libc_start_call_main (/usr/lib/libc.so.6+0x2d30f)

SUMMARY: AddressSanitizer: 32 byte(s) leaked in 1 allocation(s).

The session daemon's reply is indeed never released in
lttng_list_tracepoint_fields.

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

2 years agoFix: liblttng-ctl: non-packed structure used for tracker serialization
Jérémie Galarneau [Thu, 14 Apr 2022 21:36:54 +0000 (17:36 -0400)] 
Fix: liblttng-ctl: non-packed structure used for tracker serialization

Using unpacked structures in liblttng-ctl's protocol can cause issues
when mixing sessiond and client of different bitness. In this specific
case I doubt it causes a problem, but it could rightfully do on some
architectures.

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

2 years agoFix: test: lttng kernel modules still loaded after running test_clock_override
Jonathan Rajotte [Fri, 25 Mar 2022 18:26:38 +0000 (14:26 -0400)] 
Fix: test: lttng kernel modules still loaded after running test_clock_override

Observed issue
==============

After running test_clock_override, some lttng modules are still loaded.

$ lsmod | ag lttng
  lttng_test             32768  0
  lttng_tracer         2326528  1 lttng_test
  lttng_statedump       749568  1 lttng_tracer
  lttng_wrapper          16384  2 lttng_statedump,lttng_tracer
  lttng_uprobes          16384  1 lttng_tracer
  lttng_kprobes          16384  1 lttng_tracer
  lttng_lib_ring_buffer    61440  1 lttng_tracer
  lttng_kretprobes       16384  1 lttng_tracer
  lttng_clock_plugin_test    16384  1
  lttng_clock            16384  2 lttng_tracer,lttng_clock_plugin_test

Cause
=====

The order in which the modules are removed is important.

In `test_clock_override_timestamp` the last `modprobe --remove order` is

  modprobe --remove lttng-clock-plugin-test lttng-clock lttng-test

While other callsites order is:

  modprobe --remove lttng-test lttng-clock-plugin-test lttng-clock

Solution
========

Use

  modprobe --remove lttng-test lttng-clock-plugin-test lttng-clock

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I528df2e3e90664433337a547a74cdbe476d4ee62

2 years agoUpdate version to v2.13.7 v2.13.7
Jérémie Galarneau [Wed, 13 Apr 2022 18:27:57 +0000 (14:27 -0400)] 
Update version to v2.13.7

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
2 years agoFix: sessiond: assert on empty payload when handling client out event
Jérémie Galarneau [Fri, 8 Apr 2022 23:34:04 +0000 (19:34 -0400)] 
Fix: sessiond: assert on empty payload when handling client out event

Observed issue
==============

When servicing a large number of tracer notifications and sending
notifications to clients, the session daemon occasionally hits
an assertion:

  #4  0x00007fb224d7d116 in __assert_fail () from /usr/lib/libc.so.6
  #5  0x000056038b2fe4d7 in client_flush_outgoing_queue (client=0x7fb21400c3b0) at notification-thread-events.cpp:3586
  #6  0x000056038b2ff819 in handle_notification_thread_client_out (state=0x7fb221974090, socket=77) at notification-thread-events.cpp:4104
  #7  0x000056038b2f3d77 in thread_notification (data=0x56038cc7fe90) at notification-thread.cpp:763
  #8  0x000056038b30ca7d in launch_thread (data=0x56038cc7e220) at thread.cpp:66
  #9  0x00007fb224dcf5c2 in start_thread () from /usr/lib/libc.so.6
  #10 0x00007fb224e54584 in clone () from /usr/lib/libc.so.6

Cause
=====

A client "out" event can be received when no payload is left
to send under some circumstances.

Many threads can flush a client's outgoing queue and, if they
had to queue their message (socket was full), will use the
"communication update" command to signal the (e)poll thread
to monitor for space being made available in the socket.

Commands are sent over an internal pipe serviced by the same
thread as the client sockets.

When space is made available in the socket, there is a race
between the (e)poll thread and the other threads that may
wish to use the client's socket to flush its outgoing queue.

A non-(e)poll thread may attempt (and succeed) in flushing
the queue before the (e)poll thread gets a chance to service
the client's "out" event.

In this situation, the (e)poll thread processing the client
out event will see an empty payload: there is nothing to do.

Solution
========

The (e)poll thread can simply ignore the "client out" event
when an empty payload is seen.

There is also no need to update the transmission status as
the other thread has already enqueued a "communication
update" command to do so.

Known drawbacks
===============

None.

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

2 years agoFix: Revert of 814b4934e2604a419bcb8eec57c0450dbb47e2c3
Jonathan Rajotte [Wed, 6 Apr 2022 13:17:38 +0000 (09:17 -0400)] 
Fix: Revert of 814b4934e2604a419bcb8eec57c0450dbb47e2c3

Observed issue
==============

During high throughput event notification generation scenarios the
following deadlock happens:

 Thread 14 (Thread 0x7f74b4ff9700 (LWP 76062)):
 #0  __lll_lock_wait (futex=futex@entry=0x56408765dde8, private=0) at lowlevellock.c:52
 #1  0x00007f74c941a0a3 in __GI___pthread_mutex_lock (mutex=0x56408765dde8) at ../nptl/pthread_mutex_lock.c:80
 #2  0x000056408704b207 in run_command_wait (handle=0x56408765ddd0, cmd=0x7f74b4ff7f70) at notification-thread-commands.cpp:31
 #3  0x000056408704bcef in notification_thread_command_remove_tracer_event_source (handle=0x56408765ddd0, tracer_event_source_fd=54) at notification-thread-commands.cpp:319
 #4  0x000056408708a0c1 in delete_ust_app (app=0x7f749c000bf0) at ust-app.cpp:1059
 #5  0x000056408708a511 in delete_ust_app_rcu (head=0x7f749c000ca0) at ust-app.cpp:1122
 #6  0x00007f74c988b4a7 in call_rcu_thread (arg=0x7f74b8004a80) at ../src/urcu-call-rcu-impl.h:369
 #7  0x00007f74c9417609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #8  0x00007f74c933a163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

 Thread 13 (Thread 0x7f74b57fa700 (LWP 76047)):
 #0  0x00007f74c933a49e in epoll_wait (epfd=48, events=0x7f74a4000b60, maxevents=2, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
 #1  0x00005640870eafa6 in compat_epoll_wait (events=0x7f74b57f9240, timeout=-1, interruptible=false) at compat/poll.cpp:280
 #2  0x00005640870abb65 in thread_agent_management (data=0x56408765f0b0) at agent-thread.cpp:424
 #3  0x0000564087062b1a in launch_thread (data=0x56408765f150) at thread.cpp:66
 #4  0x00007f74c9417609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #5  0x00007f74c933a163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

 Thread 12 (Thread 0x7f74b5ffb700 (LWP 76046)):                                                                                                                                       [630/709]
 #0  0x00007f74c933a49e in epoll_wait (epfd=47, events=0x7f74a0000b60, maxevents=2, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
 #1  0x00005640870eafa6 in compat_epoll_wait (events=0x7f74b5ffa170, timeout=-1, interruptible=false) at compat/poll.cpp:280
 #2  0x00005640870a4095 in thread_application_notification (data=0x56408765ee40) at notify-apps.cpp:78
 #3  0x0000564087062b1a in launch_thread (data=0x56408765eed0) at thread.cpp:66
 #4  0x00007f74c9417609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #5  0x00007f74c933a163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

 Thread 11 (Thread 0x7f74b67fc700 (LWP 76045)):
 #0  0x00007f74c933a49e in epoll_wait (epfd=44, events=0x7f74ac000b60, maxevents=2, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
 #1  0x00005640870eafa6 in compat_epoll_wait (events=0x7f74b67fb170, timeout=-1, interruptible=false) at compat/poll.cpp:280
 #2  0x00005640870723db in thread_application_management (data=0x56408765ebd0) at manage-apps.cpp:93
 #3  0x0000564087062b1a in launch_thread (data=0x56408765ec60) at thread.cpp:66
 #4  0x00007f74c9417609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #5  0x00007f74c933a163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

 Thread 10 (Thread 0x7f74b6ffd700 (LWP 76044)):
 #0  0x00007f74c933a49e in epoll_wait (epfd=39, events=0x7f74a8000b60, maxevents=2, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
 #1  0x00005640870eafa6 in compat_epoll_wait (events=0x7f74b6ffc130, timeout=-1, interruptible=false) at compat/poll.cpp:280
 #2  0x0000564087070a27 in thread_application_registration (data=0x56408765e940) at register.cpp:214
 #3  0x0000564087062b1a in launch_thread (data=0x56408765e9f0) at thread.cpp:66
 #4  0x00007f74c9417609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #5  0x00007f74c933a163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

 Thread 9 (Thread 0x7f74b77fe700 (LWP 76043)):                                                                                                                                        [654/709]
 #0  syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
 #1  0x00005640870c8e25 in futex (uaddr=0x5640871e2800 <ust_cmd_queue>, op=0, val=-1, timeout=0x0, uaddr2=0x0, val3=0) at /home/joraj/lttng/master/install/include/urcu/futex.h:72
 #2  0x00005640870c8e6d in futex_async (uaddr=0x5640871e2800 <ust_cmd_queue>, op=0, val=-1, timeout=0x0, uaddr2=0x0, val3=0) at /home/joraj/lttng/master/install/include/urcu/futex.h:104
 #3  0x00005640870c939a in futex_nto1_wait (futex=0x5640871e2800 <ust_cmd_queue>) at futex.cpp:77
 #4  0x000056408706f2af in thread_dispatch_ust_registration (data=0x56408765e740) at dispatch.cpp:453
 #5  0x0000564087062b1a in launch_thread (data=0x56408765e760) at thread.cpp:66
 #6  0x00007f74c9417609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #7  0x00007f74c933a163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

 Thread 8 (Thread 0x7f74b7fff700 (LWP 76042)):
 #0  0x00007f74c933a49e in epoll_wait (epfd=33, events=0x7f74b0000b60, maxevents=2, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
 #1  0x00005640870eafa6 in compat_epoll_wait (events=0x7f74b7ffad40, timeout=-1, interruptible=false) at compat/poll.cpp:280
 #2  0x000056408706c424 in thread_manage_clients (data=0x56408765e4f0) at client.cpp:2528
 #3  0x0000564087062b1a in launch_thread (data=0x56408765e560) at thread.cpp:66
 #4  0x00007f74c9417609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #5  0x00007f74c933a163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

 Thread 7 (Thread 0x7f74c4b8f700 (LWP 76041)):                                                                                                                                        [672/709]
 #0  0x00007f74c933a49e in epoll_wait (epfd=31, events=0x7f74bc000b60, maxevents=3, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
 #1  0x00005640870eafa6 in compat_epoll_wait (events=0x7f74c4b8e240, timeout=-1, interruptible=false) at compat/poll.cpp:280
 #2  0x000056408705f2b6 in thread_rotation (data=0x56408765e280) at rotation-thread.cpp:804
 #3  0x0000564087062b1a in launch_thread (data=0x56408765e310) at thread.cpp:66
 #4  0x00007f74c9417609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #5  0x00007f74c933a163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

 Thread 6 (Thread 0x7f74c5390700 (LWP 76040)):
 #0  0x00007f74c925f1d2 in __GI___sigtimedwait (set=0x7f74c538f090, info=0x7f74c538f110, timeout=0x0) at ../sysdeps/unix/sysv/linux/sigtimedwait.c:29
 #1  0x000056408706138a in thread_timer (data=0x7ffc1fcbe3f0) at timer.cpp:359
 #2  0x0000564087062b1a in launch_thread (data=0x56408765e0a0) at thread.cpp:66
 #3  0x00007f74c9417609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #4  0x00007f74c933a163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

 Thread 5 (Thread 0x7f74c5b91700 (LWP 76039)):
 #0  __libc_write (nbytes=8, buf=0x7f74c5b8fc88, fd=24) at ../sysdeps/unix/sysv/linux/write.c:26
 #1  __libc_write (fd=24, buf=0x7f74c5b8fc88, nbytes=8) at ../sysdeps/unix/sysv/linux/write.c:24
 #2  0x00005640870eeb4f in lttng_write (fd=24, buf=0x7f74c5b8fc88, count=8) at readwrite.cpp:77
 #3  0x000056408704b535 in run_command_no_wait (handle=0x56408765ddd0, in_cmd=0x7f74c5b8fdf0) at notification-thread-commands.cpp:92
 #4  0x000056408704bf49 in notification_thread_client_communication_update (handle=0x56408765ddd0, id=2, transmission_status=CLIENT_TRANSMISSION_STATUS_QUEUED) at notification-thread-command
 #5  0x000056408707bc62 in client_handle_transmission_status (client=0x7f74b80050d0, status=CLIENT_TRANSMISSION_STATUS_QUEUED, user_data=0x7f74b8004410) at action-executor.cpp:258
 #6  0x0000564087057525 in notification_client_list_send_evaluation (client_list=0x7f74b8004df0, trigger=0x7f74b0001030, evaluation=0x7f74b815d1d0, source_object_creds=0x0, client_report=0x5
 #7  0x000056408707bce9 in action_executor_notify_handler (executor=0x7f74b8004410, work_item=0x7f74b815d430, item=0x7f74b80e48e0) at action-executor.cpp:269
 #8  0x000056408707dd6d in action_executor_generic_handler (executor=0x7f74b8004410, work_item=0x7f74b815d430, item=0x7f74b80e48e0) at action-executor.cpp:670
 #9  0x000056408707df01 in action_work_item_execute (executor=0x7f74b8004410, work_item=0x7f74b815d430) at action-executor.cpp:689

 #10 0x000056408707e525 in action_executor_thread (_data=0x7f74b8004410) at action-executor.cpp:771                                                                                   [698/709]
 #11 0x0000564087062b1a in launch_thread (data=0x7f74b80044b0) at thread.cpp:66
 #12 0x00007f74c9417609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #13 0x00007f74c933a163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

 Thread 4 (Thread 0x7f74c6392700 (LWP 76038)):
 #0  __lll_lock_wait (futex=futex@entry=0x56408765dde8, private=0) at lowlevellock.c:52
 #1  0x00007f74c941a0a3 in __GI___pthread_mutex_lock (mutex=0x56408765dde8) at ../nptl/pthread_mutex_lock.c:80
 #2  0x0000564087053c89 in handle_notification_thread_command (handle=0x56408765ddd0, state=0x7f74c63911b0) at notification-thread-events.cpp:3142
 #3  0x000056408704ac81 in thread_notification (data=0x56408765ddd0) at notification-thread.cpp:715
 #4  0x0000564087062b1a in launch_thread (data=0x56408765dec0) at thread.cpp:66
 #5  0x00007f74c9417609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #run_command_no_wait6  0x00007f74c933a163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

 Thread 3 (Thread 0x7f74c6b93700 (LWP 76037)):
 #0  0x00007f74c933a49e in epoll_wait (epfd=21, events=0x7f74c0000b60, maxevents=2, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
 #1  0x00005640870eafa6 in compat_epoll_wait (events=0x7f74c6b92170, timeout=-1, interruptible=false) at compat/poll.cpp:280
 #2  0x000056408706400a in thread_manage_health (data=0x56408765db50) at health.cpp:140
 #3  0x0000564087062b1a in launch_thread (data=0x56408765dbf0) at thread.cpp:66
 #4  0x00007f74c9417609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #5  0x00007f74c933a163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

 Thread 2 (Thread 0x7f74c7394700 (LWP 76036)):
 #0  syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
 #1  0x00007f74c987d238 in futex (uaddr=0x564087659b10, op=0, val=-1, timeout=0x0, uaddr2=0x0, val3=0) at ../include/urcu/futex.h:72
 #2  futex_async (uaddr=0x564087659b10, op=0, val=-1, timeout=0x0, uaddr2=0x0, val3=0) at ../include/urcu/futex.h:104
 #3  futex_wait (futex=0x564087659b10) at workqueue.c:136
 #4  0x00007f74c987ced2 in workqueue_thread (arg=0x564087659ad0) at workqueue.c:237
 #5  0x00007f74c9417609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #6  0x00007f74c933a163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

 Thread 1 (Thread 0x7f74c73cd300 (LWP 76034)):
 #0  0x00007f74c933a49e in epoll_wait (epfd=50, events=0x564087666880, maxevents=1, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
 #1  0x00005640870eafa6 in compat_epoll_wait (events=0x7ffc1fcbe280, timeout=-1, interruptible=false) at compat/poll.cpp:280
 #2  0x0000564087062244 in sessiond_wait_for_quit_pipe (timeout_ms=-1) at thread-utils.cpp:83
 #3  0x00005640870127dc in main (argc=1, argv=0x7ffc1fcbe668) at main.cpp:1921

Cause
=====

The event_pipe used to notify the notification poll loop is full and the
lttng_write call blocks with the locks for both the client and the
cmd_queue held.

Solution
========

Go back to using eventfd but without the use of EFD_SEMAPHORE (linux
2.6.30) to continue supporting kernel between 2.6.27 and 2.6.29.

The EFD_SEMAPHORE is emulated with a read, decrement, write as explained
by the initial committer of EFD_SEMAPHORE [1].

Known drawbacks
=========

This does not solve the actual block+lock problem but simply push it
back further. The lttng_write on the eventfd can block when reaching
UINT64_MAX. This would represent, at 1 command queued per ns (which is
ridiculous), ~584 years of queueing without a dequeue operation.

Reference
=======
[1] https://lwn.net/Articles/318151/

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: Ie749c4169708f57463fe3cfab2366f1015bae4e0

2 years agoFix: sessiond: inverted condition checking for empty hash table
Jérémie Galarneau [Wed, 6 Apr 2022 17:37:16 +0000 (13:37 -0400)] 
Fix: sessiond: inverted condition checking for empty hash table

I inverted a condition while reformating 2a6ebf6bd. This reverts the
condition to the intention of the original author. Mea culpa.

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

2 years agoFix: notification: kernel: consumption of event notification stalls
Jonathan Rajotte [Fri, 1 Apr 2022 12:41:17 +0000 (08:41 -0400)] 
Fix: notification: kernel: consumption of event notification stalls

Observed issue
==============

Using:

 lttng add-trigger --condition event-rule-matches --type kernel:tracepoint --name "sched_waking" --capture comm --action notify

The sessiond receives multiple event notifications from the kernel event
source then stop receiving despite the kernel event source buffer
being full.

Cause
=====

It turns out that the kernel event source, when reaching near the end of
its buffer capacity, raises the POLLPRI [1] flag and not the POLLIN
flag.

Solution
========

lttng-modules stretches a bit the usage of POLLPRI as defined by the man
page (man 2 poll):

 There is some exceptional condition on the  file  descriptor. Possibilities
 include:

 *  There is out-of-band data on a TCP socket (see tcp(7)).

 *  A  pseudoterminal  master  in  packet  mode has seen a state change on the
    slave (see ioctl_tty(2)).

 *  A cgroup.events file has been modified (see cgroups(7)).

Still, even if lttng-modules changes how it does things, lttng-tools
needs to support other lttng-modules versions.

Thus, add LPOLLPRI (EPOLLPRI/POLLPRI) to the event mask when dealing
with notification event sources.

Note
=====

In the future, during the poll loop we could also prioritize
event sources in POLLPRI 'state'.

Known drawbacks
=========

None.

References
==========

[1] https://github.com/lttng/lttng-modules/blob/c312bda00d2dc10ce5f6c1189acbefee5c6c8c6c/src/lttng-abi.c#L1169

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: Ieb428ef1037c8eb197b489a38a1ae5216ac63d4b

2 years agoFix: notification: assert on len > 0 for dropped notification message
Jonathan Rajotte [Thu, 31 Mar 2022 13:46:15 +0000 (09:46 -0400)] 
Fix: notification: assert on len > 0 for dropped notification message

Observed issue
==============

Using the notification client from
doc/examples/trigger-condition-event-matches/notification-client.cpp, an
assert is hit when the notification subsystem is under load.

 #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 #1  0x00007f69eab58859 in __GI_abort () at abort.c:79
 #2  0x00007f69eab58729 in __assert_fail_base (fmt=0x7f69eacee588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x7f69eae1d5dd "len > 0", file=0x7f69eae1d5cb "unix.cpp", line=179, function=<optimized out>) at assert.c:92
 #3  0x00007f69eab6a006 in __GI___assert_fail (assertion=0x7f69eae1d5dd "len > 0", file=0x7f69eae1d5cb "unix.cpp", line=179, function=0x7f69eae1d598 "ssize_t lttcomm_recv_unix_sock(int, void*, size_t)") at assert.c:101
 #4  0x00007f69eadd5fe6 in lttcomm_recv_unix_sock (sock=3, buf=0x55da9ecd5f89, len=0) at unix.cpp:179
 #5  0x00007f69ead7df3f in receive_message (channel=0x55da9ecd6ee0) at channel.cpp:64
 #6  0x00007f69ead7e478 in lttng_notification_channel_get_next_notification (channel=0x55da9ecd6ee0, _notification=0x7ffdefed2570) at channel.cpp:279
 #7  0x000055da9e0e742f in main (argc=2, argv=0x7ffdefed2698) at notification-client.cpp:506

 (gdb) frame
 #5  0x00007f69ead7df3f in receive_message (channel=0x55da9ecd6ee0) at channel.cpp:64
 64              ret = lttcomm_recv_unix_sock(channel->socket,

 (gdb) print msg
 $2 = {type = 5 '\005', size = 0, fds = 0, payload = 0x7ffdefed24a8 ""}

The msg type 5 is
`LTTNG_NOTIFICATION_CHANNEL_MESSAGE_TYPE_NOTIFICATION_DROPPED`

Cause
=====

The msg portion of a
`LTTNG_NOTIFICATION_CHANNEL_MESSAGE_TYPE_NOTIFICATION_DROPPED` is indeed
zero. There is no extra payload.

Solution
========

When the msg size is zero, skip the 'payload' reception phase.

Known drawbacks
=========

None.

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: Ibabb922d0e410c9902414a5eabbe04738861d772

2 years agoFix: example: print_notification is called on status all returned status
Jonathan Rajotte [Thu, 31 Mar 2022 13:44:24 +0000 (09:44 -0400)] 
Fix: example: print_notification is called on status all returned status

The notification should only be printed for
`LTTNG_NOTIFICATION_CHANNEL_STATUS_OK`.

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I5534406d8fbd5c0fff7013fda6335d54bef071a2

2 years agoFix: sessiond: assertion hit in ltt_sessions_ht_empty
Jonathan Rajotte [Mon, 28 Mar 2022 20:49:17 +0000 (16:49 -0400)] 
Fix: sessiond: assertion hit in ltt_sessions_ht_empty

Observed issue
==============

Scenario:

gdb lttng-sessiond
  set non-stop
  break rotation-thread.cpp:584
  ^ simulates a slow rotation thread or not scheduled thread.

lttng create test1
lttng enable-event -u -a
lttng start test1
lttng create test2
lttng enable-event -u -a
lttng start test2
lttng destroy test1
   This will hang on rotation pending checks on the CLI side.

In another shell:

lttng destroy test2
   This will hang on rotation pending checks on the CLI side.

Back to gdb
   thread 7
   continue

Results in:

 #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 #1  0x00007ffff786c859 in __GI_abort () at abort.c:79
 #2  0x00007ffff786c729 in __assert_fail_base (fmt=0x7ffff7a02588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x5555556bb148 "count == lttng_ht_get_count(ltt_sessions_ht_by_name)", file=0x5555556bae9f "session.cpp", line=395, function=<optimized out>) at assert.c:92
 #3  0x00007ffff787e006 in __GI___assert_fail (assertion=0x5555556bb148 "count == lttng_ht_get_count(ltt_sessions_ht_by_name)", file=0x5555556bae9f "session.cpp", line=395, function=0x5555556bb129 "int ltt_sessions_ht_empty()") at assert.c:101
 #4  0x0000555555586d59 in ltt_sessions_ht_empty () at session.cpp:395
 #5  0x0000555555586e53 in del_session_ht (ls=0x7fffdc000c30) at session.cpp:418
 #6  0x0000555555588a95 in session_release (ref=0x7fffdc001e50) at session.cpp:999
 #7  0x000055555558620f in urcu_ref_put (ref=0x7fffdc001e50, release=0x5555555886eb <session_release(urcu_ref*)>) at /home/joraj/lttng/master/install/include/urcu/ref.h:68
 #8  0x0000555555588c8f in session_put (session=0x7fffdc000c30) at session.cpp:1048
 #9  0x00005555555bf995 in handle_job_queue (handle=0x55555575d260, state=0x7fffeeffc240, queue=0x555555758960) at rotation-thread.cpp:612
 #10 0x00005555555c05da in thread_rotation (data=0x55555575d260) at rotation-thread.cpp:847
 #11 0x00005555555c3b1c in launch_thread (data=0x55555575d2f0) at thread.cpp:66
 #12 0x00007ffff7a46609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 #13 0x00007ffff7969163 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Other scenarios can lead to a similar backtrace when using the
`--no-wait` lttng destroy option.

Cause
=====

Since ed41e5709047ef545aa28082416e641e003b45e0 [1], hash table removal
for the session object for the `ltt_sessions_ht_by_name` and
`ltt_sessions_ht_by_name` are "decoupled". Removal from
`ltt_sessions_ht_by_name` is done early in `session_destroy()` while
removal from `ltt_sessions_ht_by_id` is done during `session_release` when
the last reference of a session object is released.

This can leads to `imbalances` between the size of the two hash tables
when multiple sessions are at play.

Solution
========

Rework `ltt_sessions_ht_empty()` to exit early when
`ltt_sessions_ht_by_id` is not empty. Perform a sanity check on
`ltt_sessions_ht_by_name` only when `ltt_sessions_ht_by_id` is empty.

Note
========

Ideally both hash tables' lifetime would be managed separately but it
seems easier in term of initialization to bundle them together for now
considering the limited scope of the `ltt_sessions_ht_by_name` hash
table.

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I66c459f80298f929add703ac977cccd1da6dd556

2 years agoFix: tests: missing _GNU_SOURCE for F_GETPIPE_SZ
Jonathan Rajotte [Thu, 31 Mar 2022 15:20:01 +0000 (11:20 -0400)] 
Fix: tests: missing _GNU_SOURCE for F_GETPIPE_SZ

Per man 2 fcntl:

  F_GETOWN_EX,  F_SETOWN_EX,  F_SETPIPE_SZ,  F_GETPIPE_SZ,  F_GETSIG,  F_SETSIG,
  F_NOTIFY,   F_GETLEASE,   and  F_SETLEASE  are  Linux-specific.   (Define  the
  _GNU_SOURCE macro to obtain these definitions.)

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I2b61dfb79ffa384dc2bab56cd3510ddc6ae21e85

2 years agoFix: compat: 'LTTNG_UST_ABI_PROCNAME_LEN' is undeclared
Jonathan Rajotte [Tue, 29 Mar 2022 20:31:44 +0000 (16:31 -0400)] 
Fix: compat: 'LTTNG_UST_ABI_PROCNAME_LEN' is undeclared

Observed issue
==============

On old systems, the `lttng_pthread_setname_np` function fallsback to
using the compat prctl version. In that context,
`LTTNG_UST_ABI_PROCNAME_LEN` is indeed not declared.

Solution
========

Use `LTTNG_PTHREAD_NAMELEN`. This mimics what is done in other versions
of `lttng_pthread_setname_np`.

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I73956cacd7b1e9400881b17b1cd89db2530d3a00

2 years agoFix: sessiond: cmd_enable_channel: negative error code used
Jérémie Galarneau [Fri, 25 Mar 2022 19:34:47 +0000 (15:34 -0400)] 
Fix: sessiond: cmd_enable_channel: negative error code used

A negative `lttng_error_code` value is returned (as an integer)
when a channel copy fails. Return a positive error code.

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

2 years agoUpdate version to v2.13.6 v2.13.6
Jérémie Galarneau [Tue, 29 Mar 2022 01:52:30 +0000 (21:52 -0400)] 
Update version to v2.13.6

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
2 years agoFix: hide symbols erroneously exported in 2.13.5
Michael Jeanson [Mon, 28 Mar 2022 22:25:14 +0000 (18:25 -0400)] 
Fix: hide symbols erroneously exported in 2.13.5

Change-Id: I508ac4791749240e511ef832a97e92878dd68df2
Signed-off-by: Michael Jeanson <mjeanson@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
2 years agoUpdate version to v2.13.5 v2.13.5
Jérémie Galarneau [Mon, 28 Mar 2022 16:11:03 +0000 (12:11 -0400)] 
Update version to v2.13.5

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
2 years agoFix: doc: action: wrong function documented for action_list destroy
Jonathan Rajotte [Thu, 24 Mar 2022 20:05:20 +0000 (16:05 -0400)] 
Fix: doc: action: wrong function documented for action_list destroy

The lttng_action_list_destroy function is internal.

API users must use `lttng_action_destroy()` to destroy the returned
object of `lttng_action_list_create()`.

Change-Id: Ic910efd07dd071f7e38e48d34a5e000b3f805729
Reported-by: Michael Jeason <mjeanson@efficios.com>
Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
2 years agoFix: lttng-elf: wrong error label used by error path
Jérémie Galarneau [Fri, 18 Mar 2022 14:58:03 +0000 (10:58 -0400)] 
Fix: lttng-elf: wrong error label used by error path

1486805 Resource leak
The system resource will not be reclaimed and reused, reducing the future availability of the resource.

In lttng_elf_get_symbol_offset: Leak of memory or pointers to system resources (CWE-404)

Reported-by: Coverity Scan
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I78b868773b389c2eaf3f1d45151fe9416b1fe447

2 years agoFix: use the correct endian compat macros
Michael Jeanson [Wed, 16 Mar 2022 15:40:52 +0000 (11:40 -0400)] 
Fix: use the correct endian compat macros

Document which variant of the endian macros our compat header guarantees
across all platforms and fix incorrect uses.

This was discovered with -Wundef on macOS.

Change-Id: Iaf442fe5887063661273ac2a00c9fa4015e83d5c
Signed-off-by: Michael Jeanson <mjeanson@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
2 years agoFix: tests: uninitialized lttng_payload
Jérémie Galarneau [Wed, 16 Mar 2022 21:39:07 +0000 (17:39 -0400)] 
Fix: tests: uninitialized lttng_payload

1474980 Uninitialized pointer read
Incorrect values could be read from, or even written to, an arbitrary memory location, causing incorrect computations.

In test_event_rule_userspace_probe(): Reads an uninitialized pointer or its target (CWE-457)

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

2 years agoFix: sessiond: ust-app: uninitialized name logged on stream copy failure
Jérémie Galarneau [Wed, 16 Mar 2022 21:35:43 +0000 (17:35 -0400)] 
Fix: sessiond: ust-app: uninitialized name logged on stream copy failure

1466302 Uninitialized scalar variable
The variable will contain an arbitrary value left from earlier computations.

In send_channel_uid_to_ust(buffer_reg_channel *, ust_app *, ust_app_session *, ust_app_channel *): Use of an uninitialized variable (CWE-457)

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

2 years agoFix: lttng-elf: untrusted entry size divisor
Jérémie Galarneau [Wed, 16 Mar 2022 21:29:11 +0000 (17:29 -0400)] 
Fix: lttng-elf: untrusted entry size divisor

1405557 Untrusted divisor
The divisor could be controlled by an attacker, who could cause a division by zero.

In lttng_elf_get_symbol_offset: An unscrutinized value from an untrusted source used as a divisor (CWE-369)

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

This page took 0.064184 seconds and 4 git commands to generate.