lttng-tools.git
4 years agoTests: live/test_{lttng_,}kernel: use lttng_test_filter_event instead of sched_switch
Francis Deslauriers [Thu, 9 Jul 2020 20:44:32 +0000 (16:44 -0400)] 
Tests: live/test_{lttng_,}kernel: use lttng_test_filter_event instead of sched_switch

Background
==========
These tests currently rely on system load (the `sched_switch` event) to
generate trace data.

Issue
=====
This is can be problematic for the `test_kernel`
test case because it has a fixed sized buffer to store the trace:
  #define mmap_size 524288

This caused this test failure to randomly happen on my machine:
  ok 7 - Get one index per stream
  # mmap_size not big enough
  not ok 8 - Get one data packet for stream 0, offset 0, len 4096
  #     Failed test (live_test.c:main() at line 709)
  [error] Error detaching viewer session
  not ok 9 - Detach viewer session
  #     Failed test (live_test.c:main() at line 715)

Solution
========
Using the `lttng_test_filter_event` event to control the size and
number of the event expected in the trace rather then depending on how
many Electon apps are currently fighting for my CPUs.

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I15d500d5becf9c5e526ae11ff0b2a2f4f6b753ac

4 years agoFix: consumer: Move sanity check within `consumer_subbuffer` functions
Francis Deslauriers [Thu, 9 Jul 2020 21:38:17 +0000 (17:38 -0400)] 
Fix: consumer: Move sanity check within `consumer_subbuffer` functions

The sanity check on the number bytes written by the `consumer_subbuffer`
callback was not correct channel configured in the splice output type in
a live session.

To simplify this, move checks in the callback themselves so they can be
specialized.

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I4e47a305860684c461ba7ffffd5e3bb3a21990b0

4 years agoCleanup: typo in DBG() statements
Francis Deslauriers [Tue, 7 Jul 2020 16:27:34 +0000 (12:27 -0400)] 
Cleanup: typo in DBG() statements

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I19518292b4e7bd9319cafa05f08c1854f7693168

4 years agoFix: relayd: send_viewer_streams sends stack data in padding
Jérémie Galarneau [Thu, 16 Jul 2020 16:39:20 +0000 (12:39 -0400)] 
Fix: relayd: send_viewer_streams sends stack data in padding

A single stack-allocated instance of `struct lttng_viewer_stream` is
used to send the various streams to the live viewer. This structure
contains a path and channel name which remain uninitialized beyond the
null terminator.

The structure is zeroed on every iteration.

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

4 years agoFix: kconsumer: missing wait for metadata thread in do_sync_metadata
Jérémie Galarneau [Tue, 7 Jul 2020 22:55:19 +0000 (18:55 -0400)] 
Fix: kconsumer: missing wait for metadata thread in do_sync_metadata

The `do_sync_metadata` function is invoked everytime a data sub-buffer
is consumed in live mode.

In the user space case, lttng_ustconsumer_sync_metadata() returns
EAGAIN (positive) when there is new metadata to consume. This causes the
"metadata rendez-vous" synchronization to take place. However, the
kernel variant of this function returns 0 when there is new data to
consume, causing the "rendez-vous" to be skipped.

I have not observed an issue caused by this first-hand, but the check
appears bogus and skips over an essential synchronization step.

This check has been in place since at least 2013, although the callees
and their return values may have changed at some point in the past.

Solution
--------

The user space and kernel code paths mix various return code conventions
(negative errno, positive errno, 0/-1) which makes it difficult to
understand the final return codes and most likely lead to this confusion
in the first place.

Moreover, returning EAGAIN to indicate that data is ready to be consumed
is not appropriate in view of the existing conventions in the code base.

An explicit `enum sync_metadata_status` is returned by the domains'
sync_metadata operations which allows the common code to handle the
various conditions in a straight-forward manner and for the
"rendez-vous" to take place in the kernel case.

Reported-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: Ib022eee97054c0b376853dd05593e3b94bc9a8ca

4 years agoFix: tests: interrupting get_next_notification causes test to fail
Jérémie Galarneau [Thu, 9 Jul 2020 15:44:47 +0000 (11:44 -0400)] 
Fix: tests: interrupting get_next_notification causes test to fail

Attaching a debugger to the `notification` test application causes
tests to fail when the application is waiting for a notification
as the function will return an `INTERRUPTED` status code.

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

4 years agoFix: consumer.c: wrong order of parameter in `DBG()` statement
Francis Deslauriers [Mon, 6 Jul 2020 16:31:00 +0000 (12:31 -0400)] 
Fix: consumer.c: wrong order of parameter in `DBG()` statement

This debug statement is printing the padded_subbuf_size as the
subbuf_size and inversely.

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Change-Id: I8c719e21999ffaa8df2de6089b65b90f1b211a72
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: kernel metadata file outside of kernel/ directory
Jérémie Galarneau [Mon, 29 Jun 2020 21:29:03 +0000 (17:29 -0400)] 
Fix: kernel metadata file outside of kernel/ directory

3ef395a9, a backport of a2814ea, introduces a regression that
causes the kernel trace metadata file to be created outside of
the "kernel" domain sub-directory.

master and stable-2.12 no longer need the domain sub-directory
to be passed to the consumer daemon. However, it was still used
in the 2.11 release.

Fixes #1275

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

4 years agoFix: consumer: dangling chunk on buffer allocation failure
Jonathan Rajotte [Thu, 25 Jun 2020 20:52:33 +0000 (16:52 -0400)] 
Fix: consumer: dangling chunk on buffer allocation failure

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

Using docker the /dev/shm mount size is 64 MB by default. On system
with many threads (256), combined with the default subbuffer count and
subbufer size, allocation failure of the subbuffer is inevitable since
the /dev/shm mountpoint is too small.

When a user try to destroy the problematic session, the destroy
command hangs.

  # Force the size of /dev/shm, make sure to remount it to its orignal
  # size when done testing.
  sudo mount -o remount,size=1G /dev/shm
  lttng create
  lttng enable-channel --subbuf-size 500M -u test
  lttng enable-event -u -a -c test
  lttng start
  # Run an app;
  ../lttng-ust/doc/examples/easy-ust/sample

lttng-sessiond should output:
  Error: ask_channel_creation consumer command failed
  Error: Error creating UST channel "test" on the consumer daemon

  lttng destroy

Output hang:
  Destroying session auto-20200626-112733..........

Cause
=====

The hang is caused by the check of ongoing rotation which never finishes.

The consumer reports that the trace chunk still exists. This is caused
by an imbalance of the reference count for the trace chunk on close.

This is caused by a missing lttng_trace_chunk_put in destroy_channel
which is called on the error path for the consumer channel creation.

Solution
========

Call lttng_trace_chunk_put if the channel->trace_chunk is assigned
inside the channel_destroy function.

The error handling in ust_app_channel_create is also reworked since the
return value for ust_app_channel_send would be squashed for scenario
where contexts are present.

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: Idf19b1d306cf347619ccfda1621d91d8303f3c7c

4 years agoFix: consumerd: uninitialized written_bytes on no-data sleep
Jérémie Galarneau [Wed, 17 Jun 2020 23:13:50 +0000 (19:13 -0400)] 
Fix: consumerd: uninitialized written_bytes on no-data sleep

e66d26f51 introduces a jump to a label which causes `written_bytes`
(the return value) to not be initialized.

written_bytes may be used uninitialized in this function [-Wmaybe-uninitialized]

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

4 years agoBuild fix: consumerd misnamed label
Jérémie Galarneau [Wed, 17 Jun 2020 22:54:09 +0000 (18:54 -0400)] 
Build fix: consumerd misnamed label

`sleep_stream` label was changed from `stream_sleep` as part of
a fixup/rebase which didn't make it into the master branch.

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

4 years agoconsumerd: on_sleep not called on stream when no data is available
Jérémie Galarneau [Wed, 17 Jun 2020 22:27:52 +0000 (18:27 -0400)] 
consumerd: on_sleep not called on stream when no data is available

The `on_sleep` stream operation is not invoked when a stream's `get`
operation returns ENODATA (no data available).

Since this is not an error, the normal steps of the consumption loops
should be assumed.

Not marked as a fix as this is not problematic right now. However, it
could prove misleading in the future.

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

4 years agoFix: invalid discarded events on start/stop without event production
Jonathan Rajotte [Wed, 17 Jun 2020 19:55:36 +0000 (15:55 -0400)] 
Fix: invalid discarded events on start/stop without event production

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

On consecutive start/stop command sequence the reported discarded event
count is N * CPU, where N is the number of start/stop pair executed.

Note that no event generation occurred between each start/stop pair.

    lttng start
    lttng stop
    Tracing stopped for session auto-20200616-094338
    lttng start
    lttng stop
    Waiting for data availability
    Warning: 4 events were discarded, please refer to the documentation on channel configuration.
    Tracing stopped for session auto-20200616-094338
    lttng start
    lttng stop
    Waiting for data availability
    Warning: 8 events were discarded, please refer to the documentation on channel configuration.
    Tracing stopped for session auto-20200616-094338

The issue was bisected down to:
  commit 6f9449c22eef59294cf1e1dc3610a5cbf14baec0 (HEAD)
  Author: Jérémie Galarneau <jeremie.galarneau@efficios.com>
  Date:   Sun May 10 18:00:26 2020 -0400

  consumerd: refactor: split read_subbuf into sub-operations
  [...]

Cause
=====

The discarded event local variable, in `consumer_stream_update_stats()`
is initialized with the subbuffer sequence count instead of the
subbuffer discarded event count.

Solution
========

Use the subbuffer discarded event count to initialized the variable.

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: I5ff213d0464cdb591b550f6e610bf15085b18888

4 years agotests: truncate metadata file for regenerate metadata test
Jonathan Rajotte [Wed, 17 Jun 2020 19:05:48 +0000 (15:05 -0400)] 
tests: truncate metadata file for regenerate metadata test

Truncating the metadata file ensure that we test the effect of the
regenerate metadata command. Otherwise we simply test the command
return.

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

4 years agoFix: consumerd: user space metadata not regenerated
Jérémie Galarneau [Wed, 17 Jun 2020 16:59:24 +0000 (12:59 -0400)] 
Fix: consumerd: user space metadata not regenerated

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

The LTTng-IVC tests fail on the `regenerate metadata` tests which
essentially:
  - Setups a user space session
  - Enables events
  - Traces an application
  - Stops tracing
  - Validates the trace
  - Truncates the metadata file (empties it)
  - Starts tracing
  - Regenerates the metadata
  - Stops the session
  - Validates the trace

The last trace validation step fails on an empty file (locally) or
a garbled file (remote).

The in-tree tests did no catch any of this since they essentially don't
test much. They verify that the command works (returns 0) but do not
validate any of its effects.

The issue was bisected down to:
  commit 6f9449c22eef59294cf1e1dc3610a5cbf14baec0 (HEAD)
  Author: Jérémie Galarneau <jeremie.galarneau@efficios.com>
  Date:   Sun May 10 18:00:26 2020 -0400

  consumerd: refactor: split read_subbuf into sub-operations
  [...]

Cause
=====

The commit that introduced the issue refactored the sub-buffer
consumption loop to eliminate code duplications between the user space
and kernel consumer daemons.

In doing so, it eleminated a metadata version check from the consumption
path.

The consumption of a metadata sub-buffer follows those relevant
high-level steps:
  - `get` the sub-buffer
    - /!\ user space specific /!\
      - if the `get` fails, attempt to flush the metadata cache's
        contents to the ring-buffer
  - populate `stream_subbuffer` properties (size, version, etc.)
  - check the sub-buffer's version against the last known metadata
    version (pre-consume step)
    - if they don't match, a metadata regeneration occurred: reset the
      metadata consumed position
  - consume (actual write/send)
  - `put` sub-buffer
  [...]

As shown above, the user space consumer must manage the flushing of the
metadata cache explicitly as opposed to the kernel domain for which the
tracer performs the flushing implicitly through the `get` operation.

When the user space consumer encounters a `get` failure, it checks
if all the metadata cache was flushed (consumed position != cache size),
and flushes any remaining contents.

However, the metadata version could have changed and yielded an
identical cache size: a regeneration without any new metadata will
yield the same cache size.

Since 6f9449c22, the metadata version check is only performed after
a successful `get`. This means that after a regeneration, `get`
never succeeds (there is seemingly nothing to consume), and the
metadata version check is never performed.

Therefore, the metadata stream is never put in the `reset` mode,
effectively not regenerating the data.

Note that producing new metadata (e.g. a newly registering app
announcing new events) would work around the problem here.

Solution
========

Add a metadata version check when failing to `get` a metadata
sub-buffer. This is done in `commit_one_metadata_packet()` when the
cache size is seen to be equal to the consumed position.

When this occurs, `consumer_stream_metadata_set_version()`, a new
consumer stream method, is invoked which sets the new metadata version,
sets the `reset` flag, and discards any previously bucketized metadata.

The metadata cache's consumed position is also reset, allowing the
cache flush to take place.

`metadata_stream_reset_cache()` is renamed to
`metadata_stream_reset_cache_consumed_position()` since its name is
misleading and since it is used as part of the fix.

Know drawbacks
==============

None.

Change-Id: I3b933c8293f409f860074bd49bebd8d1248b6341
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Reported-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
4 years agoFix: tests: output_dir contains the consumerd pipe
Jonathan Rajotte [Wed, 27 May 2020 22:49:25 +0000 (18:49 -0400)] 
Fix: tests: output_dir contains the consumerd pipe

Prevents failure on teardown. Otherwise, testpoint fails when removing
the consumerd pipe.

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

4 years agoFix: unix: don't PERROR on EAGAIN for non-blocking sockets
Jérémie Galarneau [Thu, 13 Feb 2020 23:21:08 +0000 (18:21 -0500)] 
Fix: unix: don't PERROR on EAGAIN for non-blocking sockets

EAGAIN is expected on non-blocking UNIX socket operations. This
results in a spammy sessiond log.

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I58ba711dad193b8d6849501f3e090797813e18ac
Depends-on: lttng-ust: I5a800fc92e588c2a6a0e26282b0ad5f31c044479

4 years agoFix: sessiond: sessiond and agent deadlock on destroy
Jérémie Galarneau [Tue, 21 Apr 2020 21:08:10 +0000 (17:08 -0400)] 
Fix: sessiond: sessiond and agent deadlock on destroy

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

While running the out-of-tree java agent tests [1], the session daemon
and agent often end up in a deadlock.

Attaching gdb to the session daemon, we can see that two threads are
blocked in an intriguing state.

Thread 13 (Thread 0x7f89027fc700 (LWP 9636)):
 #0  0x00007f891e81a4cf in __lll_lock_wait () from /usr/lib/libpthread.so.0
 #1  0x00007f891e812e03 in pthread_mutex_lock () from /usr/lib/libpthread.so.0
 #2  0x000055637f1fbd92 in session_lock_list () at session.c:156
 #3  0x000055637f25dc47 in update_agent_app (app=0x7f88ec003480) at agent-thread.c:56
 #4  0x000055637f25ec0a in thread_agent_management (data=0x556380cd2400) at agent-thread.c:426
 #5  0x000055637f22fb3a in launch_thread (data=0x556380cd24a0) at thread.c:65
 #6  0x00007f891e81046f in start_thread () from /usr/lib/libpthread.so.0
 #7  0x00007f891e7203d3 in clone () from /usr/lib/libc.so.6

Thread 8 (Thread 0x7f8919309700 (LWP 9631)):
 #0  0x00007f891e81b44d in recvmsg () from /usr/lib/libpthread.so.0
 #1  0x000055637f267847 in lttcomm_recvmsg_inet_sock (sock=0x7f88ec0033c0, buf=0x7f89192f5d5c, len=4, flags=0) at inet.c:367
 #2  0x000055637f2146c6 in recv_reply (sock=0x7f88ec0033c0, buf=0x7f89192f5d5c, size=4) at agent.c:275
 #3  0x000055637f215202 in app_context_op (app=0x7f88ec003400, ctx=0x7f8908020900, cmd=AGENT_CMD_APP_CTX_DISABLE) at agent.c:552
 #4  0x000055637f215c2d in disable_context (ctx=0x7f8908020900, domain=LTTNG_DOMAIN_JUL) at agent.c:841
 #5  0x000055637f217480 in agent_destroy (agt=0x7f890801dc20) at agent.c:1326
 #6  0x000055637f243448 in trace_ust_destroy_session (session=0x7f8908004010) at trace-ust.c:1408
 #7  0x000055637f1fd775 in session_release (ref=0x7f8908001e70) at session.c:873
 #8  0x000055637f1fb9ac in urcu_ref_put (ref=0x7f8908001e70, release=0x55637f1fd62a <session_release>) at /usr/include/urcu/ref.h:68
 #9  0x000055637f1fdad2 in session_put (session=0x7f8908000d10) at session.c:942
 #10 0x000055637f2369e6 in process_client_msg (cmd_ctx=0x7f890800e6e0, sock=0x7f8919308560, sock_error=0x7f8919308564) at client.c:2102
 #11 0x000055637f2375ab in thread_manage_clients (data=0x556380cd1840) at client.c:2347
 #12 0x000055637f22fb3a in launch_thread (data=0x556380cd18b0) at thread.c:65
 #13 0x00007f891e81046f in start_thread () from /usr/lib/libpthread.so.0
 #14 0x00007f891e7203d3 in clone () from /usr/lib/libc.so.6

T8 is holding session list lock while the cmd_destroy_session
command is being processed. More specifically, it is attempting
to destroy an "agent_context" by communicating with an "agent"
application.

Meanwhile, T13 is still registering that same "agent" application.

Cause
-----

The deadlock itself is pretty simple to understand.

The "agent thread" (T13) has the responsability of accepting new agent
application connections. When such a connection occurs, the thread
creates a new `agent_app` instance and sends the current sessions'
configuration (i.e. their event rules and contexts) to the agent
application. When that "update" is complete, a "registration done"
message is sent to the new agent application.

From the stacktrace above, we can see that T13 is attempting to update
the agent application with its initial configuration, but it is
blocked on the acquisition of the session list lock. The application's
agent is also blocked since it is waiting for the "registration done"
message before allowing tracing to proceed (not shown here, but seen
in the test logs).

Meanwhile, T8 is holding the session list lock while destroying a
session. This is expected as all client commands are executed with
this lock held. It is, amongst other reasons, used to serialize
changes to the sessions' configuration and configuration updates sent
to the tracers (i.e. because new apps appear or to keep existing
tracers in sync with the users' session configuration).

The question becomes: why is T8 tearing down an application that is
not yet registered?

First, inspecting `agent_app` immediately shows that this structure
has no built-in synchronization mechanism. Therefore, the fact that
two threads are accessing it at the same time raises a big red flag.

Speculating on the intentions of the original design, my intuition is
that the "agent_management" thread's role is limited to instantiating
an `agent_app` and synchronizing it with the various sessions'
configuration. Once that synchronization is performed, the agent
application should be published and never accessed again by the "agent
thread".

Configuration updates (i.e. new event rules, contexts) are then sent
synchronously as they are requested by a client in the context of the
client thread. Those updates are performed while holding the session
list lock.

Hence, there is only one thread that should manipulate the agent
application at any given time making an explicit `agent_app` lock
unnecessary.

Overall, this would echo what is done when a 'user space tracer'
application registers to the session daemon (see dispatch.c:368).

Evidently this isn't what is happening here.

The agent thread creates the `agent_app`, publishes it, and then
performs an "agent app update" (sending the configuration) while
holding the session list lock. This means that there is a window where
an agent application is visible to the other threads, yet has not been
properly registered.

Solution
--------

The acquisition of the session list lock is moved outside of
update_agent_app() to allow the "agent thread" to hold the session
list lock during the "configuration update" phase of the agent
application registration.

Essentially, the sequence of operation changes from:

- Agent tcp connection established
- call handle_registration()
  - agent version check
  - allocation of agent_app instance
  - new agent_add is published through the global agent_apps_ht_by_sock
    hashtable
    ***
    it is now reachable by all other threads without any form of
    exclusivity synchronization.
    ***
- update_agent_app
  - acquire session list lock
  - iterate over sessions
    - send configuration
  - release session list lock
- send registration done

to:

- Agent tcp connection established
- call accept_agent_registration()
  - agent version check
- allocation of agent_app instance
- acquire session list lock
- update_agent_app
  - iterate over sessions
    - send configuration
- send registration done
- new agent_add is published through the global agent_apps_ht_by_sock
  hashtable
- release session list lock

Links
-----

[1] https://github.com/lttng/lttng-ust-java-tests

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

4 years agoFix: incorrect specifier %lu used with size_t argument
Jérémie Galarneau [Wed, 27 May 2020 15:27:26 +0000 (11:27 -0400)] 
Fix: incorrect specifier %lu used with size_t argument

Fixes the following warning on 32-bit targets:

libtool: compile:  gcc -DHAVE_CONFIG_H -I../../../include -I../../../include -I../../../src -include config.h -I/build/include -I/home/jenkins/workspace/lttng-tools_master_portbuild/arch/armhf/babeltrace_version/stable-1.5/build/std/conf/std/liburcu_version/master/test_type/base/deps/build/include -Wall -Wno-incomplete-setjmp-declaration -Wdiscarded-qualifiers -Wmissing-declarations -Wmissing-prototypes -Wmissing-parameter-type -fno-strict-aliasing -pthread -g -O2 -MT consumer-stream.lo -MD -MP -MF .deps/consumer-stream.Tpo -c consumer-stream.c  -fPIC -DPIC -o .libs/consumer-stream.o
In file included from ../../../src/common/common.h:12:0,
                 from consumer.c:25:
consumer.c: In function ‘lttng_consumer_on_read_subbuffer_mmap’:
../../../src/common/error.h:161:35: warning: format ‘%lu’ expects argument of type ‘long unsigned int’, but argument 7 has type ‘size_t {aka unsigned int}’ [-Wformat=]
 #define DBG(fmt, args...) _ERRMSG("DEBUG1", PRINT_DBG, fmt, ## args)
                                   ^
../../../src/common/error.h:136:51: note: in definition of macro ‘__lttng_print’
    fprintf((type) == PRINT_MSG ? stdout : stderr, fmt, ## args); \
                                                   ^~~
../../../src/common/error.h:161:27: note: in expansion of macro ‘_ERRMSG’
 #define DBG(fmt, args...) _ERRMSG("DEBUG1", PRINT_DBG, fmt, ## args)
                           ^~~~~~~
consumer.c:1688:2: note: in expansion of macro ‘DBG’
  DBG("Consumer mmap write() ret %zd (len %lu)", ret, write_len);
  ^~~

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

4 years agoFix: consumerd: live client receives incomplete metadata
Jérémie Galarneau [Thu, 14 May 2020 18:24:17 +0000 (14:24 -0400)] 
Fix: consumerd: live client receives incomplete metadata

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

Babeltrace 1.5.x and Babeltrace 2.x can both report errors (albeit
differently) when using the "lttng-live" protocol that imply that the
metadata they received is incomplete.

For instance, babeltrace 1.5.3 reports the following error:

```
[error] Error creating AST
[error] [Context] Cannot open_mmap_trace of format ctf.
[error] Error adding trace
[warning] [Context] Cannot open_trace of format lttng-live at path net://localhost:xxxx/host/session/live_session.
[warning] [Context] cannot open trace "net://localhost:xxxx/host/session/live_session" for reading.
[error] opening trace "net://localhost:xxxx/host/session/live_session" for reading.
[error] none of the specified trace paths could be opened.
```

While debugging both viewers, I noticed that both were attempting to
receive the available metadata before consuming the "data" streams'
content.

Typically, the following exchange between the relay daemon and the
lttng-live client occurs when the problem is observed:

bt lttng-live:
    emits LTTNG_VIEWER_GET_METADATA command
relayd:
    returns LTTNG_VIEWER_METADATA_OK, len = 4096 (default packet size)
bt lttng-live:
    consume 4096 bytes of metadata
    emits LTTNG_VIEWER_GET_METADATA command
relayd:
    returns LTTNG_VIEWER_NO_NEW_METADATA

When the lttng-live client receives the LTTNG_VIEWER_NO_NEW_METADATA
status code, it attempts to parse all the metadata it has received
since the last LTTNG_VIEWER_NO_NEW_METADATA reply. In effect, it is
expected that this forms a logical unit of metadata that is parseable
on its own.

If this is the first time metadata is received for that trace, the
metadata is expected to contain a trace declaration, packet header
declaration, etc.

If metadata was already received, it is expected that the newly parsed
declarations can be "appended" to the existing trace schema.

It appears that the relay daemon sends the
LTTNG_VIEWER_NO_NEW_METADATA while the metadata it has sent up to that
point is not parseable on its own.

The live protocol description does not require or imply that a viewer
should attempt to parse metadata packets until it hopefully succeeds
at some point. Anyhow:
  1) This would make it impossible for a live viewer to correctly
  handle a corrupted metadata stream beyond retrying forever,
  2) This behaviour is not implemented by the two reference
  implementations of the protocol.

Cause
=====

The relay daemon provides a guarantee that it will send any available
metadata before allowing a data stream packet to be served to the
client.

In other words, a client requesting a data packet will receive the
LTTNG_VIEWER_FLAG_NEW_METADATA status code (and no data) if it
attempts to get a data stream packet while the relay daemon has
metadata already available.

This guarantee is properly enforced as far as I can tell. However,
looking at the consumer daemon implementation, it appears that
metadata packets are sent as soon as they are available.

A metadata packet is not guaranteed to be parseable on its own. For
instance, it can end in the middle the an event declaration.

Hence, this hints at a race involving the tracer, the consumer daemon,
the relay daemon, and the lttng-live client.

Consider the following scenario:
  - Metadata packets (sub-buffers) are configured to be 4kB in size,
  - a large number of kernel events are enabled (e.g. --kernel --all),
  - the network connection between the consumer and relay daemons is
    slow

1) The kernel tracer will produce enough TSDL metadata to fill the
   first sub-buffer of the "metadata" ring-buffer and signal the
   consumer daemon that a buffer is ready. The tracer then starts
   writing the remaining data in the following available sub-buffers.

2) The consumer daemon metadata thread is woken up and consumes the
   first metadata sub-buffer and sends it to the relay daemon.

3) A live client establishes an lttng-live connection to the relay
   daemon and attempts to consume the available metadata. It receives
   the first packet and, since the relay daemon doesn't know about any
   follow-up metadata, receives LTTNG_VIEWER_NO_NEW_METADATA on the
   next attempt.

4) Having received LTTNG_VIEWER_NO_NEW_METADATA, the lttng-live client
   attempts to parse the metadata it has received and fails.

This scenario is easy to reproduce by inserting a "sleep(1)" at
src/bin/lttng-relayd/main.c:1978 (as of this revision). This simulates
a relay daemon that would be slow to receive/process metadata packets
from the consumer daemon.

This problem similarly applies to the user space tracer.

Solution
========

Having no knowledge of TSDL, the relay daemon can't "bundle" packets
of metadata until they form a "parseable unit" to send to the consumer
daemon.

To provide the parseability guarantee expected by the viewers, and by
the relay daemon implicitly, we need to ensure that the consumer
daemons only send "parseable units" of metadata to the relay daemon.

Unfortunately, the consumer daemons do not know how to parse TSDL
either. In fact, only the metadata producers are able to provide the
boundaries of the "parseable units" of metadata.

The general idea of the fix is to accumulate metadata up to a point
where a "parseable unit" boundary has been identified and send that
content in one request to the relay daemon. Note that the solution
described here only concerns the live mode. In other cases, the
mechanisms described are simply bypassed.

A "metadata bucket" is added to lttng_consumer_stream when it is
created from a live channel. This bucket is filled until the
consumption position reaches the "parseable unit" end position.

A refresher about the handling of metadata in live mode
-------------------------------------------------------

Three "events" are of interest here and can cause metadata to be
consumed more or less indirectly:
  1) A metadata packet is closed, causing the metadata thread to wake
     up
  2) The live timer expires
  3) A data sub-buffer is closed, causing the data thread to wake-up

1) The first case is simple and happens regardless of whether or not
   the tracing session is in live mode or not. Metadata is always
   consumed by the metadata thread in the same way. However, this
   scenario can be "caused" by (2) and (3). See [1]. A sub-buffer is
   "acquired" from the metadata ring-buffer and sent to the relayd
   daemon as the payload of a "RELAYD_SEND_METADATA" command.

2) When the live timer expires [2], the 'check_stream' function is
   called on all data streams of the session. As its name clearly
   implies, this function is responsible for flushing all streams or
   sending a "live beacon" (called an "empty index" in the code) if
   there is no data to flush. Any flushed data will result in (3).

3) When a data sub-buffer is ready to be consumed, [1] is invoked
   by the data thread. This function acquires a sub-buffer and sends
   it to the relay daemon through the data connection.

   Then, an important synchronization step takes place. The index of
   the newly-sent packet will be sent through the control
   connection. The relay daemon waits for both the data packet and its
   matching index before making the new packet visible to live
   viewers.

   Since a data packet could contain data that requires "newer"
   metadata to be decoded, the data thread flushes the metadata stream
   and enters a "waiting" phase to pause until all metadata present in
   the metadata ring buffer has been consumed [3].

   At the end of this waiting phase, the data thread sends the data
   packet's index to the relay daemon, allowing the relayd to make it
   visible to its live clients.

How to identify a "parseable unit" boundary?
--------------------------------------------

In the case of the kernel domain, the kernel tracer produces the
actual TSDL descriptions directly. The TSDL metadata is serialized to
a metadata cache and is flushed "just in time" to the metadata
ring-buffer when a "get next" operation is performed.

There is no way, from user space, to query whether or not the metadata
cache of the kernel tracer is empty. Hence, a new
RING_RING_BUFFER_GET_NEXT_SUBBUF_METADATA_CHECK command was added to
query whether or not the kernel tracer's metadata cache is empty when
acquiring a sub-buffer.

This allows the consumer daemon to identify a "coherent" position in
the metadata stream that is safe to use as a "parseable unit"
boundary.

As for the user space domain, since the session daemon is responsible
for generating the TSDL representation of the metadata, there is no
need to change LTTng-ust APIs.

The session daemon generates coherent units of metadata and adds them
to its "registry" at once (protected by the registry's lock). It then
flushes the contents to the consumer daemon and waits for that data to
be consumed before proceeding further.

On the consumer daemon side, the metadata cache is filled with the
newly-produced contents. This is done atomically with respect to
accesses to the metadata cache as all accesses happen through a
dedicated metadata cache lock.

When the consumer's metadata polling thread is woken-up, it will
attempt to acquire (`get_next`) a sub-buffer from the metadata stream
ring-buffer. If it fails, it will flush a sub-buffer's worth of
metadata to the ring-buffer and attempt to acquire a sub-buffer again.

At this point, it is possible to determine if that sub-buffer is the
last one of a parseable metadata unit: the cache must be empty and the
ring-buffer must be empty following the consumption of this
sub-buffer. When those conditions are met, the resulting metadata
`stream_subbuffer` is tagged as being `coherent`.

Metadata bucket
---------------

A helper interface, metadata_bucket, is introduced as part of this
fix. A metadata_bucket is `fill`ed with `stream_subbuffer`s, and is
eventually `flushed` when it is filled by a `coherent` sub-buffer.

As older versions of LTTng-modules must remain supported, this new
helper is not used when the
RING_RING_BUFFER_GET_NEXT_SUBBUF_METADATA_CHECK operation is not
available. When the operation is available, the metadata stream's
bucketization is enabled, causing a bucket to be created and the
`consume` callback to be swapped.

The `consume` callback of the metadata streams is replaced by a new
implementation when the metadata bucketization is activated on the
stream. This implementation returns the padded size of the consumed
sub-buffer when they could be added to the bucket. When the bucket is
flushed, the regular `mmap`-based consumption function is called with
the bucket's contents.

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

This implementation causes the consumer daemon to buffer the whole
initial unit of metadata before sending it. In practice, this is not
expected to be a problem since the largest metadata files we have seen
in real use are a couple of megabytes wide.

Beyond the (temporary) memory use, this causes the metadata thread to
block while this potentially large chunk of metadata is sent (rather
than blocking while sending 4kb at a time).

The second point is just a consequence of existing shortcomings of the
consumerd; slow IO should not affect other unrelated streams. The
fundamental problem is that blocking IO is used and we should switch
to non-blocking communication if this is a problem (as is done in the
relay daemon).

The first point is more problematic given the existing tracer APIs.
If the tracer could provide the boundary of a "parseable unit" of
metadata, we could send the header of the RELAYD_SEND_METADATA command
with that size and send the various metadata packets as they are made
available. This would make no difference to the relay daemon as it is
not blocking on that socket and will not make the metadata size change
visible to the "live server" until it has all been received.

This size can't be determined right now since it could exceed the
total size of the "metadata" ring buffer. In other words, we can't wait
for the production of metadata to complete before starting to consume.

Finally, while implementing this fix, I also realized that the
computation of the rotation position of the metadata streams is
erroneous. The rotation code makes use of the ring-buffer's positions
to determine the rotation position. However, since both user space and
kernel domains make use of a "cache" behind the ring-buffer, that
cached content must be taken into account when computing the metadata
stream's rotation position.

References
==========

[1] https://github.com/lttng/lttng-tools/blob/d5ccf8fe0/src/common/consumer/consumer.c#L3433
[2] https://github.com/lttng/lttng-tools/blob/d5ccf8fe0/src/common/consumer/consumer-timer.c#L312
[3] https://github.com/lttng/lttng-tools/blob/d5ccf8fe0/src/common/consumer/consumer-stream.c#L492

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

4 years agoconsumerd: refactor: split read_subbuf into sub-operations
Jérémie Galarneau [Sun, 10 May 2020 22:00:26 +0000 (18:00 -0400)] 
consumerd: refactor: split read_subbuf into sub-operations

The read_subbuf code paths intertwine domain-specific operations and
metadata/data-specific logic which makes modifications error prone and
introduces a fair amount of code duplication.

lttng_consumer_read_subbuffer is effectively turned into a template
method invoking overridable callbacks making most of the consumption
logic domain and data/metadata agnostic.

The goal is not to extensively clean-up that code path. A follow-up
fix introduces metadata buffering logic which would not reasonably fit
in the current scheme. This clean-up makes it easier to safely
introduce those changes.

No changes in behaviour are intended by this change.

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

4 years agoconsumerd: move rotation logic to domain-agnostic read path
Jérémie Galarneau [Fri, 8 May 2020 20:00:11 +0000 (16:00 -0400)] 
consumerd: move rotation logic to domain-agnostic read path

The "rotation ready" logic is duplicated in both user space and kernel
specializations of the read subbuffer functions.

It is moved to the domain-agnostic caller where it is needed only
once. This makes it easier to implement a follow-up fix and reduces
code duplication.

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

4 years agosessiond: enforce mmap output type for kernel metadata channel
Jérémie Galarneau [Tue, 5 May 2020 22:54:32 +0000 (18:54 -0400)] 
sessiond: enforce mmap output type for kernel metadata channel

A follow-up fix causes the consumer daemon to accumulate metadata
packets into a complete "unit" that can be parsed before sending it to
the relay daemon.

The consumer daemon will also need to extract the contents of the
metadata cache when computing a rotation position (follow-up fix too).

Hence, it is not possible to rely on the splice back-end as the
consumer daemon may need to accumulate more content than can be backed
by the ring buffer's underlying pages.

In both cases, the splice output mode could still be used when
combined with a memfd, but I see no tangible benefit. Moreover, it
would require a 3.17 kernel.

Curiously the kernel metadata channel configuration appears to be
hard-coded twice; once in the ltt_kernel_session's
ltt_kernel_metadata, and once again in
kernel_consumer_add_metadata(). kernel_consumer_add_metadata is
modified to use the kernel session's metadata configuration.

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

4 years agoconsumerd: tag metadata channel as being part of a live session
Jérémie Galarneau [Tue, 5 May 2020 19:48:05 +0000 (15:48 -0400)] 
consumerd: tag metadata channel as being part of a live session

metadata channels that are part of a live session must be handled
differently than when they are part of non-live sessions since
complete "metadata units" must be accumulated before they are
forwarded to a relay daemon.

This allows a follow-up fix to use this information since the
live_timer_interval of a metadata channel is always 0.

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

4 years agoconsumerd: pass channel instance to stream creation function
Jérémie Galarneau [Tue, 5 May 2020 17:13:03 +0000 (13:13 -0400)] 
consumerd: pass channel instance to stream creation function

Both callsites of consumer_allocate_stream() set the stream's "chan"
pointer after the creation. Pass the channel directly to the stream
creation function so it can initialize the stream according to the
channel's settings.

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

4 years agoconsumerd: cleanup: use buffer view interface for mmap read subbuf
Jérémie Galarneau [Mon, 4 May 2020 23:04:02 +0000 (19:04 -0400)] 
consumerd: cleanup: use buffer view interface for mmap read subbuf

Replace explicit pointer + size parameters by an lttng_buffer_view
in lttng_consumer_on_read_subbuffer_mmap().

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

4 years agoconsumerd: move address computation from on_read_subbuffer_mmap
Jérémie Galarneau [Mon, 4 May 2020 22:21:48 +0000 (18:21 -0400)] 
consumerd: move address computation from on_read_subbuffer_mmap

The computation of the subbuffer's address is moved outside of
lttng_consumer_on_read_subbuffer_mmap to make it usable with a regular
buffer. This facilitates an upcoming change.

Moreover this has the benefit of isolating domain-specific logic from
this function which is supposed to be domain-agnostic.

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

4 years agoconsumerd: refactor: combine duplicated check_*_functions
Jérémie Galarneau [Wed, 29 Apr 2020 04:03:43 +0000 (00:03 -0400)] 
consumerd: refactor: combine duplicated check_*_functions

The check_ust_stream and check_kernel_stream functions are identical
except for the call to the domain-specific call to
consumer_flush_*_index.

A "flush_index" callback is passed to check_stream in order to share
the rest of that code.

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

4 years agokerner-ctl: add RING_RING_BUFFER_GET_NEXT_SUBBUF_METADATA_CHECK
Jérémie Galarneau [Wed, 29 Apr 2020 01:40:12 +0000 (21:40 -0400)] 
kerner-ctl: add RING_RING_BUFFER_GET_NEXT_SUBBUF_METADATA_CHECK

Add a wrapper for RING_RING_BUFFER_GET_NEXT_SUBBUF_METADATA_CHECK
which gets the next metadata subbuffer and returns a boolean flag
indicating whether the metadata is guaranteed to be in a consistent
state at the end of this sub-buffer (can be parsed).

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

4 years agoAdd lttng_dynamic_buffer_append_view util
Jérémie Galarneau [Fri, 15 May 2020 20:04:11 +0000 (16:04 -0400)] 
Add lttng_dynamic_buffer_append_view util

Add lttng_dynamic_buffer_append_view() which appends the contents
of a buffer view to a dynamic buffer.

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

4 years agoFix: lttng: Destroying session message repeated during destruction
Jérémie Galarneau [Thu, 14 May 2020 20:08:56 +0000 (16:08 -0400)] 
Fix: lttng: Destroying session message repeated during destruction

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

The `Destroying session X` is repeated indifinitely whenever
the data pending phase lasts more than one iteration.

```
$ lttng destroy
Destroying session eloi_turcotte.Destroying session
eloi_turcotte.Destroying session eloi_turcotte.Destroying session
eloi_turcotte.D
```

Cause
=====

Missing check that the message has been printed.

Solution
========

Use the same check as is done later for
lttng_destruction_handle_wait_for_completion().

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

None.

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

4 years agoUpdate version to v2.11.4 v2.11.4
Jérémie Galarneau [Tue, 19 May 2020 21:00:23 +0000 (17:00 -0400)] 
Update version to v2.11.4

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: common: abort on rotation after time manipulation
Jonathan Rajotte [Tue, 19 May 2020 16:23:18 +0000 (12:23 -0400)] 
Fix: common: abort on rotation after time manipulation

Observed issue
==============
Core dump:

 #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 #1  0x0000003eb4025548 in __GI_abort () at abort.c:79
 #2  0x0000003eb402542f in __assert_fail_base (fmt=0x3eb4184ae0 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x4cdee0 "(trace_chunk->timestamp_close).is_set",
     file=0x4cde78 "../../../lttng-tools-2.11.3/src/common/trace-chunk.c", line=903, function=0x4cf4a0 <__PRETTY_FUNCTION__.6756> "lttng_trace_chunk_move_to_completed")
     at assert.c:92
 #3  0x0000003eb4033af2 in __GI___assert_fail (assertion=assertion@entry=0x4cdee0 "(trace_chunk->timestamp_close).is_set",
     file=file@entry=0x4cde78 "../../../lttng-tools-2.11.3/src/common/trace-chunk.c", line=line@entry=903,
     function=function@entry=0x4cf4a0 <__PRETTY_FUNCTION__.6756> "lttng_trace_chunk_move_to_completed") at assert.c:101
 #4  0x000000000047f37e in lttng_trace_chunk_move_to_completed (trace_chunk=0x7fcb5c00e570) at ../../../lttng-tools-2.11.3/src/common/trace-chunk.c:903
 #5  0x0000000000480755 in lttng_trace_chunk_release (ref=0x7fcb5c00e598) at ../../../lttng-tools-2.11.3/src/common/trace-chunk.c:1117
 #6  urcu_ref_put (release=<optimized out>, ref=0x7fcb5c00e598) at /usr/include/urcu/ref.h:68
 #7  lttng_trace_chunk_put (chunk=0x7fcb5c00e570) at ../../../lttng-tools-2.11.3/src/common/trace-chunk.c:1150
 #8  0x0000000000429c22 in cmd_rotate_session (session=0x7fcb5c003ff0, rotate_return=rotate_return@entry=0x7fcb6b7ed470, quiet_rotation=quiet_rotation@entry=false)
     at ../../../../lttng-tools-2.11.3/src/bin/lttng-sessiond/cmd.c:5037
 #9  0x00000000004451d7 in process_client_msg (cmd_ctx=0x7fcb5c00e760, sock=sock@entry=0x7fcb6b7fd4c0, sock_error=sock_error@entry=0x7fcb6b7fd4c4)
     at ../../../../lttng-tools-2.11.3/src/bin/lttng-sessiond/client.c:1852
 #10 0x00000000004474c6 in thread_manage_clients (data=<optimized out>) at ../../../../lttng-tools-2.11.3/src/bin/lttng-sessiond/client.c:2199
 #11 0x00000000004422f2 in launch_thread (data=0x4f97a0) at ../../../../lttng-tools-2.11.3/src/bin/lttng-sessiond/thread.c:75
 #12 0x0000003eb4408ed4 in start_thread (arg=<optimized out>) at pthread_create.c:479
 #13 0x0000003eb40f8e6f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Reproduction:

 Disable ntp/any time management mechanism.

 lttng create
 lttng enable-event -u 'lttng_ust_tracef:*'
 lttng start
 lttng rotate
 date --set="$(date --date='-1 hour')"
 lttng rotate auto-20200515-142503
    Waiting for rotation to complete
    Error: Failed to query the state of the rotation.

Logs:
 DEBUG1 - 12:25:28.570037987 [2660/2717]: Setting trace chunk close command to "move to completed chunk folder" (in lttng_trace_chunk_set_close_command() at ../../../lttng-tools-2.11.3/src/common/trace-chunk.c:1073)
 Error: Failed to set trace chunk close timestamp: close timestamp is before creation timestamp
 Error: Failed to set the close timestamp of the current trace chunk of session "auto-20200515-142503"
 lttng-sessiond: ../../../lttng-tools-2.11.3/src/common/trace-chunk.c:903: lttng_trace_chunk_move_to_completed: Assertion `(trace_chunk->timestamp_close).is_set' failed.

 ...

 Aborted (core dumped)
 root@X10SDV-8C-TLN4F:~# DEBUG1 - 12:25:29.534263017 [2739/2739]: Releasing trace chunk registry to all trace chunks (in lttng_trace_chunk_registry_put_each_chunk() at ../../../lttng-tools-2.11.3/src/common/trace-chunk.c:1414)
 DEBUG1 - 12:25:29.534317468 [2739/2739]: Releasing reference to trace chunk: session_id = 0chunk_id = 2, name = "20200515T122528+0000-2", status = closed (in lttng_trace_chunk_registry_put_each_chunk() at ../../../lttng-tools-2.11.3/src/common/trace-chunk.c:1435)
 DEBUG1 - 12:25:29.534365653 [2739/2739]: Releasing reference to trace chunk: session_id = 0chunk_id = 1, name = "20200515T142520+0000-1", status = closed (in lttng_trace_chunk_registry_put_each_chunk() at ../../../lttng-tools-2.11.3/src/common/trace-chunk.c:1435)
 DEBUG1 - 12:25:29.534400638 [2739/2739]: Released reference to 2 trace chunks in lttng_trace_chunk_registry_put_each_chunk() (in lttng_trace_chunk_registry_put_each_chunk() at ../../../lttng-tools-2.11.3/src/common/trace-chunk.c:1447)
 Error: 2 trace chunks are leaked by lttng-consumerd. This can be caused by an internal error of the session daemon.

Cause
=====
The trace_chunk->timestamp_close is not set since the result from time()
is smaller than the creation timestamp.

The close timestamp is smaller because the calendar system time is
modified by an administrator.

time() offers no monotonicity guarantee and hence is exposed to time
modification of the system.

The begin and close timestamps are strictly used in the name generation
of the chunk/archives. Given the current usage of these timestamps
validating monotonicity should not be a fatal error. Name uniqueness is
provided by the chunk name suffix (auto increment).

Solution
========
Do not enforce monotonicity for the begin and close timestamps but warn
on unexpected return (begin > close).

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: Ic4b17285d150358d1569d6821c451c243e64e9a1

4 years agoFix: tests: `-Wstringop-overflow` warning
Francis Deslauriers [Mon, 4 May 2020 19:59:22 +0000 (15:59 -0400)] 
Fix: tests: `-Wstringop-overflow` warning

I get the following warning when compiling with `-Wall -Werror` with gcc
9.3.0:
  In file included from ../../src/common/macros.h:15,
                   from ../../src/common/lttng-kernel.h:14,
                   from ../../src/bin/lttng-sessiond/trace-kernel.h:14,
                   from test_kernel_data.c:16:
  In function ‘lttng_strnlen’,
      inlined from ‘lttng_strncpy’ at ../../src/common/macros.h:120:6,
      inlined from ‘test_create_kernel_event’ at test_kernel_data.c:136:2:
  ../../src/common/compat/string.h:28:8: error: ‘memchr’ reading 256 bytes from a region of size 11 [-Werror=stringop-overflow=]
     28 |  end = memchr(str, 0, max);
       |        ^~~~~~~~~~~~~~~~~~~

Fix this warning by using the RANDOM_STRING_LEN value as the max number
of bytes to copy.

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Change-Id: I61752ee17163c4d642aad21b296c0fc4fad5b7a6
(cherry picked from commit 1dd622b10db0821d77490c937caee80c65332f14)
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: load: incomplete error handling for load_session_from_file
Jonathan Rajotte [Tue, 7 Apr 2020 20:27:05 +0000 (16:27 -0400)] 
Fix: load: incomplete error handling for load_session_from_file

Observed issue
==============
lttng-ivc test fails to fail.

test_save_load_blocking_timeout[lttng-tools-2.12-lttng-tools-2.11-False]

Here we load a xml created by lttng-tools-2.12 and try to load it using
lttng-tools 2.11. We expect this to fail on the load.

The command report an error on the stderr but the command return code
value is zero.

From lttng-ivc test runtime.log:
Command #0
  Return value: 0
  Command: lttng load --input-path=/home/joraj/lttng/lttng-ivc/.tox/py3/tmp/test_save_load_blocking_timeou0/save_load saved_trace
  STDOUT:
      Session saved_trace has been loaded successfully
  STDERR:
      XML Error: Element 'process_attr_trackers': This element is not expected.
      Error: Session configuration file validation failed

Cause
==============
The error coming from load_session_from_file is not handled correctly.

Solution
========

Rework error handling in load_session_from_path and
load_session_from_file.

LTTNG_ERR_LOAD_SESSION_NOENT is NOT an error when session_name is
specified in load_session_from_path. In this scenario, we are actively
looking for the configuration of the session.

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

4 years agoUpdate version to v2.11.3 v2.11.3
Jérémie Galarneau [Thu, 16 Apr 2020 19:20:18 +0000 (15:20 -0400)] 
Update version to v2.11.3

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: lttng-destroy: missing newline on session destruction message
Jérémie Galarneau [Wed, 1 Apr 2020 22:34:59 +0000 (18:34 -0400)] 
Fix: lttng-destroy: missing newline on session destruction message

The lost packets/discarded events statistics are printed on the same
line as the session destruction progress message when the session is
stopped as part of the `destroy` command.

This is a consequence of printing the statistics as they are
retrieved; the statistics must be fetched before the destruction,
but the progress indicator is still being printed.

The statistics output is now formatted to a buffer and printed
after the session's destruction has completed.

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

4 years agoFix: common: add `void` parameter to log_add_time declaration
Simon Marchi [Wed, 25 Mar 2020 22:39:30 +0000 (18:39 -0400)] 
Fix: common: add `void` parameter to log_add_time declaration

It makes it match the definition and fixes this warning:

      CC       error.lo
    /home/smarchi/src/lttng-tools/src/common/error.c:33:13: error: no previous prototype for ‘log_add_time’ [-Werror=missing-prototypes]
     const char *log_add_time(void)
                 ^~~~~~~~~~~~

Change-Id: Ibbf5eebd8171504bc7050c754e2a5d113b6b5387
Signed-off-by: Simon Marchi <simon.marchi@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: lttng-list: don't warn when the kernel domain has no channels
Jérémie Galarneau [Mon, 23 Mar 2020 23:12:26 +0000 (19:12 -0400)] 
Fix: lttng-list: don't warn when the kernel domain has no channels

Some commands beside lttng-enable-channel have the side-effect of
creating a domain. For instance, the lttng-track and lttng-untrack
commands will implicitly create their target domains if they don't
exist. Thus, it is not unexpected for a domain to exist without
channels.

Currently, tracking process attributes in the user space and kernel
domains will result in a warning being printed when lttng-status
(or lttng-list `the_session`) is invoked.

Example output:
Tracing session arielle_bolduc: [inactive]
    Trace output: /home/jgalar/lttng-traces/arielle_bolduc-20200323-191128

=== Domain: Linux kernel ===

Tracked process attributes
  Process IDs: all
  Virtual Process IDs: 12365, 526, 41
  User IDs: all
  Virtual User IDs: all
  Group IDs: all
  Virtual Group IDs: all

Warning: No kernel channel
=== Domain: User space ===

Buffering scheme: per-user

Tracked process attributes
  Virtual Process IDs: 12365, 526, 41
  Virtual User IDs: all
  Virtual Group IDs: all

The warning is removed since it can only confuse users.

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

4 years agoFix: sessiond: occasional badfd error on repeated SIGTERM
Jérémie Galarneau [Thu, 5 Mar 2020 21:52:32 +0000 (16:52 -0500)] 
Fix: sessiond: occasional badfd error on repeated SIGTERM

The session daemon occasionally prints the following messages
when it received multiple SIGTERM signals:

PERROR - 16:50:18.505585257 [49845/49845]: write poll pipe: Bad file
descriptor (in notify_thread_pipe() at utils.c:35)

This is caused by a (somewhat inevitable) race between the teardown of
the daemon and the closing of its quit pipe. This happens more often
when kernel modules take a long time to be unloaded and the user
spams ctrl+c in the hope of convincing the daemon process to close
faster since modules are unloaded after closing the quit pipe.

Setting closed pipe fds to '-1' is safe anyway and is already
handled by the notify_thread_pipe() util.

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

4 years agoFix: lttng: incorrect domain list printed when no domain is provided
Jérémie Galarneau [Wed, 4 Mar 2020 23:27:28 +0000 (18:27 -0500)] 
Fix: lttng: incorrect domain list printed when no domain is provided

The following commands make use of a common utility function to
validate the count of domains specified and print an error when it
is invalid:
  - lttng-enable-event,
  - lttng-disable-event,
  - lttng-track,
  - lttng-untrack,
  - lttng-add-context,
  - lttng-enable-channel,
  - lttng-disable-channel.

Those commands do not allow the same domains to be used. In fact, they
all expect --kernel or --userspace only, except for the
lttng-enable-event, lttng-disable-event, and lttng-add-context
commands which allow the --log4j, --jul, and --python domain options
to be used.

Currently, the error message when no domain is specified is incorrect
for all of those commands. The error reads as follows:

`Error: Please specify a domain (-k/-u/-j).`

For most commands, the -j option cannot be used. For those that allow
agent domains, the message is missing the -l and -p domains.

This ensures that the expected domains are printed for each of those
commands.

Moreover, the message is clarified by using the long form option
names.

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

4 years agodirectory-handle: print `errno` reason on `unlinkat()` error
Francis Deslauriers [Mon, 9 Mar 2020 14:49:51 +0000 (10:49 -0400)] 
directory-handle: print `errno` reason on `unlinkat()` error

This is helpful while troubleshooting clear and rotation issues.

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I92f9551a49fced7603c8dca832566de71b188528

4 years agoFix: lttng-ctl: _handle can be NULL
Jonathan Rajotte [Tue, 3 Mar 2020 20:30:10 +0000 (15:30 -0500)] 
Fix: lttng-ctl: _handle can be NULL

lttng_destroy_session_no_wait does not care for the returned handle
and passes a NULL _handle.

This leads to an immediate LTTNG_ERR_INVALID failure on
lttng_destroy_session_no_wait calls.

lttng_destroy_session_ext already performs a null check on _handle
before assigning it to transfer ownership of the handle.

Fixes #1241

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Change-Id: I9e8bee28382fa2250dee720037efdf77b4e776b8
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoSilence `POSIX Yacc` warnings
Jérémie Galarneau [Tue, 10 Mar 2020 02:06:01 +0000 (22:06 -0400)] 
Silence `POSIX Yacc` warnings

Flex/Bison warn that we make use of two non-POSIX directives,
%code and %define. Coincidentally, we don't use POSIX Yacc!

From the bison documentation, "[...] -Wno-yacc will hide the warnings
about POSIX Yacc incompatibilities." [1].

Thus, this flag is added to the YFLAGS.

  YACC     filter-parser.c
/home/jgalar/EfficiOS/src/lttng-tools/src/lib/lttng-ctl/filter/filter-parser.y:293.1-5:
warning: POSIX Yacc does not support %code [-Wyacc]
  293 | %code provides
      | ^~~~~
/home/jgalar/EfficiOS/src/lttng-tools/src/lib/lttng-ctl/filter/filter-parser.y:301.1-7:
warning: POSIX Yacc does not support %define [-Wyacc]
  301 | %define api.pure
      | ^

[1] https://www.gnu.org/software/bison/manual/html_node/Diagnostics.html

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

4 years agoFix: relayd: use of relay_session ref count before initialization
Jérémie Galarneau [Tue, 18 Feb 2020 01:05:22 +0000 (20:05 -0500)] 
Fix: relayd: use of relay_session ref count before initialization

The relay_session's reference count is used before it is initialized
on multiple code paths of session_create(). The initialization of the
reference count, mutexes, and intrusive data structure nodes are
initialized earlier to make their use safe in the event of an error.

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

4 years agoFix: lttng: uninitialized pointer free'd when no sessiond is present
Jérémie Galarneau [Fri, 14 Feb 2020 22:09:58 +0000 (17:09 -0500)] 
Fix: lttng: uninitialized pointer free'd when no sessiond is present

The error path of get_schedules assumes that schedules_comm is !NULL,
which is not the case currently.

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

4 years agoUpdate version to v2.11.2 v2.11.2
Jérémie Galarneau [Wed, 12 Feb 2020 17:25:23 +0000 (12:25 -0500)] 
Update version to v2.11.2

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

4 years agoFix: sessiond: check for lttng-modules ABI 2.1 rather than 2.8
Jérémie Galarneau [Fri, 20 Dec 2019 03:13:10 +0000 (22:13 -0500)] 
Fix: sessiond: check for lttng-modules ABI 2.1 rather than 2.8

The clear patchset introduces a regression that breaks session
rotations when the kernel domain is used. The 2.8 lttng-modules ABI
does not exist yet.

The packet sequence number functionality was introduced in LTTng 2.8,
which introduced the 2.1 kernel tracer ABI.

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

4 years agoTests: Fix: `wait_on_file()` returns too early
Francis Deslauriers [Tue, 11 Feb 2020 02:46:34 +0000 (21:46 -0500)] 
Tests: Fix: `wait_on_file()` returns too early

Issue
=====
With the current implementation, when calling the `wait_on_file()`
function with the `file_exist` parameter set to false the function will
return even if the target file exists.

In a scenario where we enter the loop and the targer file exist, the
first call to `stat()` will return 0 and will not enter any of the `if`
and break from the loop directly.

Solution
========
If the file exists, only break from the loop if it's the desired exit
condition.

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Change-Id: Ia3e9c41a2a515815d3ff931d8f7c1c14a52b31ae
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: Tests: utils.sh: fix unbound variable
Francis Deslauriers [Fri, 7 Feb 2020 19:56:50 +0000 (14:56 -0500)] 
Fix: Tests: utils.sh: fix unbound variable

When loading `utils.sh`, we test the `LTTNG_TEST_TEARDOWN_TIMEOUT` and
define it to a default value if it's not defined already.

When running bash test scripts with the `-u` option to error out when
encountering unset variables it prints an error and exit

This commit uses a trick found here:
https://stackoverflow.com/questions/3601515/how-to-check-if-a-variable-is-set-in-bash

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Change-Id: Id24937f974ffd1ab3250296499da9360f97d393d
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoTests: Fix typo: registerd -> registered
Francis Deslauriers [Mon, 10 Feb 2020 22:18:48 +0000 (17:18 -0500)] 
Tests: Fix typo: registerd -> registered

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Change-Id: I74f6956d732c41168dfdfa101c6fcad0af6ecebe
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoTypo: 'toogle' -> 'toggle'
Francis Deslauriers [Thu, 6 Feb 2020 15:26:05 +0000 (10:26 -0500)] 
Typo: 'toogle' -> 'toggle'

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Change-Id: Id3c9a1942b21a66b626512e8378c517d48949582
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: force the use of our _FORTIFY_SOURCE definition
Jonathan Rajotte [Tue, 4 Feb 2020 21:04:41 +0000 (16:04 -0500)] 
Fix: force the use of our _FORTIFY_SOURCE definition

Some toolset (ubuntu) already defined the _FORTIFY_SOURCE.

This removes the warning we see if this is the case. Unset the variable and
reset it.

The warning:

make[3]: Entering directory '/home/joraj/lttng/master/lttng-tools/tests/regression/kernel'
  CC       select_poll_epoll-select_poll_epoll.o
<command-line>: warning: "_FORTIFY_SOURCE" redefined
<built-in>: note: this is the location of the previous definition
  CCLD     select_poll_epoll

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Change-Id: I2fa0482afa8941705a992f62a2e63657ea9e2b87
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoUpdate version to v2.11.1 v2.11.1
Jérémie Galarneau [Wed, 5 Feb 2020 22:34:46 +0000 (17:34 -0500)] 
Update version to v2.11.1

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

4 years agoFix: sessiond: snapshot errors don't clear session's trace chunk
Jérémie Galarneau [Mon, 3 Feb 2020 22:33:28 +0000 (17:33 -0500)] 
Fix: sessiond: snapshot errors don't clear session's trace chunk

The snapshot record command is implemented by creating and setting
a new trace chunk on the target session, capturing the snapshot, and
closing the session's trace chunk once it is complete.

On some error paths, the session's newly created trace chunk is not
cleared. This means that the session is seen to have a
'current_trace_chunk' on the next attempt to record a snapshot; an
unexpected condition for which an assert() exists.

This results in the following crash:
lttng-sessiond: /home/smarchi/src/lttng-tools/src/bin/lttng-sessiond/cmd.c:4685: snapshot_record: Assertion `!session->current_trace_chunk' failed.

Ensure that the session's current trace chunk is closed and cleared
when an error occurs during the command's execution.

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

4 years agoFix: sessiond: bounded snapshot record fails when no streams exist
Jérémie Galarneau [Mon, 3 Feb 2020 22:25:58 +0000 (17:25 -0500)] 
Fix: sessiond: bounded snapshot record fails when no streams exist

Attempting to record a snapshot with a `--max-size` fails when no
streams exist. For instance, attempting to record a snapshot for a
user space session when no applications are running will fail with the
following output:

Error: Invalid snapshot size. Cannot fit at least one packet per stream.
Error: Snapshot max size is invalid

The function get_session_nb_packets_per_stream() computes an
approximation of the number of packets to capture to honor the maximal
size specified. However, at the end, it doesn't distinguish between
'0' meaning that "no packets can be captured" (no streams exist) and
'0' meaning that "the max size is too small to accomodate one packet".

Those two cases can be distinguished by checking if the 'size_left' is
still the 'max_size', meaning that not even the size of one packet was
substracted from 'max_size'.

Reported-by: Simon Marchi <simark@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I5caef9ce926bbc7143a90667749ffaed972590c1

4 years agosession-descriptor: fix comment typos in session-descriptor.h
Simon Marchi [Fri, 31 Jan 2020 19:22:24 +0000 (14:22 -0500)] 
session-descriptor: fix comment typos in session-descriptor.h

Change-Id: Idafd16fd2851798a47bd95a7887f5bf9ba7828d0
Signed-off-by: Simon Marchi <simon.marchi@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: include stdlib.h in compat/string.h
Simon Marchi [Wed, 15 Jan 2020 20:42:31 +0000 (15:42 -0500)] 
Fix: include stdlib.h in compat/string.h

Fixes:

  CC       uuid.lo
In file included from /home/smarchi/src/lttng-tools/src/common/uuid.c:19:0:
/home/smarchi/src/lttng-tools/src/common/compat/string.h: In function ‘lttng_strndup’:
/home/smarchi/src/lttng-tools/src/common/compat/string.h:78:8: error: implicit declaration of function ‘malloc’ [-Werror=implicit-function-declaration]
  ret = malloc(navail);
        ^~~~~~
/home/smarchi/src/lttng-tools/src/common/compat/string.h:78:8: error: incompatible implicit declaration of built-in function ‘malloc’ [-Werror]
/home/smarchi/src/lttng-tools/src/common/compat/string.h:78:8: note: include ‘<stdlib.h>’ or provide a declaration of ‘malloc’

Note that this is in fallback code when the system doesn't provide
strndup (or, in my case, the system provides it but configure failed to
find it).

Change-Id: I5817b0b2436573b7d8fecb2956577a7b183d6296
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: lttng: sanity check of `--probe` description
Francis Deslauriers [Fri, 17 Jan 2020 20:09:21 +0000 (15:09 -0500)] 
Fix: lttng: sanity check of `--probe` description

Issue
=====
Run the following command:
  lttng enable-event -k --probe "\do_fork" my_do_fork_event
currently fails and that is expected.

But it does not fail for the right reason. In the `parse_probe_opts()`
function, during the last step of parsing the probe description we assume
it's a raw address and pass the string directly to the `strtoul()`
function. So if the probe description is not an address at all (e.g.
"\do_fork"), the `strtoul()` call will return 0 in the `addr` field of
the probe struct. This is then passed to the kernel tracer that asks the
kernel to instrument that address with a kprobe. This fails because 0x0
is not an address that can be instrumented.

Solution
========
Check that the first character of the tentative address is a digit
before trying to convert the string to an integer. This is not perfect
but at least it prevents some errors.

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Change-Id: I444f0e7694098b1cdb56ecbf5d92be8974e406dc
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: update context types for Python bindings
Christophe Bedard [Sat, 18 Jan 2020 19:29:49 +0000 (14:29 -0500)] 
Fix: update context types for Python bindings

Fixes: #1214
Signed-off-by: Christophe Bedard <bedard.christophe@gmail.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: lttng: placing probe on symbol starting with `_`
Francis Deslauriers [Fri, 17 Jan 2020 17:45:51 +0000 (12:45 -0500)] 
Fix: lttng: placing probe on symbol starting with `_`

Issue
=====
The lttng CLI tool does not parse `--probe` symbol name properly if the
name has an underscore at the beginning.
For example, the following command fails
  lttng enable-event -k --probe _do_fork my_do_fork_event

This happens because the `parse_probe_opts()` function looks if the
first character of the symbol field is an alphabetic character to
determine if a symbol was provided. The problem is that some kernel
symbols such as `_do_fork` start with an underscore.

Solution
========
check if the first character is an alphabetic character OR an
underscore.

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Change-Id: I3ee6c26641ceee508ee78e895d372c6b09fe90fb
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: build failure with -fno-common
Michael Jeanson [Thu, 16 Jan 2020 19:34:47 +0000 (14:34 -0500)] 
Fix: build failure with -fno-common

GCC 10 will default to building with -fno-common, this inhibits the
linker from merging multiple tentative definitions of a symbol in an
archive.

I'm not sure I understand what happen with the symbols in mi-lttng.h
but a similar issue was adressed in:

  commit 4965f956f3ef47388fb4a1b2f8f504abfe31afe7
  Author: Jérémie Galarneau <jeremie.galarneau@efficios.com>
  Date:   Fri May 22 12:53:30 2015 -0400

    Fix: Mark MI and Config string declarations as extern

    This fixes a build issue with GCC 5.1 which would complain about
    these symbols being defined multiple times.

Make sure these symbols are extern and defined only in one compile unit.

For more information, see:
https://gcc.gnu.org/gcc-10/porting_to.html

Change-Id: I139c9695371836cb1011f9ce192080b602ed2fbc
Signed-off-by: Michael Jeanson <mjeanson@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agodoc: Fix bind address example for lttng-relayd
Benjamin Poirier [Mon, 6 Jan 2020 05:19:54 +0000 (14:19 +0900)] 
doc: Fix bind address example for lttng-relayd

INADDR_ANY is 0.0.0.0

Fixes: c93eadade277 ("doc/man: use propagated default values in man pages")
Acked-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Signed-off-by: Benjamin Poirier <benjamin.poirier@gmail.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I6e908adca66b829128ea31cf392bccad3f96d63d

4 years agoTest: rotate_utils.sh: consider chunk archive with ust/ as empty
Mathieu Desnoyers [Fri, 20 Sep 2019 21:26:08 +0000 (17:26 -0400)] 
Test: rotate_utils.sh: consider chunk archive with ust/ as empty

Now the session daemon needs to create the ust/ subdir to pass it
to the consumer daemon even if there are no active traced applications
in per-pid tracing. Therefore, we need to consider a chunk with a
ust/ empty directory as empty.

Empty local traces have this empty subdir, but remote traces do not.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Change-Id: Ic0cda7baf6eafa5b0c7b4f0b79e03bc8ea523d93
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: consumer: do not flush on transition from NULL chunk
Mathieu Desnoyers [Thu, 12 Dec 2019 18:09:18 +0000 (13:09 -0500)] 
Fix: consumer: do not flush on transition from NULL chunk

When transitioning from NULL chunk, do not flush streams, because
the consumer has nowhere to store the packets generated by this
flush.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Change-Id: Ic92c035f6b1377849825527d0c9cc05a6b92ac38
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: consumer: honor "active" flush flag
Mathieu Desnoyers [Thu, 12 Dec 2019 18:07:18 +0000 (13:07 -0500)] 
Fix: consumer: honor "active" flush flag

Honor "active" flush flag in both kernel and ust consumers. A flush
"active" does a flush which will not generate empty packets (no event),
whereas an "inactive" flush will generate empty packets if flushing
a current packet which has no event.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Change-Id: Icc9772ba3ae18e96f24354ac6eb9223f343c3458
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: sessiond cmd.h: include missing lttng-sessiond.h
Mathieu Desnoyers [Thu, 12 Dec 2019 16:51:40 +0000 (11:51 -0500)] 
Fix: sessiond cmd.h: include missing lttng-sessiond.h

lttng-sessiond.h declares struct command_ctx which is used in cmd.h
prototypes.

It typically does not generate a compilation error because all
compile units including cmd.h also include lttng-sessiond.h, but
it is cleaner to include dependencies directly in cmd.h.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Change-Id: If3106291309cd543a886b2aecda7d4f9d4b290b3
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: sessiond: ust-app: per-pid buffers: Create empty ust/ directory
Mathieu Desnoyers [Mon, 9 Dec 2019 15:41:43 +0000 (10:41 -0500)] 
Fix: sessiond: ust-app: per-pid buffers: Create empty ust/ directory

When no applications are running, the toplevel ust/ directory is not
created in a chunk on rotation. Make sure this top level directory
is created.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Change-Id: Ia272f3182df298302e02b3e096785cb51687b8c9
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: utils: utils_stream_file_path separator
Mathieu Desnoyers [Mon, 9 Dec 2019 14:28:13 +0000 (09:28 -0500)] 
Fix: utils: utils_stream_file_path separator

Do not add a separator for empty paths.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Change-Id: Icec7b07d7abab4c010706c8cb4f199229fa04c6f
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: consumerd: use packet sequence number for rotation position
Mathieu Desnoyers [Tue, 5 Nov 2019 18:07:44 +0000 (13:07 -0500)] 
Fix: consumerd: use packet sequence number for rotation position

Refer to "Fix: relayd: use packet sequence number for rotation position"
for context of this change.

This commit introduces the changes required in the consumerd.

Some notable points related to this commit:

- Internally, the rotate_position (per-stream) is now a 64-bit
  value rather than an unsigned long.
- The scheme to rotate a stream is changed to allow using the
  backward-compatible lttng_consumer_take_snapshot() rather than
  the newer lttng_consumer_get_produced_snapshot(), thus allowing
  backward compatibility of the implicit rotation on destroy with
  pre-2.10 lttng-modules.
- The rotate position used as pivot point for the rotation is
  based on the packet_seq_num of the last packet that has been
  send over the network by consumerd, incremented by the number of
  packets between the sampled produced_pos and the consumed_pos.
  In the worse case scenario where an overwrite mode ring buffer
  overwrites its contents enough to trigger a 4GB overflow on a
  32-bit producer since the last packet was sent (e.g. due to a
  slow network), the difference between produced_pos and
  consumed_pos will be lower that what would have been expected.
  However, because this pivot position is used as a lower bound,
  being smaller than the real value is fine: the data that would
  have been misplaced in the wrong trace chunk were actually
  overwritten, and will therefore never be consumed.
- When interacting with pre-2.8 lttng-modules, the packet sequence
  number is not available. The current approach is to disallow
  rotations performed on sessions which have kernel tracing active
  with a pre-2.8 lttng-modules.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Change-Id: I8600cb5e2e9c05f3dfba0499a5fc4a3bb85dec24
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoalign.h: Implement ALIGN_FLOOR macro
Mathieu Desnoyers [Tue, 5 Nov 2019 23:56:34 +0000 (18:56 -0500)] 
align.h: Implement ALIGN_FLOOR macro

Implement the ALIGN_FLOOR macro which aligns the given value to the
previous alignment boundary, or keeps the value as-is if it is already
aligned.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Change-Id: I36d981e8fb705fafa3ff23ba2d82ec1babe73e45
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: relayd: per-pid live: no new metadata vs close
Mathieu Desnoyers [Tue, 3 Dec 2019 09:08:36 +0000 (04:08 -0500)] 
Fix: relayd: per-pid live: no new metadata vs close

When using lttng-live on a per-pid UST trace, the metadata stream is
closed after an application exits. The live viewer observes that the
stream has no more data when getting the metadata returns 0 bytes.

Internally in the relay daemon, it is assumed that a metadata stream
can be put (and thus removed) as soon as all the metadata has been sent
to the viewer, but this is not quite right. The viewer actually needs to
observe a 0-byte reply after receiving all the metadata in order to
gracefully perceive the metadata stream hang up.

Therefore, add a no_new_metadata_notified flag to the metadata stream
to track whether that 0-byte message has been sent to the viewer since
the last metadata content was sent, and postpone the reclamation of the
metadata stream until it is closed _and_ that 0-byte reply was sent to
the live viewer.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Change-Id: I0a05332284299d62b832046e4f9d22b6029c3a3e
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: relayd: use packet sequence number for rotation position
Mathieu Desnoyers [Tue, 5 Nov 2019 15:40:58 +0000 (10:40 -0500)] 
Fix: relayd: use packet sequence number for rotation position

The "network" sequence number (net_seq_num) is a 64-bit sequence number
tagging each packet sent over the network. The net_seq_num increments
monotonically (+1) for each packet sent from consumer daemon to relay
daemon, on a per-stream basis. It is tagged by the consumer daemon when
sending a trace packet to the relay daemon.

The LTTng kernel and user-space ring buffer "consumed position"
(consumed_pos) and "produced position" (produced_pos) are free-running
counters counting the number of bytes consumed and produced so far by
each stream. Because those counters are updated atomically, they are
limited to a size of 32-bit on 32-bit architectures.

The "packet" sequence number (packet_seq_num) is a sequence number
found in the packet header starting from LTTng 2.8. It is a 64-bit
sequence number assigned by the lttng-modules and lttng-ust ring
buffers. It increments monotonically (+1) for each packet produced
within a given ring buffer (stream).

Using produced_pos as rotation position and comparing it to the
net_seq_num has a few issues:

1) It breaks on 32-bit producers after generating more than 4GB of
   data per stream, due to overflow. The net_seq_num is a 64-bit
   counter, which does not overflow, but the produced_pos overflows
   after 4GB on 32-bit architectures. This can lead to never-completing
   rotations.

2) It breaks scenarios where ring buffers are configured in
   overwrite mode, and streaming to a relay daemon. Indeed, when
   the ring buffer moves the consumed_pos ahead, actually overwriting
   data within the ring buffer, it introduces an offset between the
   produced_pos and the net_seq_num. Therefore, if producers are
   generating a low- (or no-) throughput in some streams, the
   rotation may never complete, even on 64-bit architectures.

The solution proposed for this issue is to use the packet_seq_num as
rotation position rather than the net_seq_num. It takes care of
the two problematic scenarios, since the counter is always 64-bit
(even on 32-bit architectures), and because the counter is managed
by the producer, which therefore tracks progress of the ring buffer
overwrites.

This commit introduces changes required at the relayd side. A
separate commit introduces the changes required in the consumerd.

In relayd, one major restriction is the fact that the packet_seq_num
is not sent over the data socket, only through the control socket
receiving the indexes.

Therefore, in order to figure out the pivot position for the data
socket for a given stream, the associated index first needs to be
received. At that point, the corresponding net_seq_num is known,
which provides the pivot position for the data stream. Given that
the data and index sockets provide no ordering guarantees with
respect to their arrival, we handle the fact that data might have
been saved to disk in the wrong (previous) trace chunk by moving
it to the next trace chunk when the pivot position is known.

In order to allow "jumps" in the sequence numbers produced by
overwrite mode buffers, try_rotate_stream_index(), which previously
asserted that each sequence number was received in sequence, now
uses the packet_seq_num pivot position as a lower (inclusive) bound.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Change-Id: I755329e313f0980655a164b7bdb57e4f3d8e944a
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: relayd stream.c: LTTNG_OPTIONAL_GET address confusion
Mathieu Desnoyers [Wed, 18 Dec 2019 15:56:29 +0000 (10:56 -0500)] 
Fix: relayd stream.c: LTTNG_OPTIONAL_GET address confusion

The lack of proper care around use of macro arguments in LTTNG_OPTIONAL_GET
allowed this code to compile, but caused the following issue (manually
replacing "optional" argument with the a

Using LTTNG_OPTIONAL_GET(&stream->ongoing_rotation)->next_trace_chunk

with:

 #define LTTNG_OPTIONAL_GET(optional)                   \
         ({                                             \
               assert(optional.is_set);                 \
               optional.value;                          \
         })

translates to:

         ({
               assert(&stream->ongoing_rotation.is_set);
               &stream->ongoing_rotation.value;
         })->next_trace_chunk

The issue here is the assert(), which just checks that the address
is not NULL, when it should actually check that the value is set.

The prior commit fixing optional.h to add proper parentheses to the
macro rightfully fails to compile this code. Fix the erroneous user.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Change-Id: I0dd45fb60573cae6ae3e831e24266aff4406f57f
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: optional.h macro missing parentheses and guards
Mathieu Desnoyers [Wed, 18 Dec 2019 15:50:00 +0000 (10:50 -0500)] 
Fix: optional.h macro missing parentheses and guards

The are a few coding style issues with optional.h which leads to
unexpected effects when the macros are used in the caller code.

All macro parameters need to be surrounded by () (except when used near
commas, which is the C operator with least precedence).

All macros that emit code need to be surrounded by do { } while (0) so
not to emit extra ; or omit ;, which can cause subtle issues when used
with if/else statements.

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Change-Id: Iba6fde7c267f4d8c9ec1a89147045f0bcda3a67a
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agodynamic-array: fix documentation of lttng_dynamic_pointer_array_get_pointer
Simon Marchi [Fri, 13 Dec 2019 21:47:57 +0000 (16:47 -0500)] 
dynamic-array: fix documentation of lttng_dynamic_pointer_array_get_pointer

The documentation of this function says that mutating the array
invalidates the return pointer.  This is not true, since the returned
pointer is the element itself, not a pointer to the array.

Change-Id: I8b8978cddb2d1d6ce0b42ed313e9843ca418c96c
Signed-off-by: Simon Marchi <simon.marchi@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: make dist fails on sdt-probe test with autotools v1.16+
Jérémie Galarneau [Fri, 13 Dec 2019 20:25:28 +0000 (15:25 -0500)] 
Fix: make dist fails on sdt-probe test with autotools v1.16+

The 'dist' target fails when building with autotools 1.16.1 as the
behaviour of BUILT_SOURCES has changed in 1.16 [1].

BUILT_SOURCES are now built as part of the 'dist' target which causes
it to fail on machines that don't have dtrace installed.

The following error is produced: DTRACE foobar_provider.h /bin/sh: -s:
  command not found

The BUILT_SOURCES is skipped for build configurations where the build
of the test helper 'userspace-probe-sdt-binary' is disabled.

The resulting artifact, foobar_provider.h, is not part of the
distributed tarball (marked as nodist), so this doesn't have any
adverse effect.

[1] https://www.mail-archive.com/automake@gnu.org/msg20156.html

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

4 years agoFix: tests: metadata presence on relayd is not deterministic
Jonathan Rajotte [Wed, 11 Dec 2019 20:58:58 +0000 (15:58 -0500)] 
Fix: tests: metadata presence on relayd is not deterministic

There is no synchronization point guaranteeing the presence of metadata on
lttng-relayd side when the live metadata request is done. It must be
present at some point in the future but might not be at the moment we
perform the request.

Add a retry phase to this step. It must succeed in the future.

Not sure how this test was never marked as flaky.

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Change-Id: I033005c6a228013e699c74d8e8faafcb3272dd98
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: move testpoint after state update
Jonathan Rajotte [Tue, 10 Dec 2019 16:15:39 +0000 (11:15 -0500)] 
Fix: move testpoint after state update

This prevent failure and hang for the long_regression test suite.

Otherwise the sessiond error out before the test completion due to an
invalid thread state.

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Change-Id: Ie4bf3bea6f84f49f5eceb413ae75a7e6fff08a8f
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agodoc: fix typo in lttng-enable-event man page
Simon Marchi [Fri, 6 Dec 2019 21:07:03 +0000 (16:07 -0500)] 
doc: fix typo in lttng-enable-event man page

Change-Id: I81ce8f5d4eb3857ace5b1bc3a3ed3c62751dc503
Signed-off-by: Simon Marchi <simon.marchi@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: sessiond: RCU read lock imbalance on get trace chunk id error
Jérémie Galarneau [Mon, 9 Dec 2019 19:31:33 +0000 (14:31 -0500)] 
Fix: sessiond: RCU read lock imbalance on get trace chunk id error

The error path when cmd_setup_relayd() fails to get the ID of a trace
chunk causes the RCU read lock to be released even though it was never
acquired.

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

4 years agoFix: build: ust -> kernel mix-up in noinst_SCRIPTS
Jonathan Rajotte [Tue, 3 Dec 2019 16:46:24 +0000 (11:46 -0500)] 
Fix: build: ust -> kernel mix-up in noinst_SCRIPTS

This is simply a copy paste error as test_notification_ust appears
twice.

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Change-Id: I4e170a092338f5a95479a58d48247088d28d3e31
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: relayd: missing metadata stream causes all traces to be skipped
Jérémie Galarneau [Tue, 3 Dec 2019 09:59:10 +0000 (04:59 -0500)] 
Fix: relayd: missing metadata stream causes all traces to be skipped

Commit 123ed7c22 intends for a trace that doesn't have a metadata
stream to be skipped when creating viewer streams. However, the loop
over ctf_traces should be "continued" rather then "broken" from when
this situation arises. Otherwise, all ctf_traces of the session are
skipped, which is not the intention here.

Moreover, a reference to the current ctf_trace is leaked when the
break (now continue) occurs.

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

4 years agoconfigure.ac: Remove duplicated CMD_DESCR_ROTATE definition
Simon Marchi [Mon, 27 May 2019 15:52:46 +0000 (11:52 -0400)] 
configure.ac: Remove duplicated CMD_DESCR_ROTATE definition

CMD_DESCR_ROTATE is defined twice by configure.  This breaks configuring
with "-Werror -Wall", as some test programs don't compile due to:

  configure:16990: gcc -o conftest -Wall -Werror   conftest.c  >&5
  conftest.c:163: error: "CONFIG_CMD_DESCR_ROTATE" redefined [-Werror]
   #define CONFIG_CMD_DESCR_ROTATE "Archive a tracing session’s current trace chunk"

  conftest.c:154: note: this is the location of the previous definition
   #define CONFIG_CMD_DESCR_ROTATE "Archive a tracing session's current trace chunk"

  cc1: all warnings being treated as errors

Signed-off-by: Simon Marchi <simon.marchi@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: relayd: fully initialize viewer stream before publishing it
Jérémie Galarneau [Sat, 23 Nov 2019 00:04:16 +0000 (19:04 -0500)] 
Fix: relayd: fully initialize viewer stream before publishing it

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: relayd: don't send streams if there is no metadata
Francis Deslauriers [Tue, 12 Nov 2019 22:55:25 +0000 (17:55 -0500)] 
Fix: relayd: don't send streams if there is no metadata

Issue
=====
When tracing short-live UST apps in per-pid mode, it happens that traces
are closed before we can send all the streams to the viewer. This can
place the viewer in an uncomfortable position where it is aware of data
streams of a trace but can't get the metadata stream to decode the
events.

Solution
========
Only send the data streams if we have the metadata stream or if the
metadata stream was already sent. This ensures that the viewer will
either have all the {data,metadata} streams or none of them.

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
5 years agoFix: update apps on untrack only when session is active
Jonathan Rajotte [Mon, 18 Nov 2019 20:12:20 +0000 (15:12 -0500)] 
Fix: update apps on untrack only when session is active

This mimics what is done on the track side.

Fixes #1210

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
5 years agoFix: consumerd: assert on null trace chunk on session restart
Jérémie Galarneau [Fri, 22 Nov 2019 20:08:15 +0000 (15:08 -0500)] 
Fix: consumerd: assert on null trace chunk on session restart

The consumer daemon asserts on
`stream->net_seq_idx != (uint64_t) 1ULL || stream>trace_chunk'
when a session is re-started following a rotation.

Steps to reproduce, while an instrumented application is running:
$ lttng create
$ lttng enable-event -u -a
$ lttng start
$ lttng stop
$ lttng rotate
$ lttng start
-> assertion fails

The trace chunk of a stream can be null in this scenario as the
"create trace chunk" consumer command immediately sets the streams'
current trace chunk when they are transitioning from a "null" trace
chunk.

Since 1f4962443, a session restart will cause a rotation to occur from
"null" to the streams' new trace chunk. When this rotation occurs, the
channel and their streams are seen to be in the same trace chunk.
This is unexpected as this should only occur when transitioning from a
trace chunk to the "null" trace chunk (no output). In that case, the
streams are considered to have reached the point where they should
discard their current trace chunk to enter the "null trace chunk"
state (having no current output). This is exactly the opposite of
the situation here as streams are transitioning from a null to a
non-null trace chunk.

Hence, the immediate assignation of the trace chunk to the streams
should no longer be performed on creation of a trace chunk on the
consumer daemon. The streams transition from the "null" trace chunk to
a new trace chunk through the "rotate channel" command as is done for
all other rotation operations. Removing this bypass also ensures that
the rotation behaviour of both the consumer and relay daemons match.

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
5 years agoFix: sessiond: don't wait for a rotation from a null chunk to finish
Jérémie Galarneau [Wed, 20 Nov 2019 21:09:50 +0000 (16:09 -0500)] 
Fix: sessiond: don't wait for a rotation from a null chunk to finish

The rotation completion checking does not handle waiting for the
completion of a rotation _from_ a NULL trace chunk. This is correct as
there is essentially nothing to check. Streams always rotate out of a
null trace chunk immediately as it means the stream had no output and
could not receive data.

Concretely, this happens when stopping a session, rotating, and
re-starting a session.

The fix consists in simply re-working the logic of the "rotate"
command to not launch a rotation completion check job and not put the
session in the "rotation ongoing" state.

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
5 years agoFix: sessiond: duplicated rotation notification sent
Jérémie Galarneau [Wed, 20 Nov 2019 21:06:30 +0000 (16:06 -0500)] 
Fix: sessiond: duplicated rotation notification sent

A duplicate notification that a rotation was launched and completed
is sent by the rotation thread when a rotation is performed after
a session was stopped.

This code is removed at it is a left-over from the time when the
rotation thread had to explicitly rename trace output folders
when a rotation had completed.

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
5 years agoFix: relayd: remove assert of non-null stream trace chunk on rotate
Jérémie Galarneau [Tue, 19 Nov 2019 18:41:51 +0000 (13:41 -0500)] 
Fix: relayd: remove assert of non-null stream trace chunk on rotate

A stream can rotate from a "NULL" trace chunk to a new trace chunk
and the relay daemon should not assert on this condition.

This happens when a session is stopped, rotated, and started again
later on.

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
5 years agoDocs: verb/noun confusion in comment
Jérémie Galarneau [Mon, 18 Nov 2019 21:09:21 +0000 (16:09 -0500)] 
Docs: verb/noun confusion in comment

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
5 years agoFix: sessiond: no rotation performed from null chunk to new chunk
Jérémie Galarneau [Mon, 18 Nov 2019 21:01:44 +0000 (16:01 -0500)] 
Fix: sessiond: no rotation performed from null chunk to new chunk

The session daemon must rotate from a null trace chunk to a new trace
chunk when a session's current trace chunk is null. This situation
happens when a session is stopped, rotated, and started again.

This bug leaves existing streams in the "null" trace chunk and causes
the relay daemon to report a protocol error on the reception of the
first data packet following such a start.

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
5 years agoFix: invalid use of destructor in dynamic pointer array
Jérémie Galarneau [Mon, 18 Nov 2019 19:43:06 +0000 (14:43 -0500)] 
Fix: invalid use of destructor in dynamic pointer array

A dynamic pointer array is built on top of a dynamic array and uses
the dynamic array's internal "destructor" field to store the
user-specified destructor.

lttng_dynamic_pointer_array_remove_pointer currently uses
the dynamic array's remove_element directly which causes the
user destructor to be called with the underlying storage of the
pointer rather than with the pointer itself.

This change re-uses the same pattern as
lttng_dynamic_pointer_array_reset(), namely using the destructor
explicitly and setting it to NULL for the duration of the call to
the dynamic array API.

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
5 years agoFix: relayd: check for a trace chunk before writing a packet
Jérémie Galarneau [Fri, 15 Nov 2019 22:16:32 +0000 (17:16 -0500)] 
Fix: relayd: check for a trace chunk before writing a packet

Protocol errors can cause a packet to be written to a stream that
doesn't have an active trace chunk. Validate this condition for the
init and write packet operations on a stream.

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
5 years agoFix: relayd: viewer session trace chunk not released on detach
Jérémie Galarneau [Thu, 14 Nov 2019 22:12:08 +0000 (17:12 -0500)] 
Fix: relayd: viewer session trace chunk not released on detach

The 'attach' command on a viewer session expects (asserts) the trace
chunk of the viewer session to be NULL. This is reasonable as there is
no reason to hold a reference to a trace chunk while no clients are
attached.

Release the reference to the trace chunk on detach. The relay
session's trace chunk will be re-sampled (copied) when the next client
attaches to the viewer session.

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
5 years agoRequire automake >= 1.12
Michael Jeanson [Thu, 7 Nov 2019 19:02:55 +0000 (14:02 -0500)] 
Require automake >= 1.12

The test suite LOG_DRIVER statement requires that automake >= 1.12 be used
during bootstrap.

Signed-off-by: Michael Jeanson <mjeanson@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
5 years agoFix: relayd: session trace chunk is copied too late
Jérémie Galarneau [Tue, 12 Nov 2019 04:38:25 +0000 (23:38 -0500)] 
Fix: relayd: session trace chunk is copied too late

In per-pid buffering mode, a viewer can attach to a session while it
is active and find it has been closed by the time it requests new
streams. The viewer session's trace chunk is created as a side-effect
of the "get_new_streams" command and can find that the relay_session's
trace chunk has now been closed, causing the creation of the viewer
session trace chunk to fail.

This results in an unexpected error being reported to the live client.
This fix moves the creation of the viewer session's trace chunk to the
"attach" command. If the creation fails, the session is reported as
being "unknown".

Reported-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Tested-by: Francis Deslauriers <francis.deslauriers@efficios.com>
5 years agoFix: relayd: disallow 0-length session names for 2.4+ peers
Jérémie Galarneau [Fri, 8 Nov 2019 22:45:20 +0000 (17:45 -0500)] 
Fix: relayd: disallow 0-length session names for 2.4+ peers

The group-by-session-name feature assumes sessions are named for peers
more recent than 2.3. Enforce this assumption at session creation
time.

Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
5 years agoFix: sessiond: ust: deadlock with per-pid buffers
Mathieu Desnoyers [Fri, 1 Nov 2019 20:23:05 +0000 (16:23 -0400)] 
Fix: sessiond: ust: deadlock with per-pid buffers

Do not hold the registry lock while communicating with the consumerd,
because doing so causes inter-process deadlocks between consumerd and
sessiond with the metadata request notification.

The deadlock involves both sessiond and consumerd:

* lttng-sessiond:

thread 11 - thread_application_management

close_metadata()
  pthread_mutex_lock(&registry->lock);
  consumer_close_metadata()
    pthread_mutex_lock(socket->lock);

thread 15 - thread_consumer_management

ust_consumer_metadata_request()
  pthread_mutex_lock(&ust_reg->lock);

thread 8 - thread_manage_clients

consumer_is_data_pending
  pthread_mutex_lock(socket->lock);
  consumer_socket_recv()

* lttng-consumerd:

thread 4 - consumer_timer_thread

sample_channel_positions()
  pthread_mutex_lock(&stream->lock);

thread 8 - consumer_thread_sessiond_poll
  consumer_data_pending
  pthread_mutex_lock(&consumer_data.lock);
  pthread_mutex_lock(&stream->lock);

thread 7 - consumer_thread_data_poll

lttng_consumer_read_subbuffer
  pthread_mutex_lock(&stream->chan->lock);
  pthread_mutex_lock(&stream->lock);
  do_sync_metadata
    pthread_mutex_lock(&metadata->lock);
    lttng_ustconsumer_sync_metadata
      pthread_mutex_unlock(&metadata_stream->lock);
      lttng_ustconsumer_request_metadata()
        pthread_mutex_lock(&ctx->metadata_socket_lock);
        lttcomm_recv_unix_sock()

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
This page took 0.093301 seconds and 4 git commands to generate.