From 03798a93f959f6c694fe98f5647481947607c604 Mon Sep 17 00:00:00 2001 From: Julien Desfossez Date: Fri, 3 Aug 2012 14:55:00 -0400 Subject: [PATCH] Get rid of clock-raw and use real clock The clock-raw does not make much sense except internally, using this clock for seeks and with the public API is more complicated than necessary. This patch replaces the clock-raw by a clock-cycles (does not scale the timestamp with the frequency) and make sure all the calls that manipulate timestamps use the timestamp in nanoseconds with the offset applied. That way the user of the API don't need to bother with the "raw" timestamp which won't be convenient when dealing with multiple traces taken in different timezones. Traces output before and after this patch are exactly the same and multiple API calls have been tested with real timestamps and everything seems to work fine. Signed-off-by: Julien Desfossez Signed-off-by: Mathieu Desnoyers --- converter/babeltrace.c | 10 +- formats/ctf-text/ctf-text.c | 32 ++- formats/ctf/ctf.c | 246 +++++++++++++++++---- formats/ctf/events-private.h | 2 +- formats/ctf/events.c | 10 +- include/Makefile.am | 3 +- include/babeltrace/babeltrace-internal.h | 2 +- include/babeltrace/ctf-ir/metadata.h | 9 +- include/babeltrace/ctf-text/types.h | 3 +- include/babeltrace/ctf/events.h | 13 +- include/babeltrace/ctf/types.h | 3 +- include/babeltrace/format.h | 6 +- include/babeltrace/iterator.h | 4 +- include/babeltrace/trace-handle-internal.h | 6 +- include/babeltrace/trace-handle.h | 17 +- lib/context.c | 17 +- lib/iterator.c | 27 ++- lib/trace-collection.c | 4 +- lib/trace-handle.c | 42 +++- 19 files changed, 340 insertions(+), 116 deletions(-) diff --git a/converter/babeltrace.c b/converter/babeltrace.c index fdbedae5..fd6586a5 100644 --- a/converter/babeltrace.c +++ b/converter/babeltrace.c @@ -73,7 +73,7 @@ enum { OPT_FIELDS, OPT_NO_DELTA, OPT_CLOCK_OFFSET, - OPT_CLOCK_RAW, + OPT_CLOCK_CYCLES, OPT_CLOCK_SECONDS, OPT_CLOCK_DATE, OPT_CLOCK_GMT, @@ -92,7 +92,7 @@ static struct poptOption long_options[] = { { "fields", 'f', POPT_ARG_STRING, NULL, OPT_FIELDS, NULL, NULL }, { "no-delta", 0, POPT_ARG_NONE, NULL, OPT_NO_DELTA, NULL, NULL }, { "clock-offset", 0, POPT_ARG_STRING, NULL, OPT_CLOCK_OFFSET, NULL, NULL }, - { "clock-raw", 0, POPT_ARG_NONE, NULL, OPT_CLOCK_RAW, NULL, NULL }, + { "clock-cycles", 0, POPT_ARG_NONE, NULL, OPT_CLOCK_CYCLES, NULL, NULL }, { "clock-seconds", 0, POPT_ARG_NONE, NULL, OPT_CLOCK_SECONDS, NULL, NULL }, { "clock-date", 0, POPT_ARG_NONE, NULL, OPT_CLOCK_DATE, NULL, NULL }, { "clock-gmt", 0, POPT_ARG_NONE, NULL, OPT_CLOCK_GMT, NULL, NULL }, @@ -131,7 +131,7 @@ static void usage(FILE *fp) fprintf(fp, " -f, --fields name1<,name2,...> Print additional fields:\n"); fprintf(fp, " all, trace, trace:domain, trace:procname,\n"); fprintf(fp, " trace:vpid, loglevel.\n"); - fprintf(fp, " --clock-raw Disregard internal clock offset (use raw value)\n"); + fprintf(fp, " --clock-cycles Timestamp in cycles\n"); fprintf(fp, " --clock-offset seconds Clock offset in seconds\n"); fprintf(fp, " --clock-seconds Print the timestamps as [sec.ns]\n"); fprintf(fp, " (default is: [hh:mm:ss.ns])\n"); @@ -261,8 +261,8 @@ static int parse_options(int argc, char **argv) case OPT_NO_DELTA: opt_delta_field = 0; break; - case OPT_CLOCK_RAW: - opt_clock_raw = 1; + case OPT_CLOCK_CYCLES: + opt_clock_cycles = 1; break; case OPT_CLOCK_OFFSET: { diff --git a/formats/ctf-text/ctf-text.c b/formats/ctf-text/ctf-text.c index 4cb4297e..55158caa 100644 --- a/formats/ctf-text/ctf-text.c +++ b/formats/ctf-text/ctf-text.c @@ -246,9 +246,19 @@ int ctf_text_write_event(struct stream_pos *ppos, struct ctf_stream_definition * fflush(pos->fp); fprintf(stderr, "[warning] Tracer discarded %" PRIu64 " events between [", stream->events_discarded); - ctf_print_timestamp(stderr, stream, stream->prev_timestamp); - fprintf(stderr, "] and ["); - ctf_print_timestamp(stderr, stream, stream->prev_timestamp_end); + if (opt_clock_cycles) { + ctf_print_timestamp(stderr, stream, + stream->prev_cycles_timestamp); + fprintf(stderr, "] and ["); + ctf_print_timestamp(stderr, stream, + stream->prev_cycles_timestamp_end); + } else { + ctf_print_timestamp(stderr, stream, + stream->prev_real_timestamp); + fprintf(stderr, "] and ["); + ctf_print_timestamp(stderr, stream, + stream->prev_real_timestamp_end); + } fprintf(stderr, "]. You should consider recording a new trace with larger buffers or with fewer events enabled.\n"); fflush(stderr); stream->events_discarded = 0; @@ -260,7 +270,11 @@ int ctf_text_write_event(struct stream_pos *ppos, struct ctf_stream_definition * fprintf(pos->fp, "timestamp = "); else fprintf(pos->fp, "["); - ctf_print_timestamp(pos->fp, stream, stream->timestamp); + if (opt_clock_cycles) { + ctf_print_timestamp(pos->fp, stream, stream->cycles_timestamp); + } else { + ctf_print_timestamp(pos->fp, stream, stream->real_timestamp); + } if (!pos->print_names) fprintf(pos->fp, "]"); @@ -277,8 +291,8 @@ int ctf_text_write_event(struct stream_pos *ppos, struct ctf_stream_definition * fprintf(pos->fp, "delta = "); else fprintf(pos->fp, "("); - if (pos->last_timestamp != -1ULL) { - delta = stream->timestamp - pos->last_timestamp; + if (pos->last_real_timestamp != -1ULL) { + delta = stream->real_timestamp - pos->last_real_timestamp; delta_sec = delta / NSEC_PER_SEC; delta_nsec = delta % NSEC_PER_SEC; fprintf(pos->fp, "+%" PRIu64 ".%09" PRIu64, @@ -293,7 +307,8 @@ int ctf_text_write_event(struct stream_pos *ppos, struct ctf_stream_definition * fprintf(pos->fp, ", "); else fprintf(pos->fp, " "); - pos->last_timestamp = stream->timestamp; + pos->last_real_timestamp = stream->real_timestamp; + pos->last_cycles_timestamp = stream->cycles_timestamp; } if ((opt_trace_field || opt_all_fields) && stream_class->trace->path[0] != '\0') { @@ -466,7 +481,8 @@ struct trace_descriptor *ctf_text_open_trace(const char *path, int flags, pos = g_new0(struct ctf_text_stream_pos, 1); - pos->last_timestamp = -1ULL; + pos->last_real_timestamp = -1ULL; + pos->last_cycles_timestamp = -1ULL; switch (flags & O_ACCMODE) { case O_RDWR: if (!path) diff --git a/formats/ctf/ctf.c b/formats/ctf/ctf.c index cf955473..f33fa339 100644 --- a/formats/ctf/ctf.c +++ b/formats/ctf/ctf.c @@ -58,7 +58,7 @@ #define NSEC_PER_SEC 1000000000ULL -int opt_clock_raw, +int opt_clock_cycles, opt_clock_seconds, opt_clock_date, opt_clock_gmt; @@ -89,10 +89,12 @@ static void ctf_close_trace(struct trace_descriptor *descriptor); static uint64_t ctf_timestamp_begin(struct trace_descriptor *descriptor, - struct bt_trace_handle *handle); + struct bt_trace_handle *handle, enum bt_clock_type type); static uint64_t ctf_timestamp_end(struct trace_descriptor *descriptor, - struct bt_trace_handle *handle); + struct bt_trace_handle *handle, enum bt_clock_type type); +static +int ctf_convert_index_timestamp(struct trace_descriptor *tdp); static rw_dispatch read_dispatch_table[] = { @@ -127,11 +129,12 @@ struct format ctf_format = { .set_handle = ctf_set_handle, .timestamp_begin = ctf_timestamp_begin, .timestamp_end = ctf_timestamp_end, + .convert_index_timestamp = ctf_convert_index_timestamp, }; static uint64_t ctf_timestamp_begin(struct trace_descriptor *descriptor, - struct bt_trace_handle *handle) + struct bt_trace_handle *handle, enum bt_clock_type type) { struct ctf_trace *tin; uint64_t begin = ULLONG_MAX; @@ -161,8 +164,21 @@ uint64_t ctf_timestamp_begin(struct trace_descriptor *descriptor, parent); stream_pos = &cfs->pos; - index = &g_array_index(stream_pos->packet_index, - struct packet_index, 0); + if (!stream_pos->packet_real_index) + goto error; + + if (type == BT_CLOCK_REAL) { + index = &g_array_index(stream_pos->packet_real_index, + struct packet_index, + stream_pos->packet_real_index->len - 1); + } else if (type == BT_CLOCK_CYCLES) { + index = &g_array_index(stream_pos->packet_cycles_index, + struct packet_index, + stream_pos->packet_real_index->len - 1); + + } else { + goto error; + } if (index->timestamp_begin < begin) begin = index->timestamp_begin; } @@ -176,7 +192,7 @@ error: static uint64_t ctf_timestamp_end(struct trace_descriptor *descriptor, - struct bt_trace_handle *handle) + struct bt_trace_handle *handle, enum bt_clock_type type) { struct ctf_trace *tin; uint64_t end = 0; @@ -206,9 +222,21 @@ uint64_t ctf_timestamp_end(struct trace_descriptor *descriptor, parent); stream_pos = &cfs->pos; - index = &g_array_index(stream_pos->packet_index, - struct packet_index, - stream_pos->packet_index->len - 1); + if (!stream_pos->packet_real_index) + goto error; + + if (type == BT_CLOCK_REAL) { + index = &g_array_index(stream_pos->packet_real_index, + struct packet_index, + stream_pos->packet_real_index->len - 1); + } else if (type == BT_CLOCK_CYCLES) { + index = &g_array_index(stream_pos->packet_cycles_index, + struct packet_index, + stream_pos->packet_real_index->len - 1); + + } else { + goto error; + } if (index->timestamp_end > end) end = index->timestamp_end; } @@ -221,7 +249,7 @@ error: } /* - * Update stream current timestamp, keep at clock frequency. + * Update stream current timestamp */ static void ctf_update_timestamp(struct ctf_stream_definition *stream, @@ -232,39 +260,46 @@ void ctf_update_timestamp(struct ctf_stream_definition *stream, uint64_t oldval, newval, updateval; if (unlikely(integer_declaration->len == 64)) { - stream->timestamp = integer_definition->value._unsigned; + stream->prev_cycles_timestamp = stream->cycles_timestamp; + stream->cycles_timestamp = integer_definition->value._unsigned; + stream->prev_real_timestamp = ctf_get_real_timestamp(stream, + stream->prev_cycles_timestamp); + stream->real_timestamp = ctf_get_real_timestamp(stream, + stream->cycles_timestamp); return; } /* keep low bits */ - oldval = stream->timestamp; + oldval = stream->cycles_timestamp; oldval &= (1ULL << integer_declaration->len) - 1; newval = integer_definition->value._unsigned; /* Test for overflow by comparing low bits */ if (newval < oldval) newval += 1ULL << integer_declaration->len; /* updateval contains old high bits, and new low bits (sum) */ - updateval = stream->timestamp; + updateval = stream->cycles_timestamp; updateval &= ~((1ULL << integer_declaration->len) - 1); updateval += newval; - stream->prev_timestamp = stream->timestamp; - stream->timestamp = updateval; + stream->prev_cycles_timestamp = stream->cycles_timestamp; + stream->cycles_timestamp = updateval; + + /* convert to real timestamp */ + stream->prev_real_timestamp = ctf_get_real_timestamp(stream, + stream->prev_cycles_timestamp); + stream->real_timestamp = ctf_get_real_timestamp(stream, + stream->cycles_timestamp); } /* * Print timestamp, rescaling clock frequency to nanoseconds and * applying offsets as needed (unix time). */ -void ctf_print_timestamp(FILE *fp, +void ctf_print_timestamp_real(FILE *fp, struct ctf_stream_definition *stream, uint64_t timestamp) { uint64_t ts_sec = 0, ts_nsec; - if (opt_clock_raw) { - ts_nsec = ctf_get_timestamp_raw(stream, timestamp); - } else { - ts_nsec = ctf_get_timestamp(stream, timestamp); - } + ts_nsec = timestamp; /* Add command-line offset */ ts_sec += opt_clock_offset; @@ -319,6 +354,27 @@ end: return; } +/* + * Print timestamp, in cycles + */ +void ctf_print_timestamp_cycles(FILE *fp, + struct ctf_stream_definition *stream, + uint64_t timestamp) +{ + fprintf(fp, "%020" PRIu64, timestamp); +} + +void ctf_print_timestamp(FILE *fp, + struct ctf_stream_definition *stream, + uint64_t timestamp) +{ + if (opt_clock_cycles) { + ctf_print_timestamp_cycles(fp, stream, timestamp); + } else { + ctf_print_timestamp_real(fp, stream, timestamp); + } +} + static int ctf_read_event(struct stream_pos *ppos, struct ctf_stream_definition *stream) { @@ -497,11 +553,12 @@ void ctf_init_pos(struct ctf_stream_pos *pos, int fd, int open_flags) pos->offset = 0; pos->dummy = false; pos->cur_index = 0; + pos->packet_real_index = NULL; if (fd >= 0) - pos->packet_index = g_array_new(FALSE, TRUE, + pos->packet_cycles_index = g_array_new(FALSE, TRUE, sizeof(struct packet_index)); else - pos->packet_index = NULL; + pos->packet_cycles_index = NULL; switch (open_flags & O_ACCMODE) { case O_RDONLY: pos->prot = PROT_READ; @@ -537,7 +594,8 @@ void ctf_fini_pos(struct ctf_stream_pos *pos) assert(0); } } - (void) g_array_free(pos->packet_index, TRUE); + (void) g_array_free(pos->packet_cycles_index, TRUE); + (void) g_array_free(pos->packet_real_index, TRUE); } /* @@ -602,13 +660,23 @@ void ctf_packet_seek(struct stream_pos *stream_pos, size_t index, int whence) return; } /* For printing discarded event count */ - packet_index = &g_array_index(pos->packet_index, + packet_index = &g_array_index(pos->packet_cycles_index, struct packet_index, pos->cur_index); - events_discarded_diff = packet_index->events_discarded; - file_stream->parent.prev_timestamp_end = + file_stream->parent.prev_cycles_timestamp_end = + packet_index->timestamp_end; + file_stream->parent.prev_cycles_timestamp = + packet_index->timestamp_begin; + + packet_index = &g_array_index(pos->packet_real_index, + struct packet_index, pos->cur_index); + file_stream->parent.prev_real_timestamp_end = packet_index->timestamp_end; + file_stream->parent.prev_real_timestamp = + packet_index->timestamp_begin; + + events_discarded_diff = packet_index->events_discarded; if (pos->cur_index > 0) { - packet_index = &g_array_index(pos->packet_index, + packet_index = &g_array_index(pos->packet_real_index, struct packet_index, pos->cur_index - 1); events_discarded_diff -= packet_index->events_discarded; @@ -621,20 +689,23 @@ void ctf_packet_seek(struct stream_pos *stream_pos, size_t index, int whence) } } file_stream->parent.events_discarded = events_discarded_diff; - file_stream->parent.prev_timestamp = file_stream->parent.timestamp; + file_stream->parent.prev_real_timestamp = file_stream->parent.real_timestamp; + file_stream->parent.prev_cycles_timestamp = file_stream->parent.cycles_timestamp; /* The reader will expect us to skip padding */ ++pos->cur_index; break; } case SEEK_SET: pos->cur_index = index; - file_stream->parent.prev_timestamp = 0; - file_stream->parent.prev_timestamp_end = 0; + file_stream->parent.prev_real_timestamp = 0; + file_stream->parent.prev_real_timestamp_end = 0; + file_stream->parent.prev_cycles_timestamp = 0; + file_stream->parent.prev_cycles_timestamp_end = 0; break; default: assert(0); } - if (pos->cur_index >= pos->packet_index->len) { + if (pos->cur_index >= pos->packet_real_index->len) { /* * When a stream reaches the end of the * file, we need to show the number of @@ -654,11 +725,21 @@ void ctf_packet_seek(struct stream_pos *stream_pos, size_t index, int whence) fflush(stdout); fprintf(stderr, "[warning] Tracer discarded %" PRIu64 " events at end of stream between [", file_stream->parent.events_discarded); - ctf_print_timestamp(stderr, &file_stream->parent, - file_stream->parent.prev_timestamp); - fprintf(stderr, "] and ["); - ctf_print_timestamp(stderr, &file_stream->parent, - file_stream->parent.prev_timestamp_end); + if (opt_clock_cycles) { + ctf_print_timestamp(stderr, + &file_stream->parent, + file_stream->parent.prev_cycles_timestamp); + fprintf(stderr, "] and ["); + ctf_print_timestamp(stderr, &file_stream->parent, + file_stream->parent.prev_cycles_timestamp_end); + } else { + ctf_print_timestamp(stderr, + &file_stream->parent, + file_stream->parent.prev_real_timestamp); + fprintf(stderr, "] and ["); + ctf_print_timestamp(stderr, &file_stream->parent, + file_stream->parent.prev_real_timestamp_end); + } fprintf(stderr, "]. You should consider recording a new trace with larger buffers or with fewer events enabled.\n"); fflush(stderr); } @@ -667,12 +748,18 @@ void ctf_packet_seek(struct stream_pos *stream_pos, size_t index, int whence) pos->offset = EOF; return; } - packet_index = &g_array_index(pos->packet_index, struct packet_index, - pos->cur_index); + packet_index = &g_array_index(pos->packet_cycles_index, + struct packet_index, + pos->cur_index); + file_stream->parent.cycles_timestamp = packet_index->timestamp_begin; + + packet_index = &g_array_index(pos->packet_real_index, + struct packet_index, + pos->cur_index); + file_stream->parent.real_timestamp = packet_index->timestamp_begin; pos->mmap_offset = packet_index->offset; /* Lookup context/packet size in index */ - file_stream->parent.timestamp = packet_index->timestamp_begin; pos->content_size = packet_index->content_size; pos->packet_size = packet_index->packet_size; if (packet_index->data_offset < packet_index->content_size) { @@ -1189,7 +1276,7 @@ int create_stream_packet_index(struct ctf_trace *td, if (magic != CTF_MAGIC) { fprintf(stderr, "[error] Invalid magic number 0x%" PRIX64 " at packet %u (file offset %zd).\n", magic, - file_stream->pos.packet_index->len, + file_stream->pos.packet_cycles_index->len, (ssize_t) pos->mmap_offset); return -EINVAL; } @@ -1289,6 +1376,12 @@ int create_stream_packet_index(struct ctf_trace *td, field = struct_definition_get_field_from_index(file_stream->parent.stream_packet_context, len_index); packet_index.timestamp_begin = get_unsigned_int(field); + if (file_stream->parent.stream_class->trace->collection) { + packet_index.timestamp_begin = + ctf_get_real_timestamp( + &file_stream->parent, + packet_index.timestamp_begin); + } } /* read timestamp end from header */ @@ -1298,6 +1391,12 @@ int create_stream_packet_index(struct ctf_trace *td, field = struct_definition_get_field_from_index(file_stream->parent.stream_packet_context, len_index); packet_index.timestamp_end = get_unsigned_int(field); + if (file_stream->parent.stream_class->trace->collection) { + packet_index.timestamp_end = + ctf_get_real_timestamp( + &file_stream->parent, + packet_index.timestamp_end); + } } /* read events discarded from header */ @@ -1333,14 +1432,11 @@ int create_stream_packet_index(struct ctf_trace *td, packet_index.data_offset = pos->offset; /* add index to packet array */ - g_array_append_val(file_stream->pos.packet_index, packet_index); + g_array_append_val(file_stream->pos.packet_cycles_index, packet_index); pos->mmap_offset += packet_index.packet_size / CHAR_BIT; } - /* Move pos back to beginning of file */ - ctf_packet_seek(&pos->parent, 0, SEEK_SET); /* position for write */ - return 0; } @@ -1526,6 +1622,11 @@ error: return ret; } +/* + * ctf_open_trace: Open a CTF trace and index it. + * Note that the user must seek the trace after the open (using the iterator) + * since the index creation read it entirely. + */ static struct trace_descriptor *ctf_open_trace(const char *path, int flags, void (*packet_seek)(struct stream_pos *pos, size_t index, @@ -1579,7 +1680,8 @@ void ctf_init_mmap_pos(struct ctf_stream_pos *pos, pos->offset = 0; pos->dummy = false; pos->cur_index = 0; - pos->packet_index = NULL; + pos->packet_cycles_index = NULL; + pos->packet_real_index = NULL; pos->prot = PROT_READ; pos->flags = MAP_PRIVATE; pos->parent.rw_table = read_dispatch_table; @@ -1715,6 +1817,56 @@ error: return NULL; } +static +int ctf_convert_index_timestamp(struct trace_descriptor *tdp) +{ + int i, j, k; + struct ctf_trace *td = container_of(tdp, struct ctf_trace, parent); + + /* for each stream_class */ + for (i = 0; i < td->streams->len; i++) { + struct ctf_stream_declaration *stream_class; + + stream_class = g_ptr_array_index(td->streams, i); + if (!stream_class) + continue; + /* for each file_stream */ + for (j = 0; j < stream_class->streams->len; j++) { + struct ctf_stream_definition *stream; + struct ctf_stream_pos *stream_pos; + struct ctf_file_stream *cfs; + + stream = g_ptr_array_index(stream_class->streams, j); + if (!stream) + continue; + cfs = container_of(stream, struct ctf_file_stream, + parent); + stream_pos = &cfs->pos; + stream_pos->packet_real_index = g_array_new(FALSE, TRUE, + sizeof(struct packet_index)); + + for (k = 0; k < stream_pos->packet_cycles_index->len; k++) { + struct packet_index *index; + struct packet_index new_index; + + index = &g_array_index(stream_pos->packet_cycles_index, + struct packet_index, k); + memcpy(&new_index, index, + sizeof(struct packet_index)); + new_index.timestamp_begin = + ctf_get_real_timestamp(stream, + index->timestamp_begin); + new_index.timestamp_end = + ctf_get_real_timestamp(stream, + index->timestamp_end); + g_array_append_val(stream_pos->packet_real_index, + new_index); + } + } + } + return 0; +} + static void ctf_close_file_stream(struct ctf_file_stream *file_stream) { diff --git a/formats/ctf/events-private.h b/formats/ctf/events-private.h index 4ea19be5..6b3d5a17 100644 --- a/formats/ctf/events-private.h +++ b/formats/ctf/events-private.h @@ -41,7 +41,7 @@ uint64_t ctf_get_timestamp_raw(struct ctf_stream_definition *stream, } static inline -uint64_t ctf_get_timestamp(struct ctf_stream_definition *stream, +uint64_t ctf_get_real_timestamp(struct ctf_stream_definition *stream, uint64_t timestamp) { uint64_t ts_nsec; diff --git a/formats/ctf/events.c b/formats/ctf/events.c index 4fa8f303..06419a18 100644 --- a/formats/ctf/events.c +++ b/formats/ctf/events.c @@ -281,22 +281,20 @@ int bt_ctf_event_get_handle_id(const struct bt_ctf_event *ctf_event) return ret; } -uint64_t bt_ctf_get_timestamp_raw(const struct bt_ctf_event *ctf_event) +uint64_t bt_ctf_get_real_timestamp(const struct bt_ctf_event *ctf_event) { struct ctf_event_definition *event = ctf_event->parent; if (event && event->stream->has_timestamp) - return ctf_get_timestamp_raw(event->stream, - event->stream->timestamp); + return event->stream->real_timestamp; else return -1ULL; } -uint64_t bt_ctf_get_timestamp(const struct bt_ctf_event *ctf_event) +uint64_t bt_ctf_get_cycles_timestamp(const struct bt_ctf_event *ctf_event) { struct ctf_event_definition *event = ctf_event->parent; if (event && event->stream->has_timestamp) - return ctf_get_timestamp(event->stream, - event->stream->timestamp); + return event->stream->cycles_timestamp; else return -1ULL; } diff --git a/include/Makefile.am b/include/Makefile.am index 8781ec3a..f7488da0 100644 --- a/include/Makefile.am +++ b/include/Makefile.am @@ -5,7 +5,8 @@ babeltraceinclude_HEADERS = \ babeltrace/iterator.h \ babeltrace/trace-collection.h \ babeltrace/trace-handle.h \ - babeltrace/list.h + babeltrace/list.h \ + babeltrace/clock-types.h babeltracectfinclude_HEADERS = \ babeltrace/ctf/events.h \ diff --git a/include/babeltrace/babeltrace-internal.h b/include/babeltrace/babeltrace-internal.h index d256bdf5..2137c23f 100644 --- a/include/babeltrace/babeltrace-internal.h +++ b/include/babeltrace/babeltrace-internal.h @@ -60,7 +60,7 @@ extern int opt_all_field_names, opt_trace_vpid_field, opt_loglevel_field, opt_delta_field, - opt_clock_raw, + opt_clock_cycles, opt_clock_seconds, opt_clock_date, opt_clock_gmt, diff --git a/include/babeltrace/ctf-ir/metadata.h b/include/babeltrace/ctf-ir/metadata.h index 124eb7da..85b0f2d5 100644 --- a/include/babeltrace/ctf-ir/metadata.h +++ b/include/babeltrace/ctf-ir/metadata.h @@ -35,7 +35,8 @@ struct ctf_clock; struct ctf_stream_definition { struct ctf_stream_declaration *stream_class; - uint64_t timestamp; /* Current timestamp, in ns */ + uint64_t real_timestamp; /* Current timestamp, in ns */ + uint64_t cycles_timestamp; /* Current timestamp, in cycles */ uint64_t event_id; /* Current event ID */ int has_timestamp; uint64_t stream_id; @@ -52,8 +53,10 @@ struct ctf_stream_definition { /* Event discarded information */ uint64_t events_discarded; - uint64_t prev_timestamp; /* Start-of-last-packet timestamp */ - uint64_t prev_timestamp_end; /* End-of-last-packet timestamp */ + uint64_t prev_real_timestamp; /* Start-of-last-packet timestamp in ns */ + uint64_t prev_real_timestamp_end; /* End-of-last-packet timestamp in ns */ + uint64_t prev_cycles_timestamp; /* Start-of-last-packet timestamp in cycles */ + uint64_t prev_cycles_timestamp_end; /* End-of-last-packet timestamp in cycles */ }; struct ctf_event_definition { diff --git a/include/babeltrace/ctf-text/types.h b/include/babeltrace/ctf-text/types.h index 3db8a106..b9c9cc30 100644 --- a/include/babeltrace/ctf-text/types.h +++ b/include/babeltrace/ctf-text/types.h @@ -39,7 +39,8 @@ struct ctf_text_stream_pos { int dummy; /* disable output */ int print_names; /* print field names */ int field_nr; - uint64_t last_timestamp; /* to print delta */ + uint64_t last_real_timestamp; /* to print delta */ + uint64_t last_cycles_timestamp; /* to print delta */ GString *string; /* Current string */ }; diff --git a/include/babeltrace/ctf/events.h b/include/babeltrace/ctf/events.h index 1cfa9e3b..419c4c8d 100644 --- a/include/babeltrace/ctf/events.h +++ b/include/babeltrace/ctf/events.h @@ -25,6 +25,7 @@ #include #include +#include struct definition; struct bt_ctf_event; @@ -89,16 +90,16 @@ const struct definition *bt_ctf_get_top_level_scope(const struct bt_ctf_event *e const char *bt_ctf_event_name(const struct bt_ctf_event *event); /* - * bt_ctf_get_timestamp_raw: returns the timestamp of the event as written in - * the packet or -1ULL on error + * bt_ctf_get_cycles_timestamp: returns the timestamp of the event as written + * in the packet (in cycles) or -1ULL on error. */ -uint64_t bt_ctf_get_timestamp_raw(const struct bt_ctf_event *event); +uint64_t bt_ctf_get_cycles_timestamp(const struct bt_ctf_event *event); /* - * bt_ctf_get_timestamp: returns the timestamp of the event offsetted with the - * system clock source or -1ULL on error + * bt_ctf_get_real_timestamp: returns the timestamp of the event offsetted + * with the system clock source (in ns) or -1ULL on error */ -uint64_t bt_ctf_get_timestamp(const struct bt_ctf_event *event); +uint64_t bt_ctf_get_real_timestamp(const struct bt_ctf_event *event); /* * bt_ctf_get_field_list: set list pointer to an array of definition diff --git a/include/babeltrace/ctf/types.h b/include/babeltrace/ctf/types.h index 3e30b149..43afaef7 100644 --- a/include/babeltrace/ctf/types.h +++ b/include/babeltrace/ctf/types.h @@ -52,7 +52,8 @@ struct packet_index { struct ctf_stream_pos { struct stream_pos parent; int fd; /* backing file fd. -1 if unset. */ - GArray *packet_index; /* contains struct packet_index */ + GArray *packet_cycles_index; /* contains struct packet_index in cycles */ + GArray *packet_real_index; /* contains struct packet_index in ns */ int prot; /* mmap protection */ int flags; /* mmap flags */ diff --git a/include/babeltrace/format.h b/include/babeltrace/format.h index c3e7a209..4ace0b04 100644 --- a/include/babeltrace/format.h +++ b/include/babeltrace/format.h @@ -22,6 +22,7 @@ */ #include +#include #include #include @@ -63,9 +64,10 @@ struct format { void (*set_handle)(struct trace_descriptor *descriptor, struct bt_trace_handle *handle); uint64_t (*timestamp_begin)(struct trace_descriptor *descriptor, - struct bt_trace_handle *handle); + struct bt_trace_handle *handle, enum bt_clock_type type); uint64_t (*timestamp_end)(struct trace_descriptor *descriptor, - struct bt_trace_handle *handle); + struct bt_trace_handle *handle, enum bt_clock_type type); + int (*convert_index_timestamp)(struct trace_descriptor *descriptor); }; extern struct format *bt_lookup_format(bt_intern_str qname); diff --git a/include/babeltrace/iterator.h b/include/babeltrace/iterator.h index 1aaa5dd0..8c106ccb 100644 --- a/include/babeltrace/iterator.h +++ b/include/babeltrace/iterator.h @@ -36,7 +36,7 @@ struct bt_saved_pos; * * type represents the type of seek to use. * u is the argument of the seek if necessary : - * - seek_time is the timestamp to seek to when using BT_SEEK_TIME, it + * - seek_time is the real timestamp to seek to when using BT_SEEK_TIME, it * is expressed in "raw" seconds (not offsetted) * - restore is a position saved with bt_iter_get_pos, it is used with * BT_SEEK_RESTORE. @@ -94,7 +94,7 @@ int bt_iter_set_pos(struct bt_iter *iter, const struct bt_iter_pos *pos); * * This function allocates and returns a new bt_iter_pos (which must be freed * with bt_iter_free_pos) to be able to restore an iterator position based on a - * timestamp. + * real timestamp. */ struct bt_iter_pos *bt_iter_create_time_pos(struct bt_iter *iter, uint64_t timestamp); diff --git a/include/babeltrace/trace-handle-internal.h b/include/babeltrace/trace-handle-internal.h index 4a56e280..36200822 100644 --- a/include/babeltrace/trace-handle-internal.h +++ b/include/babeltrace/trace-handle-internal.h @@ -38,8 +38,10 @@ struct bt_trace_handle { struct trace_descriptor *td; struct format *format; char path[PATH_MAX]; - uint64_t timestamp_begin; - uint64_t timestamp_end; + uint64_t real_timestamp_begin; + uint64_t real_timestamp_end; + uint64_t cycles_timestamp_begin; + uint64_t cycles_timestamp_end; }; /* diff --git a/include/babeltrace/trace-handle.h b/include/babeltrace/trace-handle.h index 4c85b670..f0e23125 100644 --- a/include/babeltrace/trace-handle.h +++ b/include/babeltrace/trace-handle.h @@ -23,6 +23,7 @@ */ #include +#include /* * trace_handle : unique identifier of a trace @@ -40,16 +41,20 @@ struct bt_ctf_event; const char *bt_trace_handle_get_path(struct bt_context *ctx, int handle_id); /* - * bt_trace_handle_get_timestamp_begin : returns the creation time of the buffers - * of a trace or -1ULL on error. + * bt_trace_handle_get_timestamp_begin : returns the creation time (in + * nanoseconds or cycles depending on type) of the buffers of a trace + * or -1ULL on error. */ -uint64_t bt_trace_handle_get_timestamp_begin(struct bt_context *ctx, int handle_id); +uint64_t bt_trace_handle_get_timestamp_begin(struct bt_context *ctx, + int handle_id, enum bt_clock_type type); /* - * bt_trace_handle_get_timestamp_end : returns the destruction timestamp of the - * buffers of a trace or -1ULL on error. + * bt_trace_handle_get_timestamp_end : returns the destruction timestamp + * (in anoseconds or cycles depending on type) of the buffers of a trace + * or -1ULL on error. */ -uint64_t bt_trace_handle_get_timestamp_end(struct bt_context *ctx, int handle_id); +uint64_t bt_trace_handle_get_timestamp_end(struct bt_context *ctx, + int handle_id, enum bt_clock_type type); /* * bt_ctf_event_get_handle_id : get the handle id associated with an event diff --git a/lib/context.c b/lib/context.c index bedcc420..373944c2 100644 --- a/lib/context.c +++ b/lib/context.c @@ -104,8 +104,6 @@ int bt_context_add_trace(struct bt_context *ctx, const char *path, } handle->format = fmt; handle->td = td; - handle->timestamp_begin = fmt->timestamp_begin(td, handle); - handle->timestamp_end = fmt->timestamp_end(td, handle); strncpy(handle->path, path, PATH_MAX); handle->path[PATH_MAX - 1] = '\0'; @@ -119,8 +117,19 @@ int bt_context_add_trace(struct bt_context *ctx, const char *path, (gpointer) (unsigned long) handle->id, handle); ret = trace_collection_add(ctx->tc, td); - if (ret == 0) - return handle->id; + if (ret != 0) + goto end; + + ret = fmt->convert_index_timestamp(td); + if (ret < 0) + goto end; + + handle->real_timestamp_begin = fmt->timestamp_begin(td, handle, BT_CLOCK_REAL); + handle->real_timestamp_end = fmt->timestamp_end(td, handle, BT_CLOCK_REAL); + handle->cycles_timestamp_begin = fmt->timestamp_begin(td, handle, BT_CLOCK_CYCLES); + handle->cycles_timestamp_end = fmt->timestamp_end(td, handle, BT_CLOCK_CYCLES); + + return handle->id; end: return ret; } diff --git a/lib/iterator.c b/lib/iterator.c index c6ee4c9c..bcb77d88 100644 --- a/lib/iterator.c +++ b/lib/iterator.c @@ -41,7 +41,8 @@ struct stream_saved_pos { struct ctf_file_stream *file_stream; size_t cur_index; /* current index in packet index */ ssize_t offset; /* offset from base, in bits. EOF for end of file. */ - uint64_t current_timestamp; + uint64_t current_real_timestamp; + uint64_t current_cycles_timestamp; }; struct bt_saved_pos { @@ -70,7 +71,7 @@ int stream_compare(void *a, void *b) { struct ctf_file_stream *s_a = a, *s_b = b; - if (s_a->parent.timestamp < s_b->parent.timestamp) + if (s_a->parent.real_timestamp < s_b->parent.real_timestamp) return 1; else return 0; @@ -111,8 +112,8 @@ static int seek_file_stream_by_timestamp(struct ctf_file_stream *cfs, int i, ret; stream_pos = &cfs->pos; - for (i = 0; i < stream_pos->packet_index->len; i++) { - index = &g_array_index(stream_pos->packet_index, + for (i = 0; i < stream_pos->packet_real_index->len; i++) { + index = &g_array_index(stream_pos->packet_real_index, struct packet_index, i); if (index->timestamp_end < timestamp) continue; @@ -120,7 +121,7 @@ static int seek_file_stream_by_timestamp(struct ctf_file_stream *cfs, stream_pos->packet_seek(&stream_pos->parent, i, SEEK_SET); do { ret = stream_read_event(cfs); - } while (cfs->parent.timestamp < timestamp && ret == 0); + } while (cfs->parent.real_timestamp < timestamp && ret == 0); /* Can return either EOF, 0, or error (> 0). */ return ret; @@ -221,17 +222,20 @@ int bt_iter_set_pos(struct bt_iter *iter, const struct bt_iter_pos *iter_pos) * packet_seek, because this function resets * the timestamp to the beginning of the packet */ - stream->timestamp = saved_pos->current_timestamp; + stream->real_timestamp = saved_pos->current_real_timestamp; + stream->cycles_timestamp = saved_pos->current_cycles_timestamp; stream_pos->offset = saved_pos->offset; stream_pos->last_offset = LAST_OFFSET_POISON; - stream->prev_timestamp = 0; - stream->prev_timestamp_end = 0; + stream->prev_real_timestamp = 0; + stream->prev_real_timestamp_end = 0; + stream->prev_cycles_timestamp = 0; + stream->prev_cycles_timestamp_end = 0; printf_debug("restored to cur_index = %zd and " "offset = %zd, timestamp = %" PRIu64 "\n", stream_pos->cur_index, - stream_pos->offset, stream->timestamp); + stream_pos->offset, stream->real_timestamp); stream_read_event(saved_pos->file_stream); @@ -373,7 +377,8 @@ struct bt_iter_pos *bt_iter_get_pos(struct bt_iter *iter) saved_pos.file_stream = file_stream; saved_pos.cur_index = file_stream->pos.cur_index; - saved_pos.current_timestamp = file_stream->parent.timestamp; + saved_pos.current_real_timestamp = file_stream->parent.real_timestamp; + saved_pos.current_cycles_timestamp = file_stream->parent.cycles_timestamp; g_array_append_val( pos->u.restore->stream_saved_pos, @@ -384,7 +389,7 @@ struct bt_iter_pos *bt_iter_get_pos(struct bt_iter *iter) "timestamp = %" PRIu64 "\n", file_stream->parent.stream_id, saved_pos.cur_index, saved_pos.offset, - saved_pos.current_timestamp); + saved_pos.current_real_timestamp); /* remove the stream from the heap copy */ removed = heap_remove(&iter_heap_copy); diff --git a/lib/trace-collection.c b/lib/trace-collection.c index 42d80962..c1178748 100644 --- a/lib/trace-collection.c +++ b/lib/trace-collection.c @@ -132,7 +132,8 @@ static void clock_add(gpointer key, gpointer value, gpointer user_data) /* * Whenever we add a trace to the trace collection, check that we can - * correlate this trace with at least one other clock in the trace. + * correlate this trace with at least one other clock in the trace and + * convert the index from cycles to real time. */ int trace_collection_add(struct trace_collection *tc, struct trace_descriptor *td) @@ -177,6 +178,7 @@ int trace_collection_add(struct trace_collection *tc, clock_add, &clock_match); } + return 0; error: return -EPERM; diff --git a/lib/trace-handle.c b/lib/trace-handle.c index 050268f6..5058d373 100644 --- a/lib/trace-handle.c +++ b/lib/trace-handle.c @@ -57,24 +57,50 @@ const char *bt_trace_handle_get_path(struct bt_context *ctx, int handle_id) return handle->path; } -uint64_t bt_trace_handle_get_timestamp_begin(struct bt_context *ctx, int handle_id) +uint64_t bt_trace_handle_get_timestamp_begin(struct bt_context *ctx, + int handle_id, enum bt_clock_type type) { struct bt_trace_handle *handle; + uint64_t ret; handle = g_hash_table_lookup(ctx->trace_handles, (gpointer) (unsigned long) handle_id); - if (!handle) - return -1ULL; - return handle->timestamp_begin; + if (!handle) { + ret = -1ULL; + goto end; + } + if (type == BT_CLOCK_REAL) { + ret = handle->real_timestamp_begin; + } else if (type == BT_CLOCK_CYCLES) { + ret = handle->cycles_timestamp_begin; + } else { + ret = -1ULL; + } + +end: + return ret; } -uint64_t bt_trace_handle_get_timestamp_end(struct bt_context *ctx, int handle_id) +uint64_t bt_trace_handle_get_timestamp_end(struct bt_context *ctx, + int handle_id, enum bt_clock_type type) { struct bt_trace_handle *handle; + uint64_t ret; handle = g_hash_table_lookup(ctx->trace_handles, (gpointer) (unsigned long) handle_id); - if (!handle) - return -1ULL; - return handle->timestamp_end; + if (!handle) { + ret = -1ULL; + goto end; + } + if (type == BT_CLOCK_REAL) { + ret = handle->real_timestamp_end; + } else if (type == BT_CLOCK_CYCLES) { + ret = handle->cycles_timestamp_end; + } else { + ret = -1ULL; + } + +end: + return ret; } -- 2.34.1