X-Git-Url: http://git.efficios.com/?a=blobdiff_plain;f=plugins%2Fctf%2Fcommon%2Fnotif-iter%2Fnotif-iter.c;h=a5d9e5c8aeaf1235510ccf70ac9f238f4f53b64c;hb=0b0bf6828fd92630e50b6ea7474eacdff9264b5f;hp=acb349380c3fa626328b9805300bb38d2f97a4d0;hpb=87187cbfcf0ff2101a05e58d9043ffa86108f431;p=babeltrace.git diff --git a/plugins/ctf/common/notif-iter/notif-iter.c b/plugins/ctf/common/notif-iter/notif-iter.c index acb34938..a5d9e5c8 100644 --- a/plugins/ctf/common/notif-iter/notif-iter.c +++ b/plugins/ctf/common/notif-iter/notif-iter.c @@ -23,6 +23,9 @@ * SOFTWARE. */ +#define BT_LOG_TAG "PLUGIN-CTF-NOTIF-ITER" +#include "logging.h" + #include #include #include @@ -30,30 +33,15 @@ #include #include #include -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include -#include +#include +#include +#include #include - -#define PRINT_ERR_STREAM notit->err_stream -#define PRINT_PREFIX "ctf-notif-iter" -#include "../print.h" +#include #include "notif-iter.h" #include "../btr/btr.h" -#define BYTES_TO_BITS(x) ((x) * 8) - struct bt_ctf_notif_iter; /* A visit stack entry */ @@ -143,9 +131,6 @@ struct bt_ctf_notif_iter { /* Visit stack */ struct stack *stack; - /* Error stream (may be NULL) */ - FILE *err_stream; - /* * Current dynamic scope field pointer. * @@ -165,6 +150,9 @@ struct bt_ctf_notif_iter { /* Current packet (NULL if not created yet) */ struct bt_ctf_packet *packet; + /* Current stream (NULL if not set yet) */ + struct bt_ctf_stream *stream; + /* * Current timestamp_end field (to consider before switching packets). */ @@ -211,6 +199,9 @@ struct bt_ctf_notif_iter { /* Current position from addr (bits) */ size_t at; + + /* Position of the last event header from addr (bits) */ + size_t last_eh_at; } buf; /* Binary type reader */ @@ -229,6 +220,12 @@ struct bt_ctf_notif_iter { /* Current content size (bits) (-1 if unknown) */ int64_t cur_content_size; + /* + * Offset, in the underlying media, of the current packet's start + * (-1 if unknown). + */ + off_t cur_packet_offset; + /* bt_ctf_clock_class to uint64_t. */ GHashTable *clock_states; @@ -248,6 +245,55 @@ struct bt_ctf_notif_iter { GHashTable *sc_field_path_caches; }; +static inline +const char *state_string(enum state state) +{ + switch (state) { + case STATE_INIT: + return "STATE_INIT"; + case STATE_DSCOPE_TRACE_PACKET_HEADER_BEGIN: + return "STATE_DSCOPE_TRACE_PACKET_HEADER_BEGIN"; + case STATE_DSCOPE_TRACE_PACKET_HEADER_CONTINUE: + return "STATE_DSCOPE_TRACE_PACKET_HEADER_CONTINUE"; + case STATE_AFTER_TRACE_PACKET_HEADER: + return "STATE_AFTER_TRACE_PACKET_HEADER"; + case STATE_DSCOPE_STREAM_PACKET_CONTEXT_BEGIN: + return "STATE_DSCOPE_STREAM_PACKET_CONTEXT_BEGIN"; + case STATE_DSCOPE_STREAM_PACKET_CONTEXT_CONTINUE: + return "STATE_DSCOPE_STREAM_PACKET_CONTEXT_CONTINUE"; + case STATE_AFTER_STREAM_PACKET_CONTEXT: + return "STATE_AFTER_STREAM_PACKET_CONTEXT"; + case STATE_EMIT_NOTIF_NEW_PACKET: + return "STATE_EMIT_NOTIF_NEW_PACKET"; + case STATE_DSCOPE_STREAM_EVENT_HEADER_BEGIN: + return "STATE_DSCOPE_STREAM_EVENT_HEADER_BEGIN"; + case STATE_DSCOPE_STREAM_EVENT_HEADER_CONTINUE: + return "STATE_DSCOPE_STREAM_EVENT_HEADER_CONTINUE"; + case STATE_AFTER_STREAM_EVENT_HEADER: + return "STATE_AFTER_STREAM_EVENT_HEADER"; + case STATE_DSCOPE_STREAM_EVENT_CONTEXT_BEGIN: + return "STATE_DSCOPE_STREAM_EVENT_CONTEXT_BEGIN"; + case STATE_DSCOPE_STREAM_EVENT_CONTEXT_CONTINUE: + return "STATE_DSCOPE_STREAM_EVENT_CONTEXT_CONTINUE"; + case STATE_DSCOPE_EVENT_CONTEXT_BEGIN: + return "STATE_DSCOPE_EVENT_CONTEXT_BEGIN"; + case STATE_DSCOPE_EVENT_CONTEXT_CONTINUE: + return "STATE_DSCOPE_EVENT_CONTEXT_CONTINUE"; + case STATE_DSCOPE_EVENT_PAYLOAD_BEGIN: + return "STATE_DSCOPE_EVENT_PAYLOAD_BEGIN"; + case STATE_DSCOPE_EVENT_PAYLOAD_CONTINUE: + return "STATE_DSCOPE_EVENT_PAYLOAD_CONTINUE"; + case STATE_EMIT_NOTIF_EVENT: + return "STATE_EMIT_NOTIF_EVENT"; + case STATE_EMIT_NOTIF_END_OF_PACKET: + return "STATE_EMIT_NOTIF_END_OF_PACKET"; + case STATE_SKIP_PACKET_PADDING: + return "STATE_SKIP_PACKET_PADDING"; + default: + return "(unknown)"; + } +} + static int bt_ctf_notif_iter_switch_packet(struct bt_ctf_notif_iter *notit); @@ -271,15 +317,19 @@ struct stack *stack_new(struct bt_ctf_notif_iter *notit) stack = g_new0(struct stack, 1); if (!stack) { + BT_LOGE_STR("Failed to allocate one stack."); goto error; } stack->entries = g_ptr_array_new_with_free_func(stack_entry_free_func); if (!stack->entries) { + BT_LOGE_STR("Failed to allocate a GPtrArray."); goto error; } + BT_LOGD("Created stack: notit-addr=%p, stack-addr=%p", notit, stack); return stack; + error: g_free(stack); return NULL; @@ -289,6 +339,7 @@ static void stack_destroy(struct stack *stack) { assert(stack); + BT_LOGD("Destroying stack: addr=%p", stack); g_ptr_array_free(stack->entries, TRUE); g_free(stack); } @@ -301,8 +352,12 @@ int stack_push(struct stack *stack, struct bt_ctf_field *base) assert(stack); assert(base); + BT_LOGV("Pushing base field on stack: stack-addr=%p, " + "stack-size-before=%u, stack-size-after=%u", + stack, stack->entries->len, stack->entries->len + 1); entry = g_new0(struct stack_entry, 1); if (!entry) { + BT_LOGE_STR("Failed to allocate one stack entry."); ret = -1; goto end; } @@ -327,6 +382,9 @@ void stack_pop(struct stack *stack) { assert(stack); assert(stack_size(stack)); + BT_LOGV("Popping from stack: " + "stack-addr=%p, stack-size-before=%u, stack-size-after=%u", + stack, stack->entries->len, stack->entries->len - 1); g_ptr_array_remove_index(stack->entries, stack->entries->len - 1); } @@ -351,6 +409,8 @@ void stack_clear(struct stack *stack) assert(stack); if (!stack_empty(stack)) { + BT_LOGV("Clearing stack: stack-addr=%p, stack-size=%u", + stack, stack->entries->len); g_ptr_array_remove_range(stack->entries, 0, stack_size(stack)); } @@ -367,7 +427,7 @@ enum bt_ctf_notif_iter_status notif_iter_status_from_m_status( static inline size_t buf_size_bits(struct bt_ctf_notif_iter *notit) { - return BYTES_TO_BITS(notit->buf.sz); + return notit->buf.sz * 8; } static inline @@ -385,6 +445,8 @@ size_t packet_at(struct bt_ctf_notif_iter *notit) static inline void buf_consume_bits(struct bt_ctf_notif_iter *notit, size_t incr) { + BT_LOGV("Advancing cursor: notit-addr=%p, cur-before=%zu, cur-after=%zu", + notit, notit->buf.at, notit->buf.at + incr); notit->buf.at += incr; } @@ -392,13 +454,18 @@ static enum bt_ctf_notif_iter_status request_medium_bytes( struct bt_ctf_notif_iter *notit) { - uint8_t *buffer_addr; - size_t buffer_sz; + uint8_t *buffer_addr = NULL; + size_t buffer_sz = 0; enum bt_ctf_notif_iter_medium_status m_status; + BT_LOGV("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_LOGV("User function returned: status=%s, buf-addr=%p, buf-size=%zu", + bt_ctf_notif_iter_medium_status_string(m_status), + buffer_addr, buffer_sz); if (m_status == BT_CTF_NOTIF_ITER_MEDIUM_STATUS_OK) { assert(buffer_sz != 0); @@ -407,12 +474,131 @@ enum bt_ctf_notif_iter_status request_medium_bytes( /* Restart at the beginning of the new medium buffer */ notit->buf.at = 0; + notit->buf.last_eh_at = SIZE_MAX; /* New medium buffer size */ notit->buf.sz = buffer_sz; /* New medium buffer address */ notit->buf.addr = buffer_addr; + + BT_LOGV("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_LOGV_MEM(buffer_addr, buffer_sz, "Returned bytes at %p:", + buffer_addr); + } else if (m_status == BT_CTF_NOTIF_ITER_MEDIUM_STATUS_EOF) { + struct bt_ctf_field_type *ph_ft = + bt_ctf_trace_get_packet_header_type(notit->meta.trace); + struct bt_ctf_field_type *eh_ft = NULL; + struct bt_ctf_field_type *sec_ft = NULL; + struct bt_ctf_field_type *ec_ft = NULL; + + /* + * User returned end of stream: validate that we're not + * in the middle of a packet header, packet context, or + * event. + */ + if (notit->state == STATE_DSCOPE_TRACE_PACKET_HEADER_BEGIN) { + /* Beginning of packet: always valid */ + goto good_state; + } + + if (!notit->meta.stream_class) { + goto bad_state; + } + + if (notit->state == STATE_DSCOPE_STREAM_PACKET_CONTEXT_BEGIN) { + /* + * Beginning of packet context context is only + * valid if there's no packet header. + */ + if (!ph_ft) { + goto good_state; + } + } + + eh_ft = bt_ctf_stream_class_get_event_header_type( + notit->meta.stream_class); + sec_ft = bt_ctf_stream_class_get_event_context_type( + notit->meta.stream_class); + + if (notit->state == STATE_DSCOPE_STREAM_EVENT_HEADER_BEGIN) { + /* + * Beginning of event's header is only valid if + * the packet is not supposed to have a specific + * size (whole packet sequence has in fact only + * one packet). + */ + if (notit->cur_packet_size == -1) { + goto good_state; + } + } + + if (notit->state == STATE_DSCOPE_STREAM_EVENT_CONTEXT_BEGIN) { + /* + * Beginning of event's stream event context is + * only valid if the packet is not supposed to + * have a specific size (whole packet sequence + * has in fact only one packet), and there's no + * event header. + */ + if (notit->cur_packet_size == -1 && !eh_ft) { + goto good_state; + } + } + + if (!notit->meta.event_class) { + goto bad_state; + } + + ec_ft = bt_ctf_event_class_get_context_type( + notit->meta.event_class); + + if (notit->state == STATE_DSCOPE_EVENT_CONTEXT_BEGIN) { + /* + * Beginning of event's context is only valid if + * the packet is not supposed to have a specific + * size (whole packet sequence has in fact only + * one packet), and there's no event header and + * no stream event context. + */ + if (notit->cur_packet_size == -1 && !eh_ft && !sec_ft) { + goto good_state; + } + } + + if (notit->state == STATE_DSCOPE_EVENT_PAYLOAD_BEGIN) { + /* + * Beginning of event's context is only valid if + * the packet is not supposed to have a specific + * size (whole packet sequence has in fact only + * one packet), and there's no event header, no + * stream event context, and no event context. + */ + if (notit->cur_packet_size == -1 && !eh_ft && !sec_ft && + !ec_ft) { + goto good_state; + } + } + +bad_state: + /* All other states are invalid */ + BT_LOGW("User function returned %s, but notification iterator is in an unexpected state: " + "state=%s", + bt_ctf_notif_iter_medium_status_string(m_status), + state_string(notit->state)); + m_status = BT_CTF_NOTIF_ITER_MEDIUM_STATUS_ERROR; + +good_state: + bt_put(ph_ft); + bt_put(eh_ft); + bt_put(sec_ft); + bt_put(ec_ft); + } else if (m_status < 0) { + BT_LOGW("User function failed: status=%s", + bt_ctf_notif_iter_medium_status_string(m_status)); } return notif_iter_status_from_m_status(m_status); @@ -448,25 +634,42 @@ enum bt_ctf_notif_iter_status read_dscope_begin_state( status = buf_ensure_available_bits(notit); if (status != BT_CTF_NOTIF_ITER_STATUS_OK) { + if (status < 0) { + BT_LOGW("Cannot ensure that buffer has at least one byte: " + "notif-addr=%p, status=%s", + notit, bt_ctf_notif_iter_status_string(status)); + } else { + BT_LOGV("Cannot ensure that buffer has at least one byte: " + "notif-addr=%p, status=%s", + notit, bt_ctf_notif_iter_status_string(status)); + } + goto end; } bt_put(*dscope_field); notit->cur_dscope_field = dscope_field; + BT_LOGV("Starting BTR: notit-addr=%p, btr-addr=%p, ft-addr=%p", + notit, notit->btr, dscope_field_type); consumed_bits = bt_ctf_btr_start(notit->btr, dscope_field_type, notit->buf.addr, notit->buf.at, packet_at(notit), notit->buf.sz, &btr_status); + BT_LOGV("BTR consumed bits: size=%zu", consumed_bits); switch (btr_status) { case BT_CTF_BTR_STATUS_OK: /* type was read completely */ + BT_LOGV_STR("Field was completely decoded."); notit->state = done_state; break; case BT_CTF_BTR_STATUS_EOF: + BT_LOGV_STR("BTR needs more data to decode field completely."); notit->state = continue_state; break; default: - PERR("Binary type reader failed to start\n"); + BT_LOGW("BTR failed to start: notit-addr=%p, btr-addr=%p, " + "status=%s", notit, notit->btr, + bt_ctf_btr_status_string(btr_status)); status = BT_CTF_NOTIF_ITER_STATUS_ERROR; goto end; } @@ -488,22 +691,39 @@ enum bt_ctf_notif_iter_status read_dscope_continue_state( status = buf_ensure_available_bits(notit); if (status != BT_CTF_NOTIF_ITER_STATUS_OK) { + if (status < 0) { + BT_LOGW("Cannot ensure that buffer has at least one byte: " + "notif-addr=%p, status=%s", + notit, bt_ctf_notif_iter_status_string(status)); + } else { + BT_LOGV("Cannot ensure that buffer has at least one byte: " + "notif-addr=%p, status=%s", + notit, bt_ctf_notif_iter_status_string(status)); + } + goto end; } + BT_LOGV("Continuing BTR: notit-addr=%p, btr-addr=%p", + notit, notit->btr); consumed_bits = bt_ctf_btr_continue(notit->btr, notit->buf.addr, - notit->buf.sz, &btr_status); + notit->buf.sz, &btr_status); + BT_LOGV("BTR consumed bits: size=%zu", consumed_bits); switch (btr_status) { case BT_CTF_BTR_STATUS_OK: /* Type was read completely. */ + BT_LOGV_STR("Field was completely decoded."); notit->state = done_state; break; case BT_CTF_BTR_STATUS_EOF: /* Stay in this continue state. */ + BT_LOGV_STR("BTR needs more data to decode field completely."); break; default: - PERR("Binary type reader failed to continue\n"); + BT_LOGW("BTR failed to continue: notit-addr=%p, btr-addr=%p, " + "status=%s", notit, notit->btr, + bt_ctf_btr_status_string(btr_status)); status = BT_CTF_NOTIF_ITER_STATUS_ERROR; goto end; } @@ -517,16 +737,22 @@ end: static void put_event_dscopes(struct bt_ctf_notif_iter *notit) { + BT_LOGV_STR("Putting event header field."); BT_PUT(notit->dscopes.stream_event_header); + BT_LOGV_STR("Putting stream event context field."); BT_PUT(notit->dscopes.stream_event_context); + BT_LOGV_STR("Putting event context field."); BT_PUT(notit->dscopes.event_context); + BT_LOGV_STR("Putting event payload field."); BT_PUT(notit->dscopes.event_payload); } static void put_all_dscopes(struct bt_ctf_notif_iter *notit) { + BT_LOGV_STR("Putting packet header field."); BT_PUT(notit->dscopes.trace_packet_header); + BT_LOGV_STR("Putting packet context field."); BT_PUT(notit->dscopes.stream_packet_context); put_event_dscopes(notit); } @@ -539,6 +765,7 @@ enum bt_ctf_notif_iter_status read_packet_header_begin_state( enum bt_ctf_notif_iter_status ret = BT_CTF_NOTIF_ITER_STATUS_OK; if (bt_ctf_notif_iter_switch_packet(notit)) { + BT_LOGW("Cannot switch packet: notit-addr=%p", notit); ret = BT_CTF_NOTIF_ITER_STATUS_ERROR; goto end; } @@ -551,10 +778,22 @@ enum bt_ctf_notif_iter_status read_packet_header_begin_state( goto end; } + BT_LOGV("Decoding packet header field:" + "notit-addr=%p, trace-addr=%p, trace-name=\"%s\", ft-addr=%p", + notit, notit->meta.trace, + bt_ctf_trace_get_name(notit->meta.trace), packet_header_type); ret = read_dscope_begin_state(notit, packet_header_type, - STATE_AFTER_TRACE_PACKET_HEADER, - STATE_DSCOPE_TRACE_PACKET_HEADER_CONTINUE, - ¬it->dscopes.trace_packet_header); + STATE_AFTER_TRACE_PACKET_HEADER, + STATE_DSCOPE_TRACE_PACKET_HEADER_CONTINUE, + ¬it->dscopes.trace_packet_header); + if (ret < 0) { + BT_LOGW("Cannot decode packet header field: " + "notit-addr=%p, trace-addr=%p, " + "trace-name=\"%s\", ft-addr=%p", + notit, notit->meta.trace, + bt_ctf_trace_get_name(notit->meta.trace), + packet_header_type); + } end: BT_PUT(packet_header_type); return ret; @@ -598,6 +837,7 @@ create_stream_class_field_path_cache_entry( struct bt_ctf_field_type *event_header = NULL, *packet_context = NULL; if (!cache_entry) { + BT_LOGE_STR("Failed to allocate one stream class field path cache."); goto end; } @@ -606,10 +846,9 @@ create_stream_class_field_path_cache_entry( int i, count; count = bt_ctf_field_type_structure_get_field_count( - event_header); - if (count < 0) { - goto error; - } + event_header); + assert(count >= 0); + for (i = 0; i < count; i++) { int ret; const char *name; @@ -617,13 +856,23 @@ create_stream_class_field_path_cache_entry( ret = bt_ctf_field_type_structure_get_field( event_header, &name, NULL, i); if (ret) { + BT_LOGE("Cannot get event header structure field type's field: " + "notit-addr=%p, stream-class-addr=%p, " + "stream-class-name=\"%s\", " + "stream-class-id=%" PRId64 ", " + "ft-addr=%p, index=%d", + notit, stream_class, + bt_ctf_stream_class_get_name(stream_class), + bt_ctf_stream_class_get_id(stream_class), + event_header, i); goto error; } if (v != -1 && id != -1) { break; } - if (v == -1 && !strcmp(name, "v")) { + + if (v == -1 && strcmp(name, "v") == 0) { v = i; } else if (id == -1 && !strcmp(name, "id")) { id = i; @@ -637,10 +886,9 @@ create_stream_class_field_path_cache_entry( int i, count; count = bt_ctf_field_type_structure_get_field_count( - packet_context); - if (count < 0) { - goto error; - } + packet_context); + assert(count >= 0); + for (i = 0; i < count; i++) { int ret; const char *name; @@ -654,11 +902,20 @@ create_stream_class_field_path_cache_entry( ret = bt_ctf_field_type_structure_get_field( packet_context, &name, &field_type, i); if (ret) { + BT_LOGE("Cannot get packet context structure field type's field: " + "notit-addr=%p, stream-class-addr=%p, " + "stream-class-name=\"%s\", " + "stream-class-id=%" PRId64 ", " + "ft-addr=%p, index=%d", + notit, stream_class, + bt_ctf_stream_class_get_name(stream_class), + bt_ctf_stream_class_get_id(stream_class), + event_header, i); goto error; } if (timestamp_end == -1 && - !strcmp(name, "timestamp_end")) { + strcmp(name, "timestamp_end") == 0) { struct field_cb_override *override = g_new0( struct field_cb_override, 1); @@ -669,10 +926,8 @@ create_stream_class_field_path_cache_entry( override->func = btr_timestamp_end_cb; override->data = notit; - g_hash_table_insert(notit->field_overrides, - bt_get(field_type), override); - + bt_get(field_type), override); timestamp_end = i; } else if (packet_size == -1 && !strcmp(name, "packet_size")) { @@ -713,9 +968,9 @@ struct stream_class_field_path_cache *get_stream_class_field_path_cache( stream_class, NULL, (gpointer) &cache_entry); if (unlikely(!cache_entry_found)) { cache_entry = create_stream_class_field_path_cache_entry(notit, - stream_class); + stream_class); g_hash_table_insert(notit->sc_field_path_caches, - bt_get(stream_class), (gpointer) cache_entry); + bt_get(stream_class), (gpointer) cache_entry); } return cache_entry; @@ -728,6 +983,7 @@ enum bt_ctf_notif_iter_status set_current_stream_class( enum bt_ctf_notif_iter_status status = BT_CTF_NOTIF_ITER_STATUS_OK; struct bt_ctf_field_type *packet_header_type = NULL; struct bt_ctf_field_type *stream_id_field_type = NULL; + struct bt_ctf_stream_class *new_stream_class = NULL; uint64_t stream_id; /* Clear the current stream class field path cache. */ @@ -735,19 +991,21 @@ enum bt_ctf_notif_iter_status set_current_stream_class( /* Is there any "stream_id" field in the packet header? */ packet_header_type = bt_ctf_trace_get_packet_header_type( - notit->meta.trace); + notit->meta.trace); if (!packet_header_type) { - PERR("Failed to retrieve trace's packet header type\n"); - status = BT_CTF_NOTIF_ITER_STATUS_ERROR; - goto end; + /* + * No packet header, therefore no `stream_id` field, + * therefore only one stream class. + */ + goto single_stream_class; } assert(is_struct_type(packet_header_type)); // TODO: optimalize! stream_id_field_type = - bt_ctf_field_type_structure_get_field_type_by_name( - packet_header_type, "stream_id"); + bt_ctf_field_type_structure_get_field_type_by_name( + packet_header_type, "stream_id"); if (stream_id_field_type) { /* Find appropriate stream class using current stream ID */ int ret; @@ -764,37 +1022,83 @@ enum bt_ctf_notif_iter_status set_current_stream_class( assert(!ret); BT_PUT(stream_id_field); } else { +single_stream_class: /* Only one stream: pick the first stream class */ assert(bt_ctf_trace_get_stream_class_count( notit->meta.trace) == 1); stream_id = 0; } - BT_PUT(notit->meta.stream_class); - notit->meta.stream_class = bt_ctf_trace_get_stream_class_by_id( - notit->meta.trace, stream_id); - if (!notit->meta.stream_class) { - PERR("Cannot find stream class with ID %" PRIu64 "\n", - stream_id); + BT_LOGV("Found stream class ID to use: notit-addr=%p, " + "stream-class-id=%" PRIu64 ", " + "trace-addr=%p, trace-name=\"%s\"", + notit, stream_id, notit->meta.trace, + bt_ctf_trace_get_name(notit->meta.trace)); + + new_stream_class = bt_ctf_trace_get_stream_class_by_id( + notit->meta.trace, stream_id); + if (!new_stream_class) { + BT_LOGW("No stream class with ID of stream class ID to use in trace: " + "notit-addr=%p, stream-class-id=%" PRIu64 ", " + "trace-addr=%p, trace-name=\"%s\"", + notit, stream_id, notit->meta.trace, + bt_ctf_trace_get_name(notit->meta.trace)); status = BT_CTF_NOTIF_ITER_STATUS_ERROR; goto end; } + if (notit->meta.stream_class) { + if (new_stream_class != notit->meta.stream_class) { + BT_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-name=\"%s\", " + "prev-stream-class-id=%" PRId64 ", " + "next-stream-class-addr=%p, " + "next-stream-class-name=\"%s\", " + "next-stream-class-id=%" PRId64 ", " + "trace-addr=%p, trace-name=\"%s\"", + notit, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class), + new_stream_class, + bt_ctf_stream_class_get_name(new_stream_class), + bt_ctf_stream_class_get_id(new_stream_class), + notit->meta.trace, + bt_ctf_trace_get_name(notit->meta.trace)); + status = BT_CTF_NOTIF_ITER_STATUS_ERROR; + goto end; + } + } else { + BT_MOVE(notit->meta.stream_class, new_stream_class); + } + + BT_LOGV("Set current stream class: " + "notit-addr=%p, stream-class-addr=%p, " + "stream-class-name=\"%s\", stream-class-id=%" PRId64, + notit, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class)); + /* * Retrieve (or lazily create) the current stream class field path * cache. */ notit->cur_sc_field_path_cache = get_stream_class_field_path_cache( - notit, notit->meta.stream_class); + notit, notit->meta.stream_class); if (!notit->cur_sc_field_path_cache) { - PERR("Failed to retrieve stream class field path cache\n"); + BT_LOGW("Cannot retrieve stream class field path from cache: " + "notit-addr=%p, stream-class-addr=%p, " + "stream-class-name=\"%s\", stream-class-id=%" PRId64, + notit, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class)); status = BT_CTF_NOTIF_ITER_STATUS_ERROR; goto end; } end: BT_PUT(packet_header_type); BT_PUT(stream_id_field_type); - + bt_put(new_stream_class); return status; } @@ -821,16 +1125,40 @@ enum bt_ctf_notif_iter_status read_packet_context_begin_state( assert(notit->meta.stream_class); packet_context_type = bt_ctf_stream_class_get_packet_context_type( - notit->meta.stream_class); + notit->meta.stream_class); if (!packet_context_type) { + BT_LOGV("No packet packet context field type in stream class: continuing: " + "notit-addr=%p, stream-class-addr=%p, " + "stream-class-name=\"%s\", stream-class-id=%" PRId64, + notit, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class)); notit->state = STATE_AFTER_STREAM_PACKET_CONTEXT; goto end; } + BT_LOGV("Decoding packet context field: " + "notit-addr=%p, stream-class-addr=%p, " + "stream-class-name=\"%s\", stream-class-id=%" PRId64 ", " + "ft-addr=%p", + notit, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class), + packet_context_type); status = read_dscope_begin_state(notit, packet_context_type, - STATE_AFTER_STREAM_PACKET_CONTEXT, - STATE_DSCOPE_STREAM_PACKET_CONTEXT_CONTINUE, - ¬it->dscopes.stream_packet_context); + STATE_AFTER_STREAM_PACKET_CONTEXT, + STATE_DSCOPE_STREAM_PACKET_CONTEXT_CONTINUE, + ¬it->dscopes.stream_packet_context); + if (status < 0) { + BT_LOGW("Cannot decode packet context field: " + "notit-addr=%p, stream-class-addr=%p, " + "stream-class-name=\"%s\", " + "stream-class-id=%" PRId64 ", ft-addr=%p", + notit, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class), + packet_context_type); + } end: BT_PUT(packet_context_type); @@ -852,25 +1180,33 @@ enum bt_ctf_notif_iter_status set_current_packet_content_sizes( enum bt_ctf_notif_iter_status status = BT_CTF_NOTIF_ITER_STATUS_OK; struct bt_ctf_field *packet_size_field = NULL; struct bt_ctf_field *content_size_field = NULL; - uint64_t content_size = -1, packet_size = -1; + uint64_t content_size = -1ULL, packet_size = -1ULL; - assert(notit->dscopes.stream_packet_context); + if (!notit->dscopes.stream_packet_context) { + goto end; + } packet_size_field = bt_ctf_field_structure_get_field( - notit->dscopes.stream_packet_context, "packet_size"); + notit->dscopes.stream_packet_context, "packet_size"); content_size_field = bt_ctf_field_structure_get_field( - notit->dscopes.stream_packet_context, "content_size"); + notit->dscopes.stream_packet_context, "content_size"); if (packet_size_field) { int ret = bt_ctf_field_unsigned_integer_get_value( - packet_size_field, &packet_size); + packet_size_field, &packet_size); - assert(!ret); + assert(ret == 0); if (packet_size == 0) { - PERR("Decoded packet size is 0\n"); + BT_LOGW("Invalid packet size: packet context field indicates packet size is zero: " + "notit-addr=%p, packet-context-field-addr=%p", + notit, notit->dscopes.stream_packet_context); status = BT_CTF_NOTIF_ITER_STATUS_ERROR; goto end; } else if ((packet_size % 8) != 0) { - PERR("Decoded packet size is not a multiple of 8\n"); + BT_LOGW("Invalid packet size: packet context field indicates packet size is not a multiple of 8: " + "notit-addr=%p, packet-context-field-addr=%p, " + "packet-size=%" PRIu64, + notit, notit->dscopes.stream_packet_context, + packet_size); status = BT_CTF_NOTIF_ITER_STATUS_ERROR; goto end; } @@ -880,13 +1216,35 @@ enum bt_ctf_notif_iter_status set_current_packet_content_sizes( int ret = bt_ctf_field_unsigned_integer_get_value( content_size_field, &content_size); - assert(!ret); + assert(ret == 0); } else { content_size = packet_size; } - notit->cur_packet_size = packet_size; + if (content_size > packet_size) { + BT_LOGW("Invalid packet or content size: packet context field indicates content size is greater than packet size: " + "notit-addr=%p, packet-context-field-addr=%p, " + "packet-size=%" PRIu64 ", content-size=%" PRIu64, + notit, notit->dscopes.stream_packet_context, + packet_size, content_size); + status = BT_CTF_NOTIF_ITER_STATUS_ERROR; + goto end; + } + + if (packet_size != -1ULL) { + notit->cur_packet_size = packet_size; + } else { + /* + * Use the content size as packet size indicator if the + * packet size field is missing. This means there is no + * padding in this stream. + */ + notit->cur_packet_size = content_size; + } notit->cur_content_size = content_size; + BT_LOGV("Set current packet and content sizes: " + "notit-addr=%p, packet-size=%" PRIu64 ", content-size=%" PRIu64, + notit, packet_size, content_size); end: BT_PUT(packet_size_field); BT_PUT(content_size_field); @@ -914,18 +1272,23 @@ enum bt_ctf_notif_iter_status read_event_header_begin_state( enum bt_ctf_notif_iter_status status = BT_CTF_NOTIF_ITER_STATUS_OK; struct bt_ctf_field_type *event_header_type = NULL; + /* Reset the position of the last event header */ + notit->buf.last_eh_at = notit->buf.at; + /* Check if we have some content left */ if (notit->cur_content_size >= 0) { if (packet_at(notit) == notit->cur_content_size) { /* No more events! */ + BT_LOGV("Reached end of packet: notit-addr=%p, " + "cur=%zu", notit, packet_at(notit)); notit->state = STATE_EMIT_NOTIF_END_OF_PACKET; goto end; } else if (packet_at(notit) > notit->cur_content_size) { /* That's not supposed to happen */ - PERR("Cursor passed packet's content size:\n"); - PERR("\tDecoded content size: %zu\n", - notit->cur_content_size); - PERR("\tCursor position: %zu\n", packet_at(notit)); + BT_LOGV("Before decoding event header field: cursor is passed the packet's content: " + "notit-addr=%p, content-size=%" PRId64 ", " + "cur=%zu", notit, notit->cur_content_size, + packet_at(notit)); status = BT_CTF_NOTIF_ITER_STATUS_ERROR; goto end; } @@ -939,10 +1302,28 @@ enum bt_ctf_notif_iter_status read_event_header_begin_state( } put_event_dscopes(notit); + BT_LOGV("Decoding event header field: " + "notit-addr=%p, stream-class-addr=%p, " + "stream-class-name=\"%s\", stream-class-id=%" PRId64 ", " + "ft-addr=%p", + notit, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class), + event_header_type); status = read_dscope_begin_state(notit, event_header_type, STATE_AFTER_STREAM_EVENT_HEADER, STATE_DSCOPE_STREAM_EVENT_HEADER_CONTINUE, ¬it->dscopes.stream_event_header); + if (status < 0) { + BT_LOGW("Cannot decode event header field: " + "notit-addr=%p, stream-class-addr=%p, " + "stream-class-name=\"%s\", " + "stream-class-id=%" PRId64 ", ft-addr=%p", + notit, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class), + event_header_type); + } end: BT_PUT(event_header_type); @@ -976,9 +1357,11 @@ enum bt_ctf_notif_iter_status set_current_event_class(struct bt_ctf_notif_iter * event_header_type = bt_ctf_stream_class_get_event_header_type( notit->meta.stream_class); if (!event_header_type) { - PERR("Failed to retrieve stream class's event header type\n"); - status = BT_CTF_NOTIF_ITER_STATUS_ERROR; - goto end; + /* + * No event header, therefore no event class ID field, + * therefore only one event class. + */ + goto single_event_class; } /* Is there any "id"/"v" field in the event header? */ @@ -1019,10 +1402,15 @@ enum bt_ctf_notif_iter_status set_current_event_class(struct bt_ctf_notif_iter * goto end_v_field_type; } - ret = bt_ctf_field_unsigned_integer_get_value( - v_struct_id_field, &event_id); - if (ret) { - event_id = -1ULL; + if (bt_ctf_field_is_integer(v_struct_id_field)) { + ret = bt_ctf_field_unsigned_integer_get_value( + v_struct_id_field, &event_id); + if (ret) { + BT_LOGV("Cannot get value of unsigned integer field (`id`): continuing: " + "notit=%p, field-addr=%p", + notit, v_struct_id_field); + event_id = -1ULL; + } } end_v_field_type: @@ -1034,48 +1422,74 @@ end_v_field_type: if (id_field_type && event_id == -1ULL) { /* Check "id" field */ struct bt_ctf_field *id_field = NULL; - int ret; + int ret_get_value = 0; // TODO: optimalize! id_field = bt_ctf_field_structure_get_field( notit->dscopes.stream_event_header, "id"); - assert(id_field); - assert(bt_ctf_field_is_integer(id_field) || - bt_ctf_field_is_enumeration(id_field)); + if (!id_field) { + goto check_event_id; + } if (bt_ctf_field_is_integer(id_field)) { - ret = bt_ctf_field_unsigned_integer_get_value( + ret_get_value = bt_ctf_field_unsigned_integer_get_value( id_field, &event_id); - } else { + } else if (bt_ctf_field_is_enumeration(id_field)) { struct bt_ctf_field *container; container = bt_ctf_field_enumeration_get_container( id_field); assert(container); - ret = bt_ctf_field_unsigned_integer_get_value( + ret_get_value = bt_ctf_field_unsigned_integer_get_value( container, &event_id); BT_PUT(container); } - assert(!ret); + + assert(ret_get_value == 0); BT_PUT(id_field); } +check_event_id: if (event_id == -1ULL) { +single_event_class: /* Event ID not found: single event? */ assert(bt_ctf_stream_class_get_event_class_count( notit->meta.stream_class) == 1); event_id = 0; } + BT_LOGV("Found event class ID to use: notit-addr=%p, " + "stream-class-addr=%p, stream-class-name=\"%s\", " + "stream-class-id=%" PRId64 ", " + "event-class-id=%" PRIu64, + notit, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class), + event_id); BT_PUT(notit->meta.event_class); notit->meta.event_class = bt_ctf_stream_class_get_event_class_by_id( notit->meta.stream_class, event_id); if (!notit->meta.event_class) { - PERR("Cannot find event class with ID %" PRIu64 "\n", event_id); + BT_LOGW("No event class with ID of event class ID to use in stream class: " + "notit-addr=%p, stream-class-addr=%p, " + "stream-class-name=\"%s\", " + "stream-class-id=%" PRId64 ", " + "event-class-id=%" PRIu64, + notit, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class), + event_id); status = BT_CTF_NOTIF_ITER_STATUS_ERROR; goto end; } + BT_LOGV("Set current event class: " + "notit-addr=%p, event-class-addr=%p, " + "event-class-name=\"%s\", event-class-id=%" PRId64, + notit, notit->meta.event_class, + bt_ctf_event_class_get_name(notit->meta.event_class), + bt_ctf_event_class_get_id(notit->meta.event_class)); + end: BT_PUT(event_header_type); BT_PUT(id_field_type); @@ -1092,7 +1506,6 @@ enum bt_ctf_notif_iter_status after_event_header_state( status = set_current_event_class(notit); if (status != BT_CTF_NOTIF_ITER_STATUS_OK) { - PERR("Failed to set current event class\n"); goto end; } @@ -1116,10 +1529,28 @@ enum bt_ctf_notif_iter_status read_stream_event_context_begin_state( goto end; } + BT_LOGV("Decoding stream event context field: " + "notit-addr=%p, stream-class-addr=%p, " + "stream-class-name=\"%s\", stream-class-id=%" PRId64 ", " + "ft-addr=%p", + notit, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class), + stream_event_context_type); status = read_dscope_begin_state(notit, stream_event_context_type, STATE_DSCOPE_EVENT_CONTEXT_BEGIN, STATE_DSCOPE_STREAM_EVENT_CONTEXT_CONTINUE, ¬it->dscopes.stream_event_context); + if (status < 0) { + BT_LOGW("Cannot decode stream event context field: " + "notit-addr=%p, stream-class-addr=%p, " + "stream-class-name=\"%s\", " + "stream-class-id=%" PRId64 ", ft-addr=%p", + notit, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class), + stream_event_context_type); + } end: BT_PUT(stream_event_context_type); @@ -1148,10 +1579,29 @@ enum bt_ctf_notif_iter_status read_event_context_begin_state( notit->state = STATE_DSCOPE_EVENT_PAYLOAD_BEGIN; goto end; } + + BT_LOGV("Decoding event context field: " + "notit-addr=%p, event-class-addr=%p, " + "event-class-name=\"%s\", event-class-id=%" PRId64 ", " + "ft-addr=%p", + notit, notit->meta.event_class, + bt_ctf_event_class_get_name(notit->meta.event_class), + bt_ctf_event_class_get_id(notit->meta.event_class), + event_context_type); status = read_dscope_begin_state(notit, event_context_type, STATE_DSCOPE_EVENT_PAYLOAD_BEGIN, STATE_DSCOPE_EVENT_CONTEXT_CONTINUE, ¬it->dscopes.event_context); + if (status < 0) { + BT_LOGW("Cannot decode event context field: " + "notit-addr=%p, event-class-addr=%p, " + "event-class-name=\"%s\", " + "event-class-id=%" PRId64 ", ft-addr=%p", + notit, notit->meta.event_class, + bt_ctf_event_class_get_name(notit->meta.event_class), + bt_ctf_event_class_get_id(notit->meta.event_class), + event_context_type); + } end: BT_PUT(event_context_type); @@ -1181,10 +1631,28 @@ enum bt_ctf_notif_iter_status read_event_payload_begin_state( goto end; } + BT_LOGV("Decoding event payload field: " + "notit-addr=%p, event-class-addr=%p, " + "event-class-name=\"%s\", event-class-id=%" PRId64 ", " + "ft-addr=%p", + notit, notit->meta.event_class, + bt_ctf_event_class_get_name(notit->meta.event_class), + bt_ctf_event_class_get_id(notit->meta.event_class), + event_payload_type); status = read_dscope_begin_state(notit, event_payload_type, STATE_EMIT_NOTIF_EVENT, STATE_DSCOPE_EVENT_PAYLOAD_CONTINUE, ¬it->dscopes.event_payload); + if (status < 0) { + BT_LOGW("Cannot decode event payload field: " + "notit-addr=%p, event-class-addr=%p, " + "event-class-name=\"%s\", " + "event-class-id=%" PRId64 ", ft-addr=%p", + notit, notit->meta.event_class, + bt_ctf_event_class_get_name(notit->meta.event_class), + bt_ctf_event_class_get_id(notit->meta.event_class), + event_payload_type); + } end: BT_PUT(event_payload_type); @@ -1213,12 +1681,17 @@ enum bt_ctf_notif_iter_status skip_packet_padding_state( goto end; } else { size_t bits_to_consume; + + BT_LOGV("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_CTF_NOTIF_ITER_STATUS_OK) { goto end; } bits_to_consume = MIN(buf_available_bits(notit), bits_to_skip); + BT_LOGV("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_packet_size - packet_at(notit); if (bits_to_skip == 0) { @@ -1235,11 +1708,13 @@ static inline enum bt_ctf_notif_iter_status handle_state(struct bt_ctf_notif_iter *notit) { enum bt_ctf_notif_iter_status status = BT_CTF_NOTIF_ITER_STATUS_OK; + const enum state state = notit->state; - PDBG("Handling state %d\n", notit->state); + BT_LOGV("Handling state: notit-addr=%p, state=%s", + notit, state_string(state)); // TODO: optimalize! - switch (notit->state) { + switch (state) { case STATE_INIT: notit->state = STATE_DSCOPE_TRACE_PACKET_HEADER_BEGIN; break; @@ -1300,8 +1775,16 @@ enum bt_ctf_notif_iter_status handle_state(struct bt_ctf_notif_iter *notit) case STATE_EMIT_NOTIF_END_OF_PACKET: notit->state = STATE_SKIP_PACKET_PADDING; break; + default: + BT_LOGD("Unknown CTF plugin notification iterator state: " + "notit-addr=%p, state=%d", notit, notit->state); + abort(); } + BT_LOGV("Handled state: notit-addr=%p, status=%s, " + "prev-state=%s, cur-state=%s", + notit, bt_ctf_notif_iter_status_string(status), + state_string(state), state_string(notit->state)); return status; } @@ -1312,18 +1795,22 @@ static void bt_ctf_notif_iter_reset(struct bt_ctf_notif_iter *notit) { assert(notit); + BT_LOGD("Resetting notification iterator: addr=%p", notit); stack_clear(notit->stack); BT_PUT(notit->meta.stream_class); BT_PUT(notit->meta.event_class); BT_PUT(notit->packet); + BT_PUT(notit->stream); put_all_dscopes(notit); notit->buf.addr = NULL; notit->buf.sz = 0; notit->buf.at = 0; + notit->buf.last_eh_at = SIZE_MAX; notit->buf.packet_offset = 0; notit->state = STATE_INIT; notit->cur_content_size = -1; notit->cur_packet_size = -1; + notit->cur_packet_offset = -1; } static @@ -1331,9 +1818,19 @@ int bt_ctf_notif_iter_switch_packet(struct bt_ctf_notif_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 notification + * iterator refer to the same stream class (the first one). + */ assert(notit); + if (notit->cur_packet_size != -1) { + notit->cur_packet_offset += notit->cur_packet_size; + } + BT_LOGV("Switching packet: notit-addr=%p, cur=%zu, " + "packet-offset=%" PRId64, notit, notit->buf.at, + notit->cur_packet_offset); stack_clear(notit->stack); - BT_PUT(notit->meta.stream_class); BT_PUT(notit->meta.event_class); BT_PUT(notit->packet); BT_PUT(notit->cur_timestamp_end); @@ -1348,6 +1845,8 @@ int bt_ctf_notif_iter_switch_packet(struct bt_ctf_notif_iter *notit) /* 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; } @@ -1356,11 +1855,14 @@ int bt_ctf_notif_iter_switch_packet(struct bt_ctf_notif_iter *notit) notit->buf.sz -= consumed_bytes; notit->buf.at = 0; notit->buf.packet_offset = 0; + BT_LOGV("Adjusted buffer: addr=%p, size=%zu", + notit->buf.addr, notit->buf.sz); } notit->cur_content_size = -1; notit->cur_packet_size = -1; notit->cur_sc_field_path_cache = NULL; + end: return ret; } @@ -1376,11 +1878,9 @@ struct bt_ctf_field *get_next_field(struct bt_ctf_notif_iter *notit) assert(!stack_empty(notit->stack)); index = stack_top(notit->stack)->index; base_field = stack_top(notit->stack)->base; + assert(base_field); base_type = bt_ctf_field_get_type(base_field); - if (!base_type) { - PERR("Failed to get base field's type\n"); - goto end; - } + assert(base_type); switch (bt_ctf_field_type_get_type_id(base_type)) { case BT_CTF_FIELD_TYPE_ID_STRUCT: @@ -1397,13 +1897,15 @@ struct bt_ctf_field *get_next_field(struct bt_ctf_notif_iter *notit) next_field = bt_ctf_field_variant_get_current_field(base_field); break; default: - assert(false); - break; + BT_LOGF("Unknown base field type ID: " + "notit-addr=%p, ft-addr=%p, ft-id=%s", + notit, base_type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(base_type))); + abort(); } -end: BT_PUT(base_type); - return next_field; } @@ -1420,11 +1922,10 @@ void update_clock_state(uint64_t *state, value_type = bt_ctf_field_get_type(value_field); assert(value_type); - + assert(bt_ctf_field_type_is_integer(value_type)); requested_new_value_size = bt_ctf_field_type_integer_get_size(value_type); assert(requested_new_value_size > 0); - ret = bt_ctf_field_unsigned_integer_get_value(value_field, &requested_new_value); assert(!ret); @@ -1457,6 +1958,8 @@ void update_clock_state(uint64_t *state, /* Set the low bits of the current clock value. */ *state |= requested_new_value; end: + BT_LOGV("Updated clock's value from integer field's value: " + "value=%" PRIu64, *state); bt_put(value_type); } @@ -1465,16 +1968,13 @@ enum bt_ctf_btr_status update_clock(struct bt_ctf_notif_iter *notit, struct bt_ctf_field *int_field) { gboolean clock_class_found; - uint64_t *clock_state; + uint64_t *clock_state = NULL; struct bt_ctf_field_type *int_field_type = NULL; enum bt_ctf_btr_status ret = BT_CTF_BTR_STATUS_OK; struct bt_ctf_clock_class *clock_class = NULL; int_field_type = bt_ctf_field_get_type(int_field); - if (unlikely(!int_field_type)) { - goto end; - } - + assert(int_field_type); clock_class = bt_ctf_field_type_integer_get_mapped_clock_class( int_field_type); if (likely(!clock_class)) { @@ -1482,28 +1982,25 @@ enum bt_ctf_btr_status update_clock(struct bt_ctf_notif_iter *notit, } clock_class_found = g_hash_table_lookup_extended(notit->clock_states, - clock_class, NULL, (gpointer) &clock_state); - if (unlikely(!clock_class_found)) { - const char *clock_class_name = - bt_ctf_clock_class_get_name(clock_class); - - PERR("Unknown clock class %s mapped to integer encountered in stream\n", - clock_class_name ? : "NULL"); - ret = BT_CTF_BTR_STATUS_ERROR; - goto end; - } - - if (unlikely(!clock_state)) { + clock_class, NULL, (gpointer) &clock_state); + if (!clock_class_found) { clock_state = g_new0(uint64_t, 1); if (!clock_state) { + BT_LOGE_STR("Failed to allocate a uint64_t."); ret = BT_CTF_BTR_STATUS_ENOMEM; goto end; } + g_hash_table_insert(notit->clock_states, bt_get(clock_class), - clock_state); + clock_state); } /* Update the clock's state. */ + BT_LOGV("Updating notification iterator's clock's value from integer field: " + "notit-addr=%p, clock-class-addr=%p, " + "clock-class-name=\"%s\", value=%" PRIu64, + notit, clock_class, + bt_ctf_clock_class_get_name(clock_class), *clock_state); update_clock_state(clock_state, int_field); end: bt_put(int_field_type); @@ -1522,10 +2019,18 @@ enum bt_ctf_btr_status btr_unsigned_int_common(uint64_t value, struct bt_ctf_notif_iter *notit = data; int ret; + BT_LOGV("Common unsigned integer function called from BTR: " + "notit-addr=%p, btr-addr=%p, ft-addr=%p, " + "ft-id=%s, value=%" PRIu64, + notit, notit->btr, type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(type)), + value); + /* Create next field */ field = get_next_field(notit); if (!field) { - PERR("Failed to get next field (unsigned int)\n"); + BT_LOGW("Cannot get next field: notit-addr=%p", notit); status = BT_CTF_BTR_STATUS_ERROR; goto end_no_put; } @@ -1538,28 +2043,27 @@ enum bt_ctf_btr_status btr_unsigned_int_common(uint64_t value, break; case BT_CTF_FIELD_TYPE_ID_ENUM: int_field = bt_ctf_field_enumeration_get_container(field); + assert(int_field); type = bt_ctf_field_get_type(int_field); + assert(type); break; default: - assert(0); - type = NULL; - break; - } - - if (!int_field) { - PERR("Failed to get integer field\n"); - status = BT_CTF_BTR_STATUS_ERROR; - goto end; + BT_LOGF("Unexpected field type ID: " + "notit-addr=%p, ft-addr=%p, ft-id=%s", + notit, type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(type))); + abort(); } + assert(int_field); ret = bt_ctf_field_unsigned_integer_set_value(int_field, value); - assert(!ret); + assert(ret == 0); stack_top(notit->stack)->index++; *out_int_field = int_field; - -end: BT_PUT(field); BT_PUT(type); + end_no_put: return status; } @@ -1572,6 +2076,12 @@ enum bt_ctf_btr_status btr_timestamp_end_cb(void *value, struct bt_ctf_field *field = NULL; struct bt_ctf_notif_iter *notit = data; + BT_LOGV("`timestamp_end` unsigned integer function called from BTR: " + "notit-addr=%p, btr-addr=%p, ft-addr=%p, " + "ft-id=%s", + notit, notit->btr, type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(type))); status = btr_unsigned_int_common(*((uint64_t *) value), type, data, &field); @@ -1589,15 +2099,23 @@ enum bt_ctf_btr_status btr_unsigned_int_cb(uint64_t value, struct bt_ctf_field *field = NULL; struct field_cb_override *override; - override = g_hash_table_lookup(notit->field_overrides, - type); + BT_LOGV("Unsigned integer function called from BTR: " + "notit-addr=%p, btr-addr=%p, ft-addr=%p, " + "ft-id=%s, value=%" PRIu64, + notit, notit->btr, type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(type)), + value); + override = g_hash_table_lookup(notit->field_overrides, type); if (unlikely(override)) { + /* Override function logs errors */ status = override->func(&value, type, override->data); goto end; } status = btr_unsigned_int_common(value, type, data, &field); if (status != BT_CTF_BTR_STATUS_OK) { + /* btr_unsigned_int_common() logs errors */ goto end; } @@ -1617,10 +2135,18 @@ enum bt_ctf_btr_status btr_signed_int_cb(int64_t value, struct bt_ctf_notif_iter *notit = data; int ret; + BT_LOGV("Signed integer function called from BTR: " + "notit-addr=%p, btr-addr=%p, ft-addr=%p, " + "ft-id=%s, value=%" PRId64, + notit, notit->btr, type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(type)), + value); + /* create next field */ field = get_next_field(notit); if (!field) { - PERR("Failed to get next field (signed int)\n"); + BT_LOGW("Cannot get next field: notit-addr=%p", notit); status = BT_CTF_BTR_STATUS_ERROR; goto end_no_put; } @@ -1633,28 +2159,28 @@ enum bt_ctf_btr_status btr_signed_int_cb(int64_t value, break; case BT_CTF_FIELD_TYPE_ID_ENUM: int_field = bt_ctf_field_enumeration_get_container(field); + assert(int_field); type = bt_ctf_field_get_type(int_field); + assert(type); break; default: - assert(0); - type = NULL; - break; - } - - if (!int_field) { - PERR("Failed to get integer field\n"); - status = BT_CTF_BTR_STATUS_ERROR; - goto end; + BT_LOGF("Unexpected field type ID: " + "notit-addr=%p, ft-addr=%p, ft-id=%s", + notit, type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(type))); + abort(); } + assert(int_field); ret = bt_ctf_field_signed_integer_set_value(int_field, value); assert(!ret); stack_top(notit->stack)->index++; status = update_clock(notit, int_field); -end: BT_PUT(field); BT_PUT(int_field); BT_PUT(type); + end_no_put: return status; } @@ -1668,10 +2194,18 @@ enum bt_ctf_btr_status btr_floating_point_cb(double value, struct bt_ctf_notif_iter *notit = data; int ret; + BT_LOGV("Floating point number function called from BTR: " + "notit-addr=%p, btr-addr=%p, ft-addr=%p, " + "ft-id=%s, value=%f", + notit, notit->btr, type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(type)), + value); + /* Create next field */ field = get_next_field(notit); if (!field) { - PERR("Failed to get next field (floating point number)\n"); + BT_LOGW("Cannot get next field: notit-addr=%p", notit); status = BT_CTF_BTR_STATUS_ERROR; goto end; } @@ -1682,7 +2216,6 @@ enum bt_ctf_btr_status btr_floating_point_cb(double value, end: BT_PUT(field); - return status; } @@ -1695,10 +2228,17 @@ enum bt_ctf_btr_status btr_string_begin_cb( struct bt_ctf_notif_iter *notit = data; int ret; + BT_LOGV("String (beginning) function called from BTR: " + "notit-addr=%p, btr-addr=%p, ft-addr=%p, " + "ft-id=%s", + notit, notit->btr, type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(type))); + /* Create next field */ field = get_next_field(notit); if (!field) { - PERR("Failed to get next field (string)\n"); + BT_LOGW("Cannot get next field: notit-addr=%p", notit); status = BT_CTF_BTR_STATUS_ERROR; goto end; } @@ -1710,7 +2250,8 @@ enum bt_ctf_btr_status btr_string_begin_cb( */ ret = stack_push(notit->stack, field); if (ret) { - PERR("Failed to push string field onto the stack\n"); + BT_LOGE("Cannot push string field on stack: " + "notit-addr=%p, field-addr=%p", notit, field); status = BT_CTF_BTR_STATUS_ERROR; goto end; } @@ -1722,7 +2263,9 @@ enum bt_ctf_btr_status btr_string_begin_cb( */ ret = bt_ctf_field_string_set_value(field, ""); if (ret) { - PERR("Failed to initialize string field\n"); + BT_LOGE("Cannot initialize string field's value to an empty string: " + "notit-addr=%p, field-addr=%p, ret=%d", + notit, field, ret); status = BT_CTF_BTR_STATUS_ERROR; goto end; } @@ -1742,6 +2285,14 @@ enum bt_ctf_btr_status btr_string_cb(const char *value, struct bt_ctf_notif_iter *notit = data; int ret; + BT_LOGV("String (substring) function called from BTR: " + "notit-addr=%p, btr-addr=%p, ft-addr=%p, " + "ft-id=%s, string-length=%zu", + notit, notit->btr, type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(type)), + len); + /* Get string field */ field = stack_top(notit->stack)->base; assert(field); @@ -1749,7 +2300,9 @@ enum bt_ctf_btr_status btr_string_cb(const char *value, /* Append current string */ ret = bt_ctf_field_string_append_len(field, value, len); if (ret) { - PERR("Failed to append a string to a string field\n"); + BT_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_CTF_BTR_STATUS_ERROR; goto end; } @@ -1764,12 +2317,18 @@ enum bt_ctf_btr_status btr_string_end_cb( { struct bt_ctf_notif_iter *notit = data; + BT_LOGV("String (end) function called from BTR: " + "notit-addr=%p, btr-addr=%p, ft-addr=%p, " + "ft-id=%s", + notit, notit->btr, type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(type))); + /* Pop string field */ stack_pop(notit->stack); /* Go to next field */ stack_top(notit->stack)->index++; - return BT_CTF_BTR_STATUS_OK; } @@ -1781,6 +2340,13 @@ enum bt_ctf_btr_status btr_compound_begin_cb( struct bt_ctf_field *field; int ret; + BT_LOGV("Compound (beginning) function called from BTR: " + "notit-addr=%p, btr-addr=%p, ft-addr=%p, " + "ft-id=%s", + notit, notit->btr, type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(type))); + /* Create field */ if (stack_empty(notit->stack)) { /* Root: create dynamic scope field */ @@ -1794,20 +2360,35 @@ enum bt_ctf_btr_status btr_compound_begin_cb( * later), so also get it for our context to own it. */ bt_get(*notit->cur_dscope_field); + + if (!field) { + BT_LOGE("Cannot create compound field: " + "notit-addr=%p, ft-addr=%p, ft-id=%s", + notit, type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(type))); + status = BT_CTF_BTR_STATUS_ERROR; + goto end; + } } else { field = get_next_field(notit); - } - - if (!field) { - PERR("Failed to get next field or create dynamic scope field\n"); - status = BT_CTF_BTR_STATUS_ERROR; - goto end; + if (!field) { + BT_LOGW("Cannot get next field: notit-addr=%p", notit); + status = BT_CTF_BTR_STATUS_ERROR; + goto end; + } } /* Push field */ + assert(field); ret = stack_push(notit->stack, field); if (ret) { - PERR("Failed to push compound field onto the stack\n"); + BT_LOGE("Cannot push compound field onto the stack: " + "notit-addr=%p, ft-addr=%p, ft-id=%s, ret=%d", + notit, type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(type)), + ret); status = BT_CTF_BTR_STATUS_ERROR; goto end; } @@ -1823,6 +2404,12 @@ enum bt_ctf_btr_status btr_compound_end_cb( { struct bt_ctf_notif_iter *notit = data; + BT_LOGV("Compound (end) function called from BTR: " + "notit-addr=%p, btr-addr=%p, ft-addr=%p, " + "ft-id=%s", + notit, notit->btr, type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(type))); assert(!stack_empty(notit->stack)); /* Pop stack */ @@ -1843,6 +2430,17 @@ struct bt_ctf_field *resolve_field(struct bt_ctf_notif_iter *notit, struct bt_ctf_field *field = NULL; unsigned int i; + if (BT_LOG_ON_VERBOSE) { + GString *gstr = bt_ctf_field_path_string(path); + + BT_LOGV("Resolving field path: notit-addr=%p, field-path=\"%s\"", + notit, gstr ? gstr->str : NULL); + + if (gstr) { + g_string_free(gstr, TRUE); + } + } + switch (bt_ctf_field_path_get_root_scope(path)) { case BT_CTF_SCOPE_TRACE_PACKET_HEADER: field = notit->dscopes.trace_packet_header; @@ -1863,10 +2461,18 @@ struct bt_ctf_field *resolve_field(struct bt_ctf_notif_iter *notit, field = notit->dscopes.event_payload; break; default: - break; + BT_LOGF("Cannot resolve field path: unknown scope: " + "notit-addr=%p, root-scope=%s", + notit, bt_ctf_scope_string( + bt_ctf_field_path_get_root_scope(path))); + abort(); } if (!field) { + BT_LOGW("Cannot resolve field path: root field not found: " + "notit-addr=%p, root-scope=%s", + notit, bt_ctf_scope_string( + bt_ctf_field_path_get_root_scope(path))); goto end; } @@ -1878,10 +2484,7 @@ struct bt_ctf_field *resolve_field(struct bt_ctf_notif_iter *notit, int index = bt_ctf_field_path_get_index(path, i); field_type = bt_ctf_field_get_type(field); - if (!field_type) { - BT_PUT(field); - goto end; - } + assert(field_type); if (is_struct_type(field_type)) { next_field = bt_ctf_field_structure_get_field_by_index( @@ -1895,6 +2498,12 @@ struct bt_ctf_field *resolve_field(struct bt_ctf_notif_iter *notit, BT_PUT(field_type); if (!next_field) { + BT_LOGW("Cannot find next field: " + "notit-addr=%p, ft-addr=%p, ft-id=%s, index=%d", + notit, field_type, + bt_ctf_field_type_id_string( + bt_ctf_field_type_get_type_id(field_type)), + index); goto end; } @@ -1911,31 +2520,40 @@ int64_t btr_get_sequence_length_cb(struct bt_ctf_field_type *type, void *data) { int64_t ret = -1; int iret; + struct bt_ctf_field *seq_field; struct bt_ctf_field_path *field_path; struct bt_ctf_notif_iter *notit = data; struct bt_ctf_field *length_field = NULL; uint64_t length; field_path = bt_ctf_field_type_sequence_get_length_field_path(type); - if (!field_path) { - goto end; - } - + assert(field_path); length_field = resolve_field(notit, field_path); if (!length_field) { + BT_LOGW("Cannot resolve sequence field type's length field path: " + "notit-addr=%p, ft-addr=%p", + notit, type); goto end; } iret = bt_ctf_field_unsigned_integer_get_value(length_field, &length); if (iret) { + BT_LOGE("Cannot get value of sequence length field: " + "notit-addr=%p, field-addr=%p", + notit, length_field); goto end; } - iret = bt_ctf_field_sequence_set_length(stack_top(notit->stack)->base, - length_field); + seq_field = stack_top(notit->stack)->base; + iret = bt_ctf_field_sequence_set_length(seq_field, length_field); if (iret) { + BT_LOGE("Cannot set sequence field's length field: " + "notit-addr=%p, seq-field-addr=%p, " + "length-field-addr=%p, ", + notit, seq_field, length_field); goto end; } + ret = (int64_t) length; end: @@ -1951,17 +2569,18 @@ struct bt_ctf_field_type *btr_get_variant_type_cb( { struct bt_ctf_field_path *path; struct bt_ctf_notif_iter *notit = data; + struct bt_ctf_field *var_field; struct bt_ctf_field *tag_field = NULL; struct bt_ctf_field *selected_field = NULL; struct bt_ctf_field_type *selected_field_type = NULL; path = bt_ctf_field_type_variant_get_tag_field_path(type); - if (!path) { - goto end; - } - + assert(path); tag_field = resolve_field(notit, path); if (!tag_field) { + BT_LOGW("Cannot resolve variant field type's tag field path: " + "notit-addr=%p, ft-addr=%p", + notit, type); goto end; } @@ -1977,9 +2596,12 @@ struct bt_ctf_field_type *btr_get_variant_type_cb( * function call which is used to fill the current selected * field. */ - selected_field = bt_ctf_field_variant_get_field( - stack_top(notit->stack)->base, tag_field); + var_field = stack_top(notit->stack)->base; + selected_field = bt_ctf_field_variant_get_field(var_field, tag_field); if (!selected_field) { + BT_LOGW("Cannot get variant field's selection using tag field: " + "notit-addr=%p, var-field-addr=%p, tag-field-addr=%p", + notit, var_field, tag_field); goto end; } @@ -2011,15 +2633,39 @@ int set_event_clocks(struct bt_ctf_event *event, clock_value = bt_ctf_clock_value_create(clock_class, *clock_state); if (!clock_value) { + BT_LOGE("Cannot create clock value from clock class: " + "notit-addr=%p, clock-class-addr=%p, " + "clock-class-name=\"%s\"", + notit, clock_class, + bt_ctf_clock_class_get_name(clock_class)); ret = -1; goto end; } ret = bt_ctf_event_set_clock_value(event, clock_value); bt_put(clock_value); if (ret) { + struct bt_ctf_event_class *event_class = + bt_ctf_event_get_class(event); + + assert(event_class); + BT_LOGE("Cannot set event's clock value: " + "notit-addr=%p, event-addr=%p, " + "event-class-name=\"%s\", " + "event-class-id=%" PRId64 ", " + "clock-class-addr=%p, " + "clock-class-name=\"%s\", " + "clock-value-addr=%p", + notit, event, + bt_ctf_event_class_get_name(event_class), + bt_ctf_event_class_get_id(event_class), + clock_class, + bt_ctf_clock_class_get_name(clock_class), + clock_value); + bt_put(event_class); goto end; } } + ret = 0; end: return ret; @@ -2031,9 +2677,24 @@ struct bt_ctf_event *create_event(struct bt_ctf_notif_iter *notit) int ret; struct bt_ctf_event *event; + BT_LOGV("Creating event for event notification: " + "notit-addr=%p, event-class-addr=%p, " + "event-class-name=\"%s\", " + "event-class-id=%" PRId64, + notit, notit->meta.event_class, + bt_ctf_event_class_get_name(notit->meta.event_class), + bt_ctf_event_class_get_id(notit->meta.event_class)); + /* Create event object. */ event = bt_ctf_event_create(notit->meta.event_class); if (!event) { + BT_LOGE("Cannot create event: " + "notit-addr=%p, event-class-addr=%p, " + "event-class-name=\"%s\", " + "event-class-id=%" PRId64, + notit, notit->meta.event_class, + bt_ctf_event_class_get_name(notit->meta.event_class), + bt_ctf_event_class_get_id(notit->meta.event_class)); goto error; } @@ -2041,29 +2702,68 @@ struct bt_ctf_event *create_event(struct bt_ctf_notif_iter *notit) ret = bt_ctf_event_set_header(event, notit->dscopes.stream_event_header); if (ret) { + BT_LOGE("Cannot set event's header field: " + "notit-addr=%p, event-addr=%p, event-class-addr=%p, " + "event-class-name=\"%s\", " + "event-class-id=%" PRId64 ", field-addr=%p", + notit, event, notit->meta.event_class, + bt_ctf_event_class_get_name(notit->meta.event_class), + bt_ctf_event_class_get_id(notit->meta.event_class), + notit->dscopes.stream_event_header); goto error; } ret = bt_ctf_event_set_stream_event_context(event, notit->dscopes.stream_event_context); if (ret) { + BT_LOGE("Cannot set event's context field: " + "notit-addr=%p, event-addr=%p, event-class-addr=%p, " + "event-class-name=\"%s\", " + "event-class-id=%" PRId64 ", field-addr=%p", + notit, event, notit->meta.event_class, + bt_ctf_event_class_get_name(notit->meta.event_class), + bt_ctf_event_class_get_id(notit->meta.event_class), + notit->dscopes.stream_event_context); goto error; } ret = bt_ctf_event_set_event_context(event, notit->dscopes.event_context); if (ret) { + BT_LOGE("Cannot set event's stream event context field: " + "notit-addr=%p, event-addr=%p, event-class-addr=%p, " + "event-class-name=\"%s\", " + "event-class-id=%" PRId64 ", field-addr=%p", + notit, event, notit->meta.event_class, + bt_ctf_event_class_get_name(notit->meta.event_class), + bt_ctf_event_class_get_id(notit->meta.event_class), + notit->dscopes.event_context); goto error; } ret = bt_ctf_event_set_event_payload(event, notit->dscopes.event_payload); if (ret) { + BT_LOGE("Cannot set event's payload field: " + "notit-addr=%p, event-addr=%p, event-class-addr=%p, " + "event-class-name=\"%s\", " + "event-class-id=%" PRId64 ", field-addr=%p", + notit, event, notit->meta.event_class, + bt_ctf_event_class_get_name(notit->meta.event_class), + bt_ctf_event_class_get_id(notit->meta.event_class), + notit->dscopes.event_payload); goto error; } ret = set_event_clocks(event, notit); if (ret) { + BT_LOGE("Cannot set event's clock values: " + "notit-addr=%p, event-addr=%p, event-class-addr=%p, " + "event-class-name=\"%s\", " + "event-class-id=%" PRId64, + notit, event, notit->meta.event_class, + bt_ctf_event_class_get_name(notit->meta.event_class), + bt_ctf_event_class_get_id(notit->meta.event_class)); goto error; } @@ -2071,56 +2771,172 @@ struct bt_ctf_event *create_event(struct bt_ctf_notif_iter *notit) assert(notit->packet); ret = bt_ctf_event_set_packet(event, notit->packet); if (ret) { + BT_LOGE("Cannot set event's header field: " + "notit-addr=%p, event-addr=%p, event-class-addr=%p, " + "event-class-name=\"%s\", " + "event-class-id=%" PRId64 ", packet-addr=%p", + notit, event, notit->meta.event_class, + bt_ctf_event_class_get_name(notit->meta.event_class), + bt_ctf_event_class_get_id(notit->meta.event_class), + notit->packet); goto error; } goto end; + error: BT_PUT(event); + end: return event; } static -void create_packet(struct bt_ctf_notif_iter *notit) +uint64_t get_cur_stream_instance_id(struct bt_ctf_notif_iter *notit) { + struct bt_ctf_field *stream_instance_id_field = NULL; + uint64_t stream_instance_id = -1ULL; int ret; + + if (!notit->dscopes.trace_packet_header) { + goto end; + } + + stream_instance_id_field = bt_ctf_field_structure_get_field_by_name( + notit->dscopes.trace_packet_header, "stream_instance_id"); + if (!stream_instance_id_field) { + goto end; + } + + ret = bt_ctf_field_unsigned_integer_get_value(stream_instance_id_field, + &stream_instance_id); + if (ret) { + stream_instance_id = -1ULL; + goto end; + } + +end: + bt_put(stream_instance_id_field); + return stream_instance_id; +} + +static +int set_stream(struct bt_ctf_notif_iter *notit) +{ + int ret = 0; struct bt_ctf_stream *stream = NULL; + + BT_LOGV("Calling user function (get stream): notit-addr=%p, " + "stream-class-addr=%p, stream-class-name=\"%s\", " + "stream-class-id=%" PRId64, + notit, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class)); + stream = bt_get(notit->medium.medops.get_stream( + notit->meta.stream_class, get_cur_stream_instance_id(notit), + notit->medium.data)); + BT_LOGV("User function returned: stream-addr=%p", stream); + if (!stream) { + BT_LOGW_STR("User function failed to return a stream object for the given stream class."); + ret = -1; + goto end; + } + + if (notit->stream && stream != notit->stream) { + BT_LOGW("User function returned a different stream than the previous one for the same sequence of packets."); + ret = -1; + goto end; + } + + BT_MOVE(notit->stream, stream); + +end: + bt_put(stream); + return ret; +} + +static +void create_packet(struct bt_ctf_notif_iter *notit) +{ + int ret; struct bt_ctf_packet *packet = NULL; + BT_LOGV("Creating packet for packet notification: " + "notit-addr=%p", notit); + /* Ask the user for the stream */ - stream = notit->medium.medops.get_stream(notit->meta.stream_class, - notit->medium.data); - if (!stream) { + ret = set_stream(notit); + if (ret) { goto error; } + BT_LOGV("Creating packet from stream: " + "notit-addr=%p, stream-addr=%p, " + "stream-class-addr=%p, " + "stream-class-name=\"%s\", " + "stream-class-id=%" PRId64, + notit, notit->stream, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class)); + /* Create packet */ - packet = bt_ctf_packet_create(stream); + packet = bt_ctf_packet_create(notit->stream); if (!packet) { + BT_LOGE("Cannot create packet from stream: " + "notit-addr=%p, stream-addr=%p, " + "stream-class-addr=%p, " + "stream-class-name=\"%s\", " + "stream-class-id=%" PRId64, + notit, notit->stream, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class)); goto error; } /* Set packet's context and header fields */ if (notit->dscopes.trace_packet_header) { ret = bt_ctf_packet_set_header(packet, - notit->dscopes.trace_packet_header); + notit->dscopes.trace_packet_header); if (ret) { + BT_LOGE("Cannot set packet's header field: " + "notit-addr=%p, packet-addr=%p, " + "stream-addr=%p, " + "stream-class-addr=%p, " + "stream-class-name=\"%s\", " + "stream-class-id=%" PRId64 ", " + "field-addr=%p", + notit, packet, notit->stream, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class), + notit->dscopes.trace_packet_header); goto error; } } if (notit->dscopes.stream_packet_context) { ret = bt_ctf_packet_set_context(packet, - notit->dscopes.stream_packet_context); + notit->dscopes.stream_packet_context); if (ret) { + BT_LOGE("Cannot set packet's context field: " + "notit-addr=%p, packet-addr=%p, " + "stream-addr=%p, " + "stream-class-addr=%p, " + "stream-class-name=\"%s\", " + "stream-class-id=%" PRId64 ", " + "field-addr=%p", + notit, packet, notit->stream, notit->meta.stream_class, + bt_ctf_stream_class_get_name(notit->meta.stream_class), + bt_ctf_stream_class_get_id(notit->meta.stream_class), + notit->dscopes.trace_packet_header); goto error; } } goto end; + error: BT_PUT(packet); + end: BT_MOVE(notit->packet, packet); } @@ -2134,11 +2950,16 @@ void notify_new_packet(struct bt_ctf_notif_iter *notit, /* Initialize the iterator's current packet */ create_packet(notit); if (!notit->packet) { + BT_LOGE("Cannot create packet for packet notification: " + "notit-addr=%p", notit); return; } ret = bt_notification_packet_begin_create(notit->packet); if (!ret) { + BT_LOGE("Cannot create packet beginning notification: " + "notit-addr=%p, packet-addr=%p", + notit, notit->packet); return; } *notification = ret; @@ -2156,6 +2977,9 @@ void notify_end_of_packet(struct bt_ctf_notif_iter *notit, ret = bt_notification_packet_end_create(notit->packet); if (!ret) { + BT_LOGE("Cannot create packet end notification: " + "notit-addr=%p, packet-addr=%p", + notit, notit->packet); return; } BT_PUT(notit->packet); @@ -2167,17 +2991,31 @@ void notify_event(struct bt_ctf_notif_iter *notit, struct bt_clock_class_priority_map *cc_prio_map, struct bt_notification **notification) { - struct bt_ctf_event *event; + struct bt_ctf_event *event = NULL; struct bt_notification *ret = NULL; + /* Make sure that the event contains at least one bit of data */ + if (notit->buf.at == notit->buf.last_eh_at) { + BT_LOGE("Cannot create empty event with 0 bits of data: " + "notit-addr=%p, packet-cur=%zu", + notit, packet_at(notit)); + goto end; + } + /* Create event */ event = create_event(notit); if (!event) { + BT_LOGE("Cannot create event for event notification: " + "notit-addr=%p", notit); goto end; } ret = bt_notification_event_create(event, cc_prio_map); if (!ret) { + BT_LOGE("Cannot create event notification: " + "notit-addr=%p, event-addr=%p, " + "cc-prio-map-addr=%p", + notit, event, cc_prio_map); goto end; } *notification = ret; @@ -2185,33 +3023,6 @@ end: BT_PUT(event); } -static -int init_clock_states(GHashTable *clock_states, struct bt_ctf_trace *trace) -{ - int clock_class_count, i, ret = 0; - - clock_class_count = bt_ctf_trace_get_clock_class_count(trace); - if (clock_class_count <= 0) { - ret = -1; - goto end; - } - - for (i = 0; i < clock_class_count; i++) { - struct bt_ctf_clock_class *clock_class; - - clock_class = bt_ctf_trace_get_clock_class_by_index(trace, i); - if (!clock_class) { - ret = -1; - goto end; - } - - g_hash_table_insert(clock_states, bt_get(clock_class), NULL); - bt_put(clock_class); - } -end: - return ret; -} - static void init_trace_field_path_cache(struct bt_ctf_trace *trace, struct trace_field_path_cache *trace_field_path_cache) @@ -2231,9 +3042,7 @@ void init_trace_field_path_cache(struct bt_ctf_trace *trace, } count = bt_ctf_field_type_structure_get_field_count(packet_header); - if (count < 0) { - goto end; - } + assert(count >= 0); for (i = 0; (i < count && (stream_id == -1 || stream_instance_id == -1)); i++) { int ret; @@ -2242,6 +3051,9 @@ void init_trace_field_path_cache(struct bt_ctf_trace *trace, ret = bt_ctf_field_type_structure_get_field(packet_header, &field_name, NULL, i); if (ret) { + BT_LOGE("Cannot get structure field's field: " + "field-addr=%p, index=%d", + packet_header, i); goto end; } @@ -2252,6 +3064,7 @@ void init_trace_field_path_cache(struct bt_ctf_trace *trace, stream_instance_id = i; } } + end: trace_field_path_cache->stream_id = stream_id; trace_field_path_cache->stream_instance_id = stream_instance_id; @@ -2261,10 +3074,8 @@ end: BT_HIDDEN struct bt_ctf_notif_iter *bt_ctf_notif_iter_create(struct bt_ctf_trace *trace, size_t max_request_sz, - struct bt_ctf_notif_iter_medium_ops medops, - void *data, FILE *err_stream) + struct bt_ctf_notif_iter_medium_ops medops, void *data) { - int ret; struct bt_ctf_notif_iter *notit = NULL; struct bt_ctf_btr_cbs cbs = { .types = { @@ -2286,57 +3097,63 @@ struct bt_ctf_notif_iter *bt_ctf_notif_iter_create(struct bt_ctf_trace *trace, assert(trace); assert(medops.request_bytes); assert(medops.get_stream); + BT_LOGD("Creating CTF plugin notification iterator: " + "trace-addr=%p, trace-name=\"%s\", max-request-size=%zu, " + "data=%p", + trace, bt_ctf_trace_get_name(trace), max_request_sz, data); notit = g_new0(struct bt_ctf_notif_iter, 1); if (!notit) { - PERR("Failed to allocate memory for CTF notification iterator\n"); + BT_LOGE_STR("Failed to allocate one CTF plugin notification iterator."); goto end; } notit->clock_states = g_hash_table_new_full(g_direct_hash, - g_direct_equal, bt_put, g_free); + g_direct_equal, bt_put, g_free); if (!notit->clock_states) { - PERR("Failed to create hash table\n"); - goto error; - } - ret = init_clock_states(notit->clock_states, trace); - if (ret) { - PERR("Failed to initialize stream clock states\n"); + BT_LOGE_STR("Failed to allocate a GHashTable."); goto error; } notit->meta.trace = bt_get(trace); notit->medium.medops = medops; notit->medium.max_request_sz = max_request_sz; notit->medium.data = data; - notit->err_stream = err_stream; notit->stack = stack_new(notit); if (!notit->stack) { - PERR("Failed to create stack\n"); + BT_LOGE_STR("Failed to create field stack."); goto error; } - notit->btr = bt_ctf_btr_create(cbs, notit, err_stream); + notit->btr = bt_ctf_btr_create(cbs, notit); if (!notit->btr) { - PERR("Failed to create binary type reader\n"); + BT_LOGE_STR("Failed to create binary type reader (BTR)."); goto error; } bt_ctf_notif_iter_reset(notit); - init_trace_field_path_cache(trace, ¬it->trace_field_path_cache); notit->sc_field_path_caches = g_hash_table_new_full(g_direct_hash, - g_direct_equal, bt_put, g_free); + g_direct_equal, bt_put, g_free); if (!notit->sc_field_path_caches) { - PERR("Failed to create stream class field path caches\n"); + BT_LOGE_STR("Failed to allocate a GHashTable."); goto error; } notit->field_overrides = g_hash_table_new_full(g_direct_hash, - g_direct_equal, bt_put, g_free); + g_direct_equal, bt_put, g_free); if (!notit->field_overrides) { + BT_LOGE_STR("Failed to allocate a GHashTable."); goto error; } + BT_LOGD("Created CTF plugin notification iterator: " + "trace-addr=%p, trace-name=\"%s\", max-request-size=%zu, " + "data=%p, notit-addr=%p", + trace, bt_ctf_trace_get_name(trace), max_request_sz, data, + notit); + notit->cur_packet_offset = 0; + end: return notit; + error: bt_ctf_notif_iter_destroy(notit); notit = NULL; @@ -2349,14 +3166,19 @@ void bt_ctf_notif_iter_destroy(struct bt_ctf_notif_iter *notit) BT_PUT(notit->meta.stream_class); BT_PUT(notit->meta.event_class); BT_PUT(notit->packet); + BT_PUT(notit->stream); BT_PUT(notit->cur_timestamp_end); put_all_dscopes(notit); + BT_LOGD("Destroying CTF plugin notification iterator: addr=%p", notit); + if (notit->stack) { + BT_LOGD_STR("Destroying field stack."); stack_destroy(notit->stack); } if (notit->btr) { + BT_LOGD("Destroying BTR: btr-addr=%p", notit->btr); bt_ctf_btr_destroy(notit->btr); } @@ -2371,6 +3193,7 @@ void bt_ctf_notif_iter_destroy(struct bt_ctf_notif_iter *notit) if (notit->field_overrides) { g_hash_table_destroy(notit->field_overrides); } + g_free(notit); } @@ -2384,32 +3207,36 @@ enum bt_ctf_notif_iter_status bt_ctf_notif_iter_get_next_notification( assert(notit); assert(notification); + BT_LOGV("Getting next notification: notit-addr=%p, cc-prio-map-addr=%p", + notit, cc_prio_map); + while (true) { status = handle_state(notit); if (status == BT_CTF_NOTIF_ITER_STATUS_AGAIN) { - PDBG("Medium operation reported \"try again later\""); + BT_LOGV_STR("Medium returned BT_CTF_NOTIF_ITER_STATUS_AGAIN."); goto end; } if (status != BT_CTF_NOTIF_ITER_STATUS_OK) { if (status == BT_CTF_NOTIF_ITER_STATUS_EOF) { - PDBG("Medium operation reported end of stream\n"); + BT_LOGV_STR("Medium returned BT_CTF_NOTIF_ITER_STATUS_EOF."); } else { - PERR("Failed to handle state:\n"); - PERR("\tState: %d\n", notit->state); + BT_LOGW("Cannot handle state: " + "notit-addr=%p, state=%s", + notit, state_string(notit->state)); } goto end; } switch (notit->state) { case STATE_EMIT_NOTIF_NEW_PACKET: - PDBG("Emitting new packet notification\n"); + /* notify_new_packet() logs errors */ notify_new_packet(notit, notification); if (!*notification) { status = BT_CTF_NOTIF_ITER_STATUS_ERROR; } goto end; case STATE_EMIT_NOTIF_EVENT: - PDBG("Emitting event notification\n"); + /* notify_event() logs errors */ notify_event(notit, cc_prio_map, notification); if (!*notification) { status = BT_CTF_NOTIF_ITER_STATUS_ERROR; @@ -2423,16 +3250,19 @@ enum bt_ctf_notif_iter_status bt_ctf_notif_iter_get_next_notification( bt_ctf_field_get_type( notit->cur_timestamp_end); + assert(field_type); btr_status = update_clock(notit, notit->cur_timestamp_end); BT_PUT(field_type); if (btr_status != BT_CTF_BTR_STATUS_OK) { + BT_LOGW("Cannot update stream's clock value: " + "notit-addr=%p", notit); status = BT_CTF_NOTIF_ITER_STATUS_ERROR; goto end; } } - PDBG("Emitting end of packet notification\n"); + /* notify_end_of_packet() logs errors */ notify_end_of_packet(notit, notification); if (!*notification) { status = BT_CTF_NOTIF_ITER_STATUS_ERROR; @@ -2454,6 +3284,7 @@ enum bt_ctf_notif_iter_status bt_ctf_notif_iter_get_packet_header_context_fields struct bt_ctf_field **packet_header_field, struct bt_ctf_field **packet_context_field) { + int ret; enum bt_ctf_notif_iter_status status = BT_CTF_NOTIF_ITER_STATUS_OK; assert(notit); @@ -2466,15 +3297,16 @@ enum bt_ctf_notif_iter_status bt_ctf_notif_iter_get_packet_header_context_fields while (true) { status = handle_state(notit); if (status == BT_CTF_NOTIF_ITER_STATUS_AGAIN) { - PDBG("Medium operation reported \"try again later\""); + BT_LOGV_STR("Medium returned BT_CTF_NOTIF_ITER_STATUS_AGAIN."); goto end; } if (status != BT_CTF_NOTIF_ITER_STATUS_OK) { if (status == BT_CTF_NOTIF_ITER_STATUS_EOF) { - PDBG("Medium operation reported end of stream\n"); + BT_LOGV_STR("Medium returned BT_CTF_NOTIF_ITER_STATUS_EOF."); } else { - PERR("Failed to handle state:\n"); - PERR("\tState: %d\n", notit->state); + BT_LOGW("Cannot handle state: " + "notit-addr=%p, state=%s", + notit, state_string(notit->state)); } goto end; } @@ -2500,7 +3332,9 @@ enum bt_ctf_notif_iter_status bt_ctf_notif_iter_get_packet_header_context_fields * We should never get past the * STATE_EMIT_NOTIF_NEW_PACKET state. */ - assert(false); + BT_LOGF("Unexpected state: notit-addr=%p, state=%s", + notit, state_string(notit->state)); + abort(); } } @@ -2513,6 +3347,73 @@ set_fields: *packet_context_field = bt_get(notit->dscopes.stream_packet_context); } + ret = set_current_packet_content_sizes(notit); + if (ret) { + status = BT_CTF_NOTIF_ITER_STATUS_ERROR; + goto end; + } end: return status; } + +BT_HIDDEN +void bt_ctf_notif_iter_set_medops_data(struct bt_ctf_notif_iter *notit, + void *medops_data) +{ + assert(notit); + notit->medium.data = medops_data; +} + +BT_HIDDEN +enum bt_ctf_notif_iter_status bt_ctf_notif_iter_seek( + struct bt_ctf_notif_iter *notit, off_t offset) +{ + enum bt_ctf_notif_iter_status ret = BT_CTF_NOTIF_ITER_STATUS_OK; + enum bt_ctf_notif_iter_medium_status medium_status; + + assert(notit); + if (offset < 0) { + BT_LOGE("Cannot seek to negative offset: offset=%jd", offset); + ret = BT_CTF_NOTIF_ITER_STATUS_INVAL; + goto end; + } + + if (!notit->medium.medops.seek) { + ret = BT_CTF_NOTIF_ITER_STATUS_UNSUPPORTED; + BT_LOGD("Aborting seek as the iterator's underlying media does not implement seek support."); + goto end; + } + + medium_status = notit->medium.medops.seek( + BT_CTF_NOTIF_ITER_SEEK_WHENCE_SET, offset, + notit->medium.data); + if (medium_status != BT_CTF_NOTIF_ITER_MEDIUM_STATUS_OK) { + if (medium_status == BT_CTF_NOTIF_ITER_MEDIUM_STATUS_EOF) { + ret = BT_CTF_NOTIF_ITER_STATUS_EOF; + } else { + ret = BT_CTF_NOTIF_ITER_STATUS_ERROR; + goto end; + } + } + + bt_ctf_notif_iter_reset(notit); + notit->cur_packet_offset = offset; +end: + return ret; +} + +BT_HIDDEN +off_t bt_ctf_notif_iter_get_current_packet_offset( + struct bt_ctf_notif_iter *notit) +{ + assert(notit); + return notit->cur_packet_offset; +} + +BT_HIDDEN +off_t bt_ctf_notif_iter_get_current_packet_size( + struct bt_ctf_notif_iter *notit) +{ + assert(notit); + return notit->cur_packet_size; +}