non matching read_format: perf script fails when combining sampling group with trace event

non matching read_format: perf script fails when combining sampling group with trace event

[Milian Wolff]

[-- Attachment #1: Type: text/plain, Size: 2232 bytes --]

Hey all,

I've spotted this strange behavior:

$ perf record -e '{cycles,instructions}:PS' -e sched:sched_switch --switch-
events sleep 1
trace-cmd: No such file or directory
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.014 MB perf.data (15 samples) ]
$ perf script --show-switch-events
trace-cmd: No such file or directory
non matching read_format

When I use 'cycles' instead of '{cycles,instructions}', the above works as 
expected:

$ perf record -e 'cycles:PS' -e sched:sched_switch --switch-events sleep 1               
trace-cmd: No such file or directory
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.013 MB perf.data (8 samples) ]
$ perf script --show-switch-events
trace-cmd: No such file or directory
            perf  9777 457715.655901: 281474975716438          cycles:PS:  
ffffffff8105ef84 native_write_msr ([kernel.kallsyms])
            perf  9777 457715.655904: 281474975714469          cycles:PS:  
ffffffff8105ef84 native_write_msr ([kernel.kallsyms])
            perf  9777 457715.655905: 281474975712795          cycles:PS:  
ffffffff8105ef84 native_write_msr ([kernel.kallsyms])
            perf  9777 457715.655907: 281474975712801          cycles:PS:  
ffffffff8105ef84 native_write_msr ([kernel.kallsyms])
            perf  9777 457715.655908: 281474975712804          cycles:PS:  
ffffffff8105ef84 native_write_msr ([kernel.kallsyms])
            perf  9777 457715.655911: 281474975717052          cycles:PS:  
ffffffff813079e6 memcpy_erms ([kernel.kallsyms])
           sleep  9777 457715.655946: 281474975838141          cycles:PS:  
ffffffff8120b2da __fput ([kernel.kallsyms])
           sleep  9777 [002] 457715.656254: sched:sched_switch: 
prev_comm=sleep prev_pid=9777 prev_prio=120 prev_state=S ==> 
next_comm=swapper/2 next_pid=0 next_prio=120
           sleep  9777 457715.656254: PERF_RECORD_SWITCH OUT
           sleep  9777 457716.656361: PERF_RECORD_SWITCH IN

Can someone explain what's going on here? This smells like a bug to me.

Thanks
-- 
Milian Wolff | milian.wolff@kdab.com | Senior Software Engineer
KDAB (Deutschland) GmbH, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt, C++ and OpenGL Experts

[-- Attachment #2: smime.p7s --]
[-- Type: application/pkcs7-signature, Size: 3826 bytes --]