[LTP] [PATCH v2 6/6] sched_football: Add trace_marker messages if we're tracing

John Stultz via ltp
2024-06-25T23:56:04Z

To further help with tracing, add trace_marker messages so we
can see exactly when the game starts and ends in the tracelog.

Cc: kernel-team@android.com
Cc: Cyril Hrubis <chrubis@suse.cz>
Cc: Darren Hart <darren@os.amperecomputing.com>
Signed-off-by: John Stultz <jstultz@google.com>
---
v2:
* Pulled trace marker writing out into librttest helper functions
as suggested by Cyril
---
.../func/sched_football/sched_football.c | 5 +++
testcases/realtime/include/librttest.h | 13 ++++++++
testcases/realtime/lib/librttest.c | 32 +++++++++++++++++++
3 files changed, 50 insertions(+)

diff --git a/testcases/realtime/func/sched_football/sched_football.c b/testcases/realtime/func/sched_football/sched_football.c
index 40496cc22..b6ae692af 100644
--- a/testcases/realtime/func/sched_football/sched_football.c
+++ b/testcases/realtime/func/sched_football/sched_football.c
@@ -66,6 +66,7 @@
#include <pthread.h>
#include <sched.h>
#include <errno.h>
+#include <fcntl.h>
#include <sys/syscall.h>
#include <unistd.h>
#include <sys/prctl.h>
@@ -171,17 +172,21 @@ int referee(int game_length)
prctl(PR_SET_NAME, "referee", 0, 0, 0);
printf("Game On (%d seconds)!\n", game_length);

+ /* open trace marker early to avoid latency with the first message */
+ trace_marker_prep();
gettimeofday(&start, NULL);
now = start;

/* Start the game! */
tst_atomic_store(0, &the_ball);
+ atrace_marker_write("sched_football", "Game_started!");

/* Watch the game */
while ((now.tv_sec - start.tv_sec) < game_length) {
sleep(1);
gettimeofday(&now, NULL);
}
+ atrace_marker_write("sched_football", "Game_Over!");
final_ball = tst_atomic_load(&the_ball);
/* Blow the whistle */
printf("Game Over!\n");
diff --git a/testcases/realtime/include/librttest.h b/testcases/realtime/include/librttest.h
index 8733479e7..0a1bb0540 100644
--- a/testcases/realtime/include/librttest.h
+++ b/testcases/realtime/include/librttest.h
@@ -342,4 +342,17 @@ void latency_trace_stop(void);
*/
void latency_trace_print(void);

+/* trace_marker_prep: open trace_marker file (optional)
+ */
+void trace_marker_prep(void);
+
+/* trace_marker_write: write buf to trace_marker.
+ * Will open trace_marker file if not already open
+ */
+int trace_marker_write(char *buf, int len);
+
+/* atrace_marker_write: write atrace format message to trace_marker
+ */
+int atrace_marker_write(char *tag, char *msg);
+
#endif /* LIBRTTEST_H */
diff --git a/testcases/realtime/lib/librttest.c b/testcases/realtime/lib/librttest.c
index eaa623b72..191c667a1 100644
--- a/testcases/realtime/lib/librttest.c
+++ b/testcases/realtime/lib/librttest.c
@@ -732,3 +732,35 @@ void latency_trace_print(void)
{
read_and_print("/proc/latency_trace", STDOUT_FILENO);
}
+
+static int trace_marker_fd = -1;
+
+void trace_marker_prep(void)
+{
+ if (trace_marker_fd != -1)
+ return;
+ trace_marker_fd = open("/sys/kernel/tracing/trace_marker", O_RDWR, 0);
+}
+
+int trace_marker_write(char *buf, int len)
+{
+ if (trace_marker_fd == -1)
+ trace_marker_prep();
+
+ if (trace_marker_fd < 0)
+ return -1;
+
+ return write(trace_marker_fd, buf, len);
+}
+
+#define TRACE_BUF_LEN 256
+static char trace_buf[TRACE_BUF_LEN];
+
+int atrace_marker_write(char *tag, char *msg)
+{
+ /* Uses atrace format perfetto can visualize */
+ snprintf(trace_buf, TRACE_BUF_LEN, "I|%i|%s: %s\n", getpid(), tag, msg);
+ return trace_marker_write(trace_buf,
+ strnlen(trace_buf, TRACE_BUF_LEN));
+}
+