* [PATCH 1/2] libtracefs utest: Add matches to trace_sql() tests
2024-01-05 5:15 [PATCH 0/2] libtracefs: Add more tracefs_sql tests Steven Rostedt
@ 2024-01-05 5:15 ` Steven Rostedt
2024-01-05 5:15 ` [PATCH 2/2] libtracefs utest: Add more tests to test tracefs_sql() Steven Rostedt
1 sibling, 0 replies; 3+ messages in thread
From: Steven Rostedt @ 2024-01-05 5:15 UTC (permalink / raw)
To: linux-trace-devel; +Cc: Steven Rostedt (Google)
From: "Steven Rostedt (Google)" <rostedt@goodmis.org>
Add code to test the output of trace_sql(). Need to handle the hashed variables
too.
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
utest/tracefs-utest.c | 96 +++++++++++++++++++++++++++++++++++++++++++
1 file changed, 96 insertions(+)
diff --git a/utest/tracefs-utest.c b/utest/tracefs-utest.c
index f338a9153c0a..5bc0d45c8996 100644
--- a/utest/tracefs-utest.c
+++ b/utest/tracefs-utest.c
@@ -11,6 +11,7 @@
#include <time.h>
#include <dirent.h>
#include <ftw.h>
+#include <ctype.h>
#include <libgen.h>
#include <kbuffer.h>
#include <pthread.h>
@@ -38,22 +39,40 @@
#define SQL_1_EVENT "wakeup_1"
#define SQL_1_SQL "select sched_switch.next_pid as woke_pid, sched_waking.common_pid as waking_pid from sched_waking join sched_switch on sched_switch.next_pid = sched_waking.pid"
+#define SQL_1_MATCH "echo 's:wakeup_1 pid_t woke_pid; s32 waking_pid;' >> /sys/kernel/tracing/dynamic_events\n" \
+ "echo 'hist:keys=pid:__arg_XXXXXXXX_1=common_pid' >> /sys/kernel/tracing/events/sched/sched_waking/trigger\n" \
+ "echo 'hist:keys=next_pid:__woke_pid_XXXXXXXX_2=next_pid,__waking_pid_XXXXXXXX_3=$__arg_XXXXXXXX_1:onmatch(sched.sched_waking).trace(wakeup_1,$__woke_pid_XXXXXXXX_2,$__waking_pid_XXXXXXXX_3)' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
#define SQL_2_EVENT "wakeup_2"
#define SQL_2_SQL "select woke.next_pid as woke_pid, wake.common_pid as waking_pid from sched_waking as wake join sched_switch as woke on woke.next_pid = wake.pid"
+#define SQL_2_MATCH "echo 's:wakeup_2 pid_t woke_pid; s32 waking_pid;' >> /sys/kernel/tracing/dynamic_events\n" \
+ "echo 'hist:keys=pid:__arg_XXXXXXXX_1=common_pid' >> /sys/kernel/tracing/events/sched/sched_waking/trigger\n" \
+ "echo 'hist:keys=next_pid:__woke_pid_XXXXXXXX_2=next_pid,__waking_pid_XXXXXXXX_3=$__arg_XXXXXXXX_1:onmatch(sched.sched_waking).trace(wakeup_2,$__woke_pid_XXXXXXXX_2,$__waking_pid_XXXXXXXX_3)' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
#define SQL_3_EVENT "wakeup_lat"
#define SQL_3_SQL "select sched_switch.next_prio as prio, end.prev_prio as pprio, (sched.sched_waking.common_timestamp.usecs - end.TIMESTAMP_USECS) as lat from sched_waking as start join sched_switch as end on start.pid = end.next_pid"
+#define SQL_3_MATCH "echo 's:wakeup_lat s32 prio; s32 pprio; u64 lat;' >> /sys/kernel/tracing/dynamic_events\n" \
+ "echo 'hist:keys=pid:__arg_XXXXXXXX_1=common_timestamp.usecs' >> /sys/kernel/tracing/events/sched/sched_waking/trigger\n" \
+ "echo 'hist:keys=next_pid:__prio_XXXXXXXX_2=next_prio,__pprio_XXXXXXXX_3=prev_prio,__lat_XXXXXXXX_4=common_timestamp.usecs-$__arg_XXXXXXXX_1:onmatch(sched.sched_waking).trace(wakeup_lat,$__prio_XXXXXXXX_2,$__pprio_XXXXXXXX_3,$__lat_XXXXXXXX_4)' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
#define SQL_4_EVENT "wakeup_lat_2"
#define SQL_4_SQL "select start.pid, end.next_prio as prio, (end.TIMESTAMP_USECS - start.TIMESTAMP_USECS) as lat from sched_waking as start join sched_switch as end on start.pid = end.next_pid where (start.prio >= 1 && start.prio < 100) || !(start.pid >= 0 && start.pid <= 1) && end.prev_pid != 0"
+#define SQL_4_MATCH "echo 's:wakeup_lat_2 pid_t pid; s32 prio; u64 lat;' >> /sys/kernel/tracing/dynamic_events\n" \
+ "echo 'hist:keys=pid:__arg_XXXXXXXX_1=pid,__arg_XXXXXXXX_2=common_timestamp.usecs if (prio >= 1&&prio < 100)||!(pid >= 0&&pid <= 1)' >> /sys/kernel/tracing/events/sched/sched_waking/trigger\n" \
+ "echo 'hist:keys=next_pid:__pid_XXXXXXXX_3=$__arg_XXXXXXXX_1,__prio_XXXXXXXX_4=next_prio,__lat_XXXXXXXX_5=common_timestamp.usecs-$__arg_XXXXXXXX_2:onmatch(sched.sched_waking).trace(wakeup_lat_2,$__pid_XXXXXXXX_3,$__prio_XXXXXXXX_4,$__lat_XXXXXXXX_5) if prev_pid != 0' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
#define SQL_5_EVENT "irq_lat"
#define SQL_5_SQL "select end.common_pid as pid, (end.common_timestamp.usecs - start.common_timestamp.usecs) as irq_lat from irq_disable as start join irq_enable as end on start.common_pid = end.common_pid, start.parent_offs == end.parent_offs where start.common_pid != 0"
#define SQL_5_START "irq_disable"
+#define SQL_5_MATCH "echo 's:irq_lat s32 pid; u64 irq_lat;' >> /sys/kernel/tracing/dynamic_events\n" \
+ "echo 'hist:keys=common_pid,parent_offs:__arg_XXXXXXXX_1=common_timestamp.usecs if common_pid != 0' >> /sys/kernel/tracing/events/preemptirq/irq_disable/trigger\n" \
+ "echo 'hist:keys=common_pid,parent_offs:__pid_XXXXXXXX_2=common_pid,__irq_lat_XXXXXXXX_3=common_timestamp.usecs-$__arg_XXXXXXXX_1:onmatch(preemptirq.irq_disable).trace(irq_lat,$__pid_XXXXXXXX_2,$__irq_lat_XXXXXXXX_3)' >> /sys/kernel/tracing/events/preemptirq/irq_enable/trigger\n"
#define SQL_6_EVENT "wakeup_lat_3"
#define SQL_6_SQL "select start.pid, end.next_prio as prio, (end.TIMESTAMP_USECS - start.TIMESTAMP_USECS) as lat from sched_waking as start join sched_switch as end on start.pid = end.next_pid where (start.prio >= 1 && start.prio < 100) || !(start.pid >= 0 && start.pid <= 1) && end.prev_pid != 0"
+#define SQL_6_MATCH "echo 's:wakeup_lat_3 pid_t pid; s32 prio; u64 lat;' >> /sys/kernel/tracing/dynamic_events\n" \
+ "echo 'hist:keys=pid:__arg_XXXXXXXX_1=pid,__arg_XXXXXXXX_2=common_timestamp.usecs if (prio >= 1&&prio < 100)||!(pid >= 0&&pid <= 1)' >> /sys/kernel/tracing/events/sched/sched_waking/trigger\n" \
+ "echo 'hist:keys=next_pid:__pid_XXXXXXXX_3=$__arg_XXXXXXXX_1,__prio_XXXXXXXX_4=next_prio,__lat_XXXXXXXX_5=common_timestamp.usecs-$__arg_XXXXXXXX_2:onmatch(sched.sched_waking).trace(wakeup_lat_3,$__pid_XXXXXXXX_3,$__prio_XXXXXXXX_4,$__lat_XXXXXXXX_5) if prev_pid != 0' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
#define DEBUGFS_DEFAULT_PATH "/sys/kernel/debug"
#define TRACEFS_DEFAULT_PATH "/sys/kernel/tracing"
@@ -405,6 +424,75 @@ static void test_ftrace_marker(void)
test_instance_ftrace_marker(test_instance);
}
+static void replace_str(char *str, char *rep, char *with, int rep_len, int with_len)
+{
+ char find[rep_len + 1];
+ char *s = str;
+ int delta = rep_len - with_len;
+
+ CU_TEST(delta >= 0);
+ if (delta < 0)
+ return;
+
+ strncpy(find, rep, rep_len + 1);
+ find[rep_len] = '\0';
+
+ while ((s = strstr(s, find))) {
+ strncpy(s, with, with_len);
+ s += with_len;
+ if (delta) {
+ int new_len = strlen(s) - delta;
+ memmove(s, s + delta, new_len);
+ s[new_len] = '\0';
+ }
+ }
+}
+
+static bool test_sql(struct trace_seq *seq, const char *match)
+{
+ char string[strlen(match) + 64]; /* add some buffer room */
+ char *p, *s, *e, *c = seq->buffer;
+ bool ret;
+
+ strcpy(string, match);
+ s = string;
+
+ while ((p = strstr(s, "_XXXXXXXX_"))) {
+ CU_TEST(ret = strncmp(c, s, p - s) == 0);
+ if (!ret) {
+ printf("\n'%*.s'\n\tdoes not match\n%*.s\n",
+ (int)(p - s), c, (int)(p - s), s);
+ return ret;
+ }
+
+ /* Move c passed what was matched */
+ c += p - s;
+
+ /* Set e to the next value */
+ e = c + 1;
+ while (isdigit(*e))
+ e++;
+ /* Skip the next '_' */
+ e++;
+ /* Skip the next numbers */
+ while (isdigit(*e))
+ e++;
+
+ /* Skip the "_XXXXXXXX_" */
+ s = p + 10;
+ /* Skip the next numbers */
+ while (isdigit(*s))
+ s++;
+
+ /* Now replace all of these */
+ replace_str(s, p, c, s - p, e - c);
+
+ c = e;
+ }
+
+ return strcmp(s, c) == 0;
+}
+
static void test_instance_trace_sql(struct tracefs_instance *instance)
{
struct tracefs_synth *synth;
@@ -421,6 +509,7 @@ static void test_instance_trace_sql(struct tracefs_instance *instance)
CU_TEST(synth != NULL);
ret = tracefs_synth_echo_cmd(&seq, synth);
CU_TEST(ret == 0);
+ CU_TEST(test_sql(&seq, SQL_1_MATCH));
tracefs_synth_free(synth);
trace_seq_reset(&seq);
@@ -428,6 +517,7 @@ static void test_instance_trace_sql(struct tracefs_instance *instance)
CU_TEST(synth != NULL);
ret = tracefs_synth_echo_cmd(&seq, synth);
CU_TEST(ret == 0);
+ CU_TEST(test_sql(&seq, SQL_2_MATCH));
tracefs_synth_free(synth);
trace_seq_reset(&seq);
@@ -435,6 +525,7 @@ static void test_instance_trace_sql(struct tracefs_instance *instance)
CU_TEST(synth != NULL);
ret = tracefs_synth_echo_cmd(&seq, synth);
CU_TEST(ret == 0);
+ CU_TEST(test_sql(&seq, SQL_3_MATCH));
tracefs_synth_free(synth);
trace_seq_reset(&seq);
@@ -442,6 +533,7 @@ static void test_instance_trace_sql(struct tracefs_instance *instance)
CU_TEST(synth != NULL);
ret = tracefs_synth_echo_cmd(&seq, synth);
CU_TEST(ret == 0);
+ CU_TEST(test_sql(&seq, SQL_4_MATCH));
tracefs_synth_free(synth);
trace_seq_reset(&seq);
@@ -451,6 +543,7 @@ static void test_instance_trace_sql(struct tracefs_instance *instance)
CU_TEST(synth != NULL);
ret = tracefs_synth_echo_cmd(&seq, synth);
CU_TEST(ret == 0);
+ CU_TEST(test_sql(&seq, SQL_5_MATCH));
tracefs_synth_free(synth);
trace_seq_reset(&seq);
}
@@ -459,6 +552,7 @@ static void test_instance_trace_sql(struct tracefs_instance *instance)
CU_TEST(synth != NULL);
ret = tracefs_synth_echo_cmd(&seq, synth);
CU_TEST(ret == 0);
+ CU_TEST(test_sql(&seq, SQL_6_MATCH));
tracefs_synth_free(synth);
trace_seq_reset(&seq);
@@ -3225,6 +3319,8 @@ void test_tracefs_lib(void)
}
CU_add_test(suite, "Test tracefs/debugfs mounting", test_mounting);
+ CU_add_test(suite, "trace sql",
+ test_trace_sql);
CU_add_test(suite, "trace cpu read",
test_trace_cpu_read);
CU_add_test(suite, "trace cpu read_buf_percent",
--
2.42.0
^ permalink raw reply related [flat|nested] 3+ messages in thread* [PATCH 2/2] libtracefs utest: Add more tests to test tracefs_sql()
2024-01-05 5:15 [PATCH 0/2] libtracefs: Add more tracefs_sql tests Steven Rostedt
2024-01-05 5:15 ` [PATCH 1/2] libtracefs utest: Add matches to trace_sql() tests Steven Rostedt
@ 2024-01-05 5:15 ` Steven Rostedt
1 sibling, 0 replies; 3+ messages in thread
From: Steven Rostedt @ 2024-01-05 5:15 UTC (permalink / raw)
To: linux-trace-devel; +Cc: Steven Rostedt (Google)
From: "Steven Rostedt (Google)" <rostedt@goodmis.org>
After finding out that the "save" command of tracefs_sql() was broken for
some time, I decided that all the tracefs_sql() features should be tested.
Add tests to test: onmax, onchange, onmatch with trace, snapshot, save, and
"trace and snapshot". And all those combinations.
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
utest/tracefs-utest.c | 317 ++++++++++++++++++++++++++++++++++++++----
1 file changed, 293 insertions(+), 24 deletions(-)
diff --git a/utest/tracefs-utest.c b/utest/tracefs-utest.c
index 5bc0d45c8996..f5afec0e338a 100644
--- a/utest/tracefs-utest.c
+++ b/utest/tracefs-utest.c
@@ -37,42 +37,74 @@
#define TRACE_ON "tracing_on"
#define TRACE_CLOCK "trace_clock"
+/* Used to insert sql types and actions, must be big enough to hold them */
+#define SQL_REPLACE "RRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRR"
+
#define SQL_1_EVENT "wakeup_1"
#define SQL_1_SQL "select sched_switch.next_pid as woke_pid, sched_waking.common_pid as waking_pid from sched_waking join sched_switch on sched_switch.next_pid = sched_waking.pid"
#define SQL_1_MATCH "echo 's:wakeup_1 pid_t woke_pid; s32 waking_pid;' >> /sys/kernel/tracing/dynamic_events\n" \
"echo 'hist:keys=pid:__arg_XXXXXXXX_1=common_pid' >> /sys/kernel/tracing/events/sched/sched_waking/trigger\n" \
- "echo 'hist:keys=next_pid:__woke_pid_XXXXXXXX_2=next_pid,__waking_pid_XXXXXXXX_3=$__arg_XXXXXXXX_1:onmatch(sched.sched_waking).trace(wakeup_1,$__woke_pid_XXXXXXXX_2,$__waking_pid_XXXXXXXX_3)' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
+ "echo 'hist:keys=next_pid:__woke_pid_XXXXXXXX_2=next_pid,__waking_pid_XXXXXXXX_3=$__arg_XXXXXXXX_1:" SQL_REPLACE "' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
+#define SQL_1_VAR "$__waking_pid_XXXXXXXX_3"
+#define SQL_1_ONMATCH "onmatch(sched.sched_waking)"
+#define SQL_1_TRACE "trace(wakeup_1,$__woke_pid_XXXXXXXX_2,$__waking_pid_XXXXXXXX_3)"
+#define SQL_1_SAVE { "prev_prio" , "prev_state", NULL }
#define SQL_2_EVENT "wakeup_2"
#define SQL_2_SQL "select woke.next_pid as woke_pid, wake.common_pid as waking_pid from sched_waking as wake join sched_switch as woke on woke.next_pid = wake.pid"
#define SQL_2_MATCH "echo 's:wakeup_2 pid_t woke_pid; s32 waking_pid;' >> /sys/kernel/tracing/dynamic_events\n" \
"echo 'hist:keys=pid:__arg_XXXXXXXX_1=common_pid' >> /sys/kernel/tracing/events/sched/sched_waking/trigger\n" \
- "echo 'hist:keys=next_pid:__woke_pid_XXXXXXXX_2=next_pid,__waking_pid_XXXXXXXX_3=$__arg_XXXXXXXX_1:onmatch(sched.sched_waking).trace(wakeup_2,$__woke_pid_XXXXXXXX_2,$__waking_pid_XXXXXXXX_3)' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
+ "echo 'hist:keys=next_pid:__woke_pid_XXXXXXXX_2=next_pid,__waking_pid_XXXXXXXX_3=$__arg_XXXXXXXX_1:" SQL_REPLACE "' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
+#define SQL_2_MATCH_EVENT "sched.sched_waking"
+#define SQL_2_VAR "$__woke_pid_XXXXXXXX_2"
+#define SQL_2_ONMATCH "onmatch(sched.sched_waking)"
+#define SQL_2_TRACE "trace(wakeup_2,$__woke_pid_XXXXXXXX_2,$__waking_pid_XXXXXXXX_3)"
+#define SQL_2_SAVE { "prev_prio" , "prev_state", NULL }
#define SQL_3_EVENT "wakeup_lat"
#define SQL_3_SQL "select sched_switch.next_prio as prio, end.prev_prio as pprio, (sched.sched_waking.common_timestamp.usecs - end.TIMESTAMP_USECS) as lat from sched_waking as start join sched_switch as end on start.pid = end.next_pid"
#define SQL_3_MATCH "echo 's:wakeup_lat s32 prio; s32 pprio; u64 lat;' >> /sys/kernel/tracing/dynamic_events\n" \
"echo 'hist:keys=pid:__arg_XXXXXXXX_1=common_timestamp.usecs' >> /sys/kernel/tracing/events/sched/sched_waking/trigger\n" \
- "echo 'hist:keys=next_pid:__prio_XXXXXXXX_2=next_prio,__pprio_XXXXXXXX_3=prev_prio,__lat_XXXXXXXX_4=common_timestamp.usecs-$__arg_XXXXXXXX_1:onmatch(sched.sched_waking).trace(wakeup_lat,$__prio_XXXXXXXX_2,$__pprio_XXXXXXXX_3,$__lat_XXXXXXXX_4)' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
+ "echo 'hist:keys=next_pid:__prio_XXXXXXXX_2=next_prio,__pprio_XXXXXXXX_3=prev_prio,__lat_XXXXXXXX_4=common_timestamp.usecs-$__arg_XXXXXXXX_1:" SQL_REPLACE "' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
+#define SQL_3_MATCH_EVENT "sched.sched_waking"
+#define SQL_3_VAR "$__lat_XXXXXXXX_4"
+#define SQL_3_ONMATCH "onmatch(sched.sched_waking)"
+#define SQL_3_TRACE "trace(wakeup_lat,$__prio_XXXXXXXX_2,$__pprio_XXXXXXXX_3,$__lat_XXXXXXXX_4)"
+#define SQL_3_SAVE { "prev_prio" , "prev_state", NULL }
#define SQL_4_EVENT "wakeup_lat_2"
#define SQL_4_SQL "select start.pid, end.next_prio as prio, (end.TIMESTAMP_USECS - start.TIMESTAMP_USECS) as lat from sched_waking as start join sched_switch as end on start.pid = end.next_pid where (start.prio >= 1 && start.prio < 100) || !(start.pid >= 0 && start.pid <= 1) && end.prev_pid != 0"
#define SQL_4_MATCH "echo 's:wakeup_lat_2 pid_t pid; s32 prio; u64 lat;' >> /sys/kernel/tracing/dynamic_events\n" \
"echo 'hist:keys=pid:__arg_XXXXXXXX_1=pid,__arg_XXXXXXXX_2=common_timestamp.usecs if (prio >= 1&&prio < 100)||!(pid >= 0&&pid <= 1)' >> /sys/kernel/tracing/events/sched/sched_waking/trigger\n" \
- "echo 'hist:keys=next_pid:__pid_XXXXXXXX_3=$__arg_XXXXXXXX_1,__prio_XXXXXXXX_4=next_prio,__lat_XXXXXXXX_5=common_timestamp.usecs-$__arg_XXXXXXXX_2:onmatch(sched.sched_waking).trace(wakeup_lat_2,$__pid_XXXXXXXX_3,$__prio_XXXXXXXX_4,$__lat_XXXXXXXX_5) if prev_pid != 0' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
+ "echo 'hist:keys=next_pid:__pid_XXXXXXXX_3=$__arg_XXXXXXXX_1,__prio_XXXXXXXX_4=next_prio,__lat_XXXXXXXX_5=common_timestamp.usecs-$__arg_XXXXXXXX_2:" SQL_REPLACE " if prev_pid != 0' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
+#define SQL_4_MATCH_EVENT "sched.sched_waking"
+#define SQL_4_VAR "$__lat_XXXXXXXX_5"
+#define SQL_4_ONMATCH "onmatch(sched.sched_waking)"
+#define SQL_4_TRACE "trace(wakeup_lat_2,$__pid_XXXXXXXX_3,$__prio_XXXXXXXX_4,$__lat_XXXXXXXX_5)"
+#define SQL_4_SAVE { "prev_prio" , "prev_state", NULL }
#define SQL_5_EVENT "irq_lat"
#define SQL_5_SQL "select end.common_pid as pid, (end.common_timestamp.usecs - start.common_timestamp.usecs) as irq_lat from irq_disable as start join irq_enable as end on start.common_pid = end.common_pid, start.parent_offs == end.parent_offs where start.common_pid != 0"
#define SQL_5_START "irq_disable"
#define SQL_5_MATCH "echo 's:irq_lat s32 pid; u64 irq_lat;' >> /sys/kernel/tracing/dynamic_events\n" \
"echo 'hist:keys=common_pid,parent_offs:__arg_XXXXXXXX_1=common_timestamp.usecs if common_pid != 0' >> /sys/kernel/tracing/events/preemptirq/irq_disable/trigger\n" \
- "echo 'hist:keys=common_pid,parent_offs:__pid_XXXXXXXX_2=common_pid,__irq_lat_XXXXXXXX_3=common_timestamp.usecs-$__arg_XXXXXXXX_1:onmatch(preemptirq.irq_disable).trace(irq_lat,$__pid_XXXXXXXX_2,$__irq_lat_XXXXXXXX_3)' >> /sys/kernel/tracing/events/preemptirq/irq_enable/trigger\n"
+ "echo 'hist:keys=common_pid,parent_offs:__pid_XXXXXXXX_2=common_pid,__irq_lat_XXXXXXXX_3=common_timestamp.usecs-$__arg_XXXXXXXX_1:" SQL_REPLACE "' >> /sys/kernel/tracing/events/preemptirq/irq_enable/trigger\n"
+#define SQL_5_MATCH_EVENT "preemptirq.irq_disable"
+#define SQL_5_VAR "$__irq_lat_XXXXXXXX_3"
+#define SQL_5_ONMATCH "onmatch(preemptirq.irq_disable)"
+#define SQL_5_TRACE "trace(irq_lat,$__pid_XXXXXXXX_2,$__irq_lat_XXXXXXXX_3)"
+#define SQL_5_SAVE { "caller_offs", NULL }
#define SQL_6_EVENT "wakeup_lat_3"
#define SQL_6_SQL "select start.pid, end.next_prio as prio, (end.TIMESTAMP_USECS - start.TIMESTAMP_USECS) as lat from sched_waking as start join sched_switch as end on start.pid = end.next_pid where (start.prio >= 1 && start.prio < 100) || !(start.pid >= 0 && start.pid <= 1) && end.prev_pid != 0"
#define SQL_6_MATCH "echo 's:wakeup_lat_3 pid_t pid; s32 prio; u64 lat;' >> /sys/kernel/tracing/dynamic_events\n" \
"echo 'hist:keys=pid:__arg_XXXXXXXX_1=pid,__arg_XXXXXXXX_2=common_timestamp.usecs if (prio >= 1&&prio < 100)||!(pid >= 0&&pid <= 1)' >> /sys/kernel/tracing/events/sched/sched_waking/trigger\n" \
- "echo 'hist:keys=next_pid:__pid_XXXXXXXX_3=$__arg_XXXXXXXX_1,__prio_XXXXXXXX_4=next_prio,__lat_XXXXXXXX_5=common_timestamp.usecs-$__arg_XXXXXXXX_2:onmatch(sched.sched_waking).trace(wakeup_lat_3,$__pid_XXXXXXXX_3,$__prio_XXXXXXXX_4,$__lat_XXXXXXXX_5) if prev_pid != 0' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
+ "echo 'hist:keys=next_pid:__pid_XXXXXXXX_3=$__arg_XXXXXXXX_1,__prio_XXXXXXXX_4=next_prio,__lat_XXXXXXXX_5=common_timestamp.usecs-$__arg_XXXXXXXX_2:" SQL_REPLACE " if prev_pid != 0' >> /sys/kernel/tracing/events/sched/sched_switch/trigger\n"
+#define SQL_6_MATCH_EVENT "sched.sched_waking"
+#define SQL_6_VAR "$__lat_XXXXXXXX_5"
+#define SQL_6_ONMATCH "onmatch(sched.sched_waking)"
+#define SQL_6_TRACE "trace(wakeup_lat_3,$__pid_XXXXXXXX_3,$__prio_XXXXXXXX_4,$__lat_XXXXXXXX_5)"
+#define SQL_6_SAVE { "prev_prio" , "prev_state", NULL }
#define DEBUGFS_DEFAULT_PATH "/sys/kernel/debug"
#define TRACEFS_DEFAULT_PATH "/sys/kernel/tracing"
@@ -431,8 +463,10 @@ static void replace_str(char *str, char *rep, char *with, int rep_len, int with_
int delta = rep_len - with_len;
CU_TEST(delta >= 0);
- if (delta < 0)
+ if (delta < 0) {
+ printf("rep_len:%d with_len:%d\n", rep_len, with_len);
return;
+ }
strncpy(find, rep, rep_len + 1);
find[rep_len] = '\0';
@@ -448,19 +482,81 @@ static void replace_str(char *str, char *rep, char *with, int rep_len, int with_
}
}
-static bool test_sql(struct trace_seq *seq, const char *match)
+enum sql_type {
+ SQL_ONMATCH,
+ SQL_ONMAX,
+ SQL_ONCHANGE,
+};
+
+enum sql_action {
+ SQL_TRACE,
+ SQL_SNAPSHOT,
+ SQL_SAVE,
+ SQL_TRACE_SNAPSHOT,
+};
+
+struct trace_sql_strings {
+ const char *match;
+ const char *onmatch;
+ const char *var;
+ const char *trace;
+ char *save[4];
+};
+
+#define SQL_VAR_REPLACE "_XXXXXXXX_"
+
+static bool test_sql(struct trace_seq *seq, struct trace_sql_strings *strings,
+ enum sql_type stype, enum sql_action atype)
{
- char string[strlen(match) + 64]; /* add some buffer room */
+ char string[strlen(strings->match) + 256]; /* add a bunch for replacement */
+ char replace[1024];
+ char type[256];
char *p, *s, *e, *c = seq->buffer;
bool ret;
- strcpy(string, match);
+ strcpy(string, strings->match);
s = string;
- while ((p = strstr(s, "_XXXXXXXX_"))) {
+ switch (stype) {
+ case SQL_ONMATCH:
+ sprintf(type, "%s", strings->onmatch);
+ break;
+ case SQL_ONMAX:
+ sprintf(type, "onmax(%s)", strings->var);
+ break;
+ case SQL_ONCHANGE:
+ sprintf(type, "onchange(%s)", strings->var);
+ break;
+ }
+
+ switch (atype) {
+ case SQL_TRACE:
+ sprintf(replace, "%s.%s", type, strings->trace);
+ break;
+ case SQL_SNAPSHOT:
+ sprintf(replace, "%s.snapshot()", type);
+ break;
+ case SQL_SAVE:
+ sprintf(replace, "%s.save(", type);
+
+ for (int i = 0; strings->save[i]; i++) {
+ if (i)
+ strcat(replace, ",");
+ strcat(replace, strings->save[i]);
+ }
+ strcat(replace, ")");
+ break;
+ case SQL_TRACE_SNAPSHOT:
+ sprintf(replace, "%s.%s:%s.snapshot()", type, strings->trace, type);
+ break;
+ }
+
+ replace_str(string, SQL_REPLACE, replace, strlen(SQL_REPLACE), strlen(replace));
+
+ while ((p = strstr(s, SQL_VAR_REPLACE))) {
CU_TEST(ret = strncmp(c, s, p - s) == 0);
if (!ret) {
- printf("\n'%*.s'\n\tdoes not match\n%*.s\n",
+ printf("\n\t'%*.s'\nDOES NOT MATCH\n\t%*.s\n",
(int)(p - s), c, (int)(p - s), s);
return ret;
}
@@ -479,7 +575,7 @@ static bool test_sql(struct trace_seq *seq, const char *match)
e++;
/* Skip the "_XXXXXXXX_" */
- s = p + 10;
+ s = p + strlen(SQL_VAR_REPLACE);
/* Skip the next numbers */
while (isdigit(*s))
s++;
@@ -490,69 +586,187 @@ static bool test_sql(struct trace_seq *seq, const char *match)
c = e;
}
- return strcmp(s, c) == 0;
+ ret = strcmp(s, c) == 0;
+ if (!ret)
+ printf("\n\t'%s'\nDOES NOT MATCH\n\t%s\n", s, c);
+
+ return ret;
+}
+
+static void unhash_var(char *var, const char *hash_var)
+{
+ const char *p = hash_var + strlen(hash_var) - 1;
+ int len;
+
+ /* Skip $__ */
+ hash_var += 3;
+
+ /* Find the _XXXXXXXXX_ */
+ p = strstr(hash_var, SQL_VAR_REPLACE);
+ CU_TEST(p != NULL);
+
+ len = p - hash_var;
+
+ strncpy(var, hash_var, len);
+ var[len] = '\0';
+}
+
+static bool set_sql_type(struct tracefs_synth *synth, struct trace_sql_strings *strings,
+ enum sql_type stype, enum sql_action atype)
+{
+ enum tracefs_synth_handler handler = 0;
+ char var[256];
+ int ret = 0;
+
+ switch (stype) {
+ case SQL_ONMATCH:
+ break;
+ case SQL_ONMAX:
+ handler = TRACEFS_SYNTH_HANDLE_MAX;
+ break;
+ case SQL_ONCHANGE:
+ handler = TRACEFS_SYNTH_HANDLE_CHANGE;
+ break;
+ }
+
+ unhash_var(var, strings->var);
+
+ switch (atype) {
+ case SQL_TRACE:
+ if (handler)
+ ret = tracefs_synth_trace(synth, handler, var);
+ break;
+ case SQL_SNAPSHOT:
+ ret = tracefs_synth_snapshot(synth, handler, var);
+ break;
+ case SQL_SAVE:
+ ret = tracefs_synth_save(synth, handler, var, strings->save);
+ break;
+ case SQL_TRACE_SNAPSHOT:
+ ret = tracefs_synth_trace(synth, handler, var);
+ ret |= tracefs_synth_snapshot(synth, handler, var);
+ break;
+ }
+
+ return ret == 0;
}
-static void test_instance_trace_sql(struct tracefs_instance *instance)
+#define sql_assign_save(str, arr) \
+ do { \
+ char *__array__[] = arr; \
+ int i; \
+ \
+ for (i = 0; __array__[i]; i++) { \
+ (str)[i] = __array__[i]; \
+ } \
+ (str)[i] = NULL; \
+ } while (0)
+
+static void test_instance_trace_sql(struct tracefs_instance *instance,
+ enum sql_type stype, enum sql_action atype)
{
struct tracefs_synth *synth;
struct trace_seq seq;
struct tep_handle *tep;
struct tep_event *event;
+ struct trace_sql_strings strings;
int ret;
tep = test_tep;
trace_seq_init(&seq);
+ strings.match = SQL_1_MATCH;
+ strings.var = SQL_1_VAR;
+ strings.onmatch = SQL_1_ONMATCH;
+ strings.trace = SQL_1_TRACE;
+ sql_assign_save(strings.save, SQL_1_SAVE);
+
synth = tracefs_sql(tep, SQL_1_EVENT, SQL_1_SQL, NULL);
CU_TEST(synth != NULL);
+ CU_TEST(set_sql_type(synth, &strings, stype, atype));
ret = tracefs_synth_echo_cmd(&seq, synth);
CU_TEST(ret == 0);
- CU_TEST(test_sql(&seq, SQL_1_MATCH));
+ CU_TEST(test_sql(&seq, &strings, stype, atype));
tracefs_synth_free(synth);
trace_seq_reset(&seq);
+ strings.match = SQL_2_MATCH;
+ strings.var = SQL_2_VAR;
+ strings.onmatch = SQL_2_ONMATCH;
+ strings.trace = SQL_2_TRACE;
+ sql_assign_save(strings.save, SQL_2_SAVE);
+
synth = tracefs_sql(tep, SQL_2_EVENT, SQL_2_SQL, NULL);
CU_TEST(synth != NULL);
+ CU_TEST(set_sql_type(synth, &strings, stype, atype));
ret = tracefs_synth_echo_cmd(&seq, synth);
CU_TEST(ret == 0);
- CU_TEST(test_sql(&seq, SQL_2_MATCH));
+ CU_TEST(test_sql(&seq, &strings, stype, atype));
tracefs_synth_free(synth);
trace_seq_reset(&seq);
+ strings.match = SQL_3_MATCH;
+ strings.var = SQL_3_VAR;
+ strings.onmatch = SQL_3_ONMATCH;
+ strings.trace = SQL_3_TRACE;
+ sql_assign_save(strings.save, SQL_3_SAVE);
+
synth = tracefs_sql(tep, SQL_3_EVENT, SQL_3_SQL, NULL);
CU_TEST(synth != NULL);
+ CU_TEST(set_sql_type(synth, &strings, stype, atype));
ret = tracefs_synth_echo_cmd(&seq, synth);
CU_TEST(ret == 0);
- CU_TEST(test_sql(&seq, SQL_3_MATCH));
+ CU_TEST(test_sql(&seq, &strings, stype, atype));
tracefs_synth_free(synth);
trace_seq_reset(&seq);
+ strings.match = SQL_4_MATCH;
+ strings.var = SQL_4_VAR;
+ strings.onmatch = SQL_4_ONMATCH;
+ strings.trace = SQL_4_TRACE;
+ sql_assign_save(strings.save, SQL_4_SAVE);
+
synth = tracefs_sql(tep, SQL_4_EVENT, SQL_4_SQL, NULL);
CU_TEST(synth != NULL);
+ CU_TEST(set_sql_type(synth, &strings, stype, atype));
ret = tracefs_synth_echo_cmd(&seq, synth);
CU_TEST(ret == 0);
- CU_TEST(test_sql(&seq, SQL_4_MATCH));
+ CU_TEST(test_sql(&seq, &strings, stype, atype));
tracefs_synth_free(synth);
trace_seq_reset(&seq);
event = tep_find_event_by_name(tep, NULL, SQL_5_START);
if (event) {
+
+ strings.match = SQL_5_MATCH;
+ strings.var = SQL_5_VAR;
+ strings.onmatch = SQL_5_ONMATCH;
+ strings.trace = SQL_5_TRACE;
+ sql_assign_save(strings.save, SQL_5_SAVE);
+
synth = tracefs_sql(tep, SQL_5_EVENT, SQL_5_SQL, NULL);
CU_TEST(synth != NULL);
+ CU_TEST(set_sql_type(synth, &strings, stype, atype));
ret = tracefs_synth_echo_cmd(&seq, synth);
CU_TEST(ret == 0);
- CU_TEST(test_sql(&seq, SQL_5_MATCH));
+ CU_TEST(test_sql(&seq, &strings, stype, atype));
tracefs_synth_free(synth);
trace_seq_reset(&seq);
}
+ strings.match = SQL_6_MATCH;
+ strings.var = SQL_6_VAR;
+ strings.onmatch = SQL_6_ONMATCH;
+ strings.trace = SQL_6_TRACE;
+ sql_assign_save(strings.save, SQL_6_SAVE);
+
synth = tracefs_sql(tep, SQL_6_EVENT, SQL_6_SQL, NULL);
CU_TEST(synth != NULL);
+ CU_TEST(set_sql_type(synth, &strings, stype, atype));
ret = tracefs_synth_echo_cmd(&seq, synth);
CU_TEST(ret == 0);
- CU_TEST(test_sql(&seq, SQL_6_MATCH));
+ CU_TEST(test_sql(&seq, &strings, stype, atype));
tracefs_synth_free(synth);
trace_seq_reset(&seq);
@@ -561,9 +775,50 @@ static void test_instance_trace_sql(struct tracefs_instance *instance)
static void test_trace_sql(void)
{
- test_instance_trace_sql(test_instance);
+ test_instance_trace_sql(test_instance, SQL_ONMATCH, SQL_TRACE);
+}
+
+static void test_trace_sql_trace_onmax(void)
+{
+ test_instance_trace_sql(test_instance, SQL_ONMAX, SQL_TRACE);
+}
+
+static void test_trace_sql_trace_onchange(void)
+{
+ test_instance_trace_sql(test_instance, SQL_ONCHANGE, SQL_TRACE);
}
+static void test_trace_sql_snapshot_onmax(void)
+{
+ test_instance_trace_sql(test_instance, SQL_ONMAX, SQL_SNAPSHOT);
+}
+
+static void test_trace_sql_snapshot_onchange(void)
+{
+ test_instance_trace_sql(test_instance, SQL_ONCHANGE, SQL_SNAPSHOT);
+}
+
+static void test_trace_sql_save_onmax(void)
+{
+ test_instance_trace_sql(test_instance, SQL_ONMAX, SQL_SAVE);
+}
+
+static void test_trace_sql_save_onchange(void)
+{
+ test_instance_trace_sql(test_instance, SQL_ONCHANGE, SQL_SAVE);
+}
+
+static void test_trace_sql_trace_snapshot_onmax(void)
+{
+ test_instance_trace_sql(test_instance, SQL_ONMAX, SQL_TRACE_SNAPSHOT);
+}
+
+static void test_trace_sql_trace_snapshot_onchange(void)
+{
+ test_instance_trace_sql(test_instance, SQL_ONCHANGE, SQL_TRACE_SNAPSHOT);
+}
+
+
static void call_getppid(int cnt)
{
int i;
@@ -3319,8 +3574,6 @@ void test_tracefs_lib(void)
}
CU_add_test(suite, "Test tracefs/debugfs mounting", test_mounting);
- CU_add_test(suite, "trace sql",
- test_trace_sql);
CU_add_test(suite, "trace cpu read",
test_trace_cpu_read);
CU_add_test(suite, "trace cpu read_buf_percent",
@@ -3333,6 +3586,22 @@ void test_tracefs_lib(void)
test_trace_function_pid_filter);
CU_add_test(suite, "trace sql",
test_trace_sql);
+ CU_add_test(suite, "trace sql trace onmax",
+ test_trace_sql_trace_onmax);
+ CU_add_test(suite, "trace sql trace onchange",
+ test_trace_sql_trace_onchange);
+ CU_add_test(suite, "trace sql snapshot onmax",
+ test_trace_sql_snapshot_onmax);
+ CU_add_test(suite, "trace sql snapshot onchange",
+ test_trace_sql_snapshot_onchange);
+ CU_add_test(suite, "trace sql save onmax",
+ test_trace_sql_save_onmax);
+ CU_add_test(suite, "trace sql save onchange",
+ test_trace_sql_save_onchange);
+ CU_add_test(suite, "trace sql trace and snapshot onmax",
+ test_trace_sql_trace_snapshot_onmax);
+ CU_add_test(suite, "trace sql trace and snapshot onchange",
+ test_trace_sql_trace_snapshot_onchange);
CU_add_test(suite, "tracing file / directory APIs",
test_trace_file);
CU_add_test(suite, "instance file / directory APIs",
--
2.42.0
^ permalink raw reply related [flat|nested] 3+ messages in thread