perf trace: Add augmenter for clock_gettime's rqtp timespec arg
authorArnaldo Carvalho de Melo <acme@redhat.com>
Thu, 10 Nov 2022 18:30:10 +0000 (15:30 -0300)
committerArnaldo Carvalho de Melo <acme@redhat.com>
Thu, 10 Nov 2022 18:30:10 +0000 (15:30 -0300)
One more before going the BTF way:

  # perf trace -e /home/acme/git/perf/tools/perf/examples/bpf/augmented_raw_syscalls.o,*nanosleep
         ? pool-gsd-smart/2893  ... [continued]: clock_nanosleep())    = 0
         ? gpm/1042  ... [continued]: clock_nanosleep())    = 0
     1.232 pool-gsd-smart/2893 clock_nanosleep(rqtp: { .tv_sec: 1, .tv_nsec: 0 }, rmtp: 0x7f64d7ffec50) ...
     1.232 pool-gsd-smart/2893  ... [continued]: clock_nanosleep())    = 0
   327.329 gpm/1042 clock_nanosleep(rqtp: { .tv_sec: 2, .tv_nsec: 0 }, rmtp: 0x7ffddfd1cf20) ...
  1002.482 pool-gsd-smart/2893 clock_nanosleep(rqtp: { .tv_sec: 1, .tv_nsec: 0 }, rmtp: 0x7f64d7ffec50) = 0
   327.329 gpm/1042  ... [continued]: clock_nanosleep())    = 0
  2003.947 pool-gsd-smart/2893 clock_nanosleep(rqtp: { .tv_sec: 1, .tv_nsec: 0 }, rmtp: 0x7f64d7ffec50) ...
  2003.947 pool-gsd-smart/2893  ... [continued]: clock_nanosleep())    = 0
  2327.858 gpm/1042 clock_nanosleep(rqtp: { .tv_sec: 2, .tv_nsec: 0 }, rmtp: 0x7ffddfd1cf20) ...
         ? crond/1384  ... [continued]: clock_nanosleep())    = 0
  3005.382 pool-gsd-smart/2893 clock_nanosleep(rqtp: { .tv_sec: 1, .tv_nsec: 0 }, rmtp: 0x7f64d7ffec50) ...
  3005.382 pool-gsd-smart/2893  ... [continued]: clock_nanosleep())    = 0
  3675.633 crond/1384 clock_nanosleep(rqtp: { .tv_sec: 60, .tv_nsec: 0 }, rmtp: 0x7ffcc02b66b0) ...
^C#

Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
tools/perf/builtin-trace.c
tools/perf/examples/bpf/augmented_raw_syscalls.c
tools/perf/trace/beauty/Build
tools/perf/trace/beauty/beauty.h
tools/perf/trace/beauty/timespec.c [new file with mode: 0644]

index 5690c33c523b37d740bb49c48823cff0a381a897..c93b359abc312ac82688dbed69cd2c51c50a40db 100644 (file)
@@ -924,6 +924,8 @@ static struct syscall_fmt syscall_fmts[] = {
          .arg = { [0] = { .scnprintf = SCA_PTR, /* brk */ }, }, },
        { .name     = "clock_gettime",
          .arg = { [0] = STRARRAY(clk_id, clockid), }, },
+       { .name     = "clock_nanosleep",
+         .arg = { [2] = { .scnprintf = SCA_TIMESPEC,  /* rqtp */ }, }, },
        { .name     = "clone",      .errpid = true, .nr_args = 5,
          .arg = { [0] = { .name = "flags",         .scnprintf = SCA_CLONE_FLAGS, },
                   [1] = { .name = "child_stack",   .scnprintf = SCA_HEX, },
index 0599823e8ae1b4c071e3388f255925fbde942a07..7dc24c9173a753fd09e283a28d24c8abaebfefb6 100644 (file)
 // FIXME: These should come from system headers
 typedef char bool;
 typedef int pid_t;
+typedef long long int __s64;
+typedef __s64 time64_t;
+
+struct timespec64 {
+       time64_t        tv_sec;
+       long int        tv_nsec;
+};
 
 /* bpf-output associated map */
 struct __augmented_syscalls__ {
@@ -337,6 +344,27 @@ failure:
        return 1; /* Failure: don't filter */
 }
 
+SEC("!syscalls:sys_enter_clock_nanosleep")
+int sys_enter_clock_nanosleep(struct syscall_enter_args *args)
+{
+       struct augmented_args_payload *augmented_args = augmented_args_payload();
+       const void *rqtp_arg = (const void *)args->args[2];
+       unsigned int len = sizeof(augmented_args->args);
+       __u32 size = sizeof(struct timespec64);
+
+        if (augmented_args == NULL)
+               goto failure;
+
+       if (size > sizeof(augmented_args->__data))
+                goto failure;
+
+       bpf_probe_read(&augmented_args->__data, size, rqtp_arg);
+
+       return augmented__output(args, augmented_args, len + size);
+failure:
+       return 1; /* Failure: don't filter */
+}
+
 static pid_t getpid(void)
 {
        return bpf_get_current_pid_tgid();
index 433dc39053a7f0fbe7e58466110e403b62b3fe07..d11ce256f511403432a55721b88cae91733dee05 100644 (file)
@@ -17,4 +17,5 @@ perf-y += sockaddr.o
 perf-y += socket.o
 perf-y += statx.o
 perf-y += sync_file_range.o
+perf-y += timespec.o
 perf-y += tracepoints/
index f527a46ab4e728e0671f0f96fc9d718e754c2a76..4c59edddd6a878fa0b0ab35e111cdcbe364fee68 100644 (file)
@@ -244,6 +244,9 @@ size_t syscall_arg__scnprintf_statx_mask(char *bf, size_t size, struct syscall_a
 size_t syscall_arg__scnprintf_sync_file_range_flags(char *bf, size_t size, struct syscall_arg *arg);
 #define SCA_SYNC_FILE_RANGE_FLAGS syscall_arg__scnprintf_sync_file_range_flags
 
+size_t syscall_arg__scnprintf_timespec(char *bf, size_t size, struct syscall_arg *arg);
+#define SCA_TIMESPEC syscall_arg__scnprintf_timespec
+
 size_t open__scnprintf_flags(unsigned long flags, char *bf, size_t size, bool show_prefix);
 
 void syscall_arg__set_ret_scnprintf(struct syscall_arg *arg,
diff --git a/tools/perf/trace/beauty/timespec.c b/tools/perf/trace/beauty/timespec.c
new file mode 100644 (file)
index 0000000..e1a61f0
--- /dev/null
@@ -0,0 +1,21 @@
+// SPDX-License-Identifier: LGPL-2.1
+// Copyright (C) 2022, Red Hat Inc, Arnaldo Carvalho de Melo <acme@redhat.com>
+
+#include "trace/beauty/beauty.h"
+#include <inttypes.h>
+#include <time.h>
+
+static size_t syscall_arg__scnprintf_augmented_timespec(struct syscall_arg *arg, char *bf, size_t size)
+{
+       struct timespec *ts = (struct timespec *)arg->augmented.args;
+
+       return scnprintf(bf, size, "{ .tv_sec: %" PRIu64 ", .tv_nsec: %" PRIu64 " }", ts->tv_sec, ts->tv_nsec);
+}
+
+size_t syscall_arg__scnprintf_timespec(char *bf, size_t size, struct syscall_arg *arg)
+{
+       if (arg->augmented.args)
+               return syscall_arg__scnprintf_augmented_timespec(arg, bf, size);
+
+       return scnprintf(bf, size, "%#lx", arg->val);
+}