Tracing sched_switch events for client application when process is switched back in

[Milian Wolff <milian.wolff@kdab.com>]

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

Hey all,

when you have an application like this:

~~~~~~
#include <unistd.h>

int main()
{
   for (int i = 0; i < 100; ++i) {
       usleep(10);
   }
}
~~~~~~

Then record sched:sched_switch events for it:

~~~~~~
$ perf record -e sched:sched_switch ./a.out 
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.031 MB perf.data (100 samples) ]
~~~~~~

Note how it's only 100 samples, instead of 200 for both, the switch-out and 
switch-in events. Apparently we only get the switch-out events:

~~~~~
$ perf script -F trace | uniq -c
     99 a.out:3994 [120] S ==> swapper/7:0 [120]
      1 a.out:3994 [120] S ==> swapper/7:0 [1
~~~~~

Doing a global trace, or using LTTNG, we also see the switch-in events:

~~~~~
$ perf record -e sched:sched_switch -a ./a.out 
$ perf script -F trace | grep a.out | sort | uniq -c
    100 a.out:11570 [120] S ==> swapper/4:0 [120]
      1 a.out:11570 [120] x ==> swapper/4:0 [120]
    100 swapper/4:0 [120] R ==> a.out:11570 [120]
~~~~~

Is there any way I can get both sched switch events, i.e. not only the one 
with prev_tid=$client_tid, but also the one with next_tid=$client_tid? One way 
that seems to work is the following:

~~~~~
$ perf record -e sched:sched_switch --filter 'prev_comm=="a.out" || 
next_comm=="a.out"' -a ./a.out 
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 1.499 MB perf.data (201 samples) ]
$ perf script -F trace | grep a.out | sort | uniq -c
      1 akonadi_notes_a:2160 [120] S ==> a.out:14710 [120]
      3 a.out:14710 [120] S ==> swapper/2:0 [120]
     97 a.out:14710 [120] S ==> swapper/6:0 [120]
      1 a.out:14710 [120] x ==> swapper/6:0 [120]
      1 ksoftirqd/6:47 [120] S ==> a.out:14710 [120]
      1 mysqld:14707 [120] S ==> a.out:14710 [120]
      1 QDBusConnection:2140 [120] S ==> a.out:14710 [120]
      1 QDBusConnection:2213 [120] S ==> a.out:14710 [120]
      2 swapper/2:0 [120] R ==> a.out:14710 [120]
     93 swapper/6:0 [120] R ==> a.out:14710 [120]
~~~~~

The above workaround will not work for more complex applications, with 
secondary threads that can have different comm names. So:

Where is the "default" filtering done, which simply drops all events from 
sources that do not match the pid of the created process? I assume this 
happens in kernel space? Could it be adapted to also include switch_switch 
events when next_tid belongs to the pid we use for filtering?

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

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