#define BT_COMP_OR_COMP_CLASS_LOGE(_self_comp, _self_comp_class, _fmt, ...) \
BT_COMP_OR_COMP_CLASS_LOG(BT_LOG_ERROR,_self_comp, _self_comp_class, _fmt, ##__VA_ARGS__)
+#define BT_COMP_OR_COMP_CLASS_LOGW(_self_comp, _self_comp_class, _fmt, ...) \
+ BT_COMP_OR_COMP_CLASS_LOG(BT_LOG_WARNING,_self_comp, _self_comp_class, _fmt, ##__VA_ARGS__)
+#define BT_COMP_OR_COMP_CLASS_LOGI(_self_comp, _self_comp_class, _fmt, ...) \
+ BT_COMP_OR_COMP_CLASS_LOG(BT_LOG_INFO,_self_comp, _self_comp_class, _fmt, ##__VA_ARGS__)
+#define BT_COMP_OR_COMP_CLASS_LOGD(_self_comp, _self_comp_class, _fmt, ...) \
+ BT_COMP_OR_COMP_CLASS_LOG(BT_LOG_DEBUG,_self_comp, _self_comp_class, _fmt, ##__VA_ARGS__)
/*
* Logs error with errno string from component or component class context,
return LTTNG_LIVE_ITERATOR_STATUS_OK;
}
+ BT_COMP_LOGD("Lazily initializing self message iterator for live session: "
+ "session-id=%"PRIu64", self-msg-iter-addr=%p", session->id,
+ self_msg_iter);
+
for (trace_idx = 0; trace_idx < session->traces->len; trace_idx++) {
struct lttng_live_trace *trace =
g_ptr_array_index(session->traces, trace_idx);
}
ctf_tc = ctf_metadata_decoder_borrow_ctf_trace_class(
trace->metadata->decoder);
+ BT_COMP_LOGD("Creating CTF message iterator: "
+ "session-id=%"PRIu64", ctf-tc-addr=%p, "
+ "stream-iter-name=%s, self-msg-iter-addr=%p",
+ session->id, ctf_tc, stream_iter->name->str, self_msg_iter);
stream_iter->msg_iter = ctf_msg_iter_create(ctf_tc,
lttng_live->max_query_size, medops, stream_iter,
log_level, self_comp, self_msg_iter);
}
static
-const char *print_state(struct lttng_live_stream_iterator *s)
+const char *lttng_live_stream_state_string(enum lttng_live_stream_state state)
{
- switch (s->state) {
+ switch (state) {
case LTTNG_LIVE_STREAM_ACTIVE_NO_DATA:
return "ACTIVE_NO_DATA";
case LTTNG_LIVE_STREAM_QUIESCENT_NO_DATA:
}
}
-#define print_stream_state(live_stream_iter) \
+#define LTTNG_LIVE_LOGD_STREAM_ITER(live_stream_iter) \
do { \
- BT_COMP_LOGD("stream state %s last_inact_ts %" PRId64 \
- ", curr_inact_ts %" PRId64, \
- print_state(live_stream_iter), \
+ BT_COMP_LOGD("Live stream iterator state=%s, last-inact-ts=%" PRId64 \
+ ", curr-inact-ts %" PRId64, \
+ lttng_live_stream_state_string(live_stream_iter->state), \
live_stream_iter->last_inactivity_ts, \
live_stream_iter->current_inactivity_ts); \
} while (0);
bt_logging_level log_level = trace->log_level;
bt_self_component *self_comp = trace->self_comp;
- BT_COMP_LOGD("Destroy lttng_live_trace");
+ BT_COMP_LOGD("Destroying live trace: trace-id=%"PRIu64, trace->id);
BT_ASSERT(trace->stream_iterators);
g_ptr_array_free(trace->stream_iterators, TRUE);
bt_logging_level log_level = session->log_level;
bt_self_component *self_comp = session->self_comp;
+ BT_COMP_LOGD("Creating live trace: "
+ "session-id=%"PRIu64", trace-id=%"PRIu64,
+ session->id, trace_id);
trace = g_new0(struct lttng_live_trace, 1);
if (!trace) {
BT_COMP_LOGE_APPEND_CAUSE(self_comp,
trace->new_metadata_needed = true;
g_ptr_array_add(session->traces, trace);
- BT_COMP_LOGI("Create trace");
goto end;
error:
g_free(trace);
bt_logging_level log_level = lttng_live_msg_iter->log_level;
bt_self_component *self_comp = lttng_live_msg_iter->self_comp;
+ BT_COMP_LOGD("Adding live session: "
+ "session-id=%" PRIu64 ", hostname=\"%s\" session-name=\"%s\"",
+ session_id, hostname, session_name);
+
session = g_new0(struct lttng_live_session, 1);
if (!session) {
BT_COMP_LOGE_APPEND_CAUSE(self_comp,
session->session_name = g_string_new(session_name);
BT_ASSERT(session->session_name);
- BT_COMP_LOGI("Reading from session: %" PRIu64 " hostname: %s session_name: %s",
- session->id, hostname, session_name);
g_ptr_array_add(lttng_live_msg_iter->sessions, session);
goto end;
error:
log_level = session->log_level;
self_comp = session->self_comp;
- BT_COMP_LOGD("Destroy lttng live session");
+ BT_COMP_LOGD("Destroying live session: "
+ "session-id=%"PRIu64", session-name=\"%s\"",
+ session->id, session->session_name->str);
if (session->id != -1ULL) {
if (lttng_live_detach_session(session)) {
if (!lttng_live_graph_is_canceled(
if (orig_state == LTTNG_LIVE_STREAM_QUIESCENT_NO_DATA &&
last_inact_ts == curr_inact_ts) {
ret = LTTNG_LIVE_ITERATOR_STATUS_AGAIN;
- print_stream_state(lttng_live_stream);
+ LTTNG_LIVE_LOGD_STREAM_ITER(lttng_live_stream);
} else {
ret = LTTNG_LIVE_ITERATOR_STATUS_CONTINUE;
}
enum lttng_live_iterator_status status;
uint64_t trace_idx;
+ BT_COMP_LOGD("Updating all streams for session: "
+ "session-id=%"PRIu64", session-name=\"%s\"",
+ session->id, session->session_name->str);
+
if (!session->attached) {
enum lttng_live_viewer_status attach_status =
lttng_live_attach_session(session,
trace_idx);
break;
default:
+ BT_COMP_LOGE_APPEND_CAUSE(self_comp,
+ "Error updating trace metadata: "
+ "stream-iter-status=%s, trace-id=%"PRIu64,
+ lttng_live_iterator_status_string(status),
+ trace->id);
goto end;
}
}
enum session_not_found_action sess_not_found_act =
lttng_live_msg_iter->lttng_live_comp->params.sess_not_found_act;
+ BT_COMP_LOGD("Update data and metadata of all sessions"
+ "live-msg-iter-addr=%p", lttng_live_msg_iter);
/*
* In a remotely distant future, we could add a "new
* session" flag to the protocol, which would tell us that we
*/
if (lttng_live_msg_iter->sessions->len == 0) {
if (sess_not_found_act != SESSION_NOT_FOUND_ACTION_CONTINUE) {
+ BT_COMP_LOGD("No session found. Exiting in accordance with the `session-not-found-action` parameter");
status = LTTNG_LIVE_ITERATOR_STATUS_END;
goto end;
} else {
+ BT_COMP_LOGD("No session found. Try creating a new one in accordance with the `session-not-found-action` parameter");
/*
* Retry to create a viewer session for the requested
* session name.
if (lttng_live_stream->state != LTTNG_LIVE_STREAM_ACTIVE_DATA) {
ret = LTTNG_LIVE_ITERATOR_STATUS_ERROR;
+ BT_COMP_LOGE_APPEND_CAUSE(self_comp,
+ "Invalid state of live stream iterator"
+ "stream-iter-status=%s",
+ lttng_live_stream_state_string(lttng_live_stream->state));
goto end;
}
default:
ret = LTTNG_LIVE_ITERATOR_STATUS_ERROR;
BT_COMP_LOGE_APPEND_CAUSE(self_comp,
- "CTF message iterator return an error or failed: "
- "msg_iter=%p", lttng_live_stream->msg_iter);
+ "CTF message iterator failed to get next message: "
+ "msg-iter=%p, msg-iter-status=%s",
+ lttng_live_stream->msg_iter,
+ ctf_msg_iter_status_string(status));
break;
}
bt_self_component *self_comp = lttng_live_msg_iter->self_comp;
enum lttng_live_iterator_status live_status;
+ BT_COMP_LOGD("Finding the next message for stream iterator: "
+ "stream-name=\"%s\"", stream_iter->name->str);
+
if (stream_iter->has_stream_hung_up) {
/*
* The stream has hung up and the stream was properly closed
}
retry:
- print_stream_state(stream_iter);
+ LTTNG_LIVE_LOGD_STREAM_ITER(stream_iter);
live_status = lttng_live_iterator_handle_new_streams_and_metadata(
lttng_live_msg_iter);
if (live_status != LTTNG_LIVE_ITERATOR_STATUS_OK) {
BT_ASSERT_DBG(live_trace);
BT_ASSERT_DBG(live_trace->stream_iterators);
+
+ BT_COMP_LOGD("Finding the next stream iterator for trace: "
+ "trace-id=%"PRIu64, live_trace->id);
/*
* Update the current message of every stream iterators of this trace.
* The current msg of every stream must have a timestamp equal or
int64_t youngest_candidate_msg_ts = INT64_MAX;
struct lttng_live_stream_iterator *youngest_candidate_stream_iter = NULL;
+ BT_COMP_LOGD("Finding the next stream iterator for session: "
+ "session-id=%"PRIu64, session->id);
/*
* Make sure we are attached to the session and look for new streams
* and metadata.
bt_self_component *self_comp = trace->self_comp;
enum lttng_live_get_one_metadata_status metadata_status;
+ BT_COMP_LOGD("Updating metadata for trace: trace-id=%"PRIu64, trace->id);
+
/* No metadata stream yet. */
if (!metadata) {
if (session->new_streams_needed) {
keep_receiving = false;
break;
case LTTNG_LIVE_GET_ONE_METADATA_STATUS_CLOSED:
+ BT_COMP_LOGD("Metadata stream was closed by the Relay, the trace is no longer active: "
+ "trace-id=%"PRIu64", metadata-stream-id=%"PRIu64,
+ trace->id, metadata->stream_id);
keep_receiving = false;
break;
case LTTNG_LIVE_GET_ONE_METADATA_STATUS_ERROR:
+ BT_COMP_LOGE_APPEND_CAUSE(self_comp,
+ "Error getting one trace metadata packet: "
+ "trace-id=%"PRIu64, trace->id);
goto error;
default:
bt_common_abort();
/* The memory buffer `metadata_buf` contains all the metadata. */
if (bt_close_memstream(&metadata_buf, &size, fp)) {
- BT_COMP_LOGE_APPEND_CAUSE_ERRNO(self_comp,
- "Metadata bt_close_memstream", ".");
+ BT_COMP_LOGW_ERRNO("Metadata bt_close_memstream", ".");
}
fp = NULL;
* The call to ctf_metadata_decoder_append_content() will append
* new metadata to our current trace class.
*/
+ BT_COMP_LOGD("Appending new metadata to the ctf_trace class");
decoder_status = ctf_metadata_decoder_append_content(
metadata->decoder, fp);
switch (decoder_status) {
closeret = fclose(fp);
if (closeret) {
- BT_COMP_LOGE_APPEND_CAUSE_ERRNO(self_comp,
- "Error on fclose", ".");
+ BT_COMP_LOGW_ERRNO("Error on fclose", ".");
}
}
free(metadata_buf);
error_buf);
goto end;
}
+ viewer_connection->proto = lttng_live_url_parts.proto;
+ lttng_live_url_parts.proto = NULL;
viewer_connection->relay_hostname = lttng_live_url_parts.hostname;
lttng_live_url_parts.hostname = NULL;
lttng_live_url_parts.session_name = NULL;
}
- BT_COMP_LOGI("Connecting to hostname : %s, port : %d, "
- "target hostname : %s, session name : %s, proto : %s",
- viewer_connection->relay_hostname->str,
- viewer_connection->port,
- !viewer_connection->target_hostname ?
- "<none>" : viewer_connection->target_hostname->str,
- !viewer_connection->session_name ?
- "<none>" : viewer_connection->session_name->str,
- lttng_live_url_parts.proto->str);
ret = 0;
end:
const size_t cmd_buf_len = sizeof(cmd) + sizeof(connect);
char cmd_buf[cmd_buf_len];
+ BT_COMP_OR_COMP_CLASS_LOGD(self_comp, self_comp_class,
+ "Handshaking with the Relay: "
+ "major-version=%u, minor-version=%u",
+ LTTNG_LIVE_MAJOR, LTTNG_LIVE_MINOR);
+
cmd.cmd = htobe32(LTTNG_VIEWER_CONNECT);
cmd.data_size = htobe64((uint64_t) sizeof(connect));
cmd.cmd_version = htobe32(0);
goto end;
}
- BT_COMP_LOGI("Received viewer session ID : %" PRIu64,
- (uint64_t) be64toh(connect.viewer_session_id));
- BT_COMP_LOGI("Relayd version : %u.%u", be32toh(connect.major),
- be32toh(connect.minor));
+ BT_COMP_OR_COMP_CLASS_LOGI(self_comp, self_comp_class,
+ "Received viewer session ID : %" PRIu64,
+ (uint64_t) be64toh(connect.viewer_session_id));
+ BT_COMP_OR_COMP_CLASS_LOGI(self_comp, self_comp_class,
+ "Relayd version : %u.%u", be32toh(connect.major),
+ be32toh(connect.minor));
if (LTTNG_LIVE_MAJOR != be32toh(connect.major)) {
BT_COMP_OR_COMP_CLASS_LOGE_APPEND_CAUSE(self_comp,
goto error;
}
+ BT_COMP_OR_COMP_CLASS_LOGD(self_comp, self_comp_class,
+ "Connecting to hostname : %s, port : %d, "
+ "target hostname : %s, session name : %s, proto : %s",
+ viewer_connection->relay_hostname->str,
+ viewer_connection->port,
+ !viewer_connection->target_hostname ?
+ "<none>" : viewer_connection->target_hostname->str,
+ !viewer_connection->session_name ?
+ "<none>" : viewer_connection->session_name->str,
+ viewer_connection->proto->str);
+
host = gethostbyname(viewer_connection->relay_hostname->str);
if (!host) {
BT_COMP_OR_COMP_CLASS_LOGE_APPEND_CAUSE(self_comp,
error:
if (viewer_connection->control_sock != BT_INVALID_SOCKET) {
if (bt_socket_close(viewer_connection->control_sock) == BT_SOCKET_ERROR) {
- BT_COMP_OR_COMP_CLASS_LOGE(self_comp, self_comp_class,
- "Error closing socket: %s", bt_socket_errormsg());
+ BT_COMP_OR_COMP_CLASS_LOGW(self_comp, self_comp_class,
+ "Error closing socket: %s.", bt_socket_errormsg());
}
}
viewer_connection->control_sock = BT_INVALID_SOCKET;
void lttng_live_disconnect_viewer(
struct live_viewer_connection *viewer_connection)
{
+ bt_self_component_class *self_comp_class = viewer_connection->self_comp_class;
+ bt_self_component *self_comp = viewer_connection->self_comp;
+
if (viewer_connection->control_sock == BT_INVALID_SOCKET) {
return;
}
if (bt_socket_close(viewer_connection->control_sock) == BT_SOCKET_ERROR) {
- BT_COMP_LOGE("Error closing socket: %s",
- bt_socket_errormsg());
+ BT_COMP_OR_COMP_CLASS_LOGW(self_comp, self_comp_class,
+ "Error closing socket: %s", bt_socket_errormsg());
viewer_connection->control_sock = BT_INVALID_SOCKET;
}
}
bt_self_component_class *self_comp_class =
viewer_connection->self_comp_class;
+ BT_COMP_LOGD("Asking the Relay for the list of sessions");
+
cmd.cmd = htobe32(LTTNG_VIEWER_LIST_SESSIONS);
cmd.data_size = htobe64((uint64_t) 0);
cmd.cmd_version = htobe32(0);
lsession.session_name[LTTNG_VIEWER_NAME_MAX - 1] = '\0';
session_id = be64toh(lsession.id);
- BT_COMP_LOGI("Adding session %" PRIu64 " hostname: %s session_name: %s",
+ BT_COMP_LOGI("Adding session to internal list: "
+ "session-id=%" PRIu64 ", hostname=\"%s\", session-name=\"%s\"",
session_id, lsession.hostname, lsession.session_name);
if ((strncmp(lsession.session_name,
LTTNG_VIEWER_NAME_MAX) == 0) && (strncmp(lsession.hostname,
viewer_connection->target_hostname->str,
LTTNG_VIEWER_HOST_NAME_MAX) == 0)) {
+
if (lttng_live_add_session(lttng_live_msg_iter, session_id,
lsession.hostname,
lsession.session_name)) {
bt_self_component_class *self_comp_class =
viewer_connection->self_comp_class;
+ BT_COMP_OR_COMP_CLASS_LOGD(self_comp, self_comp_class,
+ "Creating a viewer session");
+
cmd.cmd = htobe32(LTTNG_VIEWER_CREATE_SESSION);
cmd.data_size = htobe64((uint64_t) 0);
cmd.cmd_version = htobe32(0);
const size_t cmd_buf_len = sizeof(cmd) + sizeof(rq);
char cmd_buf[cmd_buf_len];
+ BT_COMP_LOGD("Attaching to session: session-id=%"PRIu64, session_id);
+
cmd.cmd = htobe32(LTTNG_VIEWER_ATTACH_SESSION);
cmd.data_size = htobe64((uint64_t) sizeof(rq));
cmd.cmd_version = htobe32(0);
const size_t cmd_buf_len = sizeof(cmd) + sizeof(rq);
char cmd_buf[cmd_buf_len];
+ BT_COMP_LOGD("Requesting new metadata for trace: "
+ "trace-id=%"PRIu64", metadata-stream-id=%"PRIu64,
+ trace->id, metadata->stream_id);
+
rq.stream_id = htobe64(metadata->stream_id);
cmd.cmd = htobe32(LTTNG_VIEWER_GET_METADATA);
cmd.data_size = htobe64((uint64_t) sizeof(rq));
char cmd_buf[cmd_buf_len];
uint32_t flags, rp_status;
+ BT_COMP_LOGD("Requesting next index for stream: "
+ "stream-id=%"PRIu64, stream->viewer_stream_id);
+
cmd.cmd = htobe32(LTTNG_VIEWER_GET_NEXT_INDEX);
cmd.data_size = htobe64((uint64_t) sizeof(rq));
cmd.cmd_version = htobe32(0);
goto end;
}
+ BT_COMP_LOGD("Requesting new streams for session: "
+ "session-id=%"PRIu64, session->id);
+
cmd.cmd = htobe32(LTTNG_VIEWER_GET_NEW_STREAMS);
cmd.data_size = htobe64((uint64_t) sizeof(rq));
cmd.cmd_version = htobe32(0);
goto error;
}
- BT_COMP_LOGI("Establishing connection to url \"%s\"...", url);
+ BT_COMP_OR_COMP_CLASS_LOGD(self_comp, self_comp_class,
+ "Establishing connection to url \"%s\"...", url);
status = lttng_live_connect_viewer(viewer_connection);
/*
* Only print error and append cause in case of error. not in case of
} else if (status == LTTNG_LIVE_VIEWER_STATUS_INTERRUPTED) {
goto error;
}
- BT_COMP_LOGI("Connection to url \"%s\" is established", url);
+ BT_COMP_OR_COMP_CLASS_LOGD(self_comp, self_comp_class,
+ "Connection to url \"%s\" is established", url);
*viewer = viewer_connection;
status = LTTNG_LIVE_VIEWER_STATUS_OK;
void live_viewer_connection_destroy(
struct live_viewer_connection *viewer_connection)
{
- BT_COMP_LOGI("Closing connection to url \"%s\"", viewer_connection->url->str);
+ bt_self_component *self_comp = viewer_connection->self_comp;
+ bt_self_component_class *self_comp_class = viewer_connection->self_comp_class;
if (!viewer_connection) {
goto end;
}
+ BT_COMP_OR_COMP_CLASS_LOGD(self_comp, self_comp_class,
+ "Closing connection to relay:"
+ "relay-url=\"%s\"", viewer_connection->url->str);
+
lttng_live_disconnect_viewer(viewer_connection);
if (viewer_connection->url) {
g_string_free(viewer_connection->session_name, true);
}
+ if (viewer_connection->proto) {
+ g_string_free(viewer_connection->proto, true);
+ }
+
g_free(viewer_connection);
bt_socket_fini();
GString *relay_hostname;
GString *target_hostname;
GString *session_name;
+ GString *proto;
BT_SOCKET control_sock;
int port;