Issue observed
==============
In the CI, builds on SLES15SP5 frequently experience timeouts. From
prior inspections, there are hangs during
tests/regression/tools/clear/test_ust while waiting for babeltrace to
exit.
It is possible to reproduce the problem fairly easily:
$ lttng create --live
$ lttng enable-event --userspace --all
$ lttng start
# Launch an application that emits a couple of events
$ ./my_app
$ lttng stop
# Clear the data, this eventually results in the deletion of all
# trace files on the relay daemon's end.
$ lttng clear
# Attach to the live session from another terminal
$ babeltrace -i lttng-live net://...
# The 'destroy' command completes, but the viewer never exits.
$ lttng destroy
Cause
=====
After the clear command completes, the relay daemon no longer has any
data to serve. We notice that the live client loops endlessly repeatably
sending GET_METADATA requests. In response, the relay daemon replies
with the NO_NEW_METADATA status.
In concrete terms, the viewer_get_metadata() function short-circuits to
send that reply when it sees that the metadata stream has no active
trace chunk (i.e., there are no backing files from which to read the
data at the moment).
This situation is not abnormal in itself: it is legitimate for a client
to wait for the metadata to become available again. For example, in the
reproducer above, it would be possible for the user to restart the
tracing (lttng start), which would create a new trace chunk and make the
metadata stream available. New events could also be emitted following
this restart.
However, when a session's connection is closed, there is no hope that
the metadata stream will ever transition back to an active trace chunk.
Solution
========
When the metadata stream has no active chunk and the corresponding
consumerd-side connection has been closed, there is no way the relay
daemon will be able to serve the metadata contents to the client.
As such, the viewer stream can be disposed-of since it will no longer be
of any use to the client. Since some client implementations expect at
least one GET_METADATA command to result in NO_NEW_METADATA, that status
code is initially returned.
Later, when the client emits a follow-up GET_METADATA request for that
same stream, it will receive an "error" status indicating that the
stream no longer exists. This situation is not treated as an error by
the clients. For instance, babeltrace2 will simply close the
corresponding trace and indicate it ended.
The 'no_new_metadata_notified' flag doesn't appear to be necessary to
implement the behaviour expected by the clients (seeing at least one
NO_NEW_METADATA status reply for every metadata stream). The
viewer_get_metadata() function is refactored a bit to drop the global
reference to the viewer metadata stream as it exits, while still
returning the NO_NEW_METADATA status code.
Known drawbacks
===============
None.
Note
====
The commit message of
e8b269fa provides more details behind the
intention of the 'no_new_metadata_notified' flag.
Change-Id: Ib1b80148d7f214f7aed221d3559e479b69aedd82
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
struct lttng_viewer_get_metadata request;
struct lttng_viewer_metadata_packet reply;
struct relay_viewer_stream *vstream = nullptr;
+ bool dispose_of_stream = false;
LTTNG_ASSERT(conn);
reply.status = htobe32(LTTNG_VIEWER_METADATA_ERR);
goto send_reply;
}
+
+ pthread_mutex_lock(&vstream->stream->trace->session->lock);
+ pthread_mutex_lock(&vstream->stream->trace->lock);
pthread_mutex_lock(&vstream->stream->lock);
if (!vstream->stream->is_metadata) {
ERR("Invalid metadata stream");
if (vstream->metadata_sent >= vstream->stream->metadata_received) {
/*
- * The live viewers expect to receive a NO_NEW_METADATA
- * status before a stream disappears, otherwise they abort the
- * entire live connection when receiving an error status.
- *
* Clear feature resets the metadata_received to 0 until the
* same metadata is received again.
*/
* The live viewer considers a closed 0 byte metadata stream as
* an error.
*/
- if (vstream->metadata_sent > 0) {
- if (vstream->stream->closed && vstream->stream->no_new_metadata_notified) {
- /*
- * Release ownership for the viewer metadata
- * stream. Note that this reference is the
- * viewer's reference. The vstream still exists
- * until the end of the function as
- * viewer_stream_get_by_id() took a reference.
- */
- viewer_stream_put(vstream);
- }
-
- vstream->stream->no_new_metadata_notified = true;
- }
+ dispose_of_stream = vstream->metadata_sent > 0 && vstream->stream->closed;
goto send_reply;
}
len = vstream->stream->metadata_received - vstream->metadata_sent;
if (!vstream->stream_file.trace_chunk) {
+ if (vstream->stream->trace->session->connection_closed) {
+ /*
+ * If the connection is closed, there is no way for the metadata stream
+ * to ever transition back to an active chunk. As such, signal to the viewer
+ * that there is no new metadata available.
+ *
+ * The stream can be disposed-of. On the next execution of this command,
+ * the relay daemon will reply with an error status since the stream can't
+ * be found.
+ */
+ dispose_of_stream = true;
+ }
+
reply.status = htobe32(LTTNG_VIEWER_NO_NEW_METADATA);
len = 0;
goto send_reply;
health_code_update();
if (vstream) {
pthread_mutex_unlock(&vstream->stream->lock);
+ pthread_mutex_unlock(&vstream->stream->trace->lock);
+ pthread_mutex_unlock(&vstream->stream->trace->session->lock);
}
ret = send_response(conn->sock, &reply, sizeof(reply));
if (ret < 0) {
end:
if (vstream) {
viewer_stream_put(vstream);
+ if (dispose_of_stream) {
+ /*
+ * Trigger the destruction of the viewer stream
+ * by releasing its global reference.
+ *
+ * The live viewers expect to receive a NO_NEW_METADATA
+ * status before a stream disappears, otherwise they abort the
+ * entire live connection when receiving an error status.
+ *
+ * On the next query for this stream, an error will be reported to the
+ * client.
+ */
+ viewer_stream_put(vstream);
+ }
}
+
return ret;
}
recv_len = packet ? packet->size : 0;
recv_len += padding_len;
stream->metadata_received += recv_len;
- if (recv_len) {
- stream->no_new_metadata_notified = false;
- }
}
DBG("Wrote to %sstream %" PRIu64 ": data_length = %zu, padding_length = %zu",
struct cds_list_head recv_node;
/* Protected by session lock. */
bool published;
- /* Notified viewer that no new metadata is available. */
- bool no_new_metadata_notified;
/*
* Node of stream within global stream hash table.
*/