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

[John Stultz via ltp <ltp@lists.linux.it>]

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));
+}
+
-- 
2.45.2.741.gdbec12cfda-goog


-- 
Mailing list info: https://lists.linux.it/listinfo/ltp