lttng-tools:stable-2.13

Last commit made on 2024-04-05
Get this branch:
git clone -b stable-2.13 https://git.launchpad.net/lttng-tools

Branch merges

Branch information

Name:
stable-2.13
Repository:
lp:lttng-tools

Recent commits

e6681c6... by =?utf-8?q?J=C3=A9r=C3=A9mie_Galarneau?= <email address hidden>

Update version to v2.13.13

Signed-off-by: Jérémie Galarneau <email address hidden>

bd60b0d... by =?utf-8?q?J=C3=A9r=C3=A9mie_Galarneau?= <email address hidden>

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 <email address hidden>
Change-Id: I9556cad5fd22cbbcba0a2d6716d46cd963c7778f

6601185... by =?utf-8?q?J=C3=A9r=C3=A9mie_Galarneau?= <email address hidden>

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 <email address hidden>
Change-Id: I9768408581fc6a06f47892850a3a91669df35188

a73d949... by =?utf-8?q?J=C3=A9r=C3=A9mie_Galarneau?= <email address hidden>

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 <email address hidden>
Change-Id: Ib6a04969dd82857e3b8ac2ca2545cfb098b2d04f

c0e55b9... by =?utf-8?q?J=C3=A9r=C3=A9mie_Galarneau?= <email address hidden>

Update version to v2.13.12

Signed-off-by: Jérémie Galarneau <email address hidden>

53f0972... by orbea <email address hidden>

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 <email address hidden>
Signed-off-by: Jérémie Galarneau <email address hidden>
Change-Id: I03102ed78af835daa9b9a5836c2979a5f5d4bd8c

5d2369e... by =?utf-8?q?J=C3=A9r=C3=A9mie_Galarneau?= <email address hidden>

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 <email address hidden>

883b91c... by =?utf-8?q?J=C3=A9r=C3=A9mie_Galarneau?= <email address hidden>

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 <email address hidden>

3b67e33... by Kienan Stewart <email address hidden>

tests: Fix typo in tests/regression/kernel/test_ns_contexts

Change-Id: I50e6027f87b6d4a08a61337782356f8fbc6a64ae
Signed-off-by: Kienan Stewart <email address hidden>
Signed-off-by: Jérémie Galarneau <email address hidden>

cea28ac... by =?utf-8?q?J=C3=A9r=C3=A9mie_Galarneau?= <email address hidden>

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 <email address hidden>
Signed-off-by: Jérémie Galarneau <email address hidden>
Change-Id: Ic505ff0671c321f808050831ef2b7152cdbf4b8a