Handle tr end async trace events

Kernel commit https://lore.kernel.org/lkml/[email protected]/ set `PERF_IP_FLAG_ASYNC` on trace end events. As per https://github.com/torvalds/linux/blob/7ee022567bf9e2e0b3cd92461a2f4986ecc99673/tools/perf/builtin-script.c#L1546 This means that where `perf` would have previously outputted `tr end jmp`, it now outputs `tr end async`. Adjust our regex to allow `async`, and treat it as a branch. Signed-off-by: Tudor Brindus <[email protected]>
janestreet · Jan 10, 2024 · 3b73ef9 · 3b73ef9
1 parent 1087cbf
commit 3b73ef9
Show file tree

Hide file tree

Showing 4 changed files with 21 additions and 3 deletions.
diff --git a/core/event.ml b/core/event.ml
@@ -2,6 +2,7 @@ open! Core
 
 module Kind = struct
   type t =
+    | Async
     | Call
     | Return
     | Syscall

diff --git a/core/event.mli b/core/event.mli
@@ -2,6 +2,7 @@ open! Core
 
 module Kind : sig
   type t =
+    | Async
     | Call
     | Return
     | Syscall

diff --git a/src/perf_decode.ml b/src/perf_decode.ml
@@ -22,7 +22,7 @@ let perf_callstack_entry_re = Re.Perl.re "^\t *([0-9a-f]+) (.*)$" |> Re.compile
 
 let perf_branches_event_re =
   Re.Perl.re
-    {|^ *(call|return|tr strt|syscall|sysret|hw int|iret|tr end|tr strt tr end|tr end  (?:call|return|syscall|sysret|iret)|jmp|jcc) +([0-9a-f]+) (.*) => +([0-9a-f]+) (.*)$|}
+    {|^ *(call|return|tr strt|syscall|sysret|hw int|iret|tr end|tr strt tr end|tr end  (?:async|call|return|syscall|sysret|iret)|jmp|jcc) +([0-9a-f]+) (.*) => +([0-9a-f]+) (.*)$|}
   |> Re.compile
 ;;
 
@@ -262,6 +262,7 @@ let parse_perf_branches_event ?perf_maps (thread : Event.Thread.t) time line : E
       | "hw int" -> Some Hardware_interrupt
       | "iret" -> Some Iret
       | "sysret" -> Some Sysret
+      | "async" -> Some Async
       | "" -> None
       | _ ->
         printf "Warning: skipping unrecognized perf output: %s\n%!" line;
@@ -688,6 +689,18 @@ let%test_module _ =
           ((thread ((pid (25375)) (tid (25375)))) (time 52d4h33m11.343298468s)
            (data (Trace (kind Call) (src 0x7f6fce0b71f4) (dst 0x7ffd193838e0)))))) |}]
     ;;
+
+    let%expect_test "tr end  async" =
+      check
+        {| 25375/25375 4509191.343298468:                            1   branches:uH:   tr end  async                     7f6fce0b71f4 [unknown] (foo.so) =>     0 [unknown] ([unknown])|};
+      [%expect
+        {|
+        ((Ok
+          ((thread ((pid (25375)) (tid (25375)))) (time 52d4h33m11.343298468s)
+           (data
+            (Trace (trace_state_change End) (kind Async) (src 0x7f6fce0b71f4)
+             (dst 0x0)))))) |}]
+    ;;
   end)
 ;;
 

diff --git a/src/trace_writer.ml b/src/trace_writer.ml
@@ -1032,16 +1032,19 @@ let write_event (T t) ?events_writer event =
          ~time;
        (match kind, trace_state_change with
         | Some Call, (None | Some End) -> call t thread_info ~time ~location:dst
-        | ( Some (Call | Syscall | Return | Hardware_interrupt | Iret | Sysret | Jump)
+        | ( Some
+              (Async | Call | Syscall | Return | Hardware_interrupt | Iret | Sysret | Jump)
           , Some Start )
+        | Some Async, None
         | Some (Hardware_interrupt | Jump), Some End ->
           raise_s
             [%message
               "BUG: magic-trace devs thought this event was impossible, but you just \
                proved them wrong. Please report this to \
                https://github.com/janestreet/magic-trace/issues/"
                 (event : Event.t)]
-        | None, Some End -> call t thread_info ~time ~location:Event.Location.untraced
+        | (None | Some Async), Some End ->
+          call t thread_info ~time ~location:Event.Location.untraced
         | Some Syscall, Some End ->
           (* We should only be getting these under /u *)
           assert_trace_scope t outer_event [ Userspace ];