From 68c40154442f0a7a736c01050daf034784eb9e01 Mon Sep 17 00:00:00 2001 From: Mathieu Desnoyers Date: Thu, 12 Dec 2019 12:10:27 -0500 Subject: [PATCH] relayd: add extra debug output MIME-Version: 1.0 Content-Type: text/plain; charset=utf8 Content-Transfer-Encoding: 8bit Signed-off-by: Mathieu Desnoyers Change-Id: Ie83470b293e10441357302a0d6e2668522d983ed Signed-off-by: Jérémie Galarneau --- src/bin/lttng-relayd/live.c | 15 +++++++++++++++ src/bin/lttng-relayd/stream.c | 30 ++++++++++++++++++++++++++++-- 2 files changed, 43 insertions(+), 2 deletions(-) diff --git a/src/bin/lttng-relayd/live.c b/src/bin/lttng-relayd/live.c index 250d85c6f..ae0c2cb73 100644 --- a/src/bin/lttng-relayd/live.c +++ b/src/bin/lttng-relayd/live.c @@ -1271,6 +1271,12 @@ static int check_index_status(struct relay_viewer_stream *vstream, { int ret; + DBG("Check index status: index_received_seqcount %" PRIu64 " " + "index_sent_seqcount %" PRIu64 " " + "for stream %" PRIu64, + rstream->index_received_seqcount, + vstream->index_sent_seqcount, + vstream->stream->stream_handle); if ((trace->session->connection_closed || rstream->closed) && rstream->index_received_seqcount == vstream->index_sent_seqcount) { @@ -1295,6 +1301,8 @@ static int check_index_status(struct relay_viewer_stream *vstream, index->status = htobe32(LTTNG_VIEWER_INDEX_INACTIVE); index->timestamp_end = htobe64(rstream->beacon_ts_end); index->stream_id = htobe64(rstream->ctf_stream_id); + DBG("Check index status: inactive with beacon, for stream %" PRIu64, + vstream->stream->stream_handle); goto index_ready; } else if (rstream->index_received_seqcount == vstream->index_sent_seqcount) { @@ -1304,6 +1312,8 @@ static int check_index_status(struct relay_viewer_stream *vstream, * we can only ask the client to retry later. */ index->status = htobe32(LTTNG_VIEWER_INDEX_RETRY); + DBG("Check index status: retry for stream %" PRIu64, + vstream->stream->stream_handle); goto index_ready; } else if (!tracefile_array_seq_in_file(rstream->tfa, vstream->current_tracefile_id, @@ -1343,6 +1353,11 @@ static int check_index_status(struct relay_viewer_stream *vstream, vstream->current_tracefile_id, vstream->index_sent_seqcount)) { index->status = htobe32(LTTNG_VIEWER_INDEX_RETRY); + DBG("Check index status: retry: " + "tracefile array sequence number %" PRIu64 + " not in file for stream %" PRIu64, + vstream->index_sent_seqcount, + vstream->stream->stream_handle); goto index_ready; } assert(tracefile_array_seq_in_file(rstream->tfa, diff --git a/src/bin/lttng-relayd/stream.c b/src/bin/lttng-relayd/stream.c index 501e6e90a..62b426360 100644 --- a/src/bin/lttng-relayd/stream.c +++ b/src/bin/lttng-relayd/stream.c @@ -146,8 +146,8 @@ static int stream_rotate_data_file(struct relay_stream *stream) { int ret = 0; - DBG("Rotating stream %" PRIu64 " data file", - stream->stream_handle); + DBG("Rotating stream %" PRIu64 " data file with size %" PRIu64, + stream->stream_handle, stream->tracefile_size_current); if (stream->stream_fd) { stream_fd_put(stream->stream_fd); @@ -179,6 +179,8 @@ static int stream_rotate_data_file(struct relay_stream *stream) goto end; } } + DBG("%s: reset tracefile_size_current for stream %" PRIu64 " was %" PRIu64, + __func__, stream->stream_handle, stream->tracefile_size_current); stream->tracefile_size_current = 0; stream->pos_after_last_complete_data_index = 0; stream->ongoing_rotation.value.data_rotated = true; @@ -367,6 +369,15 @@ static int try_rotate_stream_data(struct relay_stream *stream) goto end; } + DBG("%s: Stream %" PRIu64 + " (rotate_at_index_packet_seq_num = %" PRIu64 + ", rotate_at_prev_data_net_seq = %" PRIu64 + ", prev_data_seq = %" PRIu64 ")", + __func__, stream->stream_handle, + stream->ongoing_rotation.value.packet_seq_num, + stream->ongoing_rotation.value.prev_data_net_seq, + stream->prev_data_seq); + if (stream->prev_data_seq == -1ULL || stream->ongoing_rotation.value.prev_data_net_seq == -1ULL || stream->prev_data_seq < @@ -483,6 +494,15 @@ static int try_rotate_stream_index(struct relay_stream *stream) goto end; } + DBG("%s: Stream %" PRIu64 + " (rotate_at_packet_seq_num = %" PRIu64 + ", received_packet_seq_num = " + "(value = %" PRIu64 ", is_set = %" PRIu8 "))", + __func__, stream->stream_handle, + stream->ongoing_rotation.value.packet_seq_num, + stream->received_packet_seq_num.value, + stream->received_packet_seq_num.is_set); + if (!stream->received_packet_seq_num.is_set || LTTNG_OPTIONAL_GET(stream->received_packet_seq_num) + 1 < stream->ongoing_rotation.value.packet_seq_num) { @@ -1030,6 +1050,8 @@ int stream_init_packet(struct relay_stream *stream, size_t packet_size, * Reset current size because we just performed a stream * rotation. */ + DBG("%s: reset tracefile_size_current for stream %" PRIu64 " was %" PRIu64, + __func__, stream->stream_handle, stream->tracefile_size_current); stream->tracefile_size_current = 0; *file_rotated = true; } else { @@ -1217,6 +1239,8 @@ int stream_add_index(struct relay_stream *stream, ASSERT_LOCKED(stream->lock); + DBG("stream_add_index for stream %" PRIu64, stream->stream_handle); + /* Live beacon handling */ if (index_info->packet_size == 0) { DBG("Received live beacon for stream %" PRIu64, @@ -1319,6 +1343,8 @@ int stream_reset_file(struct relay_stream *stream) stream->stream_fd = NULL; } + DBG("%s: reset tracefile_size_current for stream %" PRIu64 " was %" PRIu64, + __func__, stream->stream_handle, stream->tracefile_size_current); stream->tracefile_size_current = 0; stream->prev_data_seq = 0; stream->prev_index_seq = 0; -- 2.34.1