ctf: index: accommodate bug in barectf tracer

This commit is to accommodate the indexing of non-compliant CTF traces
produced by the barectf tracer.

What makes those traces non-compliant ?
=======================================
A bug in barectf leads to events being emitted with timestamp less than
their packet's `timestamp_begin` field.

At a higher level, such event would appear as before the beginning of
its own containing packet and not within the range of any packet of the
trace.

How this commit fixes the index for the affected traces
=====================================================
For each index entry excluding the first:
  - Decode the packet until the first event and use the timestamp of
    this event as the `timestamp_begin` of this index entry.
  - Set the previous index entry's `timestamp_end` to the
    `timestamp_end` of the current index entry.

Affected versions
=================
  - before barectf 2.3.1

Tracer commit fixing the issue
===============================
barectf master branch: 27bc6f1e6265a0da01d8f1cf2d669f1a1537c47e

Signed-off-by: Francis Deslauriers <francis.deslauriers@efficios.com>
Change-Id: I1e683467bda15d586a063ca9231cc536e143b346
Reviewed-on: https://review.lttng.org/c/babeltrace/+/1435
Tested-by: jenkins <jenkins@lttng.org>
Reviewed-by: Philippe Proulx <eeppeliteloop@gmail.com>

diff --git a/src/plugins/ctf/fs-src/fs.c b/src/plugins/ctf/fs-src/fs.c
index 1cb42e09791fd097715dce6c0aea71d482590b5f..901bda0a8354d3e0753c56377150e519822fbdec 100644 (file)
--- a/src/plugins/ctf/fs-src/fs.c
+++ b/src/plugins/ctf/fs-src/fs.c
@@ -1770,6 +1770,15 @@ end:
        return ret;
 }
 
+static
+int decode_packet_first_event_timestamp(struct ctf_fs_trace *ctf_fs_trace,
+       struct ctf_clock_class *default_cc,
+       struct ctf_fs_ds_index_entry *index_entry, uint64_t *cs, int64_t *ts_ns)
+{
+       return decode_clock_snapshot_after_event(ctf_fs_trace, default_cc,
+               index_entry, FIRST_EVENT, cs, ts_ns);
+}
+
 static
 int decode_packet_last_event_timestamp(struct ctf_fs_trace *ctf_fs_trace,
        struct ctf_clock_class *default_cc,
@@ -1869,6 +1878,77 @@ end:
        return ret;
 }
 
+/*
+ * Fix up packet index entries for barectf's "event-before-packet" bug.
+ * Some buggy barectf tracer versions may emit events with a timestamp that is
+ * less than the timestamp_begin of the their packets.
+ *
+ * To fix up this erroneous data we do the following:
+ *  1. Starting at the second index entry, set the timestamp_begin of the
+ *     current entry to the timestamp of the first event of the packet.
+ *  2. Set the previous entry's timestamp_end to the timestamp_begin of the
+ *     current packet.
+ *
+ * Known buggy tracer versions:
+ *  - before barectf 2.3.1
+ */
+static
+int fix_index_barectf_event_before_packet_bug(struct ctf_fs_trace *trace)
+{
+       int ret = 0;
+       guint ds_file_group_i;
+       GPtrArray *ds_file_groups = trace->ds_file_groups;
+       bt_logging_level log_level = trace->log_level;
+
+       for (ds_file_group_i = 0; ds_file_group_i < ds_file_groups->len;
+                       ds_file_group_i++) {
+               guint entry_i;
+               struct ctf_clock_class *default_cc;
+               struct ctf_fs_ds_file_group *ds_file_group =
+                       g_ptr_array_index(ds_file_groups, ds_file_group_i);
+
+               struct ctf_fs_ds_index *index = ds_file_group->index;
+
+               BT_ASSERT(index);
+               BT_ASSERT(index->entries);
+               BT_ASSERT(index->entries->len > 0);
+
+               BT_ASSERT(ds_file_group->sc->default_clock_class);
+               default_cc = ds_file_group->sc->default_clock_class;
+
+               /*
+                * 1. Iterate over the index, starting from the second entry
+                * (index = 1).
+                */
+               for (entry_i = 1; entry_i < index->entries->len;
+                               entry_i++) {
+                       struct ctf_fs_ds_index_entry *curr_entry, *prev_entry;
+                       prev_entry = g_ptr_array_index(index->entries, entry_i - 1);
+                       curr_entry = g_ptr_array_index(index->entries, entry_i);
+                       /*
+                        * 2. Set the current entry `begin` timestamp to the
+                        * timestamp of the first event of the current packet.
+                        */
+                       ret = decode_packet_first_event_timestamp(trace, default_cc,
+                               curr_entry, &curr_entry->timestamp_begin,
+                               &curr_entry->timestamp_begin_ns);
+                       if (ret) {
+                               BT_LOGE_STR("Failed to decode first event's clock snapshot");
+                               goto end;
+                       }
+
+                       /*
+                        * 3. Set the previous entry `end` timestamp to the
+                        * timestamp of the first event of the current packet.
+                        */
+                       prev_entry->timestamp_end = curr_entry->timestamp_begin;
+                       prev_entry->timestamp_end_ns = curr_entry->timestamp_begin_ns;
+               }
+       }
+end:
+       return ret;
+}
+
 /*
  * Extract the tracer information necessary to compare versions.
  * Returns 0 on success, and -1 if the extraction is not successful because the
@@ -1982,6 +2062,30 @@ bool is_tracer_affected_by_lttng_event_after_packet_bug(
        return is_affected;
 }
 
+static
+bool is_tracer_affected_by_barectf_event_before_packet_bug(
+               struct tracer_info *curr_tracer_info)
+{
+       bool is_affected = false;
+
+       if (strcmp(curr_tracer_info->name, "barectf") == 0) {
+               if (curr_tracer_info->major < 2) {
+                       is_affected = true;
+               } else if (curr_tracer_info->major == 2) {
+                       if (curr_tracer_info->minor < 3) {
+                               is_affected = true;
+                       } else if (curr_tracer_info->minor == 3) {
+                               /* fixed in barectf 2.3.1 */
+                               if (curr_tracer_info->patch < 1) {
+                                       is_affected = true;
+                               }
+                       }
+               }
+       }
+
+       return is_affected;
+}
+
 /*
  * Looks for trace produced by known buggy tracers and fix up the index
  * produced earlier.
@@ -2027,6 +2131,16 @@ int fix_packet_index_tracer_bugs(struct ctf_fs_component *ctf_fs)
                                goto end;
                        }
                }
+
+               if (is_tracer_affected_by_barectf_event_before_packet_bug(
+                               &current_tracer_info)) {
+                       BT_LOGI_STR("Trace may be affected by barectf tracer packet timestamp bug. Fixing up.");
+                       ret = fix_index_barectf_event_before_packet_bug(trace);
+                       if (ret) {
+                               BT_LOGE_STR("Failed to fix barectf event-before-packet bug.");
+                               goto end;
+                       }
+               }
        }
 end:
        return ret;