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 250d85c6fb39fde7558004f95c198b216b009a6d..ae0c2cb738aa4e82022ed51bf82725b275f1b188 100644 (file)
--- 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;
 
 {
        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) {
        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);
                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) {
                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);
                 * 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,
                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);
                                        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,
                        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 501e6e90a109615d09a562de1059aca894d64523..62b426360ac1830def68230f3d40d860d968520c 100644 (file)
--- 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;
 
 {
        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);
 
        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;
                }
        }
                        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;
        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;
        }
 
                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 <
        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;
        }
 
                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) {
        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.
                 */
                 * 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 {
                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);
 
 
        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,
        /* 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;
        }
 
                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;
        stream->tracefile_size_current = 0;
        stream->prev_data_seq = 0;
        stream->prev_index_seq = 0;