From: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Date: Thu, 12 Dec 2019 17:10:27 +0000 (-0500)
Subject: relayd: add extra debug output
X-Git-Tag: v2.12.0-rc1~129
X-Git-Url: https://git.lttng.org./?a=commitdiff_plain;h=68c40154442f0a7a736c01050daf034784eb9e01;p=lttng-tools.git

relayd: add extra debug output

Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Change-Id: Ie83470b293e10441357302a0d6e2668522d983ed
Signed-off-by: Jérémie Galarneau <jeremie.galarneau@efficios.com>
---

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;