X-Git-Url: http://git.efficios.com/?a=blobdiff_plain;f=src%2Fplugins%2Fctf%2Fcommon%2Fmsg-iter%2Fmsg-iter.c;h=dd350c75ecfe4bb52f7b3b3904aeff1a5fed0334;hb=fe4df857056b4a03898f1031f136359ce733b0f5;hp=99c585980bf8db9b97f151c3921676613ab1b9be;hpb=80870e64b3eaa36324881feb46773794c3ead8c7;p=babeltrace.git diff --git a/src/plugins/ctf/common/msg-iter/msg-iter.c b/src/plugins/ctf/common/msg-iter/msg-iter.c index 99c58598..dd350c75 100644 --- a/src/plugins/ctf/common/msg-iter/msg-iter.c +++ b/src/plugins/ctf/common/msg-iter/msg-iter.c @@ -23,8 +23,10 @@ * SOFTWARE. */ +#define BT_COMP_LOG_SELF_COMP (notit->self_comp) +#define BT_LOG_OUTPUT_LEVEL (notit->log_level) #define BT_LOG_TAG "PLUGIN/CTF/MSG-ITER" -#include "logging.h" +#include "logging/comp-logging.h" #include #include @@ -62,8 +64,12 @@ struct stack_entry { size_t index; }; +struct bt_msg_iter; + /* Visit stack */ struct stack { + struct bt_msg_iter *notit; + /* Entries (struct stack_entry) */ GArray *entries; @@ -74,6 +80,7 @@ struct stack { /* State */ enum state { STATE_INIT, + STATE_SWITCH_PACKET, STATE_DSCOPE_TRACE_PACKET_HEADER_BEGIN, STATE_DSCOPE_TRACE_PACKET_HEADER_CONTINUE, STATE_AFTER_TRACE_PACKET_HEADER, @@ -82,7 +89,6 @@ enum state { STATE_AFTER_STREAM_PACKET_CONTEXT, STATE_CHECK_EMIT_MSG_STREAM_BEGINNING, STATE_EMIT_MSG_STREAM_BEGINNING, - STATE_EMIT_MSG_STREAM_ACTIVITY_BEGINNING, STATE_CHECK_EMIT_MSG_DISCARDED_EVENTS, STATE_CHECK_EMIT_MSG_DISCARDED_PACKETS, STATE_EMIT_MSG_DISCARDED_EVENTS, @@ -98,11 +104,12 @@ enum state { STATE_DSCOPE_EVENT_PAYLOAD_BEGIN, STATE_DSCOPE_EVENT_PAYLOAD_CONTINUE, STATE_EMIT_MSG_EVENT, + STATE_EMIT_QUEUED_MSG_EVENT, STATE_SKIP_PACKET_PADDING, STATE_EMIT_MSG_PACKET_END_MULTI, STATE_EMIT_MSG_PACKET_END_SINGLE, - STATE_CHECK_EMIT_MSG_STREAM_ACTIVITY_END, - STATE_EMIT_MSG_STREAM_ACTIVITY_END, + STATE_CHECK_EMIT_MSG_STREAM_END, + STATE_EMIT_QUEUED_MSG_PACKET_END, STATE_EMIT_MSG_STREAM_END, STATE_DONE, }; @@ -122,15 +129,18 @@ struct bt_msg_iter { /* Current message iterator to create messages (weak) */ bt_self_message_iterator *msg_iter; - /* - * True to emit stream beginning and stream activity beginning - * messages. - */ + /* True to emit a stream beginning message. */ bool emit_stream_begin_msg; - /* True to emit stream end and stream activity end messages */ + /* True to emit a stream end message. */ bool emit_stream_end_msg; + /* + * True if library objects are unavailable during the decoding and + * should not be created/used. + */ + bool dry_run; + /* True to set the stream */ bool set_stream; @@ -173,6 +183,12 @@ struct bt_msg_iter { /* Current event message (NULL if not created yet) */ bt_message *event_msg; + /* + * True if we need to emit a packet beginning message before we emit + * the next event message or the packet end message. + */ + bool emit_delayed_packet_beginning_msg; + /* Database of current dynamic scopes */ struct { bt_field *stream_packet_context; @@ -244,6 +260,12 @@ struct bt_msg_iter { /* Stored values (for sequence lengths, variant tags) */ GArray *stored_values; + + /* Iterator's current log level */ + bt_logging_level log_level; + + /* Iterator's owning self component, or `NULL` if none (query) */ + bt_self_component *self_comp; }; static inline @@ -251,69 +273,68 @@ const char *state_string(enum state state) { switch (state) { case STATE_INIT: - return "STATE_INIT"; + return "INIT"; + case STATE_SWITCH_PACKET: + return "SWITCH_PACKET"; case STATE_DSCOPE_TRACE_PACKET_HEADER_BEGIN: - return "STATE_DSCOPE_TRACE_PACKET_HEADER_BEGIN"; + return "DSCOPE_TRACE_PACKET_HEADER_BEGIN"; case STATE_DSCOPE_TRACE_PACKET_HEADER_CONTINUE: - return "STATE_DSCOPE_TRACE_PACKET_HEADER_CONTINUE"; + return "DSCOPE_TRACE_PACKET_HEADER_CONTINUE"; case STATE_AFTER_TRACE_PACKET_HEADER: - return "STATE_AFTER_TRACE_PACKET_HEADER"; + return "AFTER_TRACE_PACKET_HEADER"; case STATE_DSCOPE_STREAM_PACKET_CONTEXT_BEGIN: - return "STATE_DSCOPE_STREAM_PACKET_CONTEXT_BEGIN"; + return "DSCOPE_STREAM_PACKET_CONTEXT_BEGIN"; case STATE_DSCOPE_STREAM_PACKET_CONTEXT_CONTINUE: - return "STATE_DSCOPE_STREAM_PACKET_CONTEXT_CONTINUE"; + return "DSCOPE_STREAM_PACKET_CONTEXT_CONTINUE"; case STATE_AFTER_STREAM_PACKET_CONTEXT: - return "STATE_AFTER_STREAM_PACKET_CONTEXT"; + return "AFTER_STREAM_PACKET_CONTEXT"; case STATE_EMIT_MSG_STREAM_BEGINNING: - return "STATE_EMIT_MSG_STREAM_BEGINNING"; - case STATE_EMIT_MSG_STREAM_ACTIVITY_BEGINNING: - return "STATE_EMIT_MSG_STREAM_ACTIVITY_BEGINNING"; + return "EMIT_MSG_STREAM_BEGINNING"; case STATE_EMIT_MSG_PACKET_BEGINNING: - return "STATE_EMIT_MSG_PACKET_BEGINNING"; + return "EMIT_MSG_PACKET_BEGINNING"; case STATE_EMIT_MSG_DISCARDED_EVENTS: - return "STATE_EMIT_MSG_DISCARDED_EVENTS"; + return "EMIT_MSG_DISCARDED_EVENTS"; case STATE_EMIT_MSG_DISCARDED_PACKETS: - return "STATE_EMIT_MSG_DISCARDED_PACKETS"; + return "EMIT_MSG_DISCARDED_PACKETS"; case STATE_DSCOPE_EVENT_HEADER_BEGIN: - return "STATE_DSCOPE_EVENT_HEADER_BEGIN"; + return "DSCOPE_EVENT_HEADER_BEGIN"; case STATE_DSCOPE_EVENT_HEADER_CONTINUE: - return "STATE_DSCOPE_EVENT_HEADER_CONTINUE"; + return "DSCOPE_EVENT_HEADER_CONTINUE"; case STATE_AFTER_EVENT_HEADER: - return "STATE_AFTER_EVENT_HEADER"; + return "AFTER_EVENT_HEADER"; case STATE_DSCOPE_EVENT_COMMON_CONTEXT_BEGIN: - return "STATE_DSCOPE_EVENT_COMMON_CONTEXT_BEGIN"; + return "DSCOPE_EVENT_COMMON_CONTEXT_BEGIN"; case STATE_DSCOPE_EVENT_COMMON_CONTEXT_CONTINUE: - return "STATE_DSCOPE_EVENT_COMMON_CONTEXT_CONTINUE"; + return "DSCOPE_EVENT_COMMON_CONTEXT_CONTINUE"; case STATE_DSCOPE_EVENT_SPEC_CONTEXT_BEGIN: - return "STATE_DSCOPE_EVENT_SPEC_CONTEXT_BEGIN"; + return "DSCOPE_EVENT_SPEC_CONTEXT_BEGIN"; case STATE_DSCOPE_EVENT_SPEC_CONTEXT_CONTINUE: - return "STATE_DSCOPE_EVENT_SPEC_CONTEXT_CONTINUE"; + return "DSCOPE_EVENT_SPEC_CONTEXT_CONTINUE"; case STATE_DSCOPE_EVENT_PAYLOAD_BEGIN: - return "STATE_DSCOPE_EVENT_PAYLOAD_BEGIN"; + return "DSCOPE_EVENT_PAYLOAD_BEGIN"; case STATE_DSCOPE_EVENT_PAYLOAD_CONTINUE: - return "STATE_DSCOPE_EVENT_PAYLOAD_CONTINUE"; + return "DSCOPE_EVENT_PAYLOAD_CONTINUE"; case STATE_EMIT_MSG_EVENT: - return "STATE_EMIT_MSG_EVENT"; + return "EMIT_MSG_EVENT"; + case STATE_EMIT_QUEUED_MSG_EVENT: + return "EMIT_QUEUED_MSG_EVENT"; case STATE_SKIP_PACKET_PADDING: - return "STATE_SKIP_PACKET_PADDING"; + return "SKIP_PACKET_PADDING"; case STATE_EMIT_MSG_PACKET_END_MULTI: - return "STATE_EMIT_MSG_PACKET_END_MULTI"; + return "EMIT_MSG_PACKET_END_MULTI"; case STATE_EMIT_MSG_PACKET_END_SINGLE: - return "STATE_EMIT_MSG_PACKET_END_SINGLE"; - case STATE_EMIT_MSG_STREAM_ACTIVITY_END: - return "STATE_EMIT_MSG_STREAM_ACTIVITY_END"; + return "EMIT_MSG_PACKET_END_SINGLE"; + case STATE_EMIT_QUEUED_MSG_PACKET_END: + return "EMIT_QUEUED_MSG_PACKET_END"; case STATE_EMIT_MSG_STREAM_END: - return "STATE_EMIT_MSG_STREAM_END"; + return "EMIT_MSG_STREAM_END"; case STATE_DONE: - return "STATE_DONE"; + return "DONE"; default: return "(unknown)"; } } -static -int bt_msg_iter_switch_packet(struct bt_msg_iter *notit); - static struct stack *stack_new(struct bt_msg_iter *notit) { @@ -321,17 +342,18 @@ struct stack *stack_new(struct bt_msg_iter *notit) stack = g_new0(struct stack, 1); if (!stack) { - BT_LOGE_STR("Failed to allocate one stack."); + BT_COMP_LOGE_STR("Failed to allocate one stack."); goto error; } + stack->notit = notit; stack->entries = g_array_new(FALSE, TRUE, sizeof(struct stack_entry)); if (!stack->entries) { - BT_LOGE_STR("Failed to allocate a GArray."); + BT_COMP_LOGE_STR("Failed to allocate a GArray."); goto error; } - BT_LOGD("Created stack: notit-addr=%p, stack-addr=%p", notit, stack); + BT_COMP_LOGD("Created stack: notit-addr=%p, stack-addr=%p", notit, stack); goto end; error: @@ -345,8 +367,11 @@ end: static void stack_destroy(struct stack *stack) { + struct bt_msg_iter *notit; + BT_ASSERT(stack); - BT_LOGD("Destroying stack: addr=%p", stack); + notit = stack->notit; + BT_COMP_LOGD("Destroying stack: addr=%p", stack); if (stack->entries) { g_array_free(stack->entries, TRUE); @@ -359,10 +384,12 @@ static void stack_push(struct stack *stack, bt_field *base) { struct stack_entry *entry; + struct bt_msg_iter *notit; BT_ASSERT(stack); + notit = stack->notit; BT_ASSERT(base); - BT_LOGV("Pushing base field on stack: stack-addr=%p, " + BT_COMP_LOGT("Pushing base field on stack: stack-addr=%p, " "stack-size-before=%zu, stack-size-after=%zu", stack, stack->size, stack->size + 1); @@ -386,9 +413,12 @@ unsigned int stack_size(struct stack *stack) static void stack_pop(struct stack *stack) { + struct bt_msg_iter *notit; + BT_ASSERT(stack); BT_ASSERT(stack_size(stack)); - BT_LOGV("Popping from stack: " + notit = stack->notit; + BT_COMP_LOGT("Popping from stack: " "stack-addr=%p, stack-size-before=%zu, stack-size-after=%zu", stack, stack->size, stack->size - 1); stack->size--; @@ -445,7 +475,7 @@ size_t packet_at(struct bt_msg_iter *notit) static inline void buf_consume_bits(struct bt_msg_iter *notit, size_t incr) { - BT_LOGV("Advancing cursor: notit-addr=%p, cur-before=%zu, cur-after=%zu", + BT_COMP_LOGT("Advancing cursor: notit-addr=%p, cur-before=%zu, cur-after=%zu", notit, notit->buf.at, notit->buf.at + incr); notit->buf.at += incr; } @@ -458,12 +488,12 @@ enum bt_msg_iter_status request_medium_bytes( size_t buffer_sz = 0; enum bt_msg_iter_medium_status m_status; - BT_LOGD("Calling user function (request bytes): notit-addr=%p, " + BT_COMP_LOGD("Calling user function (request bytes): notit-addr=%p, " "request-size=%zu", notit, notit->medium.max_request_sz); m_status = notit->medium.medops.request_bytes( notit->medium.max_request_sz, &buffer_addr, &buffer_sz, notit->medium.data); - BT_LOGD("User function returned: status=%s, buf-addr=%p, buf-size=%zu", + BT_COMP_LOGD("User function returned: status=%s, buf-addr=%p, buf-size=%zu", bt_msg_iter_medium_status_string(m_status), buffer_addr, buffer_sz); if (m_status == BT_MSG_ITER_MEDIUM_STATUS_OK) { @@ -482,11 +512,11 @@ enum bt_msg_iter_status request_medium_bytes( /* New medium buffer address */ notit->buf.addr = buffer_addr; - BT_LOGD("User function returned new bytes: " + BT_COMP_LOGD("User function returned new bytes: " "packet-offset=%zu, cur=%zu, size=%zu, addr=%p", notit->buf.packet_offset, notit->buf.at, notit->buf.sz, notit->buf.addr); - BT_LOGD_MEM(buffer_addr, buffer_sz, "Returned bytes at %p:", + BT_COMP_LOGD_MEM(buffer_addr, buffer_sz, "Returned bytes at %p:", buffer_addr); } else if (m_status == BT_MSG_ITER_MEDIUM_STATUS_EOF) { /* @@ -511,7 +541,7 @@ enum bt_msg_iter_status request_medium_bytes( } /* All other states are invalid */ - BT_LOGW("User function returned %s, but message iterator is in an unexpected state: " + BT_COMP_LOGW("User function returned %s, but message iterator is in an unexpected state: " "state=%s, cur-packet-size=%" PRId64 ", cur=%zu, " "packet-cur=%zu, last-eh-at=%zu", bt_msg_iter_medium_status_string(m_status), @@ -521,7 +551,7 @@ enum bt_msg_iter_status request_medium_bytes( notit->buf.last_eh_at); m_status = BT_MSG_ITER_MEDIUM_STATUS_ERROR; } else if (m_status < 0) { - BT_LOGW("User function failed: status=%s", + BT_COMP_LOGW("User function failed: status=%s", bt_msg_iter_medium_status_string(m_status)); } @@ -558,25 +588,25 @@ enum bt_msg_iter_status read_dscope_begin_state( size_t consumed_bits; notit->cur_dscope_field = dscope_field; - BT_LOGV("Starting BFCR: notit-addr=%p, bfcr-addr=%p, fc-addr=%p", + BT_COMP_LOGT("Starting BFCR: notit-addr=%p, bfcr-addr=%p, fc-addr=%p", notit, notit->bfcr, dscope_fc); consumed_bits = bt_bfcr_start(notit->bfcr, dscope_fc, notit->buf.addr, notit->buf.at, packet_at(notit), notit->buf.sz, &bfcr_status); - BT_LOGV("BFCR consumed bits: size=%zu", consumed_bits); + BT_COMP_LOGT("BFCR consumed bits: size=%zu", consumed_bits); switch (bfcr_status) { case BT_BFCR_STATUS_OK: /* Field class was read completely */ - BT_LOGV_STR("Field was completely decoded."); + BT_COMP_LOGT_STR("Field was completely decoded."); notit->state = done_state; break; case BT_BFCR_STATUS_EOF: - BT_LOGV_STR("BFCR needs more data to decode field completely."); + BT_COMP_LOGT_STR("BFCR needs more data to decode field completely."); notit->state = continue_state; break; default: - BT_LOGW("BFCR failed to start: notit-addr=%p, bfcr-addr=%p, " + BT_COMP_LOGW("BFCR failed to start: notit-addr=%p, bfcr-addr=%p, " "status=%s", notit, notit->bfcr, bt_bfcr_status_string(bfcr_status)); status = BT_MSG_ITER_STATUS_ERROR; @@ -598,17 +628,17 @@ enum bt_msg_iter_status read_dscope_continue_state( enum bt_bfcr_status bfcr_status; size_t consumed_bits; - BT_LOGV("Continuing BFCR: notit-addr=%p, bfcr-addr=%p", + BT_COMP_LOGT("Continuing BFCR: notit-addr=%p, bfcr-addr=%p", notit, notit->bfcr); status = buf_ensure_available_bits(notit); if (status != BT_MSG_ITER_STATUS_OK) { if (status < 0) { - BT_LOGW("Cannot ensure that buffer has at least one byte: " + BT_COMP_LOGW("Cannot ensure that buffer has at least one byte: " "msg-addr=%p, status=%s", notit, bt_msg_iter_status_string(status)); } else { - BT_LOGV("Cannot ensure that buffer has at least one byte: " + BT_COMP_LOGT("Cannot ensure that buffer has at least one byte: " "msg-addr=%p, status=%s", notit, bt_msg_iter_status_string(status)); } @@ -618,20 +648,20 @@ enum bt_msg_iter_status read_dscope_continue_state( consumed_bits = bt_bfcr_continue(notit->bfcr, notit->buf.addr, notit->buf.sz, &bfcr_status); - BT_LOGV("BFCR consumed bits: size=%zu", consumed_bits); + BT_COMP_LOGT("BFCR consumed bits: size=%zu", consumed_bits); switch (bfcr_status) { case BT_BFCR_STATUS_OK: /* Type was read completely. */ - BT_LOGV_STR("Field was completely decoded."); + BT_COMP_LOGT_STR("Field was completely decoded."); notit->state = done_state; break; case BT_BFCR_STATUS_EOF: /* Stay in this continue state. */ - BT_LOGV_STR("BFCR needs more data to decode field completely."); + BT_COMP_LOGT_STR("BFCR needs more data to decode field completely."); break; default: - BT_LOGW("BFCR failed to continue: notit-addr=%p, bfcr-addr=%p, " + BT_COMP_LOGW("BFCR failed to continue: notit-addr=%p, bfcr-addr=%p, " "status=%s", notit, notit->bfcr, bt_bfcr_status_string(bfcr_status)); status = BT_MSG_ITER_STATUS_ERROR; @@ -665,6 +695,71 @@ void release_all_dscopes(struct bt_msg_iter *notit) release_event_dscopes(notit); } +static +enum bt_msg_iter_status switch_packet_state(struct bt_msg_iter *notit) +{ + enum bt_msg_iter_status status = BT_MSG_ITER_STATUS_OK; + + /* + * We don't put the stream class here because we need to make + * sure that all the packets processed by the same message + * iterator refer to the same stream class (the first one). + */ + BT_ASSERT(notit); + + if (notit->cur_exp_packet_total_size != -1) { + notit->cur_packet_offset += notit->cur_exp_packet_total_size; + } + + BT_COMP_LOGD("Switching packet: notit-addr=%p, cur=%zu, " + "packet-offset=%" PRId64, notit, notit->buf.at, + notit->cur_packet_offset); + stack_clear(notit->stack); + notit->meta.ec = NULL; + BT_PACKET_PUT_REF_AND_RESET(notit->packet); + BT_MESSAGE_PUT_REF_AND_RESET(notit->event_msg); + release_all_dscopes(notit); + notit->cur_dscope_field = NULL; + + /* + * Adjust current buffer so that addr points to the beginning of the new + * packet. + */ + if (notit->buf.addr) { + size_t consumed_bytes = (size_t) (notit->buf.at / CHAR_BIT); + + /* Packets are assumed to start on a byte frontier. */ + if (notit->buf.at % CHAR_BIT) { + BT_COMP_LOGW("Cannot switch packet: current position is not a multiple of 8: " + "notit-addr=%p, cur=%zu", notit, notit->buf.at); + status = BT_MSG_ITER_STATUS_ERROR; + goto end; + } + + notit->buf.addr += consumed_bytes; + notit->buf.sz -= consumed_bytes; + notit->buf.at = 0; + notit->buf.packet_offset = 0; + BT_COMP_LOGD("Adjusted buffer: addr=%p, size=%zu", + notit->buf.addr, notit->buf.sz); + } + + notit->cur_exp_packet_content_size = -1; + notit->cur_exp_packet_total_size = -1; + notit->cur_stream_class_id = -1; + notit->cur_event_class_id = -1; + notit->cur_data_stream_id = -1; + notit->prev_packet_snapshots = notit->snapshots; + notit->snapshots.discarded_events = UINT64_C(-1); + notit->snapshots.packets = UINT64_C(-1); + notit->snapshots.beginning_clock = UINT64_C(-1); + notit->snapshots.end_clock = UINT64_C(-1); + notit->state = STATE_DSCOPE_TRACE_PACKET_HEADER_BEGIN; + +end: + return status; +} + static enum bt_msg_iter_status read_packet_header_begin_state( struct bt_msg_iter *notit) @@ -672,12 +767,6 @@ enum bt_msg_iter_status read_packet_header_begin_state( struct ctf_field_class *packet_header_fc = NULL; enum bt_msg_iter_status ret = BT_MSG_ITER_STATUS_OK; - if (bt_msg_iter_switch_packet(notit)) { - BT_LOGW("Cannot switch packet: notit-addr=%p", notit); - ret = BT_MSG_ITER_STATUS_ERROR; - goto end; - } - /* * Make sure at least one bit is available for this packet. An * empty packet is impossible. If we reach the end of the medium @@ -689,7 +778,7 @@ enum bt_msg_iter_status read_packet_header_begin_state( break; case BT_MSG_ITER_STATUS_EOF: ret = BT_MSG_ITER_STATUS_OK; - notit->state = STATE_CHECK_EMIT_MSG_STREAM_ACTIVITY_END; + notit->state = STATE_CHECK_EMIT_MSG_STREAM_END; goto end; default: goto end; @@ -705,14 +794,14 @@ enum bt_msg_iter_status read_packet_header_begin_state( notit->cur_stream_class_id = -1; notit->cur_event_class_id = -1; notit->cur_data_stream_id = -1; - BT_LOGD("Decoding packet header field:" + BT_COMP_LOGD("Decoding packet header field:" "notit-addr=%p, trace-class-addr=%p, fc-addr=%p", notit, notit->meta.tc, packet_header_fc); ret = read_dscope_begin_state(notit, packet_header_fc, STATE_AFTER_TRACE_PACKET_HEADER, STATE_DSCOPE_TRACE_PACKET_HEADER_CONTINUE, NULL); if (ret < 0) { - BT_LOGW("Cannot decode packet header field: " + BT_COMP_LOGW("Cannot decode packet header field: " "notit-addr=%p, trace-class-addr=%p, " "fc-addr=%p", notit, notit->meta.tc, packet_header_fc); @@ -742,7 +831,7 @@ enum bt_msg_iter_status set_current_stream_class(struct bt_msg_iter *notit) * stream class. */ if (notit->meta.tc->stream_classes->len != 1) { - BT_LOGW("Need exactly one stream class since there's " + BT_COMP_LOGW("Need exactly one stream class since there's " "no stream class ID field: " "notit-addr=%p", notit); status = BT_MSG_ITER_STATUS_ERROR; @@ -756,7 +845,7 @@ enum bt_msg_iter_status set_current_stream_class(struct bt_msg_iter *notit) new_stream_class = ctf_trace_class_borrow_stream_class_by_id( notit->meta.tc, notit->cur_stream_class_id); if (!new_stream_class) { - BT_LOGW("No stream class with ID of stream class ID to use in trace class: " + BT_COMP_LOGW("No stream class with ID of stream class ID to use in trace class: " "notit-addr=%p, stream-class-id=%" PRIu64 ", " "trace-class-addr=%p", notit, notit->cur_stream_class_id, notit->meta.tc); @@ -766,7 +855,7 @@ enum bt_msg_iter_status set_current_stream_class(struct bt_msg_iter *notit) if (notit->meta.sc) { if (new_stream_class != notit->meta.sc) { - BT_LOGW("Two packets refer to two different stream classes within the same packet sequence: " + BT_COMP_LOGW("Two packets refer to two different stream classes within the same packet sequence: " "notit-addr=%p, prev-stream-class-addr=%p, " "prev-stream-class-id=%" PRId64 ", " "next-stream-class-addr=%p, " @@ -784,7 +873,7 @@ enum bt_msg_iter_status set_current_stream_class(struct bt_msg_iter *notit) notit->meta.sc = new_stream_class; } - BT_LOGD("Set current stream class: " + BT_COMP_LOGD("Set current stream class: " "notit-addr=%p, stream-class-addr=%p, " "stream-class-id=%" PRId64, notit, notit->meta.sc, notit->meta.sc->id); @@ -799,7 +888,7 @@ enum bt_msg_iter_status set_current_stream(struct bt_msg_iter *notit) enum bt_msg_iter_status status = BT_MSG_ITER_STATUS_OK; bt_stream *stream = NULL; - BT_LOGD("Calling user function (get stream): notit-addr=%p, " + BT_COMP_LOGD("Calling user function (get stream): notit-addr=%p, " "stream-class-addr=%p, stream-class-id=%" PRId64, notit, notit->meta.sc, notit->meta.sc->id); @@ -807,16 +896,16 @@ enum bt_msg_iter_status set_current_stream(struct bt_msg_iter *notit) notit->meta.sc->ir_sc, notit->cur_data_stream_id, notit->medium.data); bt_stream_get_ref(stream); - BT_LOGD("User function returned: stream-addr=%p", stream); + BT_COMP_LOGD("User function returned: stream-addr=%p", stream); if (!stream) { - BT_LOGW_STR("User function failed to return a stream object " + BT_COMP_LOGW_STR("User function failed to return a stream object " "for the given stream class."); status = BT_MSG_ITER_STATUS_ERROR; goto end; } if (notit->stream && stream != notit->stream) { - BT_LOGW("User function returned a different stream than the " + BT_COMP_LOGW("User function returned a different stream than the " "previous one for the same sequence of packets."); status = BT_MSG_ITER_STATUS_ERROR; goto end; @@ -835,9 +924,9 @@ enum bt_msg_iter_status set_current_packet(struct bt_msg_iter *notit) enum bt_msg_iter_status status = BT_MSG_ITER_STATUS_OK; bt_packet *packet = NULL; - BT_LOGD("Creating packet for packet message: " + BT_COMP_LOGD("Creating packet for packet message: " "notit-addr=%p", notit); - BT_LOGD("Creating packet from stream: " + BT_COMP_LOGD("Creating packet from stream: " "notit-addr=%p, stream-addr=%p, " "stream-class-addr=%p, " "stream-class-id=%" PRId64, @@ -848,7 +937,7 @@ enum bt_msg_iter_status set_current_packet(struct bt_msg_iter *notit) BT_ASSERT(notit->stream); packet = bt_packet_create(notit->stream); if (!packet) { - BT_LOGE("Cannot create packet from stream: " + BT_COMP_LOGE("Cannot create packet from stream: " "notit-addr=%p, stream-addr=%p, " "stream-class-addr=%p, " "stream-class-id=%" PRId64, @@ -895,7 +984,7 @@ enum bt_msg_iter_status read_packet_context_begin_state( BT_ASSERT(notit->meta.sc); packet_context_fc = notit->meta.sc->packet_context_fc; if (!packet_context_fc) { - BT_LOGD("No packet packet context field class in stream class: continuing: " + BT_COMP_LOGD("No packet packet context field class in stream class: continuing: " "notit-addr=%p, stream-class-addr=%p, " "stream-class-id=%" PRId64, notit, notit->meta.sc, @@ -906,7 +995,7 @@ enum bt_msg_iter_status read_packet_context_begin_state( BT_ASSERT(!notit->packet_context_field); - if (packet_context_fc->in_ir) { + if (packet_context_fc->in_ir && !notit->dry_run) { /* * Create free packet context field from stream class. * This field is going to be moved to the packet once we @@ -920,7 +1009,7 @@ enum bt_msg_iter_status read_packet_context_begin_state( bt_packet_context_field_create( notit->meta.sc->ir_sc); if (!notit->packet_context_field) { - BT_LOGE_STR("Cannot create packet context field wrapper from stream class."); + BT_COMP_LOGE_STR("Cannot create packet context field wrapper from stream class."); status = BT_MSG_ITER_STATUS_ERROR; goto end; } @@ -931,7 +1020,7 @@ enum bt_msg_iter_status read_packet_context_begin_state( BT_ASSERT(notit->dscopes.stream_packet_context); } - BT_LOGD("Decoding packet context field: " + BT_COMP_LOGD("Decoding packet context field: " "notit-addr=%p, stream-class-addr=%p, " "stream-class-id=%" PRId64 ", fc-addr=%p", notit, notit->meta.sc, @@ -941,7 +1030,7 @@ enum bt_msg_iter_status read_packet_context_begin_state( STATE_DSCOPE_STREAM_PACKET_CONTEXT_CONTINUE, notit->dscopes.stream_packet_context); if (status < 0) { - BT_LOGW("Cannot decode packet context field: " + BT_COMP_LOGW("Cannot decode packet context field: " "notit-addr=%p, stream-class-addr=%p, " "stream-class-id=%" PRId64 ", fc-addr=%p", notit, notit->meta.sc, @@ -986,7 +1075,7 @@ enum bt_msg_iter_status set_current_packet_content_sizes( if (notit->cur_exp_packet_content_size > notit->cur_exp_packet_total_size) { - BT_LOGW("Invalid packet or content size: " + BT_COMP_LOGW("Invalid packet or content size: " "content size is greater than packet size: " "notit-addr=%p, packet-context-field-addr=%p, " "packet-size=%" PRId64 ", content-size=%" PRId64, @@ -997,7 +1086,7 @@ enum bt_msg_iter_status set_current_packet_content_sizes( goto end; } - BT_LOGD("Set current packet and content sizes: " + BT_COMP_LOGD("Set current packet and content sizes: " "notit-addr=%p, packet-size=%" PRIu64 ", content-size=%" PRIu64, notit, notit->cur_exp_packet_total_size, notit->cur_exp_packet_content_size); @@ -1046,14 +1135,14 @@ enum bt_msg_iter_status read_event_header_begin_state(struct bt_msg_iter *notit) if (G_UNLIKELY(packet_at(notit) == notit->cur_exp_packet_content_size)) { /* No more events! */ - BT_LOGD("Reached end of packet: notit-addr=%p, " + BT_COMP_LOGD("Reached end of packet: notit-addr=%p, " "cur=%zu", notit, packet_at(notit)); notit->state = STATE_EMIT_MSG_PACKET_END_MULTI; goto end; } else if (G_UNLIKELY(packet_at(notit) > notit->cur_exp_packet_content_size)) { /* That's not supposed to happen */ - BT_LOGD("Before decoding event header field: cursor is passed the packet's content: " + BT_COMP_LOGD("Before decoding event header field: cursor is passed the packet's content: " "notit-addr=%p, content-size=%" PRId64 ", " "cur=%zu", notit, notit->cur_exp_packet_content_size, @@ -1087,7 +1176,7 @@ enum bt_msg_iter_status read_event_header_begin_state(struct bt_msg_iter *notit) goto end; } - BT_LOGD("Decoding event header field: " + BT_COMP_LOGD("Decoding event header field: " "notit-addr=%p, stream-class-addr=%p, " "stream-class-id=%" PRId64 ", " "fc-addr=%p", @@ -1098,7 +1187,7 @@ enum bt_msg_iter_status read_event_header_begin_state(struct bt_msg_iter *notit) STATE_AFTER_EVENT_HEADER, STATE_DSCOPE_EVENT_HEADER_CONTINUE, NULL); if (status < 0) { - BT_LOGW("Cannot decode event header field: " + BT_COMP_LOGW("Cannot decode event header field: " "notit-addr=%p, stream-class-addr=%p, " "stream-class-id=%" PRId64 ", fc-addr=%p", notit, notit->meta.sc, @@ -1131,7 +1220,7 @@ enum bt_msg_iter_status set_current_event_class(struct bt_msg_iter *notit) * event class. */ if (notit->meta.sc->event_classes->len != 1) { - BT_LOGW("Need exactly one event class since there's " + BT_COMP_LOGW("Need exactly one event class since there's " "no event class ID field: " "notit-addr=%p", notit); status = BT_MSG_ITER_STATUS_ERROR; @@ -1145,7 +1234,7 @@ enum bt_msg_iter_status set_current_event_class(struct bt_msg_iter *notit) new_event_class = ctf_stream_class_borrow_event_class_by_id( notit->meta.sc, notit->cur_event_class_id); if (!new_event_class) { - BT_LOGW("No event class with ID of event class ID to use in stream class: " + BT_COMP_LOGW("No event class with ID of event class ID to use in stream class: " "notit-addr=%p, stream-class-id=%" PRIu64 ", " "event-class-id=%" PRIu64 ", " "trace-class-addr=%p", @@ -1156,7 +1245,7 @@ enum bt_msg_iter_status set_current_event_class(struct bt_msg_iter *notit) } notit->meta.ec = new_event_class; - BT_LOGD("Set current event class: " + BT_COMP_LOGD("Set current event class: " "notit-addr=%p, event-class-addr=%p, " "event-class-id=%" PRId64 ", " "event-class-name=\"%s\"", @@ -1176,7 +1265,7 @@ enum bt_msg_iter_status set_current_event_message( BT_ASSERT(notit->meta.ec); BT_ASSERT(notit->packet); - BT_LOGD("Creating event message from event class and packet: " + BT_COMP_LOGD("Creating event message from event class and packet: " "notit-addr=%p, ec-addr=%p, ec-name=\"%s\", packet-addr=%p", notit, notit->meta.ec, notit->meta.ec->name->str, @@ -1185,16 +1274,16 @@ enum bt_msg_iter_status set_current_event_message( BT_ASSERT(notit->meta.sc); if (bt_stream_class_borrow_default_clock_class(notit->meta.sc->ir_sc)) { - msg = bt_message_event_create_with_default_clock_snapshot( + msg = bt_message_event_create_with_packet_and_default_clock_snapshot( notit->msg_iter, notit->meta.ec->ir_ec, notit->packet, notit->default_clock_snapshot); } else { - msg = bt_message_event_create(notit->msg_iter, + msg = bt_message_event_create_with_packet(notit->msg_iter, notit->meta.ec->ir_ec, notit->packet); } if (!msg) { - BT_LOGE("Cannot create event message: " + BT_COMP_LOGE("Cannot create event message: " "notit-addr=%p, ec-addr=%p, ec-name=\"%s\", " "packet-addr=%p", notit, notit->meta.ec, @@ -1225,6 +1314,10 @@ enum bt_msg_iter_status after_event_header_state( goto end; } + if (G_UNLIKELY(notit->dry_run)) { + goto next_state; + } + status = set_current_event_message(notit); if (status != BT_MSG_ITER_STATUS_OK) { goto end; @@ -1233,6 +1326,8 @@ enum bt_msg_iter_status after_event_header_state( notit->event = bt_message_event_borrow_event( notit->event_msg); BT_ASSERT(notit->event); + +next_state: notit->state = STATE_DSCOPE_EVENT_COMMON_CONTEXT_BEGIN; end: @@ -1252,7 +1347,7 @@ enum bt_msg_iter_status read_event_common_context_begin_state( goto end; } - if (event_common_context_fc->in_ir) { + if (event_common_context_fc->in_ir && !notit->dry_run) { BT_ASSERT(!notit->dscopes.event_common_context); notit->dscopes.event_common_context = bt_event_borrow_common_context_field( @@ -1260,7 +1355,7 @@ enum bt_msg_iter_status read_event_common_context_begin_state( BT_ASSERT(notit->dscopes.event_common_context); } - BT_LOGV("Decoding event common context field: " + BT_COMP_LOGT("Decoding event common context field: " "notit-addr=%p, stream-class-addr=%p, " "stream-class-id=%" PRId64 ", " "fc-addr=%p", @@ -1272,7 +1367,7 @@ enum bt_msg_iter_status read_event_common_context_begin_state( STATE_DSCOPE_EVENT_COMMON_CONTEXT_CONTINUE, notit->dscopes.event_common_context); if (status < 0) { - BT_LOGW("Cannot decode event common context field: " + BT_COMP_LOGW("Cannot decode event common context field: " "notit-addr=%p, stream-class-addr=%p, " "stream-class-id=%" PRId64 ", fc-addr=%p", notit, notit->meta.sc, @@ -1305,7 +1400,7 @@ enum bt_msg_iter_status read_event_spec_context_begin_state( goto end; } - if (event_spec_context_fc->in_ir) { + if (event_spec_context_fc->in_ir && !notit->dry_run) { BT_ASSERT(!notit->dscopes.event_spec_context); notit->dscopes.event_spec_context = bt_event_borrow_specific_context_field( @@ -1313,7 +1408,7 @@ enum bt_msg_iter_status read_event_spec_context_begin_state( BT_ASSERT(notit->dscopes.event_spec_context); } - BT_LOGV("Decoding event specific context field: " + BT_COMP_LOGT("Decoding event specific context field: " "notit-addr=%p, event-class-addr=%p, " "event-class-name=\"%s\", event-class-id=%" PRId64 ", " "fc-addr=%p", @@ -1326,7 +1421,7 @@ enum bt_msg_iter_status read_event_spec_context_begin_state( STATE_DSCOPE_EVENT_SPEC_CONTEXT_CONTINUE, notit->dscopes.event_spec_context); if (status < 0) { - BT_LOGW("Cannot decode event specific context field: " + BT_COMP_LOGW("Cannot decode event specific context field: " "notit-addr=%p, event-class-addr=%p, " "event-class-name=\"%s\", " "event-class-id=%" PRId64 ", fc-addr=%p", @@ -1361,7 +1456,7 @@ enum bt_msg_iter_status read_event_payload_begin_state( goto end; } - if (event_payload_fc->in_ir) { + if (event_payload_fc->in_ir && !notit->dry_run) { BT_ASSERT(!notit->dscopes.event_payload); notit->dscopes.event_payload = bt_event_borrow_payload_field( @@ -1369,7 +1464,7 @@ enum bt_msg_iter_status read_event_payload_begin_state( BT_ASSERT(notit->dscopes.event_payload); } - BT_LOGV("Decoding event payload field: " + BT_COMP_LOGT("Decoding event payload field: " "notit-addr=%p, event-class-addr=%p, " "event-class-name=\"%s\", event-class-id=%" PRId64 ", " "fc-addr=%p", @@ -1382,7 +1477,7 @@ enum bt_msg_iter_status read_event_payload_begin_state( STATE_DSCOPE_EVENT_PAYLOAD_CONTINUE, notit->dscopes.event_payload); if (status < 0) { - BT_LOGW("Cannot decode event payload field: " + BT_COMP_LOGW("Cannot decode event payload field: " "notit-addr=%p, event-class-addr=%p, " "event-class-name=\"%s\", " "event-class-id=%" PRId64 ", fc-addr=%p", @@ -1408,16 +1503,17 @@ enum bt_msg_iter_status skip_packet_padding_state(struct bt_msg_iter *notit) { enum bt_msg_iter_status status = BT_MSG_ITER_STATUS_OK; size_t bits_to_skip; + const enum state next_state = STATE_SWITCH_PACKET; BT_ASSERT(notit->cur_exp_packet_total_size > 0); bits_to_skip = notit->cur_exp_packet_total_size - packet_at(notit); if (bits_to_skip == 0) { - notit->state = STATE_DSCOPE_TRACE_PACKET_HEADER_BEGIN; + notit->state = next_state; goto end; } else { size_t bits_to_consume; - BT_LOGD("Trying to skip %zu bits of padding: notit-addr=%p, size=%zu", + BT_COMP_LOGD("Trying to skip %zu bits of padding: notit-addr=%p, size=%zu", bits_to_skip, notit, bits_to_skip); status = buf_ensure_available_bits(notit); if (status != BT_MSG_ITER_STATUS_OK) { @@ -1425,13 +1521,13 @@ enum bt_msg_iter_status skip_packet_padding_state(struct bt_msg_iter *notit) } bits_to_consume = MIN(buf_available_bits(notit), bits_to_skip); - BT_LOGD("Skipping %zu bits of padding: notit-addr=%p, size=%zu", + BT_COMP_LOGD("Skipping %zu bits of padding: notit-addr=%p, size=%zu", bits_to_consume, notit, bits_to_consume); buf_consume_bits(notit, bits_to_consume); bits_to_skip = notit->cur_exp_packet_total_size - packet_at(notit); if (bits_to_skip == 0) { - notit->state = STATE_DSCOPE_TRACE_PACKET_HEADER_BEGIN; + notit->state = next_state; goto end; } } @@ -1549,11 +1645,11 @@ end: } static -enum bt_msg_iter_status check_emit_msg_stream_activity_end( +enum bt_msg_iter_status check_emit_msg_stream_end( struct bt_msg_iter *notit) { if (notit->emit_stream_end_msg) { - notit->state = STATE_EMIT_MSG_STREAM_ACTIVITY_END; + notit->state = STATE_EMIT_MSG_STREAM_END; } else { notit->state = STATE_DONE; } @@ -1567,13 +1663,16 @@ enum bt_msg_iter_status handle_state(struct bt_msg_iter *notit) enum bt_msg_iter_status status = BT_MSG_ITER_STATUS_OK; const enum state state = notit->state; - BT_LOGV("Handling state: notit-addr=%p, state=%s", + BT_COMP_LOGT("Handling state: notit-addr=%p, state=%s", notit, state_string(state)); // TODO: optimalize! switch (state) { case STATE_INIT: - notit->state = STATE_DSCOPE_TRACE_PACKET_HEADER_BEGIN; + notit->state = STATE_SWITCH_PACKET; + break; + case STATE_SWITCH_PACKET: + status = switch_packet_state(notit); break; case STATE_DSCOPE_TRACE_PACKET_HEADER_BEGIN: status = read_packet_header_begin_state(notit); @@ -1597,9 +1696,6 @@ enum bt_msg_iter_status handle_state(struct bt_msg_iter *notit) status = check_emit_msg_stream_beginning_state(notit); break; case STATE_EMIT_MSG_STREAM_BEGINNING: - notit->state = STATE_EMIT_MSG_STREAM_ACTIVITY_BEGINNING; - break; - case STATE_EMIT_MSG_STREAM_ACTIVITY_BEGINNING: notit->state = STATE_CHECK_EMIT_MSG_DISCARDED_EVENTS; break; case STATE_CHECK_EMIT_MSG_DISCARDED_EVENTS: @@ -1647,6 +1743,9 @@ enum bt_msg_iter_status handle_state(struct bt_msg_iter *notit) case STATE_EMIT_MSG_EVENT: notit->state = STATE_DSCOPE_EVENT_HEADER_BEGIN; break; + case STATE_EMIT_QUEUED_MSG_EVENT: + notit->state = STATE_EMIT_MSG_EVENT; + break; case STATE_SKIP_PACKET_PADDING: status = skip_packet_padding_state(notit); break; @@ -1654,13 +1753,13 @@ enum bt_msg_iter_status handle_state(struct bt_msg_iter *notit) notit->state = STATE_SKIP_PACKET_PADDING; break; case STATE_EMIT_MSG_PACKET_END_SINGLE: - notit->state = STATE_CHECK_EMIT_MSG_STREAM_ACTIVITY_END; + notit->state = STATE_CHECK_EMIT_MSG_STREAM_END; break; - case STATE_CHECK_EMIT_MSG_STREAM_ACTIVITY_END: - status = check_emit_msg_stream_activity_end(notit); + case STATE_CHECK_EMIT_MSG_STREAM_END: + status = check_emit_msg_stream_end(notit); break; - case STATE_EMIT_MSG_STREAM_ACTIVITY_END: - notit->state = STATE_EMIT_MSG_STREAM_END; + case STATE_EMIT_QUEUED_MSG_PACKET_END: + notit->state = STATE_EMIT_MSG_PACKET_END_SINGLE; break; case STATE_EMIT_MSG_STREAM_END: notit->state = STATE_DONE; @@ -1668,12 +1767,12 @@ enum bt_msg_iter_status handle_state(struct bt_msg_iter *notit) case STATE_DONE: break; default: - BT_LOGF("Unknown CTF plugin message iterator state: " + BT_COMP_LOGF("Unknown CTF plugin message iterator state: " "notit-addr=%p, state=%d", notit, notit->state); abort(); } - BT_LOGV("Handled state: notit-addr=%p, status=%s, " + BT_COMP_LOGT("Handled state: notit-addr=%p, status=%s, " "prev-state=%s, cur-state=%s", notit, bt_msg_iter_status_string(status), state_string(state), state_string(notit->state)); @@ -1684,7 +1783,7 @@ BT_HIDDEN void bt_msg_iter_reset_for_next_stream_file(struct bt_msg_iter *notit) { BT_ASSERT(notit); - BT_LOGD("Resetting message iterator: addr=%p", notit); + BT_COMP_LOGD("Resetting message iterator: addr=%p", notit); stack_clear(notit->stack); notit->meta.sc = NULL; notit->meta.ec = NULL; @@ -1722,8 +1821,6 @@ void bt_msg_iter_reset(struct bt_msg_iter *notit) bt_msg_iter_reset_for_next_stream_file(notit); notit->cur_stream_class_id = -1; notit->cur_data_stream_id = -1; - notit->emit_stream_begin_msg = true; - notit->emit_stream_end_msg = true; notit->snapshots.discarded_events = UINT64_C(-1); notit->snapshots.packets = UINT64_C(-1); notit->prev_packet_snapshots.discarded_events = UINT64_C(-1); @@ -1732,70 +1829,6 @@ void bt_msg_iter_reset(struct bt_msg_iter *notit) notit->prev_packet_snapshots.end_clock = UINT64_C(-1); } -static -int bt_msg_iter_switch_packet(struct bt_msg_iter *notit) -{ - int ret = 0; - - /* - * We don't put the stream class here because we need to make - * sure that all the packets processed by the same message - * iterator refer to the same stream class (the first one). - */ - BT_ASSERT(notit); - - if (notit->cur_exp_packet_total_size != -1) { - notit->cur_packet_offset += notit->cur_exp_packet_total_size; - } - - BT_LOGD("Switching packet: notit-addr=%p, cur=%zu, " - "packet-offset=%" PRId64, notit, notit->buf.at, - notit->cur_packet_offset); - stack_clear(notit->stack); - notit->meta.ec = NULL; - BT_PACKET_PUT_REF_AND_RESET(notit->packet); - BT_MESSAGE_PUT_REF_AND_RESET(notit->event_msg); - release_all_dscopes(notit); - notit->cur_dscope_field = NULL; - - /* - * Adjust current buffer so that addr points to the beginning of the new - * packet. - */ - if (notit->buf.addr) { - size_t consumed_bytes = (size_t) (notit->buf.at / CHAR_BIT); - - /* Packets are assumed to start on a byte frontier. */ - if (notit->buf.at % CHAR_BIT) { - BT_LOGW("Cannot switch packet: current position is not a multiple of 8: " - "notit-addr=%p, cur=%zu", notit, notit->buf.at); - ret = -1; - goto end; - } - - notit->buf.addr += consumed_bytes; - notit->buf.sz -= consumed_bytes; - notit->buf.at = 0; - notit->buf.packet_offset = 0; - BT_LOGD("Adjusted buffer: addr=%p, size=%zu", - notit->buf.addr, notit->buf.sz); - } - - notit->cur_exp_packet_content_size = -1; - notit->cur_exp_packet_total_size = -1; - notit->cur_stream_class_id = -1; - notit->cur_event_class_id = -1; - notit->cur_data_stream_id = -1; - notit->prev_packet_snapshots = notit->snapshots; - notit->snapshots.discarded_events = UINT64_C(-1); - notit->snapshots.packets = UINT64_C(-1); - notit->snapshots.beginning_clock = UINT64_C(-1); - notit->snapshots.end_clock = UINT64_C(-1); - -end: - return ret; -} - static bt_field *borrow_next_field(struct bt_msg_iter *notit) { @@ -1829,7 +1862,9 @@ bt_field *borrow_next_field(struct bt_msg_iter *notit) next_field = bt_field_array_borrow_element_field_by_index( base_field, index); break; - case BT_FIELD_CLASS_TYPE_VARIANT: + case BT_FIELD_CLASS_TYPE_VARIANT_WITHOUT_SELECTOR: + case BT_FIELD_CLASS_TYPE_VARIANT_WITH_UNSIGNED_SELECTOR: + case BT_FIELD_CLASS_TYPE_VARIANT_WITH_SIGNED_SELECTOR: BT_ASSERT(index == 0); next_field = bt_field_variant_borrow_selected_option_field( base_field); @@ -1880,7 +1915,7 @@ void update_default_clock(struct bt_msg_iter *notit, uint64_t new_val, notit->default_clock_snapshot |= new_val; end: - BT_LOGV("Updated default clock's value from integer field's value: " + BT_COMP_LOGT("Updated default clock's value from integer field's value: " "value=%" PRIu64, notit->default_clock_snapshot); } @@ -1893,7 +1928,7 @@ enum bt_bfcr_status bfcr_unsigned_int_cb(uint64_t value, bt_field *field = NULL; struct ctf_field_class_int *int_fc = (void *) fc; - BT_LOGV("Unsigned integer function called from BFCR: " + BT_COMP_LOGT("Unsigned integer function called from BFCR: " "notit-addr=%p, bfcr-addr=%p, fc-addr=%p, " "fc-type=%d, fc-in-ir=%d, value=%" PRIu64, notit, notit->bfcr, fc, fc->type, fc->in_ir, value); @@ -1920,7 +1955,7 @@ enum bt_bfcr_status bfcr_unsigned_int_cb(uint64_t value, break; case CTF_FIELD_CLASS_MEANING_MAGIC: if (value != 0xc1fc1fc1) { - BT_LOGW("Invalid CTF magic number: notit-addr=%p, " + BT_COMP_LOGW("Invalid CTF magic number: notit-addr=%p, " "magic=%" PRIx64, notit, value); status = BT_BFCR_STATUS_ERROR; goto end; @@ -1953,7 +1988,7 @@ update_def_clock: (uint64_t) int_fc->storing_index) = value; } - if (G_UNLIKELY(!fc->in_ir)) { + if (G_UNLIKELY(!fc->in_ir || notit->dry_run)) { goto end; } @@ -1964,7 +1999,7 @@ update_def_clock: BT_FIELD_CLASS_TYPE_UNSIGNED_INTEGER || bt_field_get_class_type(field) == BT_FIELD_CLASS_TYPE_UNSIGNED_ENUMERATION); - bt_field_unsigned_integer_set_value(field, value); + bt_field_integer_unsigned_set_value(field, value); stack_top(notit->stack)->index++; end: @@ -1982,7 +2017,7 @@ enum bt_bfcr_status bfcr_unsigned_int_char_cb(uint64_t value, struct ctf_field_class_int *int_fc = (void *) fc; char str[2] = {'\0', '\0'}; - BT_LOGV("Unsigned integer character function called from BFCR: " + BT_COMP_LOGT("Unsigned integer character function called from BFCR: " "notit-addr=%p, bfcr-addr=%p, fc-addr=%p, " "fc-type=%d, fc-in-ir=%d, value=%" PRIu64, notit, notit->bfcr, fc, fc->type, fc->in_ir, value); @@ -1990,7 +2025,7 @@ enum bt_bfcr_status bfcr_unsigned_int_char_cb(uint64_t value, BT_ASSERT(!int_fc->mapped_clock_class); BT_ASSERT(int_fc->storing_index < 0); - if (G_UNLIKELY(!fc->in_ir)) { + if (G_UNLIKELY(!fc->in_ir || notit->dry_run)) { goto end; } @@ -2011,7 +2046,7 @@ enum bt_bfcr_status bfcr_unsigned_int_char_cb(uint64_t value, str[0] = (char) value; ret = bt_field_string_append_with_length(string_field, str, 1); if (ret) { - BT_LOGE("Cannot append character to string field's value: " + BT_COMP_LOGE("Cannot append character to string field's value: " "notit-addr=%p, field-addr=%p, ret=%d", notit, string_field, ret); status = BT_BFCR_STATUS_ERROR; @@ -2031,7 +2066,7 @@ enum bt_bfcr_status bfcr_signed_int_cb(int64_t value, struct bt_msg_iter *notit = data; struct ctf_field_class_int *int_fc = (void *) fc; - BT_LOGV("Signed integer function called from BFCR: " + BT_COMP_LOGT("Signed integer function called from BFCR: " "notit-addr=%p, bfcr-addr=%p, fc-addr=%p, " "fc-type=%d, fc-in-ir=%d, value=%" PRId64, notit, notit->bfcr, fc, fc->type, fc->in_ir, value); @@ -2042,7 +2077,7 @@ enum bt_bfcr_status bfcr_signed_int_cb(int64_t value, (uint64_t) int_fc->storing_index) = (uint64_t) value; } - if (G_UNLIKELY(!fc->in_ir)) { + if (G_UNLIKELY(!fc->in_ir || notit->dry_run)) { goto end; } @@ -2053,7 +2088,7 @@ enum bt_bfcr_status bfcr_signed_int_cb(int64_t value, BT_FIELD_CLASS_TYPE_SIGNED_INTEGER || bt_field_get_class_type(field) == BT_FIELD_CLASS_TYPE_SIGNED_ENUMERATION); - bt_field_signed_integer_set_value(field, value); + bt_field_integer_signed_set_value(field, value); stack_top(notit->stack)->index++; end: @@ -2068,21 +2103,27 @@ enum bt_bfcr_status bfcr_floating_point_cb(double value, bt_field *field = NULL; struct bt_msg_iter *notit = data; - BT_LOGV("Floating point number function called from BFCR: " + BT_COMP_LOGT("Floating point number function called from BFCR: " "notit-addr=%p, bfcr-addr=%p, fc-addr=%p, " "fc-type=%d, fc-in-ir=%d, value=%f", notit, notit->bfcr, fc, fc->type, fc->in_ir, value); - if (G_UNLIKELY(!fc->in_ir)) { + if (G_UNLIKELY(!fc->in_ir || notit->dry_run)) { goto end; } field = borrow_next_field(notit); + bt_field_class_type type = bt_field_get_class_type(field); BT_ASSERT(field); BT_ASSERT(bt_field_borrow_class_const(field) == fc->ir_fc); - BT_ASSERT(bt_field_get_class_type(field) == - BT_FIELD_CLASS_TYPE_REAL); - bt_field_real_set_value(field, value); + BT_ASSERT(type == BT_FIELD_CLASS_TYPE_DOUBLE_PRECISION_REAL || + type == BT_FIELD_CLASS_TYPE_SINGLE_PRECISION_REAL); + + if (type == BT_FIELD_CLASS_TYPE_SINGLE_PRECISION_REAL) { + bt_field_real_single_precision_set_value(field, (float) value); + } else { + bt_field_real_double_precision_set_value(field, value); + } stack_top(notit->stack)->index++; end: @@ -2095,14 +2136,13 @@ enum bt_bfcr_status bfcr_string_begin_cb( { bt_field *field = NULL; struct bt_msg_iter *notit = data; - int ret; - BT_LOGV("String (beginning) function called from BFCR: " + BT_COMP_LOGT("String (beginning) function called from BFCR: " "notit-addr=%p, bfcr-addr=%p, fc-addr=%p, " "fc-type=%d, fc-in-ir=%d", notit, notit->bfcr, fc, fc->type, fc->in_ir); - if (G_UNLIKELY(!fc->in_ir)) { + if (G_UNLIKELY(!fc->in_ir || notit->dry_run)) { goto end; } @@ -2111,8 +2151,7 @@ enum bt_bfcr_status bfcr_string_begin_cb( BT_ASSERT(bt_field_borrow_class_const(field) == fc->ir_fc); BT_ASSERT(bt_field_get_class_type(field) == BT_FIELD_CLASS_TYPE_STRING); - ret = bt_field_string_clear(field); - BT_ASSERT(ret == 0); + bt_field_string_clear(field); /* * Push on stack. Not a compound class per se, but we know that @@ -2134,13 +2173,13 @@ enum bt_bfcr_status bfcr_string_cb(const char *value, struct bt_msg_iter *notit = data; int ret; - BT_LOGV("String (substring) function called from BFCR: " + BT_COMP_LOGT("String (substring) function called from BFCR: " "notit-addr=%p, bfcr-addr=%p, fc-addr=%p, " "fc-type=%d, fc-in-ir=%d, string-length=%zu", notit, notit->bfcr, fc, fc->type, fc->in_ir, len); - if (G_UNLIKELY(!fc->in_ir)) { + if (G_UNLIKELY(!fc->in_ir || notit->dry_run)) { goto end; } @@ -2150,7 +2189,7 @@ enum bt_bfcr_status bfcr_string_cb(const char *value, /* Append current substring */ ret = bt_field_string_append_with_length(field, value, len); if (ret) { - BT_LOGE("Cannot append substring to string field's value: " + BT_COMP_LOGE("Cannot append substring to string field's value: " "notit-addr=%p, field-addr=%p, string-length=%zu, " "ret=%d", notit, field, len, ret); status = BT_BFCR_STATUS_ERROR; @@ -2167,12 +2206,12 @@ enum bt_bfcr_status bfcr_string_end_cb( { struct bt_msg_iter *notit = data; - BT_LOGV("String (end) function called from BFCR: " + BT_COMP_LOGT("String (end) function called from BFCR: " "notit-addr=%p, bfcr-addr=%p, fc-addr=%p, " "fc-type=%d, fc-in-ir=%d", notit, notit->bfcr, fc, fc->type, fc->in_ir); - if (G_UNLIKELY(!fc->in_ir)) { + if (G_UNLIKELY(!fc->in_ir || notit->dry_run)) { goto end; } @@ -2192,12 +2231,12 @@ enum bt_bfcr_status bfcr_compound_begin_cb( struct bt_msg_iter *notit = data; bt_field *field; - BT_LOGV("Compound (beginning) function called from BFCR: " + BT_COMP_LOGT("Compound (beginning) function called from BFCR: " "notit-addr=%p, bfcr-addr=%p, fc-addr=%p, " "fc-type=%d, fc-in-ir=%d", notit, notit->bfcr, fc, fc->type, fc->in_ir); - if (!fc->in_ir) { + if (G_UNLIKELY(!fc->in_ir || notit->dry_run)) { goto end; } @@ -2224,13 +2263,10 @@ enum bt_bfcr_status bfcr_compound_begin_cb( struct ctf_field_class_array_base *array_fc = (void *) fc; if (array_fc->is_text) { - int ret; - BT_ASSERT(bt_field_get_class_type(field) == BT_FIELD_CLASS_TYPE_STRING); notit->done_filling_string = false; - ret = bt_field_string_clear(field); - BT_ASSERT(ret == 0); + bt_field_string_clear(field); bt_bfcr_set_unsigned_int_cb(notit->bfcr, bfcr_unsigned_int_char_cb); } @@ -2245,12 +2281,12 @@ enum bt_bfcr_status bfcr_compound_end_cb( { struct bt_msg_iter *notit = data; - BT_LOGV("Compound (end) function called from BFCR: " + BT_COMP_LOGT("Compound (end) function called from BFCR: " "notit-addr=%p, bfcr-addr=%p, fc-addr=%p, " "fc-type=%d, fc-in-ir=%d", notit, notit->bfcr, fc, fc->type, fc->in_ir); - if (!fc->in_ir) { + if (G_UNLIKELY(!fc->in_ir || notit->dry_run)) { goto end; } @@ -2298,6 +2334,11 @@ int64_t bfcr_get_sequence_length_cb(struct ctf_field_class *fc, void *data) length = (uint64_t) g_array_index(notit->stored_values, uint64_t, seq_fc->stored_length_index); + + if (G_UNLIKELY(notit->dry_run)){ + goto end; + } + seq_field = stack_top(notit->stack)->base; BT_ASSERT(seq_field); @@ -2310,15 +2351,16 @@ int64_t bfcr_get_sequence_length_cb(struct ctf_field_class *fc, void *data) if (!seq_fc->base.is_text) { BT_ASSERT(bt_field_get_class_type(seq_field) == BT_FIELD_CLASS_TYPE_DYNAMIC_ARRAY); - ret = bt_field_dynamic_array_set_length(seq_field, + ret = bt_field_array_dynamic_set_length(seq_field, (uint64_t) length); if (ret) { - BT_LOGE("Cannot set dynamic array field's length field: " + BT_COMP_LOGE("Cannot set dynamic array field's length field: " "notit-addr=%p, field-addr=%p, " "length=%" PRIu64, notit, seq_field, length); } } +end: return length; } @@ -2372,7 +2414,7 @@ struct ctf_field_class *bfcr_borrow_variant_selected_field_class_cb( } if (option_index < 0) { - BT_LOGW("Cannot find variant field class's option: " + BT_COMP_LOGW("Cannot find variant field class's option: " "notit-addr=%p, var-fc-addr=%p, u-tag=%" PRIu64 ", " "i-tag=%" PRId64, notit, var_fc, tag.u, tag.i); goto end; @@ -2381,13 +2423,13 @@ struct ctf_field_class *bfcr_borrow_variant_selected_field_class_cb( selected_option = ctf_field_class_variant_borrow_option_by_index( var_fc, (uint64_t) option_index); - if (selected_option->fc->in_ir) { + if (selected_option->fc->in_ir && !notit->dry_run) { bt_field *var_field = stack_top(notit->stack)->base; - ret = bt_field_variant_select_option_field( + ret = bt_field_variant_select_option_field_by_index( var_field, option_index); if (ret) { - BT_LOGW("Cannot select variant field's option field: " + BT_COMP_LOGW("Cannot select variant field's option field: " "notit-addr=%p, var-field-addr=%p, " "opt-index=%" PRId64, notit, var_field, option_index); @@ -2412,53 +2454,7 @@ void create_msg_stream_beginning(struct bt_msg_iter *notit, ret = bt_message_stream_beginning_create(notit->msg_iter, notit->stream); if (!ret) { - BT_LOGE("Cannot create stream beginning message: " - "notit-addr=%p, stream-addr=%p", - notit, notit->stream); - return; - } - - *message = ret; -} - -static -void create_msg_stream_activity_beginning(struct bt_msg_iter *notit, - bt_message **message) -{ - bt_message *ret = NULL; - - BT_ASSERT(notit->stream); - BT_ASSERT(notit->msg_iter); - ret = bt_message_stream_activity_beginning_create(notit->msg_iter, - notit->stream); - if (!ret) { - BT_LOGE("Cannot create stream activity beginning message: " - "notit-addr=%p, stream-addr=%p", - notit, notit->stream); - return; - } - - *message = ret; -} - -static -void create_msg_stream_activity_end(struct bt_msg_iter *notit, - bt_message **message) -{ - bt_message *ret = NULL; - - if (!notit->stream) { - BT_LOGE("Cannot create stream for stream message: " - "notit-addr=%p", notit); - return; - } - - BT_ASSERT(notit->stream); - BT_ASSERT(notit->msg_iter); - ret = bt_message_stream_activity_end_create(notit->msg_iter, - notit->stream); - if (!ret) { - BT_LOGE("Cannot create stream activity end message: " + BT_COMP_LOGE("Cannot create stream beginning message: " "notit-addr=%p, stream-addr=%p", notit, notit->stream); return; @@ -2473,7 +2469,7 @@ void create_msg_stream_end(struct bt_msg_iter *notit, bt_message **message) bt_message *ret; if (!notit->stream) { - BT_LOGE("Cannot create stream for stream message: " + BT_COMP_LOGE("Cannot create stream for stream message: " "notit-addr=%p", notit); return; } @@ -2482,7 +2478,7 @@ void create_msg_stream_end(struct bt_msg_iter *notit, bt_message **message) ret = bt_message_stream_end_create(notit->msg_iter, notit->stream); if (!ret) { - BT_LOGE("Cannot create stream end message: " + BT_COMP_LOGE("Cannot create stream end message: " "notit-addr=%p, stream-addr=%p", notit, notit->stream); return; @@ -2493,20 +2489,13 @@ void create_msg_stream_end(struct bt_msg_iter *notit, bt_message **message) static void create_msg_packet_beginning(struct bt_msg_iter *notit, - bt_message **message) + bt_message **message, bool use_default_cs) { int ret; - enum bt_msg_iter_status status; bt_message *msg = NULL; - const bt_stream_class *sc; - - status = set_current_packet(notit); - if (status != BT_MSG_ITER_STATUS_OK) { - goto end; - } + const bt_stream_class *sc = notit->meta.sc->ir_sc; BT_ASSERT(notit->packet); - sc = notit->meta.sc->ir_sc; BT_ASSERT(sc); if (notit->packet_context_field) { @@ -2532,16 +2521,28 @@ void create_msg_packet_beginning(struct bt_msg_iter *notit, if (notit->meta.sc->packets_have_ts_begin) { BT_ASSERT(notit->snapshots.beginning_clock != UINT64_C(-1)); + uint64_t raw_cs_value; + + /* + * Either use the decoded packet `timestamp_begin` field or the + * current stream's default clock_snapshot. + */ + if (use_default_cs) { + raw_cs_value = notit->default_clock_snapshot; + } else { + raw_cs_value = notit->snapshots.beginning_clock; + } + msg = bt_message_packet_beginning_create_with_default_clock_snapshot( notit->msg_iter, notit->packet, - notit->snapshots.beginning_clock); + raw_cs_value); } else { msg = bt_message_packet_beginning_create(notit->msg_iter, notit->packet); } if (!msg) { - BT_LOGE("Cannot create packet beginning message: " + BT_COMP_LOGE("Cannot create packet beginning message: " "notit-addr=%p, packet-addr=%p", notit, notit->packet); goto end; @@ -2553,17 +2554,86 @@ end: return; } +static +void emit_delayed_packet_beg_msg(struct bt_msg_iter *notit, + bt_message **message) +{ + bool packet_beg_ts_need_fix_up; + + notit->emit_delayed_packet_beginning_msg = false; + + /* + * Only fix the packet's timestamp_begin if it's larger than the first + * event of the packet. If there was no event in the packet, the + * `default_clock_snapshot` field will be either equal or greater than + * `snapshots.beginning_clock` so there is not fix needed. + */ + packet_beg_ts_need_fix_up = + notit->default_clock_snapshot < notit->snapshots.beginning_clock; + + /* create_msg_packet_beginning() logs errors */ + create_msg_packet_beginning(notit, message, packet_beg_ts_need_fix_up); + + return; +} + + static void create_msg_packet_end(struct bt_msg_iter *notit, bt_message **message) { bt_message *msg; + bool update_default_cs = true; if (!notit->packet) { return; } - /* Update default clock from packet's end time */ - if (notit->snapshots.end_clock != UINT64_C(-1)) { + /* + * Check if we need to emit the delayed packet + * beginning message instead of the packet end message. + */ + if (G_UNLIKELY(notit->emit_delayed_packet_beginning_msg)) { + emit_delayed_packet_beg_msg(notit, message); + /* Don't forget to emit the packet end message. */ + notit->state = STATE_EMIT_QUEUED_MSG_PACKET_END; + return; + } + + /* Check if may be affected by lttng-crash timestamp_end quirk. */ + if (G_UNLIKELY(notit->meta.tc->quirks.lttng_crash)) { + /* + * Check if the `timestamp_begin` field is non-zero but + * `timestamp_end` is zero. It means the trace is affected by + * the lttng-crash packet `timestamp_end` quirk and must be + * fixed up by omitting to update the default clock snapshot to + * the `timestamp_end` as is typically done. + */ + if (notit->snapshots.beginning_clock != 0 && + notit->snapshots.end_clock == 0) { + update_default_cs = false; + } + } + + /* + * Check if may be affected by lttng event-after-packet `timestamp_end` + * quirk. + */ + if (notit->meta.tc->quirks.lttng_event_after_packet) { + /* + * Check if `timestamp_end` is smaller then the current + * default_clock_snapshot (which is set to the last event + * decoded). It means the trace is affected by the lttng + * `event-after-packet` packet `timestamp_end` quirk and must + * be fixed up by omitting to update the default clock snapshot + * to the `timestamp_end` as is typically done. + */ + if (notit->snapshots.end_clock < notit->default_clock_snapshot) { + update_default_cs = false; + } + } + + /* Update default clock from packet's end time. */ + if (notit->snapshots.end_clock != UINT64_C(-1) && update_default_cs) { notit->default_clock_snapshot = notit->snapshots.end_clock; } @@ -2573,14 +2643,14 @@ void create_msg_packet_end(struct bt_msg_iter *notit, bt_message **message) BT_ASSERT(notit->snapshots.end_clock != UINT64_C(-1)); msg = bt_message_packet_end_create_with_default_clock_snapshot( notit->msg_iter, notit->packet, - notit->snapshots.end_clock); + notit->default_clock_snapshot); } else { msg = bt_message_packet_end_create(notit->msg_iter, notit->packet); } if (!msg) { - BT_LOGE("Cannot create packet end message: " + BT_COMP_LOGE("Cannot create packet end message: " "notit-addr=%p, packet-addr=%p", notit, notit->packet); return; @@ -2628,7 +2698,7 @@ void create_msg_discarded_events(struct bt_msg_iter *notit, } if (!msg) { - BT_LOGE("Cannot create discarded events message: " + BT_COMP_LOGE("Cannot create discarded events message: " "notit-addr=%p, stream-addr=%p", notit, notit->stream); return; @@ -2668,7 +2738,7 @@ void create_msg_discarded_packets(struct bt_msg_iter *notit, } if (!msg) { - BT_LOGE("Cannot create discarded packets message: " + BT_COMP_LOGE("Cannot create discarded packets message: " "notit-addr=%p, stream-addr=%p", notit, notit->stream); return; @@ -2683,7 +2753,8 @@ void create_msg_discarded_packets(struct bt_msg_iter *notit, BT_HIDDEN struct bt_msg_iter *bt_msg_iter_create(struct ctf_trace_class *tc, size_t max_request_sz, - struct bt_msg_iter_medium_ops medops, void *data) + struct bt_msg_iter_medium_ops medops, void *data, + bt_logging_level log_level, bt_self_component *self_comp) { struct bt_msg_iter *notit = NULL; struct bt_bfcr_cbs cbs = { @@ -2706,14 +2777,19 @@ struct bt_msg_iter *bt_msg_iter_create(struct ctf_trace_class *tc, BT_ASSERT(tc); BT_ASSERT(medops.request_bytes); BT_ASSERT(medops.borrow_stream); - BT_LOGD("Creating CTF plugin message iterator: " + BT_COMP_LOG_CUR_LVL(BT_LOG_DEBUG, log_level, self_comp, + "Creating CTF plugin message iterator: " "trace-addr=%p, max-request-size=%zu, " - "data=%p", tc, max_request_sz, data); + "data=%p, log-level=%s", tc, max_request_sz, data, + bt_common_logging_level_string(log_level)); notit = g_new0(struct bt_msg_iter, 1); if (!notit) { - BT_LOGE_STR("Failed to allocate one CTF plugin message iterator."); + BT_COMP_LOG_CUR_LVL(BT_LOG_ERROR, log_level, self_comp, + "Failed to allocate one CTF plugin message iterator."); goto end; } + notit->self_comp = self_comp; + notit->log_level = log_level; notit->meta.tc = tc; notit->medium.medops = medops; notit->medium.max_request_sz = max_request_sz; @@ -2723,21 +2799,22 @@ struct bt_msg_iter *bt_msg_iter_create(struct ctf_trace_class *tc, g_array_set_size(notit->stored_values, tc->stored_value_count); if (!notit->stack) { - BT_LOGE_STR("Failed to create field stack."); + BT_COMP_LOGE_STR("Failed to create field stack."); goto error; } - notit->bfcr = bt_bfcr_create(cbs, notit, BT_LOG_OUTPUT_LEVEL); + notit->bfcr = bt_bfcr_create(cbs, notit, log_level, NULL); if (!notit->bfcr) { - BT_LOGE_STR("Failed to create binary class reader (BFCR)."); + BT_COMP_LOGE_STR("Failed to create binary class reader (BFCR)."); goto error; } bt_msg_iter_reset(notit); - BT_LOGD("Created CTF plugin message iterator: " + BT_COMP_LOGD("Created CTF plugin message iterator: " "trace-addr=%p, max-request-size=%zu, " - "data=%p, notit-addr=%p", - tc, max_request_sz, data, notit); + "data=%p, notit-addr=%p, log-level=%s", + tc, max_request_sz, data, notit, + bt_common_logging_level_string(log_level)); notit->cur_packet_offset = 0; end: @@ -2755,15 +2832,15 @@ void bt_msg_iter_destroy(struct bt_msg_iter *notit) BT_STREAM_PUT_REF_AND_RESET(notit->stream); release_all_dscopes(notit); - BT_LOGD("Destroying CTF plugin message iterator: addr=%p", notit); + BT_COMP_LOGD("Destroying CTF plugin message iterator: addr=%p", notit); if (notit->stack) { - BT_LOGD_STR("Destroying field stack."); + BT_COMP_LOGD_STR("Destroying field stack."); stack_destroy(notit->stack); } if (notit->bfcr) { - BT_LOGD("Destroying BFCR: bfcr-addr=%p", notit->bfcr); + BT_COMP_LOGD("Destroying BFCR: bfcr-addr=%p", notit->bfcr); bt_bfcr_destroy(notit->bfcr); } @@ -2784,15 +2861,15 @@ enum bt_msg_iter_status bt_msg_iter_get_next_message( BT_ASSERT(message); notit->msg_iter = msg_iter; notit->set_stream = true; - BT_LOGD("Getting next message: notit-addr=%p", notit); + BT_COMP_LOGD("Getting next message: notit-addr=%p", notit); while (true) { status = handle_state(notit); if (G_UNLIKELY(status == BT_MSG_ITER_STATUS_AGAIN)) { - BT_LOGD_STR("Medium returned BT_MSG_ITER_STATUS_AGAIN."); + BT_COMP_LOGD_STR("Medium returned BT_MSG_ITER_STATUS_AGAIN."); goto end; } else if (G_UNLIKELY(status != BT_MSG_ITER_STATUS_OK)) { - BT_LOGW("Cannot handle state: notit-addr=%p, state=%s", + BT_COMP_LOGW("Cannot handle state: notit-addr=%p, state=%s", notit, state_string(notit->state)); goto end; } @@ -2800,8 +2877,27 @@ enum bt_msg_iter_status bt_msg_iter_get_next_message( switch (notit->state) { case STATE_EMIT_MSG_EVENT: BT_ASSERT(notit->event_msg); - *message = notit->event_msg; - notit->event_msg = NULL; + + /* + * Check if we need to emit the delayed packet + * beginning message instead of the event message. + */ + if (G_UNLIKELY(notit->emit_delayed_packet_beginning_msg)) { + emit_delayed_packet_beg_msg(notit, message); + if (!*message) { + status = BT_MSG_ITER_STATUS_ERROR; + } + + /* + * Don't forget to emit the event message of + * the event record that was just decoded. + */ + notit->state = STATE_EMIT_QUEUED_MSG_EVENT; + + } else { + *message = notit->event_msg; + notit->event_msg = NULL; + } goto end; case STATE_EMIT_MSG_DISCARDED_EVENTS: /* create_msg_discared_events() logs errors */ @@ -2822,11 +2918,26 @@ enum bt_msg_iter_status bt_msg_iter_get_next_message( goto end; case STATE_EMIT_MSG_PACKET_BEGINNING: - /* create_msg_packet_beginning() logs errors */ - create_msg_packet_beginning(notit, message); + status = set_current_packet(notit); + if (status != BT_MSG_ITER_STATUS_OK) { + goto end; + } - if (!*message) { - status = BT_MSG_ITER_STATUS_ERROR; + if (G_UNLIKELY(notit->meta.tc->quirks.barectf_event_before_packet)) { + notit->emit_delayed_packet_beginning_msg = true; + /* + * There is no message to return yet as this + * packet beginning message is delayed until we + * decode the first event message of the + * packet. + */ + break; + } else { + /* create_msg_packet_beginning() logs errors */ + create_msg_packet_beginning(notit, message, false); + if (!*message) { + status = BT_MSG_ITER_STATUS_ERROR; + } } goto end; @@ -2839,24 +2950,6 @@ enum bt_msg_iter_status bt_msg_iter_get_next_message( status = BT_MSG_ITER_STATUS_ERROR; } - goto end; - case STATE_EMIT_MSG_STREAM_ACTIVITY_BEGINNING: - /* create_msg_stream_activity_beginning() logs errors */ - create_msg_stream_activity_beginning(notit, message); - - if (!*message) { - status = BT_MSG_ITER_STATUS_ERROR; - } - - goto end; - case STATE_EMIT_MSG_STREAM_ACTIVITY_END: - /* create_msg_stream_activity_end() logs errors */ - create_msg_stream_activity_end(notit, message); - - if (!*message) { - status = BT_MSG_ITER_STATUS_ERROR; - } - goto end; case STATE_EMIT_MSG_STREAM_BEGINNING: /* create_msg_stream_beginning() logs errors */ @@ -2890,39 +2983,37 @@ end: } static -enum bt_msg_iter_status read_packet_header_context_fields( - struct bt_msg_iter *notit) +enum bt_msg_iter_status decode_until_state( struct bt_msg_iter *notit, + enum state target_state_1, enum state target_state_2) { - int ret; enum bt_msg_iter_status status = BT_MSG_ITER_STATUS_OK; BT_ASSERT(notit); notit->set_stream = false; - if (notit->state == STATE_EMIT_MSG_PACKET_BEGINNING) { - /* We're already there */ - goto end; - } + do { + /* + * Check if we reached the state at which we want to stop + * decoding. + */ + if (notit->state == target_state_1 || + notit->state == target_state_2) { + goto end; + } - while (true) { status = handle_state(notit); if (G_UNLIKELY(status == BT_MSG_ITER_STATUS_AGAIN)) { - BT_LOGD_STR("Medium returned BT_MSG_ITER_STATUS_AGAIN."); + BT_COMP_LOGD_STR("Medium returned BT_MSG_ITER_STATUS_AGAIN."); goto end; } else if (G_UNLIKELY(status != BT_MSG_ITER_STATUS_OK)) { - BT_LOGW("Cannot handle state: notit-addr=%p, state=%s", + BT_COMP_LOGW("Cannot handle state: notit-addr=%p, state=%s", notit, state_string(notit->state)); goto end; } switch (notit->state) { - case STATE_EMIT_MSG_PACKET_BEGINNING: - /* - * Packet header and context fields are - * potentially decoded (or they don't exist). - */ - goto end; case STATE_INIT: + case STATE_SWITCH_PACKET: case STATE_DSCOPE_TRACE_PACKET_HEADER_BEGIN: case STATE_DSCOPE_TRACE_PACKET_HEADER_CONTINUE: case STATE_AFTER_TRACE_PACKET_HEADER: @@ -2931,30 +3022,62 @@ enum bt_msg_iter_status read_packet_header_context_fields( case STATE_AFTER_STREAM_PACKET_CONTEXT: case STATE_CHECK_EMIT_MSG_STREAM_BEGINNING: case STATE_EMIT_MSG_STREAM_BEGINNING: - case STATE_EMIT_MSG_STREAM_ACTIVITY_BEGINNING: case STATE_CHECK_EMIT_MSG_DISCARDED_EVENTS: case STATE_EMIT_MSG_DISCARDED_EVENTS: case STATE_CHECK_EMIT_MSG_DISCARDED_PACKETS: case STATE_EMIT_MSG_DISCARDED_PACKETS: - /* Non-emitting state: continue */ + case STATE_EMIT_MSG_PACKET_BEGINNING: + case STATE_DSCOPE_EVENT_HEADER_BEGIN: + case STATE_DSCOPE_EVENT_HEADER_CONTINUE: + case STATE_AFTER_EVENT_HEADER: + case STATE_DSCOPE_EVENT_COMMON_CONTEXT_BEGIN: + case STATE_DSCOPE_EVENT_COMMON_CONTEXT_CONTINUE: + case STATE_DSCOPE_EVENT_SPEC_CONTEXT_BEGIN: + case STATE_DSCOPE_EVENT_SPEC_CONTEXT_CONTINUE: + case STATE_DSCOPE_EVENT_PAYLOAD_BEGIN: + case STATE_DSCOPE_EVENT_PAYLOAD_CONTINUE: + case STATE_EMIT_MSG_EVENT: + case STATE_EMIT_QUEUED_MSG_EVENT: + case STATE_SKIP_PACKET_PADDING: + case STATE_EMIT_MSG_PACKET_END_MULTI: + case STATE_EMIT_MSG_PACKET_END_SINGLE: + case STATE_EMIT_QUEUED_MSG_PACKET_END: + case STATE_CHECK_EMIT_MSG_STREAM_END: + case STATE_EMIT_MSG_STREAM_END: break; + case STATE_DONE: + /* fall-through */ default: - /* - * We should never get past the - * STATE_EMIT_MSG_PACKET_BEGINNING state. - */ - BT_LOGF("Unexpected state: notit-addr=%p, state=%s", + /* We should never get to the STATE_DONE state. */ + BT_COMP_LOGF("Unexpected state: notit-addr=%p, state=%s", notit, state_string(notit->state)); abort(); } - } + } while (true); end: + return status; +} + +static +enum bt_msg_iter_status read_packet_header_context_fields( + struct bt_msg_iter *notit) +{ + int ret; + enum bt_msg_iter_status status = BT_MSG_ITER_STATUS_OK; + + status = decode_until_state(notit, STATE_EMIT_MSG_PACKET_BEGINNING, -1); + if (status != BT_MSG_ITER_STATUS_OK) { + goto end; + } + ret = set_current_packet_content_sizes(notit); if (ret) { status = BT_MSG_ITER_STATUS_ERROR; + goto end; } +end: return status; } @@ -2975,14 +3098,14 @@ enum bt_msg_iter_status bt_msg_iter_seek(struct bt_msg_iter *notit, BT_ASSERT(notit); if (offset < 0) { - BT_LOGE("Cannot seek to negative offset: offset=%jd", offset); + BT_COMP_LOGE("Cannot seek to negative offset: offset=%jd", (intmax_t) offset); ret = BT_MSG_ITER_STATUS_INVAL; goto end; } if (!notit->medium.medops.seek) { ret = BT_MSG_ITER_STATUS_UNSUPPORTED; - BT_LOGD("Aborting seek as the iterator's underlying media does not implement seek support."); + BT_COMP_LOGD("Aborting seek as the iterator's underlying media does not implement seek support."); goto end; } @@ -3004,6 +3127,42 @@ end: return ret; } +static +enum bt_msg_iter_status clock_snapshot_at_msg_iter_state( + struct bt_msg_iter *notit, enum state target_state_1, + enum state target_state_2, uint64_t *clock_snapshot) +{ + enum bt_msg_iter_status status = BT_MSG_ITER_STATUS_OK; + + BT_ASSERT(notit); + BT_ASSERT(clock_snapshot); + status = decode_until_state(notit, target_state_1, target_state_2); + if (status != BT_MSG_ITER_STATUS_OK) { + goto end; + } + + *clock_snapshot = notit->default_clock_snapshot; +end: + return status; +} + +BT_HIDDEN +enum bt_msg_iter_status bt_msg_iter_curr_packet_first_event_clock_snapshot( + struct bt_msg_iter *notit, uint64_t *first_clock_snapshot) +{ + return clock_snapshot_at_msg_iter_state(notit, + STATE_AFTER_EVENT_HEADER, -1, first_clock_snapshot); +} + +BT_HIDDEN +enum bt_msg_iter_status bt_msg_iter_curr_packet_last_event_clock_snapshot( + struct bt_msg_iter *notit, uint64_t *last_clock_snapshot) +{ + return clock_snapshot_at_msg_iter_state(notit, + STATE_EMIT_MSG_PACKET_END_SINGLE, + STATE_EMIT_MSG_PACKET_END_MULTI, last_clock_snapshot); +} + BT_HIDDEN enum bt_msg_iter_status bt_msg_iter_get_packet_properties( struct bt_msg_iter *notit, @@ -3044,3 +3203,10 @@ void bt_msg_iter_set_emit_stream_end_message(struct bt_msg_iter *notit, { notit->emit_stream_end_msg = val; } + +BT_HIDDEN +void bt_msg_iter_set_dry_run(struct bt_msg_iter *notit, + bool val) +{ + notit->dry_run = val; +}