lttng-tools.git
4 years agoFix: common: improper use of negative return
Jonathan Rajotte [Tue, 28 Jul 2020 14:19:30 +0000 (10:19 -0400)] 
Fix: common: improper use of negative return

From Coverity:

  CID 1431053 (#1 of 2): Improper use of negative value (NEGATIVE_RETURNS)
  5. negative_returns: fd_count is passed to a parameter that cannot be
     negative.

Solution
========

Check return value for fd_count and goto error if negative.

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

4 years agoFix: sessiond: unchecked return value
Jonathan Rajotte [Tue, 28 Jul 2020 14:15:04 +0000 (10:15 -0400)] 
Fix: sessiond: unchecked return value

From coverity:

  CID 1431054 (#1 of 1): Unchecked return value (CHECKED_RETURN)
  1. check_return: Calling lttng_dynamic_buffer_set_size without
     checking return value (as is done elsewhere 32 out of 40 times).

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

4 years agoFix: relayd: wrong stream type used in DBG statement
Jérémie Galarneau [Mon, 27 Jul 2020 22:14:30 +0000 (18:14 -0400)] 
Fix: relayd: wrong stream type used in DBG statement

get_next_index() is never invoked for metadata streams; the
debug statement was erroneously copy-pasted from the get_metadata()
function.

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

4 years agosessiond: client: use common payload send fds util
Jérémie Galarneau [Fri, 24 Jul 2020 17:48:00 +0000 (13:48 -0400)] 
sessiond: client: use common payload send fds util

Use lttcomm_send_payload_view_fds_unix_sock instead of an open-coded
version of the same functionality.

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

4 years agopayload: use fd_handle instead of raw file descriptors
Jérémie Galarneau [Wed, 22 Jul 2020 20:15:44 +0000 (16:15 -0400)] 
payload: use fd_handle instead of raw file descriptors

Using raw file descriptors with lttng_payloads introduces scary file
descriptor corner-cases when mixing with asynchroneous communication and
lttng_payloads.

Since an lttng_payload doesn't own its file descriptors, attempting it
is easy to fall into a situation where a file descriptor is referenced
by an lttng_payload while the owner is destroyed.

For instance, a userspace probe could be destroyed while its description
is waiting to be sent to a client.

The various use sites of the payload/payload_view APIs are adjusted.

Utilities to send/recv fds through unix sockets using the payload and
payload view interfaces are added as part of this commit as they use
the payload's fd_handles.

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

4 years agoAdd fd_handle interface
Jérémie Galarneau [Wed, 22 Jul 2020 19:29:17 +0000 (15:29 -0400)] 
Add fd_handle interface

An fd_handle allows the reference counting of file descriptors which may
be shared by multiple objects. There is no synchronization imposed (or
provided) for the use of the underlying file descriptors as this utility
meant to be used on file descriptors where this would not make
sense (eventfd, dir fd, etc.)

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

4 years agopayload: don't re-initialize destination payload on copy
Jérémie Galarneau [Wed, 22 Jul 2020 20:43:26 +0000 (16:43 -0400)] 
payload: don't re-initialize destination payload on copy

This makes it possible to re-use the same destination payload
and not always re-allocate memory for its underlying arrays.

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

4 years agouprobe: transmit binary file descritptor through lttng_payload
Jérémie Galarneau [Fri, 19 Jun 2020 22:44:56 +0000 (18:44 -0400)] 
uprobe: transmit binary file descritptor through lttng_payload

Adapt the userspace probe objects to use the lttng_payload interface.
This streamlines the acquisition of the file descriptors when those
objects are serialized.

File descriptors are transmitted in both directions between liblttng-ctl
and the session daemon making it possible (and safe) to compare
userspace probe instances.

Currently the event listing API does not allow us to express userspace
probe locations that contain a file descriptor. This is an unfortunate
consequence of returning a "flat" array to list events.

Indeed, we can't store a file descriptor in the userspace probe
locations returned to the user in this API since the destructors of the
probe locations are never called. The user simply free()'s the returned
array, which would leak the file descriptors.

The consequence of this is that we can't allow the creation of event
rules using a probe location returned by an lttng_list_events() call.
This is not unsolvable, but I'm not sure if there really is a use-case
for this.

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

4 years agoFix: payload view: payload view always refers to parent's position
Jérémie Galarneau [Tue, 23 Jun 2020 04:23:01 +0000 (00:23 -0400)] 
Fix: payload view: payload view always refers to parent's position

A payload view's fd iterator must point to the root view's fd iterator
and not necessarily its parent's. This would cause the iterator
to be reset when views were nested more than two levels deep.

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

4 years agoFix: lttng: leak of userspace probe path on listing
Jérémie Galarneau [Tue, 23 Jun 2020 03:35:02 +0000 (23:35 -0400)] 
Fix: lttng: leak of userspace probe path on listing

realpath() returns a malloc'ed string when `resolved_path` is NULL.
`binary_path` can be safely free'd after it is printed.

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

4 years agopayload: incomplete sentence in lttng_payload_init comment
Jérémie Galarneau [Tue, 23 Jun 2020 03:10:18 +0000 (23:10 -0400)] 
payload: incomplete sentence in lttng_payload_init comment

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

4 years agocommon: add lttng_payload_view fd count accessor and buffer init
Jérémie Galarneau [Fri, 19 Jun 2020 22:54:58 +0000 (18:54 -0400)] 
common: add lttng_payload_view fd count accessor and buffer init

Allow the initialization of a payload view from a subset of a dynamic
buffer (echoing the lttng_buffer_view API) and add an accessor for the
fd count property.

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

4 years agocommon: move lttng_payload[_view] to libcommon
Jérémie Galarneau [Fri, 19 Jun 2020 22:43:47 +0000 (18:43 -0400)] 
common: move lttng_payload[_view] to libcommon

The payload utils are moved from libsessiond-comm to libcommon since
they present a circular dependancy: a payload uses the dynamic buffer
utilities while the actions, triggers, and conditions make use of the
lttng_payload utilities.

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

4 years agocommon: add lttng_dynamic_array_set_count()
Jérémie Galarneau [Fri, 19 Jun 2020 22:20:08 +0000 (18:20 -0400)] 
common: add lttng_dynamic_array_set_count()

Add an lttng_dynamic_array_set_count() helper to resize a dynamic
array.

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

4 years agosessiond: prepare client replies through an lttng_payload
Jérémie Galarneau [Tue, 16 Jun 2020 04:14:13 +0000 (00:14 -0400)] 
sessiond: prepare client replies through an lttng_payload

Modify the command context structure to contain an lttng_payload. This
allows commands to return a payload which contains a file descriptor
without accessing the socket directly.

An interesting side-benefit is that, in practice, this eliminates all
dynamic allocations from the client communications beyond the first
command served. The command context is re-used and the reply buffer is
allocated once and not released (only its size is reset to 0).

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

4 years agoClean-up: sessiond: change spaces to tab
Jérémie Galarneau [Tue, 16 Jun 2020 03:48:37 +0000 (23:48 -0400)] 
Clean-up: sessiond: change spaces to tab

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

4 years agoFix: uprobe: missing error code on allocation failure
Jérémie Galarneau [Mon, 15 Jun 2020 22:44:23 +0000 (18:44 -0400)] 
Fix: uprobe: missing error code on allocation failure

lttng_userspace_probe_location_function_create_from_payload
does not report an allocation failure when strdup fails.

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

4 years agoFix: sessiond: don't negate error code on list error
Jérémie Galarneau [Mon, 15 Jun 2020 22:43:02 +0000 (18:43 -0400)] 
Fix: sessiond: don't negate error code on list error

Listing errors are already negative. Negating in the error path
causes error codes to be interpreted as a number of events and
cause a communication error further on.

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

4 years agouserspace-probe: implement is_equal
Jonathan Rajotte [Fri, 31 Jan 2020 21:05:16 +0000 (16:05 -0500)] 
userspace-probe: implement is_equal

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

4 years agoFix: send/received actual size is overwritten by 'expected' size
Jonathan Rajotte [Thu, 9 Jul 2020 20:22:19 +0000 (16:22 -0400)] 
Fix: send/received actual size is overwritten by 'expected' size

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

None.

Cause
=====

None.

Solution
========

Return the actual send/received size. Caller code correctly handles
partial send/receive.

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

4 years agounix: add non block send and receive flavors for fd passing
Jonathan Rajotte [Fri, 10 Jul 2020 12:46:04 +0000 (08:46 -0400)] 
unix: add non block send and receive flavors for fd passing

These will be used by the notification subsystem.

It is important to note that based on our current knowledge the sending
/receiving of fds is an all or nothing scenario. The fds are actually
part of the control message instead of the `payload`. On the receiving
side, a reception of N fds will only yield a "read" count of 1 bytes on
reception.

Albeit we don't have to account for the partial send/receive, we have to
manage the EAGAIN/EWOULDBLOCK scenario off non-blocking socket.

The caller of these function must handle the following scenario:

  ret < 0 -> error
  ret == 0 (Nothing received/sent)
  ret > 0 -> success

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

4 years agoFix: partial recv lead to client disconnect
Jonathan Rajotte [Thu, 9 Jul 2020 18:57:57 +0000 (14:57 -0400)] 
Fix: partial recv lead to client disconnect

On EWOULDBLOCK and EAGAIN, the ret value from
`lttcomm_send_unix_sock_non_block` and
`lttcomm_recv_unix_sock_non_block` would be equal to -1.

Solution
=====

For such cases, set ret equal to zero since it is effectively what was
received/sent. Caller should treat ret  >= 0 as `success` anyway.

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

4 years agotests: return the proper TAP exit code
Michael Jeanson [Mon, 13 Jul 2020 19:41:01 +0000 (15:41 -0400)] 
tests: return the proper TAP exit code

The C TAP library provides the 'exit_status()' function that will return
the proper exit code according to the number of tests that succeeded or
failed.

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

4 years agoAdd tests/unit/test_payload to .gitignore
Michael Jeanson [Tue, 7 Jul 2020 19:16:19 +0000 (15:16 -0400)] 
Add tests/unit/test_payload to .gitignore

Signed-off-by: Michael Jeanson <mjeanson@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: Ic792326a78f6eac8d12682dc23642290f14289ff
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
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 agoCleanup: Tests: live/test_{lttng_,}ust: testapp not in background
Francis Deslauriers [Thu, 9 Jul 2020 20:30:14 +0000 (16:30 -0400)] 
Cleanup: Tests: live/test_{lttng_,}ust: testapp not in background

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

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: use sys/types.h for ssize_t on Cygwin
Jonathan Rajotte [Tue, 21 Jul 2020 15:00:40 +0000 (11:00 -0400)] 
Fix: use sys/types.h for ssize_t on Cygwin

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

On cygwin worker:
  In file included from snapshot.c:10:
  ../../src/common/snapshot.h:33:1: error: unknown type name `ssize_t`; did you mean `_ssize_t`?
     33 | ssize_t lttng_snapshot_output_create_from_buffer(
        | ^~~~~~~
        | _ssize_t
  snapshot.c:128:9: error: conflicting types for `lttng_snapshot_output_create_from_buffer`
    128 | ssize_t lttng_snapshot_output_create_from_buffer(
        |         ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
  In file included from snapshot.c:10:
  ../../src/common/snapshot.h:33:9: note: previous declaration of `lttng_snapshot_output_create_from_buffer` was here
     33 | ssize_t lttng_snapshot_output_create_from_buffer(
        |

Solution
========

Include sys/types.h.

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

4 years agoAdd kernel and UST time namespace context
Michael Jeanson [Mon, 6 Jul 2020 16:18:01 +0000 (12:18 -0400)] 
Add kernel and UST time namespace context

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

4 years agoFix: sessiond: wrong variable checked for error code
Jérémie Galarneau [Tue, 21 Jul 2020 16:51:48 +0000 (12:51 -0400)] 
Fix: sessiond: wrong variable checked for error code

Coverity reports:
  1430513 Logically dead code

  The indicated dead code may have performed some action; that action
  will never occur.

  In ust_app_open_packets: Code can never be reached because of a
  logical contradiction (CWE-561)

The `open_ret` variable should be checked instead of `ret` after calling
consumer_open_channel_packets.

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

4 years agoFix: consumerd: double unlock on rotate channel error path
Jérémie Galarneau [Tue, 21 Jul 2020 16:44:59 +0000 (12:44 -0400)] 
Fix: consumerd: double unlock on rotate channel error path

Coverity Scan reports:
  1430541 Double unlock

  May result in undefined behavior.

  In lttng_consumer_rotate_channel: Attempt to release a non-recursive
  lock that is not held (CWE-765)

The error path should jump to end_unlock_channel as the stream
lock is only held for the duration of the call to
consumer_stream_open_packet.

This bug was introduced by the previous commit.

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

4 years agoFix: consumerd: packet sent before channel rotation
Jérémie Galarneau [Mon, 20 Jul 2020 19:29:41 +0000 (15:29 -0400)] 
Fix: consumerd: packet sent before channel rotation

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

A clear test occasionally fails with the following output:
  # Test ust streaming rotate-clear
  # Parameters: tracing_active=0, clear_twice=1, rotate_before=0, rotate_after=0, buffer_type=uid
  ok 605 - Create session S0BXcJKWrmAwNSzm with uri:net://localhost and opts:
  PASS: tools/clear/test_ust 605 - Create session S0BXcJKWrmAwNSzm with uri:net://localhost and opts:
  ok 606 - Enable channel chan for session S0BXcJKWrmAwNSzm
  PASS: tools/clear/test_ust 606 - Enable channel chan for session S0BXcJKWrmAwNSzm
  ok 607 - Enable ust event tp:tptest for session S0BXcJKWrmAwNSzm
  PASS: tools/clear/test_ust 607 - Enable ust event tp:tptest for session S0BXcJKWrmAwNSzm
  ok 608 - Start tracing for session S0BXcJKWrmAwNSzm
  PASS: tools/clear/test_ust 608 - Start tracing for session S0BXcJKWrmAwNSzm
  ok 609 - Rotate session S0BXcJKWrmAwNSzm
  PASS: tools/clear/test_ust 609 - Rotate session S0BXcJKWrmAwNSzm
  ok 610 - Stop lttng tracing for session S0BXcJKWrmAwNSzm
  PASS: tools/clear/test_ust 610 - Stop lttng tracing for session S0BXcJKWrmAwNSzm
  ok 611 - Clear session S0BXcJKWrmAwNSzm
  PASS: tools/clear/test_ust 611 - Clear session S0BXcJKWrmAwNSzm
  ok 612 - Clear session S0BXcJKWrmAwNSzm
  PASS: tools/clear/test_ust 612 - Clear session S0BXcJKWrmAwNSzm
  Error: Relayd rotate streams replied error 97
  Error: Relayd rotate stream failed. Cleaning up relayd 33
  Error: Relayd send index failed. Cleaning up relayd 33.
  Error: Rotate channel failed
  Error: Stream 76 relayd ID 33 unknown. Can't write index.
  Error: Stream 74 relayd ID 33 unknown. Can't write index.
  Error: Stream 72 relayd ID 33 unknown. Can't write index.
  ok 613 - Start tracing for session S0BXcJKWrmAwNSzm
  PASS: tools/clear/test_ust 613 - Start tracing for session S0BXcJKWrmAwNSzm
  not ok 614 - Stop lttng tracing for session S0BXcJKWrmAwNSzm
  FAIL: tools/clear/test_ust 614 - Stop lttng tracing for session S0BXcJKWrmAwNSzm
  #   Failed test 'Stop lttng tracing for session S0BXcJKWrmAwNSzm'
  #   in ./tools/clear//../../../utils/utils.sh:stop_lttng_tracing_opt() at line 1311.
  ok 615 - Validate trace for event tp:tptest, 1 events
  PASS: tools/clear/test_ust 615 - Validate trace for event tp:tptest, 1 events
  not ok 616 - Read a total of 1 events, expected 4
  FAIL: tools/clear/test_ust 616 - Read a total of 1 events, expected 4
  #   Failed test 'Read a total of 1 events, expected 4'
  #   in ./tools/clear//../../../utils/utils.sh:validate_trace_count() at line 1764.
  Error: Failed to perform an implicit rotation as part of the destruction of session "S0BXcJKWrmAwNSzm": Unknown error code
  not ok 617 - Destroy session S0BXcJKWrmAwNSzm
  FAIL: tools/clear/test_ust 617 - Destroy session S0BXcJKWrmAwNSzm
  #   Failed test 'Destroy session S0BXcJKWrmAwNSzm'
  #   in ./tools/clear//../../../utils/utils.sh:destroy_lttng_session() at line 1347.
  # Test ust streaming clear-rotate

Looking at the relay daemon log when the problem is reproduced,
we see:
  Error: Protocol error: received a packet for a stream that doesn't have a current trace chunk: stream_id = 1, channel_name = chan_0

Cause
=====

The "rotate channel" consumer command iterates over a channel's streams
to perform a rotation and open a new packet when necessary
(see comments).

In the case where a channel is associated with a relay daemon, the
rotation positions are accumulated to send a single "rotate channel
streams" command to the relay daemon. This is done to reduce the time
needed to complete a rotation when tracing to a relay daemon through an
high-latency network connection.

Unfortunately, this causes packets to be opened before the rotation
command was sent to the relay daemon as the "open packet" command
is performed during the iteration on the streams.

Solution
========

Streams for which a packet should be opened are accumulated into an
array of stream pointers. The "open packet" is performed after a
successful rotation of the streams as a second "pass".

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

None.

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

4 years agoClean-up: relayd: missing space in debug statement
Jérémie Galarneau [Mon, 20 Jul 2020 15:48:23 +0000 (11:48 -0400)] 
Clean-up: relayd: missing space in debug statement

Missing space in rotation debug statement results in logs of the form:
  [...] Rotate stream 1at sequence number 4 [...]

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

4 years agoFix: relayd: wrong specifier used in DBG format string
Jérémie Galarneau [Fri, 17 Jul 2020 18:26:17 +0000 (14:26 -0400)] 
Fix: relayd: wrong specifier used in DBG format string

`len` is of type uint64_t while the format string specifies a size of
`%zd`. This results in a warning on most 32-bit architectures.

  In file included from ../../../src/common/common.h:12:0,
                   from live.c:33:
  live.c: In function `viewer_get_metadata`:
  ../../../src/common/error.h:161:35: warning: format `%zd` expects
  argument of type `signed size_t`, but argument 6 has type `uint64_t
  {aka long long 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)
                             ^~~~~~~
  live.c:2051:4: note: in expansion of macro `DBG`
      DBG("Failed to read metadata: requested = %zd, got = %zd",
      ^~~

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

4 years agoTests: add a "new metadata after clear" test
Jérémie Galarneau [Thu, 16 Jul 2020 21:17:08 +0000 (17:17 -0400)] 
Tests: add a "new metadata after clear" test

Add a test that validates that the relay daemon performs a
metadata stream rotation after a clear.

The test enables a single event and launches a test application to
trigger it 10 times. Once the 10 event occurrences have been seen
by the live client, the session is cleared.

Then, two new events (statedump start and end) are enabled. This causes
new event descriptions to be appended to the metadata stream.

After a clear, the relay daemon should rotate the metadata stream
and send the new contents to the client. The client will then
be able to decode the statedump start/end events.

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

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 agoClean-up: consumer: move open packet to post_consume
Jérémie Galarneau [Wed, 8 Jul 2020 18:57:40 +0000 (14:57 -0400)] 
Clean-up: consumer: move open packet to post_consume

Move the "open packet" step of read_subbuffer to a post-consume callback
as this only needs to be done for data streams; it does not belong in
the core of the read_subbuffer template method.

Change-Id: Ia4d3f8f833e213a8d0e39bcf5ec766c2c05bcf80
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoFix: stream intersection fails on snapshot of cleared session
Jérémie Galarneau [Fri, 26 Jun 2020 22:40:12 +0000 (18:40 -0400)] 
Fix: stream intersection fails on snapshot of cleared session

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

In the following scenario:
  lttng create --snapshot
  lttng enable-event -u -a
  lttng start
  taskset -c 0 <tracepoint producing app>
  lttng clear
  taskset -c 0 <tracepoint producing app>
  lttng snapshot record
  lttng destroy

When using the stream-intersection mode, babetrace complains that the
time range for the intersection is invalid since the begin timestamp is
after the end timestamp.

This is caused by the presence of "inactive" streams for which no events
are recorded between the clear action and the recording of the snapshot.
These streams have a begin timestamp roughly equal to the moment when
the snapshot was taken (i.e. the end timestamp). Babeltrace, in
stream-intersection mode, attempts to use the latest beginning timestamp
of all streams as the start of the intersection and the earliest end
timestamp as the end boundary.

Path                                                        │File size        │Packets     │Timestamp: beginning         │Timestamp: end               │
snapshot-1-20200622-212617-1/ust/uid/1000/64-bit/channel0_0 │        4.000 KiB│           1│2020-06-22 21:26:01.903685878│2020-06-22 21:26:17.630456312
snapshot-1-20200622-212617-1/ust/uid/1000/64-bit/channel0_1 │        4.000 KiB│           1│2020-06-22 21:26:17.630909310│2020-06-22 21:26:17.630909310
snapshot-1-20200622-212617-1/ust/uid/1000/64-bit/channel0_2 │        4.000 KiB│           1│2020-06-22 21:26:17.631295033│2020-06-22 21:26:17.631295033
snapshot-1-20200622-212617-1/ust/uid/1000/64-bit/channel0_3 │        4.000 KiB│           1│2020-06-22 21:26:17.631673614│2020-06-22 21:26:17.631673614

Cause
=====

The packet beginning timestamps of the buffers are initialized on
creation (on the first "start" of a tracing session). When a "clear" is
performed on a session, all open packets are closed and the existing
contents are purged.

If a stream is inactive, it is possible for no packet to be "opened"
until a snapshot of the tracing session is recorded.

Solution
========

A new consumer command, "open channel packets" is added. This command
performs a "flush empty" operation on all streams of a channel.

This command is invoked after a clear (after the tracing is re-started)
and on start. This ensures that streams are opened as soon as possible
after a clear, a rotation, or a session start.

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

In the case of an inactive stream, this results an extra empty packet at
the beginning of the inactive streams (typically 4kB) in the snapshots.

In the case of an active stream, this change will cause the first packet
to be empty or contain few events. If the stream is active enough to
wrap-around, that empty packet will simply be overwritten.

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

4 years agoFix: relayd: viewer metadata is not rotated after a session clear
Jérémie Galarneau [Mon, 13 Jul 2020 22:42:22 +0000 (18:42 -0400)] 
Fix: relayd: viewer metadata is not rotated after a session clear

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

Following a session clear, babeltrace sometimes doesn't receive
the content of the metadata that is announced in the get_metadata
reply header.

This causes babeltrace2 to assert (a fix has been submitted) since
the protocol state becomes de-synchronized, causing babeltrace to
interpret follow-up replies as garbage.

This was occasionally observed on the CI when running the "clear" tests.

Cause
=====

There are no provisions made for rotating a viewer metadata stream when
a clear is performed on a live session. This means that a client can
request metadata that is only present in a newer chunk.

In the case of the crashes observed on the CI, the relay daemon attempts
to service a get_new_metadata request of size `4096`. It then fails to
read the data (as it was never present in the original trace chunk).

The relay daemon does not interpret the `0` returned by lttng_read() as
an error and sends a reply announcing `4096`bytes of metadata and no
payload.

Solution
========

Two fixes are rolled into this patch.

First, the return of lttng_read is checked for `0` and that situation is
handled as an error. However, this still leaves the problem of the
metadata stream not being rotated.

Secondly, the metadata relay_stream is checked for a rotation on every
`get_metadata` command. If a rotation has been detected, a viewer
rotation is performed on the metadata stream (very similar to the data
stream).

This solves the problem, but it leaves a case which the protocol does
not account for.

Essentially, the following can take place:
  - relayd sets the "NEW_METADATA" flag as part of a `get_next_index`
    query reply
  - A rotation of the metadata stream occurs, no data is sent.
  - client requests metadata
    - metadata sent > received (was reset to 0 as part of the rotation)

In this scenario, the current implementation returned NO_NEW_METADATA,
but it is erroneous. Returning this guarantees to the viewer that it
will be able to decode all data packets that follow (until new metadata
is signalled, if ever).

Ideally, we would return a `RETRY` code, as is done by the data stream
handler when it detects that a rotation is taking place. Unfortunately,
such a code doesn't exist for the `get_metadata` command.

We return ̀ OK` with a length of 0, which is technically correct since
viewers are supposed to fetch metadata until the relay daemon returns
the `NO_NEW_METADATA` status code. However, supporting this has required
changes to babeltrace2's lttng-live source component.

I'm anticipating that most implementations don't handle the 0-length
case any better.

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

Older viewers may not handle `OK` replies with a length of 0 gracefully.

Sending `NO_NEW_METADATA` is not an option as it breaks the guarantee
that all necessary metadata will be received before `NO_NEW_METADATA`.

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

4 years agoFix: post-clear trace chunk has a late beginning packet
Jérémie Galarneau [Thu, 25 Jun 2020 23:22:24 +0000 (19:22 -0400)] 
Fix: post-clear trace chunk has a late beginning packet

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

In the following scenario:
  - create a regular session
  - enable an event that occurs on only one core
  - start tracing
  - trace for a while
  - stop tracing
  - clear the session
  - start
  - trace for a while (referred to the "active period" later on)
  - stop

The resulting trace will contain a very short stream intersection as the
active stream will contain packets spanning the entire active period.
However, all other streams will contain a single packet at the end of
the active period with a duration of 0 ns.

This presents two problems:
  1) This makes the stream intersection mode of viewers unusable,
  2) This misleads the user into thinking that tracing was not active
     for some buffers.

Cause
=====

The packet beginning timestamps of the buffers are initialized on
creation (on the first "start" of a tracing session). When a "clear" is
performed on a session, all open packets are closed and the existing
contents are purged.

If a stream is inactive, it is possible for no packet to be "opened"
until the "stop" of the tracing session.

On stop, a "flush_empty" is performed. Such a flush opens a packet
(if it was not already the case), closes it, and marks the packet as
being ready for consumption.

Solution
========

Attempt to flush an empty packet as close to the rotation point as
possible. In the event where a stream remains inactive after the
rotation point, this ensures that the new trace chunk has a beginning
timestamp set at the begining of the trace chunk instead of only
creating an empty packet when the trace chunk is stopped.

This indicates to the viewers that the stream was being recorded, but
more importantly it allows viewers to determine a useable trace
intersection.

This presents a problem in the case where the ring-buffer is completely
full.

Consider the following scenario:
  - The consumption of data is slow (slow network, for instance),
  - The ring buffer is full,
  - A rotation is initiated,
    - The flush below does nothing (no space left to open a new packet),
  - The other streams rotate very soon, and new data is produced in the
    new chunk,
  - This stream completes its rotation long after the rotation was
    initiated
  - The session is stopped before any event can be produced in this
    stream's buffers.

The resulting trace chunk will have a single packet temporaly at the end
of the trace chunk for this stream making the stream intersection more
narrow than it should be.

To work-around this, an empty flush is performed after the first
consumption of a packet during a rotation if the initial flush failed.
The idea is that consuming a packet frees enough space to switch packets
in this scenario and allows the tracer to "stamp" the beginning of the
new trace chunk at the earliest possible point.

Note that metadata streams are always skipped when opening a packet.
This is done for two reasons:
  1) Timestamps are not relevant to the metadata stream
  2) Inserting an empty packet in the metadata stream after a rotation
     breaks the use of "clear" in live mode.

     The contents of the metadata streams of successive chunks must be
     strict superset of one another as live clients only receive the
     information appended to a metadata stream (i.e. the parts it
     already has received can't change).

     If a flush_empty was performed after a clear/rotation, it would
     result in an empty packet being inserted at the beginning of the
     metadata stream that wasn't present in the first chunk.

     This would cause the live client and relay daemon to have
     mismatching copies of the metadata stream.

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

In the case of an inactive stream, this results in the completed trace
chunk archive containing an extra empty packet at the beginning of the
stream (typically 4kB).

In the case of an active stream, this change will cause the first packet
to be empty or contain few events.

Those are all efficiency losses that are inevitable (AFAIK) given the
current buffer control APIs. It will be possible to recoup those losses
if an API allowing the consumer daemon to open a new packet is
introduced.

As noted in the comments, this patch is not final. The flush after the
rotation should not be open-coded in lttng_consumer_read_subbuffer. It
should be a data-stream specific "post-consume" step.

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

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 agoClean-up: relayd: unused tcp keep alive config return value
Jérémie Galarneau [Tue, 14 Jul 2020 21:15:49 +0000 (17:15 -0400)] 
Clean-up: relayd: unused tcp keep alive config return value

gcc 10.1.0 reports:
  tcp_keep_alive.c: In function \u2018tcp_keep_alive_init\u2019:
  tcp_keep_alive.c:519:9: warning: \u2018removed_return.58\u2019 is used uninitialized in this function [-Wuninitialized]
    519 |  return tcp_keep_alive_init_config(&support, &config);
        |         ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

tcp_keep_alive_init is a constructor and, as such, should not return a
value. GCC warns that its return value is unused (although with a
somewhat strange warning message).

The return value of tcp_keep_alive_init_config is ignored as all
error paths log a suitable error and not much more can be done.

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

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: 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 agoConvert `README.md` to `README.adoc`
Philippe Proulx [Tue, 5 May 2020 19:37:30 +0000 (15:37 -0400)] 
Convert `README.md` to `README.adoc`

Asciidoctor offers more features than Markdown which this README can
benefit from (attributes, table of contents, description lists, and
non-HTML internal anchors to name a few).

On GitHub, the table of contents is placed right after the preamble,
before the first section's heading. Otherwise, it's placed on the left
for increased readability (not supported by GitHub).

Signed-off-by: Philippe Proulx <eeppeliteloop@gmail.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: Id4965abaa7151cb0fc3caca290fcf5d3669f0b80

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 agotests: gen-ust-events-ns/tp.h: Fix build with musl libc
Ovidiu Panait [Mon, 18 May 2020 13:39:26 +0000 (16:39 +0300)] 
tests: gen-ust-events-ns/tp.h: Fix build with musl libc

Fix the following build error with musl libc:
In file included from ../../../../../lttng-tools-2.12.0/tests/utils/testapp/gen-ust-events-ns/tp.h:14,
                 from ../../../../../lttng-tools-2.12.0/tests/utils/testapp/gen-ust-events-ns/tp.c:10:
../../../../../lttng-tools-2.12.0/tests/utils/testapp/gen-ust-events-ns/tp.h:17:10: error: unknown type name 'ino_t'; did you mean 'int8_t'?
   17 |  TP_ARGS(ino_t, ns_ino),
      |          ^~~~~
../../../../../lttng-tools-2.12.0/tests/utils/testapp/gen-ust-events-ns/tp.h:17:10: error: unknown type name 'ino_t'; did you mean 'int8_t'?
   17 |  TP_ARGS(ino_t, ns_ino),
      |          ^~~~~
../../../../../lttng-tools-2.12.0/tests/utils/testapp/gen-ust-events-ns/./tp.h:17:2: error: unknown type name 'ino_t'; did you mean 'int8_t'?
   17 |  TP_ARGS(ino_t, ns_ino),
      |  ^~~~~~~
../../../../../lttng-tools-2.12.0/tests/utils/testapp/gen-ust-events-ns/./tp.h:17:2: error: unknown type name 'ino_t'; did you mean 'int8_t'?
   17 |  TP_ARGS(ino_t, ns_ino),
      |  ^~~~~~~

Signed-off-by: Ovidiu Panait <ovidiu.panait@windriver.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: Ic7a73c6754fc30a62bdf6519062c07be65a2eaba

4 years agoactions: Expose lttng_action_type_string internally
Jonathan Rajotte [Wed, 15 Jan 2020 17:00:25 +0000 (12:00 -0500)] 
actions: Expose lttng_action_type_string internally

This will ease debugging output on the action handling code.

Change-Id: I81b6faf5bb8b5082edcf3895ea88c8690572475a
Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoactions: introduce action group
Simon Marchi [Mon, 2 Dec 2019 21:41:52 +0000 (16:41 -0500)] 
actions: introduce action group

This patch introduces action groups as a new kind of action.

When creating a trigger, it is only possible to attach a single action.
Action groups allow users to attach more than one action.

A group is created using lttng_action_group_create.  Actions are added
to it using lttng_action_group_add_action.  The group can then be used
in a trigger, like any other action.

The operations required to be implemented by actions (serialize,
create_from_buffer, validate) are implemented by executing the operation
on all elements.

Current limitations are:

- To avoid any cycle, it is not possible to add a group inside a group.

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

4 years agoactions: Make lttng_action reference countable
Jérémie Galarneau [Wed, 5 Feb 2020 23:13:07 +0000 (18:13 -0500)] 
actions: Make lttng_action reference countable

lttng_action objects will be shared with the action executor subsystem
which executes them asynchronously. This introduces an ambiguous
ownership since triggers could be unregistered while an action is
executing (or pending execution).

Also ease the object ownership management of the group action sub
actions. This allow clients to add multiple time the same action to an
action group without any problem.

The currently user-visible 'destroy' method simply calls the 'put'
method which preserves the expected behaviour for current users (both
internal and public) of the API.

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

4 years agoactions: introduce snapshot session action
Simon Marchi [Mon, 2 Dec 2019 20:20:38 +0000 (15:20 -0500)] 
actions: introduce snapshot session action

This patch introduces the API for the "snapshot session" action.

A snapshot session action is created using the
lttng_action_snapshot_session_create function. It is mandatory to set a
session name using lttng_action_snapshot_session_set_session_name before
using the action in a trigger.

It is possible, but optional, to provide a snapshot name with
lttng_action_snapshot_session_set_snapshot_name.

The patch adds the code for serializing the action and deserializing it
on the sessiond side, but not the code for executing it.

Change-Id: I2b76680d44bf69eb705f2a238fffef2519b82534
Signed-off-by: Simon Marchi <simon.marchi@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoClean-up: replace space by tabs
Jonathan Rajotte [Fri, 5 Jun 2020 15:30:49 +0000 (11:30 -0400)] 
Clean-up: replace space by tabs

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

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 agoliblttng-ctl: use lttng_payload for serialize/create_from_buffer
Jérémie Galarneau [Wed, 10 Jun 2020 19:39:47 +0000 (15:39 -0400)] 
liblttng-ctl: use lttng_payload for serialize/create_from_buffer

Some objects used in the sessiond <-> liblttng-ctl communication (e.g.
such as userspace probe event rule) contain file descriptors that
must be carried accross process boundaries (fd passing).

Since those objects are often nested within a higher-level object
hierarchy, it makes sense to adapt the existing
serialize/create_from_buffer interface to use an lttng_payload.

An lttng_payload contains a dynamic buffer and an array of file
descriptors. Objects are expected to push their file descriptors in the
payload in the same way they currently push the bytes of their binary
representation in a dynamic buffer.

Conversely, an lttng_payload_view interface is added and contains a
buffer_view and an iterator which allows objects to ̀ pop` a file
descriptors when appropriate.

Tests are added to validate the FD consumption behaviour depending
on the origin of payload views (root view or descendant view).

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

4 years agocommon: set dynamic-buffer's data to NULL on reset()
Jérémie Galarneau [Wed, 10 Jun 2020 17:02:29 +0000 (13:02 -0400)] 
common: set dynamic-buffer's data to NULL on reset()

Set 'data' to NULL after the reset of a dynamic_buffer since
re-using it (e.g. appending) will cause realloc to be called
with an invalid pointer.

Not marked as a fix as no code currently re-uses a buffer after
a reset().

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

4 years agoClean-up: coding style fixes in dynamic-buffer.c
Jérémie Galarneau [Wed, 10 Jun 2020 17:00:16 +0000 (13:00 -0400)] 
Clean-up: coding style fixes in dynamic-buffer.c

1) An empty line is expected before any statement after a scope is
   closed
2) Variables should be marked const where possible.

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

4 years agoliblttng-ctl: add facilities for lttng_snapshot_output object
Jonathan Rajotte [Tue, 9 Jun 2020 00:29:58 +0000 (20:29 -0400)] 
liblttng-ctl: add facilities for lttng_snapshot_output object

Internal:
  is_equal, serialize, validate, from_buffer.

Public:
  set_local_path, set_network_url set_network_urls

These APIs are used by the upcoming "snapshot session" action
used to trigger a snapshot on a given condition.

The internal API is added to transmit a snapshot output as part of an
action while the public API is added to clean-up the current
snapshot_output API which will be used by the client to create the
snapshot_session actions.

For instance, with set_local_path, it is no longer necessary to create a
local snapshot output by calling lttng_snapshot_output_set_ctrl_url
with a "file://" protocol.

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

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 agoactions: introduce rotate session action
Simon Marchi [Mon, 2 Dec 2019 20:01:50 +0000 (15:01 -0500)] 
actions: introduce rotate session action

This patch introduces the API for the "rotate session" action.

A rotate session action is created using the
lttng_action_rotate_session_create function.  It is mandatory to set a
session name using lttng_action_rotate_session_set_session_name before
using the action in a trigger.

The patch adds the code for serializing the action and deserializing it
on the sessiond side, but not the code for executing it.

Change-Id: I8ed1a71a00deaa6abafaff703a8980c2c7598bda
Signed-off-by: Simon Marchi <simon.marchi@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoactions: introduce stop session action
Simon Marchi [Mon, 2 Dec 2019 19:53:11 +0000 (14:53 -0500)] 
actions: introduce stop session action

This patch introduces the API for the "stop session" action.

A stop session action is created using the
lttng_action_stop_session_create function.  It is mandatory to set a
session name using lttng_action_stop_session_set_session_name before
using the action in a trigger.

The patch adds the code for serializing the action and deserializing it
on the sessiond side, but not the code for executing it.

Change-Id: Ie00d744340f85f15a333680cf86d3882bd612d1a
Signed-off-by: Simon Marchi <simon.marchi@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoactions: introduce start session action
Simon Marchi [Fri, 29 Nov 2019 21:48:45 +0000 (16:48 -0500)] 
actions: introduce start session action

This patch introduces the API for the "start session" action.

A start session action is created using the
lttng_action_start_session_create function.  It is mandatory to set a
session name using lttng_action_start_session_set_session_name before
using the action in a trigger.

The patch adds the code for serializing the action and deserializing it
on the sessiond side, but not the code for executing it.

Change-Id: I90598e25a461ccabcf7dc327aaa73b3d35e203af
Signed-off-by: Simon Marchi <simon.marchi@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoactions: implement is_equal
Jonathan Rajotte [Sat, 14 Dec 2019 00:06:41 +0000 (19:06 -0500)] 
actions: implement is_equal

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Change-Id: I9272253202cfd0d6b6fb165293a534a824fbe854
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoClean-up: sort includes per clang format in action.c
Jonathan Rajotte [Sat, 18 Apr 2020 04:10:41 +0000 (00:10 -0400)] 
Clean-up: sort includes per clang format in action.c

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Change-Id: I1dd53d6c7a6e561d4537ba483f38e1ac2ace391e
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoformat: AlignOperand introduces spaces
Jonathan Rajotte [Mon, 20 Apr 2020 18:27:45 +0000 (14:27 -0400)] 
format: AlignOperand introduces spaces

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

t = tabs
s = space
tabs = 8 blanks

clang-format on this code will align with the operand using space.

consumed_len = sizeof(struct lttng_action_start_session_comm) +
t       ssssssscomm->session_name_len;

We want:
consumed_len = sizeof(struct lttng_action_start_session_comm) +
t       t       comm->session_name_len;

Solution
========

Explicitly set it to false.

Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Change-Id: I39bee6d82b20f4b6f9587a2911abb183de767d25
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
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 agoFix: common: fs_handle_seek returns negative value on success
Jonathan Rajotte [Thu, 21 May 2020 00:53:45 +0000 (20:53 -0400)] 
Fix: common: fs_handle_seek returns negative value on success

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

Babeltrace 1/2 fails to fetch data from a live session.

Error:

 PLUGIN/SRC.CTF.LTTNG-LIVE/VIEWER lttng_live_get_stream_bytes@viewer-connection.c:1593 [lttng-live] Received get_data_packet response: error
 PLUGIN/CTF/MSG-ITER request_medium_bytes@msg-iter.c:546 [lttng-live] User function failed: status=ERROR
 PLUGIN/CTF/MSG-ITER ctf_msg_iter_get_next_message@msg-iter.c:2881 [lttng-live] Cannot handle state: msg-it-addr=0x562d87521a40, state=DSCOPE_TRACE_PACKET_HEADER_BEGIN
 PLUGIN/SRC.CTF.LTTNG-LIVE lttng_live_iterator_next_handle_one_active_data_stream@lttng-live.c:821 [lttng-live] CTF message iterator failed to get next message: msg-iter=0x562d87521a40, msg-iter-status=ERROR
 PLUGIN/SRC.CTF.LTTNG-LIVE lttng_live_msg_iter_next@lttng-live.c:1499 [lttng-live] Error preparing the next batch of messages: live-iter-status=LTTNG_LIVE_ITERATOR_STATUS_ERROR
 LIB/MSG-ITER bt_message_iterator_next@iterator.c:865 Component input port message iterator's "next" method failed: iter-addr=0x562d8751ab70, iter-upstream-comp-name="lttng-live", iter-upstream-comp-log-level=WARNING, iter-upstream-comp-class-type=SOURCE, iter-upstream-comp-class-name="lttng-live", iter-upstream-comp-class-partial-descr="Connect to an LTTng relay daemon", iter-upstream-port-type=OUTPUT, iter-upstream-port-name="out", status=ERROR
 PLUGIN/FLT.UTILS.MUXER muxer_upstream_msg_iter_next@muxer.c:446 [muxer] Upstream iterator's next method returned an error: status=ERROR
 PLUGIN/FLT.UTILS.MUXER validate_muxer_upstream_msg_iters@muxer.c:989 [muxer] Cannot validate muxer's upstream message iterator wrapper: muxer-msg-iter-addr=0x562d87515280, muxer-upstream-msg-iter-wrap-addr=0x562d8751ca90
 PLUGIN/FLT.UTILS.MUXER muxer_msg_iter_next@muxer.c:1417 [muxer] Cannot get next message: comp-addr=0x562d8751a260, muxer-comp-addr=0x562d8751a2e0, muxer-msg-iter-addr=0x562d87515280, msg-iter-addr=0x562d8751aa90, status=ERROR
 LIB/MSG-ITER bt_message_iterator_next@iterator.c:865 Component input port message iterator's "next" method failed: iter-addr=0x562d8751aa90, iter-upstream-comp-name="muxer", iter-upstream-comp-log-level=WARNING, iter-upstream-comp-class-type=FILTER, iter-upstream-comp-class-name="muxer", iter-upstream-comp-class-partial-descr="Sort messages from multiple inpu", iter-upstream-port-type=OUTPUT, iter-upstream-port-name="out", status=ERROR
 LIB/GRAPH consume_graph_sink@graph.c:462 Component's "consume" method failed: status=ERROR, comp-addr=0x562d8751a3d0, comp-name="pretty", comp-log-level=WARNING, comp-class-type=SINK, comp-class-name="pretty", comp-class-partial-descr="Pretty-print messages (`text` fo", comp-class-is-frozen=0, comp-class-so-handle-addr=0x562d8751a110, comp-class-so-handle-path="/usr/local/lib/babeltrace2/plugins/babeltrace-plugin-text.so", comp-input-port-count=1, comp-output-port-count=0
 CLI cmd_run@babeltrace2.c:2529 Graph failed to complete successfully
 PLUGIN/SRC.CTF.LTTNG-LIVE/VIEWER lttng_live_session_detach@viewer-connection.c:1211 [lttng-live] Unknown detach return code 0

The relevant relayd log:

 DEBUG2 - Relay get data packet (in viewer_get_packet() at live.c:1770)
 PERROR - Failed to seek file system handle of viewer stream 4 to offset 2244861952: Success (in viewer_get_packet() at live.c:1810)
 DEBUG1 - Sent 262156 bytes for stream 4 (in viewer_get_packet() at live.c:1852)

Cause
=====

The fs_handle_seek function calls lseek on a stream file of ~2.5GB. The
return value of the lseek call is downcasted from off_t (signed 64 bit
on my system) to int. The resulting value is negative and force an error
at the call sites.

Solution
========

Use off_t as the return type.

Note that current call sites of fs_handle_seek already expect an off_t
return value.

ag fs_handle_seek:

 src/bin/lttng-relayd/stream.c
 249: lseek_ret = fs_handle_seek(previous_stream_file, previous_stream_copy_origin, SEEK_SET);

 src/bin/lttng-relayd/live.c
 1804: lseek_ret = fs_handle_seek(vstream->stream_file.handle,

 src/bin/lttng-relayd/viewer-stream.c
 176: lseek_ret = fs_handle_seek(

ag lseek_ret:

 src/bin/lttng-relayd/stream.c
 193: off_t lseek_ret, previous_stream_copy_origin;

 src/bin/lttng-relayd/live.c
 1760: off_t lseek_ret;

 src/bin/lttng-relayd/viewer-stream.c
 174: off_t lseek_ret;

Known drawbacks
=========

This limitation existed before this patch.

On 32bit system without _FILE_OFFSET_BITS=64 defined at compile time
(-D_FILE_OFFSET_BITS=64) the lseek operation could return EOVERFLOW for
stream file bigger then 2,147,483,647 bytes. Anybody working on a 32bit
system should be aware of the limitation of working in 32bit.

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

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 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 agoMake lttng_dynamic_buffer_append_buffer const-correct
Jérémie Galarneau [Fri, 15 May 2020 19:55:27 +0000 (15:55 -0400)] 
Make lttng_dynamic_buffer_append_buffer const-correct

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

4 years ago.gitignore: add test_buffer_view
Jérémie Galarneau [Tue, 12 May 2020 18:37:37 +0000 (14:37 -0400)] 
.gitignore: add test_buffer_view

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

4 years agoFix: liblttng-ctl: leak of tracker handle in lttng_[un]track_pid
Jérémie Galarneau [Wed, 20 May 2020 19:56:03 +0000 (15:56 -0400)] 
Fix: liblttng-ctl: leak of tracker handle in lttng_[un]track_pid

The lttng_track_pid and lttng_untrack_pid functions were reimplemented
on top of the new lttng_process_attr_tracker_handle API (new in 2.12).

Both functions do not destroy the tracker handle on their return
path.

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

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 agoTests: test_exclusion: exclusion after tracing active
Francis Deslauriers [Tue, 5 May 2020 16:27:52 +0000 (12:27 -0400)] 
Tests: test_exclusion: exclusion after tracing active

This testcase tests for a UST bug where exclusions made when the tracing
is active are not excluding the undesired events.

This UST bug was fixed by the following commit:
  commit de713d8a77cbd77e60f58537b0fc222f98fde395
  Author: Francis Deslauriers <francis.deslauriers@efficios.com>
  Date:   Tue May 5 11:51:58 2020 -0400

      Fix: event probes attached before event enabled

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: I6d896682d5f5e16582ab195c6f4d6946de394843
Depends-on: lttng-ust: Id984f266d976f346b001db81cd8a2b74965b5ef2

4 years agoTests: `gen-ust-nevents`: add syncpoints
Francis Deslauriers [Tue, 5 May 2020 16:19:13 +0000 (12:19 -0400)] 
Tests: `gen-ust-nevents`: add syncpoints

Adds two sync points:
  `--sync-in-main`: create a file when `gen-ust-nevents` when app is in
  main,
  `--sync-before-first-event`: wait on a file before starting to
  generate any events.

Those two sync points allow for tests to do work when the testapp has
reached main BUT before any events are generated.

This is useful to perform actions on a UST channel once tracing has
started and is active on a particular app.

For example, we want to test a scenario where events are enabled once an
app is already generating other events.

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

4 years agoTests: accept built-in kernel modules
Francis Deslauriers [Thu, 14 May 2020 18:56:05 +0000 (14:56 -0400)] 
Tests: accept built-in kernel modules

When validating that the kernel tracer is available on the system also
consider that it might be built directly in the kernel.

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

4 years agoAPI: missing includes in lttng.h
Jonathan Rajotte [Mon, 11 May 2020 18:21:51 +0000 (14:21 -0400)] 
API: missing includes in lttng.h

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

4 years agoAPI: missing clear and clear-handle includes in lttng.h
Jonathan Rajotte [Mon, 11 May 2020 18:03:34 +0000 (14:03 -0400)] 
API: missing clear and clear-handle includes in lttng.h

Refs: #1266

Reported-by: Shuo Yang <shuoyang@didiglobal.com>
Signed-off-by: Jonathan Rajotte <jonathan.rajotte-julien@efficios.com>
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
Change-Id: Ia933831e806e51a071f05b2c0425799f2f6410cf

4 years agoAPI: sort lttng.h includes
Jonathan Rajotte [Mon, 11 May 2020 18:02:00 +0000 (14:02 -0400)] 
API: sort lttng.h includes

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

4 years agoFix: API: missing end brace for C++ linkage specification.
Jonathan Rajotte [Mon, 11 May 2020 13:57:53 +0000 (09:57 -0400)] 
Fix: API: missing end brace for C++ linkage specification.

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

4 years agoREADME.md: fix typos in component descriptions
Jérémie Galarneau [Tue, 5 May 2020 17:49:37 +0000 (13:49 -0400)] 
README.md: fix typos in component descriptions

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

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 agoImprove README.md
Philippe Proulx [Thu, 30 Apr 2020 16:33:51 +0000 (12:33 -0400)] 
Improve README.md

Changes:

* Harmonize voice and style.

* Add non-breaking spaces and hyphens where missing.

* Add many internal and external links.

* Add `lttng-crash` and the Python bindings to the list of components.

* Use `≥` instead of `>=` (welcome to 2020).

* Do not specify why you need to configure with `--disable-epoll` to use
  a Linux kernel < 2.6.27: I don't think the end user needs to know
  about poll() vs. epoll().

* Do not mention Mathieu Desnoyers and Paul E. McKenney (this is a
  README, not the `THANKS` file).

* Mention Babeltrace 2 instead of Babeltrace.

* Use `https://babeltrace.org/` instead of
  `https://lttng.org/babeltrace`.

* Add kmod to the list of optional dependencies.

* Specify that you can use `--enable-embedded-help` at build
  configuration time if you don't plan to have a manual pager installed
  on your system.

* Don't mention the known GNU gold bug
  (`http://sourceware.org/bugzilla/show_bug.cgi?id=11317`).

  Again, the end user only cares about which minimal version of the tool
  to use, not why.

* Use clear, ordered build steps.

  For the configuration step, specify which options are available and
  what they change.

* Remove the link to `doc/quickstart.txt`.

  Link to the LTTng Documentation and online manual pages instead, which
  are more complete.

* Remove the link to `doc/streaming-howto.txt`: the LTTng Documentation
  and online manual pages cover this topic.

* Change the "Contact" section for the "Community" section and put all
  the community/communication links in there.

* Remove the "Package contents" section: end users do not care about
  this and we're not keeping it updated as we amend the project's source
  anyway.

Signed-off-by: Philippe Proulx <eeppeliteloop@gmail.com>
Change-Id: I4e4c0b183d9a18243db23cde3edb608e32c5e30e
(cherry picked from commit f8bd3a12204c10743dfbc456d363e30894eddfc5)
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
4 years agoDocs: fix comment typo in lttng-error.h
Christophe Bedard [Wed, 8 Apr 2020 21:04:48 +0000 (17:04 -0400)] 
Docs: fix comment typo in lttng-error.h

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

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