From: Jérémie Galarneau Date: Sat, 17 Feb 2024 13:57:47 +0000 (-0500) Subject: Fix: relayd: live: dispose of zombie viewer metadata stream X-Git-Url: https://git.lttng.org/?p=lttng-tools.git;a=commitdiff_plain;h=55d3f5e528059267f44fb24b179b992bf2b0cfa6 Fix: relayd: live: dispose of zombie viewer metadata stream Issue observed ============== In the CI, builds on SLES15SP5 frequently experience timeouts. From prior inspections, there are hangs during tests/regression/tools/clear/test_ust while waiting for babeltrace to exit. It is possible to reproduce the problem fairly easily: $ lttng create --live $ lttng enable-event --userspace --all $ lttng start # Launch an application that emits a couple of events $ ./my_app $ lttng stop # Clear the data, this eventually results in the deletion of all # trace files on the relay daemon's end. $ lttng clear # Attach to the live session from another terminal $ babeltrace -i lttng-live net://... # The 'destroy' command completes, but the viewer never exits. $ lttng destroy Cause ===== After the clear command completes, the relay daemon no longer has any data to serve. We notice that the live client loops endlessly repeatably sending GET_METADATA requests. In response, the relay daemon replies with the NO_NEW_METADATA status. In concrete terms, the viewer_get_metadata() function short-circuits to send that reply when it sees that the metadata stream has no active trace chunk (i.e., there are no backing files from which to read the data at the moment). This situation is not abnormal in itself: it is legitimate for a client to wait for the metadata to become available again. For example, in the reproducer above, it would be possible for the user to restart the tracing (lttng start), which would create a new trace chunk and make the metadata stream available. New events could also be emitted following this restart. However, when a session's connection is closed, there is no hope that the metadata stream will ever transition back to an active trace chunk. Solution ======== When the metadata stream has no active chunk and the corresponding consumerd-side connection has been closed, there is no way the relay daemon will be able to serve the metadata contents to the client. As such, the viewer stream can be disposed-of since it will no longer be of any use to the client. Since some client implementations expect at least one GET_METADATA command to result in NO_NEW_METADATA, that status code is initially returned. Later, when the client emits a follow-up GET_METADATA request for that same stream, it will receive an "error" status indicating that the stream no longer exists. This situation is not treated as an error by the clients. For instance, babeltrace2 will simply close the corresponding trace and indicate it ended. The 'no_new_metadata_notified' flag doesn't appear to be necessary to implement the behaviour expected by the clients (seeing at least one NO_NEW_METADATA status reply for every metadata stream). The viewer_get_metadata() function is refactored a bit to drop the global reference to the viewer metadata stream as it exits, while still returning the NO_NEW_METADATA status code. Known drawbacks =============== None. Note ==== The commit message of e8b269fa provides more details behind the intention of the 'no_new_metadata_notified' flag. Change-Id: Ib1b80148d7f214f7aed221d3559e479b69aedd82 Signed-off-by: Jérémie Galarneau --- diff --git a/src/bin/lttng-relayd/live.cpp b/src/bin/lttng-relayd/live.cpp index 99037e417..f1f97f917 100644 --- a/src/bin/lttng-relayd/live.cpp +++ b/src/bin/lttng-relayd/live.cpp @@ -2128,6 +2128,7 @@ static int viewer_get_metadata(struct relay_connection *conn) 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); @@ -2156,6 +2157,9 @@ static int viewer_get_metadata(struct relay_connection *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"); @@ -2164,10 +2168,6 @@ static int viewer_get_metadata(struct relay_connection *conn) 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. */ @@ -2176,20 +2176,7 @@ static int viewer_get_metadata(struct relay_connection *conn) * 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; } @@ -2227,6 +2214,19 @@ static int viewer_get_metadata(struct relay_connection *conn) 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; @@ -2357,6 +2357,8 @@ 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) { @@ -2382,7 +2384,22 @@ end_free: 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; } diff --git a/src/bin/lttng-relayd/stream.cpp b/src/bin/lttng-relayd/stream.cpp index 94d5d6d17..a0935231d 100644 --- a/src/bin/lttng-relayd/stream.cpp +++ b/src/bin/lttng-relayd/stream.cpp @@ -1109,9 +1109,6 @@ int stream_write(struct relay_stream *stream, 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", diff --git a/src/bin/lttng-relayd/stream.hpp b/src/bin/lttng-relayd/stream.hpp index 44a897794..a616e425a 100644 --- a/src/bin/lttng-relayd/stream.hpp +++ b/src/bin/lttng-relayd/stream.hpp @@ -162,8 +162,6 @@ struct relay_stream { 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. */