[PATCH 0/4] rtla: Collect and print number of missed events

[PATCH 0/4] rtla: Collect and print number of missed events

[Tomas Glozar]

Due to tracefs buffer overflow, it can happen that rtla misses events,
making the tracing results inaccurate.

Count both the number of missed events and the total number of processed
events, and display missed events as well as their percentage. The numbers
are displayed for both osnoise and timerlat, even though for the earlier,
missed events are generally not expected.

For hist, the number is displayed at the end of the run; for top, it is
displayed on each printing of the top table.

Note: In the future, rtla might transition to using ftrace histogram
triggers to collect data. In that case, this code will be removed;
nevertheless, it is necessary until that happens.

Tomas Glozar (4):
  rtla: Count missed trace events
  rtla: Count all processed events
  rtla: Add function to report missed events
  rtla: Report missed event count

 tools/tracing/rtla/src/osnoise.c       | 20 ++++++++++++++
 tools/tracing/rtla/src/osnoise.h       |  1 +
 tools/tracing/rtla/src/osnoise_hist.c  |  1 +
 tools/tracing/rtla/src/osnoise_top.c   |  1 +
 tools/tracing/rtla/src/timerlat_hist.c |  1 +
 tools/tracing/rtla/src/timerlat_top.c  |  1 +
 tools/tracing/rtla/src/trace.c         | 38 ++++++++++++++++++++++++++
 tools/tracing/rtla/src/trace.h         |  2 ++
 8 files changed, 65 insertions(+)

-- 
2.48.1

[PATCH 1/4] rtla: Count missed trace events

[Tomas Glozar]

Add function collect_missed_events to trace.c to act as a callback for
tracefs_follow_missed_events, summing the number of total missed events
into a new field missing_events of struct trace_instance.

In case record->missed_events is negative, trace->missed_events is set
to UINT64_MAX to signify an unknown number of events was missed.

The callback is activated on initialization of the trace instance.

Signed-off-by: Tomas Glozar <tglozar@redhat.com>
---
 tools/tracing/rtla/src/trace.c | 34 ++++++++++++++++++++++++++++++++++
 tools/tracing/rtla/src/trace.h |  1 +
 2 files changed, 35 insertions(+)

diff --git a/tools/tracing/rtla/src/trace.c b/tools/tracing/rtla/src/trace.c
index 170a706248ab..69a6bd2b3746 100644
--- a/tools/tracing/rtla/src/trace.c
+++ b/tools/tracing/rtla/src/trace.c
@@ -126,6 +126,31 @@ collect_registered_events(struct tep_event *event, struct tep_record *record,
 	return 0;
 }
 
+/*
+ * collect_missed_events - record number of missed events
+ *
+ * If rtla cannot keep up with events generated by tracer, events are going
+ * to fall out of the ring buffer.
+ * Collect how many events were missed so it can be reported to the user.
+ */
+static int
+collect_missed_events(struct tep_event *event, struct tep_record *record,
+		      int cpu, void *context)
+{
+	struct trace_instance *trace = context;
+
+	if (trace->missed_events == UINT64_MAX)
+		return 0;
+
+	if (record->missed_events > 0)
+		trace->missed_events += record->missed_events;
+	else
+		/* Events missed but no data on how many */
+		trace->missed_events = UINT64_MAX;
+
+	return 0;
+}
+
 /*
  * trace_instance_destroy - destroy and free a rtla trace instance
  */
@@ -181,6 +206,15 @@ int trace_instance_init(struct trace_instance *trace, char *tool_name)
 	 */
 	tracefs_trace_off(trace->inst);
 
+	/*
+	 * Collect the number of events missed due to tracefs buffer
+	 * overflow.
+	 */
+	trace->missed_events = 0;
+	tracefs_follow_missed_events(trace->inst,
+				     collect_missed_events,
+				     trace);
+
 	return 0;
 
 out_err:
diff --git a/tools/tracing/rtla/src/trace.h b/tools/tracing/rtla/src/trace.h
index c7c92dc9a18a..027cb66f5604 100644
--- a/tools/tracing/rtla/src/trace.h
+++ b/tools/tracing/rtla/src/trace.h
@@ -17,6 +17,7 @@ struct trace_instance {
 	struct tracefs_instance		*inst;
 	struct tep_handle		*tep;
 	struct trace_seq		*seq;
+	unsigned long long		missed_events;
 };
 
 int trace_instance_init(struct trace_instance *trace, char *tool_name);
-- 
2.48.1

[PATCH 2/4] rtla: Count all processed events

[Tomas Glozar]

Add a field processed_events to struct trace_instance and increment it
in collect_registered_events, regardless of whether a handler is
registered for the event.

The purpose is to calculate the percentange of events that were missed
due to tracefs buffer overflow.

Signed-off-by: Tomas Glozar <tglozar@redhat.com>
---
 tools/tracing/rtla/src/trace.c | 4 ++++
 tools/tracing/rtla/src/trace.h | 1 +
 2 files changed, 5 insertions(+)

diff --git a/tools/tracing/rtla/src/trace.c b/tools/tracing/rtla/src/trace.c
index 69a6bd2b3746..b9c4b6c2ce79 100644
--- a/tools/tracing/rtla/src/trace.c
+++ b/tools/tracing/rtla/src/trace.c
@@ -118,6 +118,8 @@ collect_registered_events(struct tep_event *event, struct tep_record *record,
 	struct trace_instance *trace = context;
 	struct trace_seq *s = trace->seq;
 
+	trace->processed_events++;
+
 	if (!event->handler)
 		return 0;
 
@@ -215,6 +217,8 @@ int trace_instance_init(struct trace_instance *trace, char *tool_name)
 				     collect_missed_events,
 				     trace);
 
+	trace->processed_events = 0;
+
 	return 0;
 
 out_err:
diff --git a/tools/tracing/rtla/src/trace.h b/tools/tracing/rtla/src/trace.h
index 027cb66f5604..2fd96cf36ce7 100644
--- a/tools/tracing/rtla/src/trace.h
+++ b/tools/tracing/rtla/src/trace.h
@@ -18,6 +18,7 @@ struct trace_instance {
 	struct tep_handle		*tep;
 	struct trace_seq		*seq;
 	unsigned long long		missed_events;
+	unsigned long long		processed_events;
 };
 
 int trace_instance_init(struct trace_instance *trace, char *tool_name);
-- 
2.48.1

[PATCH 3/4] rtla: Add function to report missed events

[Tomas Glozar]

Add osnoise_report_missed_events to be used to report the number
of missed events either during or after an osnoise or timerlat run.
Also, display the percentage of missed events compared to the total
number of received events.

If an unknown number of missed events was reported during the run, the
entire number of missed events is reported as unknown.

Signed-off-by: Tomas Glozar <tglozar@redhat.com>
---
 tools/tracing/rtla/src/osnoise.c | 20 ++++++++++++++++++++
 tools/tracing/rtla/src/osnoise.h |  1 +
 2 files changed, 21 insertions(+)

diff --git a/tools/tracing/rtla/src/osnoise.c b/tools/tracing/rtla/src/osnoise.c
index 245e9344932b..eede5e01bff6 100644
--- a/tools/tracing/rtla/src/osnoise.c
+++ b/tools/tracing/rtla/src/osnoise.c
@@ -1079,6 +1079,26 @@ struct osnoise_tool *osnoise_init_trace_tool(char *tracer)
 	return NULL;
 }
 
+/*
+ * osnoise_report_missed_events - report number of events dropped by trace
+ * buffer
+ */
+void
+osnoise_report_missed_events(struct osnoise_tool *tool)
+{
+	unsigned long long total_events;
+
+	if (tool->trace.missed_events == UINT64_MAX)
+		printf("unknown number of events missed, results might not be accurate\n");
+	else if (tool->trace.missed_events > 0) {
+		total_events = tool->trace.processed_events + tool->trace.missed_events;
+
+		printf("%lld (%.2f%%) events missed, results might not be accurate\n",
+		       tool->trace.missed_events,
+		       (double) tool->trace.missed_events / total_events * 100.0);
+	}
+}
+
 static void osnoise_usage(int err)
 {
 	int i;
diff --git a/tools/tracing/rtla/src/osnoise.h b/tools/tracing/rtla/src/osnoise.h
index 555f4f4903cc..43e4b7bb7f4a 100644
--- a/tools/tracing/rtla/src/osnoise.h
+++ b/tools/tracing/rtla/src/osnoise.h
@@ -104,6 +104,7 @@ struct osnoise_tool {
 void osnoise_destroy_tool(struct osnoise_tool *top);
 struct osnoise_tool *osnoise_init_tool(char *tool_name);
 struct osnoise_tool *osnoise_init_trace_tool(char *tracer);
+void osnoise_report_missed_events(struct osnoise_tool *tool);
 
 int osnoise_hist_main(int argc, char *argv[]);
 int osnoise_top_main(int argc, char **argv);
-- 
2.48.1

[PATCH 4/4] rtla: Report missed event count

[Tomas Glozar]

Print how many events were missed by trace buffer overflow in the main
instance at the end of the run (for hist) or during the run (for top).

Signed-off-by: Tomas Glozar <tglozar@redhat.com>
---
 tools/tracing/rtla/src/osnoise_hist.c  | 1 +
 tools/tracing/rtla/src/osnoise_top.c   | 1 +
 tools/tracing/rtla/src/timerlat_hist.c | 1 +
 tools/tracing/rtla/src/timerlat_top.c  | 1 +
 4 files changed, 4 insertions(+)

diff --git a/tools/tracing/rtla/src/osnoise_hist.c b/tools/tracing/rtla/src/osnoise_hist.c
index 214e2c93fde0..21376c00bcb3 100644
--- a/tools/tracing/rtla/src/osnoise_hist.c
+++ b/tools/tracing/rtla/src/osnoise_hist.c
@@ -440,6 +440,7 @@ osnoise_print_stats(struct osnoise_hist_params *params, struct osnoise_tool *too
 	trace_seq_reset(trace->seq);
 
 	osnoise_print_summary(params, trace, data);
+	osnoise_report_missed_events(tool);
 }
 
 /*
diff --git a/tools/tracing/rtla/src/osnoise_top.c b/tools/tracing/rtla/src/osnoise_top.c
index 45647495ce3b..3d3daf12538d 100644
--- a/tools/tracing/rtla/src/osnoise_top.c
+++ b/tools/tracing/rtla/src/osnoise_top.c
@@ -280,6 +280,7 @@ osnoise_print_stats(struct osnoise_top_params *params, struct osnoise_tool *top)
 
 	trace_seq_do_printf(trace->seq);
 	trace_seq_reset(trace->seq);
+	osnoise_report_missed_events(top);
 }
 
 /*
diff --git a/tools/tracing/rtla/src/timerlat_hist.c b/tools/tracing/rtla/src/timerlat_hist.c
index 4403cc4eba30..c18b3456a3d5 100644
--- a/tools/tracing/rtla/src/timerlat_hist.c
+++ b/tools/tracing/rtla/src/timerlat_hist.c
@@ -656,6 +656,7 @@ timerlat_print_stats(struct timerlat_hist_params *params, struct osnoise_tool *t
 
 	timerlat_print_summary(params, trace, data);
 	timerlat_print_stats_all(params, trace, data);
+	osnoise_report_missed_events(tool);
 }
 
 /*
diff --git a/tools/tracing/rtla/src/timerlat_top.c b/tools/tracing/rtla/src/timerlat_top.c
index 059b468981e4..8869a0988955 100644
--- a/tools/tracing/rtla/src/timerlat_top.c
+++ b/tools/tracing/rtla/src/timerlat_top.c
@@ -435,6 +435,7 @@ timerlat_print_stats(struct timerlat_top_params *params, struct osnoise_tool *to
 
 	trace_seq_do_printf(trace->seq);
 	trace_seq_reset(trace->seq);
+	osnoise_report_missed_events(top);
 }
 
 /*
-- 
2.48.1

Re: [PATCH 4/4] rtla: Report missed event count

[Gabriele Monaco]

On Thu, 2025-01-23 at 15:23 +0100, Tomas Glozar wrote:
> Print how many events were missed by trace buffer overflow in the
> main
> instance at the end of the run (for hist) or during the run (for
> top).
> 
> Signed-off-by: Tomas Glozar <tglozar@redhat.com>
> ---

The patchset seems to work as expected, I get the number of dropped
events and the percentage, of course if I let it run too long, I get
unknown number.
Tested on a 128 cores arm64 box with -p100, known to miss events:

run for 5s
4611870 (24.12%) events missed, results might not be accurate

run for 1m
104653605 (45.44%) events missed, results might not be accurate

run for 5m
539717695 (46.85%) events missed, results might not be accurate

run for 10m
1098569155 (47.68%) events missed, results might not be accurate

run for 1h
6749574550 (48.83%) events missed, results might not be accurate

Tested-by: Gabriele Monaco <gmonaco@redhat.com>