* Sampling on sched:sched_switch
@ 2015-04-13 13:04 sahil aggarwal
2015-04-13 15:11 ` Arnaldo Carvalho de Melo
0 siblings, 1 reply; 10+ messages in thread
From: sahil aggarwal @ 2015-04-13 13:04 UTC (permalink / raw)
To: linux-perf-users
Hi
I am enabling sampling on tracepoint: sched:sched_switch, during which
i get no data points for a particular process but when i run:
perf stat -e "context_switch" <some exec>
then it shows that exec was context switched.
How it could be possible.?
Thanks
Regards
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Sampling on sched:sched_switch
2015-04-13 13:04 Sampling on sched:sched_switch sahil aggarwal
@ 2015-04-13 15:11 ` Arnaldo Carvalho de Melo
2015-04-14 5:42 ` sahil aggarwal
0 siblings, 1 reply; 10+ messages in thread
From: Arnaldo Carvalho de Melo @ 2015-04-13 15:11 UTC (permalink / raw)
To: sahil aggarwal; +Cc: linux-perf-users
Em Mon, Apr 13, 2015 at 06:34:38PM +0530, sahil aggarwal escreveu:
> Hi
>
> I am enabling sampling on tracepoint: sched:sched_switch, during which
> i get no data points for a particular process but when i run:
"sampling" what target? System wide? How are you setting up
perf_event_attr?
> perf stat -e "context_switch" <some exec>
s/context_switch/sched:sched_switch/g, right?
> then it shows that exec was context switched.
>
> How it could be possible.?
Why would it not?
[root@zoo ~]# perf stat -e sched:sched_switch usleep 1
Performance counter stats for 'usleep 1':
1 sched:sched_switch
0.001180692 seconds time elapsed
[root@zoo ~]#
[root@zoo ~]# perf trace --ev sched:sched_switch usleep 1 | tail
0.407 ( 0.004 ms): usleep/9676 mprotect(start: 0x601000, len: 4096, prot: READ ) = 0
0.417 ( 0.005 ms): usleep/9676 mprotect(start: 0x7f1649452000, len: 4096, prot: READ) = 0
0.429 ( 0.010 ms): usleep/9676 munmap(addr: 0x7f1649436000, len: 108577 ) = 0
0.495 ( 0.002 ms): usleep/9676 brk( ) = 0xe5b000
0.500 ( 0.004 ms): usleep/9676 brk(brk: 0xe7c000 ) = 0xe7c000
0.503 ( 0.001 ms): usleep/9676 brk( ) = 0xe7c000
0.525 ( 0.005 ms): usleep/9676 nanosleep(rqtp: 0x7fffc0c7f7e0 ) ...
0.525 ( ): sched:sched_switch:usleep:9676 [120] S ==> swapper/2:0 [120])
0.582 ( 0.062 ms): usleep/9676 ... [continued]: nanosleep()) = 0
0.588 ( 0.000 ms): usleep/9676 exit_group(
[root@zoo ~]#
When we expected it to :-)
Now, this is how perf_event_attr is being set, in both cases (the code setting
up the perf_event_attr in 'perf trace' and 'perf stat' is the same):
[root@zoo ~]# perf stat -vv -e sched:sched_switch usleep 1
<SNIP>
perf_event_attr:
type 2
size 112
config 107
{ sample_period, sample_freq } 1
sample_type TIME|CPU|PERIOD|RAW
read_format TOTAL_TIME_ENABLED|TOTAL_TIME_RUNNING
disabled 1
inherit 1
enable_on_exec 1
exclude_guest 1
------------------------------------------------------------
sys_perf_event_open: pid 9685 cpu -1 group_fd -1 flags 0x8
sched:sched_switch: 1 688844 688844
Performance counter stats for 'usleep 1':
1 sched:sched_switch
0.001368517 seconds time elapsed
[root@zoo ~]#
[root@zoo ~]# perf trace -vv --ev sched:sched_switch usleep 1
<SNIP>
perf_event_attr:
type 2
size 112
config 107
{ sample_period, sample_freq } 1
sample_type IP|TID|TIME|ID|CPU|PERIOD|RAW
read_format ID
disabled 1
inherit 1
mmap 1
comm 1
enable_on_exec 1
task 1
sample_id_all 1
exclude_guest 1
mmap2 1
comm_exec 1
{ wakeup_events, wakeup_watermark } 1
<SNIP setting up the other events, for the syscall events>
0.491 ( 0.002 ms): usleep/9693 brk( ) = 0xd41000
0.502 ( 0.004 ms): usleep/9693 brk(brk: 0xd62000 ) = 0xd62000
0.505 ( 0.002 ms): usleep/9693 brk( ) = 0xd62000
0.527 ( 0.005 ms): usleep/9693 nanosleep(rqtp: 0x7ffc7df44ee0 ) ...
0.527 ( ): sched:sched_switch:usleep:9693 [120] S ==> swapper/1:0 [120])
0.583 ( 0.061 ms): usleep/9693 ... [continued]: nanosleep()) = 0
0.589 ( 0.000 ms): usleep/9693 exit_group(
[root@zoo ~]#
In the 'perf trace' case we need more stuff into sample_type, like ID, because
we need to map back to multiple events: sched:sched_switch, raw_syscalls:sys_e{nter,xit}, etc.
- Arnaldo
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Sampling on sched:sched_switch
2015-04-13 15:11 ` Arnaldo Carvalho de Melo
@ 2015-04-14 5:42 ` sahil aggarwal
2015-04-14 12:15 ` Arnaldo Carvalho de Melo
0 siblings, 1 reply; 10+ messages in thread
From: sahil aggarwal @ 2015-04-14 5:42 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo; +Cc: linux-perf-users
Hi Arnaldo
In my case:
bash-4.1# sudo perf stat -e sched:sched_switch sleep 1
Performance counter stats for 'sleep 1':
0 sched:sched_switch
1.004714901 seconds time elapsed
And if i do:
bash-4.1# perf stat -e cs sleep 1
Performance counter stats for 'sleep 1':
1 cs
1.003306642 seconds time elapsed
To enable sampling on sched:sched_switch my perf_event_attr look like:
e_open->attr.disabled = 1;
e_open->attr.type = PERF_TYPE_TRACEPOINT;
e_open->attr.config = 87;
e_open->attr.size = sizeof(e_open->attr);
e_open->attr.sample_period = 1;
e_open->attr.inherit = 1;
e_open->attr.sample_type = PERF_SAMPLE_TIME |
PERF_SAMPLE_RAW |
PERF_SAMPLE_CPU |
PERF_SAMPLE_TID ;
e_open->attr.__reserved_1 = 0;
e_open->attr.read_format = 0;
Running in separate thread for each CPU:
perf_event_open(&e_open->attr,2552,0,-1,0)
perf_event_open(&e_open->attr,2552,1,-1,0)
But if do :
e_open->attr.disabled = 1;
e_open->attr.type = PERF_TYPE_SOFTWARE;
e_open->attr.config = PERF_COUNT_SW_CONTEXT_SWITCHES;
e_open->attr.size = sizeof(e_open->attr);
e_open->attr.sample_period = 1;
e_open->attr.inherit = 1;
e_open->attr.sample_type = PERF_SAMPLE_TIME |
PERF_SAMPLE_RAW |
PERF_SAMPLE_CPU |
PERF_SAMPLE_TID ;
e_open->attr.__reserved_1 = 0;
e_open->attr.read_format = 0;
It writes events to ring buffer but of course without any
args(prev_comm,prev_pid,next_comm,next_pid)
So i am not able to understand this difference. Why sched:sched_switch
doesnt give me any counter.
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Sampling on sched:sched_switch
2015-04-14 5:42 ` sahil aggarwal
@ 2015-04-14 12:15 ` Arnaldo Carvalho de Melo
2015-04-14 12:30 ` sahil aggarwal
0 siblings, 1 reply; 10+ messages in thread
From: Arnaldo Carvalho de Melo @ 2015-04-14 12:15 UTC (permalink / raw)
To: sahil aggarwal; +Cc: linux-perf-users
Em Tue, Apr 14, 2015 at 11:12:11AM +0530, sahil aggarwal escreveu:
> In my case:
> bash-4.1# sudo perf stat -e sched:sched_switch sleep 1
> Performance counter stats for 'sleep 1':
> 0 sched:sched_switch
> 1.004714901 seconds time elapsed
So, there are some critical pieces of information missing here:
- perf --version
- cat /proc/cpuinfo
- uname -a
- What distribution is this?
So that we can try to figure this out.
> And if i do:
> bash-4.1# perf stat -e cs sleep 1
> Performance counter stats for 'sleep 1':
> 1 cs
> 1.003306642 seconds time elapsed
> To enable sampling on sched:sched_switch my perf_event_attr look like:
> e_open->attr.disabled = 1;
> e_open->attr.type = PERF_TYPE_TRACEPOINT;
> e_open->attr.config = 87;
in my machine:
[root@zoo ~]# cat /sys/kernel/debug/events/sched/sched_switch/format
name: sched_switch
ID: 263
> e_open->attr.size = sizeof(e_open->attr);
> e_open->attr.sample_period = 1;
> e_open->attr.inherit = 1;
> e_open->attr.sample_type = PERF_SAMPLE_TIME |
> PERF_SAMPLE_RAW |
> PERF_SAMPLE_CPU |
> PERF_SAMPLE_TID ;
> e_open->attr.__reserved_1 = 0;
> e_open->attr.read_format = 0;
> Running in separate thread for each CPU:
Running in separate thread for each CPU? Can you ellaborate on this?
> perf_event_open(&e_open->attr,2552,0,-1,0)
> perf_event_open(&e_open->attr,2552,1,-1,0)
So you have two counters, one in each CPU, for the same thread? What is
the intent?
If I go to do it with 'perf stat' it uses:
[root@zoo ~]# perf stat -vv -p 7762 -e sched:*switch 2>&1 | grep sys_perf_event_open
sys_perf_event_open: pid 7762 cpu -1 group_fd -1 flags 0x8
^C[root@zoo ~]#
Just one sys_perf_event_open syscall, stating that its the thread 7762
that should be monitored, in whatever CPU it ends up running.
Of course I can have multiple sys_perf_event_open() calls, from
different users even, if they have the appropriate permissions, and as
well many from the same user, but why, on the same monitoring session,
create one thread per CPU if the thread will only run in one CPU at a
time? You will end up having to order events from multiple ring buffers,
etc.
>
> But if do :
>
> e_open->attr.disabled = 1;
> e_open->attr.type = PERF_TYPE_SOFTWARE;
> e_open->attr.config = PERF_COUNT_SW_CONTEXT_SWITCHES;
> e_open->attr.size = sizeof(e_open->attr);
> e_open->attr.sample_period = 1;
> e_open->attr.inherit = 1;
> e_open->attr.sample_type = PERF_SAMPLE_TIME |
>
> PERF_SAMPLE_RAW |
>
> PERF_SAMPLE_CPU |
>
> PERF_SAMPLE_TID ;
> e_open->attr.__reserved_1 = 0;
> e_open->attr.read_format = 0;
>
> It writes events to ring buffer but of course without any
> args(prev_comm,prev_pid,next_comm,next_pid)
>
> So i am not able to understand this difference. Why sched:sched_switch
> doesnt give me any counter.
The difference is that you're using two different kinds of events, as you
can see on the attr.type and attr.config above, for some reason in your
case the PERF_TYPE_TRACEPOINT one is not happening, being lost or not
being asked for in some subtle way.
- Arnaldo
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Sampling on sched:sched_switch
2015-04-14 12:15 ` Arnaldo Carvalho de Melo
@ 2015-04-14 12:30 ` sahil aggarwal
2015-04-14 12:59 ` Arnaldo Carvalho de Melo
0 siblings, 1 reply; 10+ messages in thread
From: sahil aggarwal @ 2015-04-14 12:30 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo; +Cc: linux-perf-users
> So, there are some critical pieces of information missing here:
>
> - perf --version
bash-4.1# perf --version
perf version 3.2.17
> - cat /proc/cpuinfo
processor : 0
vendor_id : GenuineIntel
cpu family : 6
model : 45
model name : Intel(R) Xeon(R) CPU E5-2643 0 @ 3.30GHz
stepping : 7
microcode : 0x70d
cpu MHz : 3299.897
cache size : 10240 KB
physical id : 0
siblings : 4
core id : 0
cpu cores : 4
apicid : 0
initial apicid : 0
fpu : yes
fpu_exception : yes
cpuid level : 13
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov
pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx
pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl
xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl
vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid dca sse4_1 sse4_2 x2apic
popcnt tsc_deadline_timer aes xsave avx lahf_lm ida arat xsaveopt pln
pts dtherm tpr_shadow vnmi flexpriority ept vpid
bogomips : 6599.79
clflush size : 64
cache_alignment : 64
address sizes : 46 bits physical, 48 bits virtual
power management:
processor : 1
vendor_id : GenuineIntel
cpu family : 6
model : 45
model name : Intel(R) Xeon(R) CPU E5-2643 0 @ 3.30GHz
stepping : 7
microcode : 0x70d
cpu MHz : 3299.897
cache size : 10240 KB
physical id : 0
siblings : 4
core id : 3
cpu cores : 4
apicid : 6
initial apicid : 6
fpu : yes
fpu_exception : yes
cpuid level : 13
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov
pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx
pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl
xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl
vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid dca sse4_1 sse4_2 x2apic
popcnt tsc_deadline_timer aes xsave avx lahf_lm ida arat xsaveopt pln
pts dtherm tpr_shadow vnmi flexpriority ept vpid
bogomips : 6600.30
clflush size : 64
cache_alignment : 64
address sizes : 46 bits physical, 48 bits virtual
power management:
> - uname -a
bash-4.1# uname -a
Linux ops-es2 3.2.66-amd64 #1 SMP Wed Mar 4 16:29:30 IST 2015 x86_64 GNU/Linux
> [root@zoo ~]# cat /sys/kernel/debug/events/sched/sched_switch/format
> name: sched_switch
> ID: 263
bash-4.1# cat /sys/kernel/debug/tracing/events/sched/sched_switch/id
87
> So you have two counters, one in each CPU, for the same thread? What is
> the intent?
I have multiple tracepoints(say ~20-25), i tried it to enable them for
all CPU's but when i do attr->inherit = 1, it doesnt mmap the FD(
Gives EINVAL). When i digged the perf code a bit, i found :
if (evlist->cpus->map[0] < 0)
no_inherit = true;
So, i thought may be it doesn't allow trace on all CPU's when i
inherit. Does that make sense.?
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Sampling on sched:sched_switch
2015-04-14 12:30 ` sahil aggarwal
@ 2015-04-14 12:59 ` Arnaldo Carvalho de Melo
2015-04-14 13:30 ` sahil aggarwal
0 siblings, 1 reply; 10+ messages in thread
From: Arnaldo Carvalho de Melo @ 2015-04-14 12:59 UTC (permalink / raw)
To: sahil aggarwal; +Cc: linux-perf-users
Em Tue, Apr 14, 2015 at 06:00:17PM +0530, sahil aggarwal escreveu:
> > So, there are some critical pieces of information missing here:
> > - perf --version
> bash-4.1# perf --version
> perf version 3.2.17
This is really, really super old, but should probably not be a problem
:-)
> > - cat /proc/cpuinfo
> processor : 0
> vendor_id : GenuineIntel
> cpu family : 6
> model : 45
> model name : Intel(R) Xeon(R) CPU E5-2643 0 @ 3.30GHz
<SNIP>
> > - uname -a
> bash-4.1# uname -a
> Linux ops-es2 3.2.66-amd64 #1 SMP Wed Mar 4 16:29:30 IST 2015 x86_64 GNU/Linux
Humm, when you think that something is wrong about a piece of software you're
dealing with, please try using the latest release for that software to see if
the results are the same, because you may be hitting a bug long fixed.
Anyway, read on :-)
> > [root@zoo ~]# cat /sys/kernel/debug/events/sched/sched_switch/format
> > name: sched_switch
> > ID: 263
> bash-4.1# cat /sys/kernel/debug/tracing/events/sched/sched_switch/id
> 87
> > So you have two counters, one in each CPU, for the same thread? What is
> > the intent?
> I have multiple tracepoints(say ~20-25), i tried it to enable them for
> all CPU's but when i do attr->inherit = 1, it doesnt mmap the FD(
This is incomplete: "multiple events for all CPUS" ok, but for a specific
thread? Or for all of them?
See this, look for the inherit flag, then look for the CPU arg to
sys_perf_event_open, many tracepoints, a process that creates a process that
creates a process that makes a networking call that hits net:*skb* tracepoints,
is something like that that you want?
[root@zoo ~]# perf stat -vv -e sched:* -e skb:* time time ping -c 1 127.0.0.1
<SNIP>
------------------------------------------------------------
perf_event_attr:
type 2
size 112
config 10b
{ sample_period, sample_freq } 1
sample_type TIME|CPU|PERIOD|RAW
read_format TOTAL_TIME_ENABLED|TOTAL_TIME_RUNNING
disabled 1
inherit 1
enable_on_exec 1
exclude_guest 1
------------------------------------------------------------
sys_perf_event_open: pid 9944 cpu -1 group_fd -1 flags 0x8
------------------------------------------------------------
perf_event_attr:
type 2
size 112
config 10a
{ sample_period, sample_freq } 1
sample_type TIME|CPU|PERIOD|RAW
read_format TOTAL_TIME_ENABLED|TOTAL_TIME_RUNNING
disabled 1
inherit 1
enable_on_exec 1
exclude_guest 1
------------------------------------------------------------
sys_perf_event_open: pid 9944 cpu -1 group_fd -1 flags 0x8
------------------------------------------------------------
perf_event_attr:
type 2
size 112
config 109
{ sample_period, sample_freq } 1
sample_type TIME|CPU|PERIOD|RAW
read_format TOTAL_TIME_ENABLED|TOTAL_TIME_RUNNING
disabled 1
inherit 1
enable_on_exec 1
exclude_guest 1
------------------------------------------------------------
sys_perf_event_open: pid 9944 cpu -1 group_fd -1 flags 0x8
------------------------------------------------------------
perf_event_attr:
type 2
size 112
config 108
{ sample_period, sample_freq } 1
sample_type TIME|CPU|PERIOD|RAW
read_format TOTAL_TIME_ENABLED|TOTAL_TIME_RUNNING
disabled 1
inherit 1
enable_on_exec 1
exclude_guest 1
------------------------------------------------------------
sys_perf_event_open: pid 9944 cpu -1 group_fd -1 flags 0x8
------------------------------------------------------------
<suppress many other tracepoint perf_event_attr dumps>
------------------------------------------------------------
sys_perf_event_open: pid 9944 cpu -1 group_fd -1 flags 0x8
PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
64 bytes from 127.0.0.1: icmp_seq=1 ttl=64 time=0.061 ms
--- 127.0.0.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.061/0.061/0.061/0.000 ms
0.00user 0.00system 0:00.00elapsed 0%CPU (0avgtext+0avgdata 2244maxresident)k
0inputs+0outputs (0major+102minor)pagefaults 0swaps
0.00user 0.00system 0:00.00elapsed 50%CPU (0avgtext+0avgdata 2244maxresident)k
0inputs+0outputs (0major+182minor)pagefaults 0swaps
sched:sched_kthread_stop: 0 2488023 2488023
sched:sched_kthread_stop_ret: 0 2488023 2488023
sched:sched_wakeup: 130 2488023 2488023
sched:sched_wakeup_new: 4 2488023 2488023
sched:sched_switch: 122 2488023 2488023
sched:sched_migrate_task: 6 2488023 2488023
sched:sched_process_free: 0 2488023 2488023
sched:sched_process_exit: 3 2488023 2488023
sched:sched_wait_task: 0 2488023 2488023
sched:sched_process_wait: 2 2488023 2488023
sched:sched_process_fork: 2 2488023 2488023
sched:sched_process_exec: 3 2488023 2488023
sched:sched_stat_wait: 0 2488023 2488023
sched:sched_stat_sleep: 0 2488023 2488023
sched:sched_stat_iowait: 0 2488023 2488023
sched:sched_stat_blocked: 0 2488023 2488023
sched:sched_stat_runtime: 2354533 2488023 2488023
sched:sched_pi_setprio: 0 2488023 2488023
sched:sched_move_numa: 0 2488023 2488023
sched:sched_stick_numa: 0 2488023 2488023
sched:sched_swap_numa: 0 2488023 2488023
sched:sched_wake_idle_without_ipi: 7 2488023 2488023
skb:kfree_skb: 1 2488023 2488023
skb:consume_skb: 2 2488023 2488023
skb:skb_copy_datagram_iovec: 1 2488023 2488023
Performance counter stats for 'time time ping -c 1 127.0.0.1':
0 sched:sched_kthread_stop
0 sched:sched_kthread_stop_ret
130 sched:sched_wakeup
4 sched:sched_wakeup_new
122 sched:sched_switch
6 sched:sched_migrate_task
0 sched:sched_process_free
3 sched:sched_process_exit
0 sched:sched_wait_task
2 sched:sched_process_wait
2 sched:sched_process_fork
3 sched:sched_process_exec
0 sched:sched_stat_wait
0 sched:sched_stat_sleep
0 sched:sched_stat_iowait
0 sched:sched_stat_blocked
2,354,533 sched:sched_stat_runtime
0 sched:sched_pi_setprio
0 sched:sched_move_numa
0 sched:sched_stick_numa
0 sched:sched_swap_numa
7 sched:sched_wake_idle_without_ipi
1 skb:kfree_skb
2 skb:consume_skb
1 skb:skb_copy_datagram_iovec
0.003088642 seconds time elapsed
[root@zoo ~]#
> Gives EINVAL). When i digged the perf code a bit, i found :
>
> if (evlist->cpus->map[0] < 0)
> no_inherit = true;
>
> So, i thought may be it doesn't allow trace on all CPU's when i
> inherit. Does that make sense.?
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Sampling on sched:sched_switch
2015-04-14 12:59 ` Arnaldo Carvalho de Melo
@ 2015-04-14 13:30 ` sahil aggarwal
2015-04-14 14:22 ` Arnaldo Carvalho de Melo
0 siblings, 1 reply; 10+ messages in thread
From: sahil aggarwal @ 2015-04-14 13:30 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo; +Cc: linux-perf-users
> This is incomplete: "multiple events for all CPUS" ok, but for a specific
> thread? Or for all of them?
If i have 2 CPU's, i made it run 2 threads each per CPU. Both threads
have different streams for same tracepoints polling on them. Well, had
to go with this approach since enabling tracepoints on all CPU when
inherit was not working for me :(
> See this, look for the inherit flag, then look for the CPU arg to
> sys_perf_event_open, many tracepoints, a process that creates a process that
> creates a process that makes a networking call that hits net:*skb* tracepoints,
> is something like that that you want?
This is exactly what i want. But things seem to be working in unexpected way.
> [root@zoo ~]# perf stat -vv -e sched:* -e skb:* time time ping -c 1 127.0.0.1
> <SNIP>
> ------------------------------------------------------------
> perf_event_attr:
> type 2
> size 112
> config 10b
> { sample_period, sample_freq } 1
> sample_type TIME|CPU|PERIOD|RAW
> read_format TOTAL_TIME_ENABLED|TOTAL_TIME_RUNNING
> disabled 1
> inherit 1
> enable_on_exec 1
> exclude_guest 1
> ------------------------------------------------------------
> sys_perf_event_open: pid 9944 cpu -1 group_fd -1 flags 0x8
> ------------------------------------------------------------
I think i should figure out why mmap is failing when inherit=1, seeing
this it doesn't make sense. Will get back to you if i find something.
Thank you Arnaldo.
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Sampling on sched:sched_switch
2015-04-14 13:30 ` sahil aggarwal
@ 2015-04-14 14:22 ` Arnaldo Carvalho de Melo
2015-04-14 14:55 ` sahil aggarwal
0 siblings, 1 reply; 10+ messages in thread
From: Arnaldo Carvalho de Melo @ 2015-04-14 14:22 UTC (permalink / raw)
To: sahil aggarwal; +Cc: linux-perf-users
Em Tue, Apr 14, 2015 at 07:00:43PM +0530, sahil aggarwal escreveu:
> > This is incomplete: "multiple events for all CPUS" ok, but for a specific
> > thread? Or for all of them?
> If i have 2 CPU's, i made it run 2 threads each per CPU. Both threads
> have different streams for same tracepoints polling on them. Well, had
> to go with this approach since enabling tracepoints on all CPU when
> inherit was not working for me :(
My question stands: "Are you monitoring a specific thread? Or all
threads in the system"?
> > See this, look for the inherit flag, then look for the CPU arg to
> > sys_perf_event_open, many tracepoints, a process that creates a process that
> > creates a process that makes a networking call that hits net:*skb* tracepoints,
> > is something like that that you want?
> This is exactly what i want. But things seem to be working in unexpected way.
Read below
> > [root@zoo ~]# perf stat -vv -e sched:* -e skb:* time time ping -c 1 127.0.0.1
> > <SNIP>
> > ------------------------------------------------------------
> > perf_event_attr:
> > type 2
> > size 112
> > config 10b
> > { sample_period, sample_freq } 1
> > sample_type TIME|CPU|PERIOD|RAW
> > read_format TOTAL_TIME_ENABLED|TOTAL_TIME_RUNNING
> > disabled 1
> > inherit 1
> > enable_on_exec 1
> > exclude_guest 1
> > ------------------------------------------------------------
> > sys_perf_event_open: pid 9944 cpu -1 group_fd -1 flags 0x8
> > ------------------------------------------------------------
>
> I think i should figure out why mmap is failing when inherit=1, seeing
> this it doesn't make sense. Will get back to you if i find something.
'perf stat' doesn't use mmap, its just counting events, lemme try
mmaping that same workload:
[root@zoo ~]# trace -o /tmp/trace.output -vv --ev sched:* --ev skb:* time time ping -c 1 127.0.0.1
<SNIP>
------------------------------------------------------------
perf_event_attr:
type 2
size 112
config 10b
{ sample_period, sample_freq } 1
sample_type IP|TID|TIME|ID|CPU|PERIOD|RAW
read_format ID
disabled 1
inherit 1
mmap 1
comm 1
enable_on_exec 1
task 1
sample_id_all 1
exclude_guest 1
mmap2 1
comm_exec 1
{ wakeup_events, wakeup_watermark } 1
------------------------------------------------------------
sys_perf_event_open: pid 19784 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open: pid 19784 cpu 1 group_fd -1 flags 0x8
sys_perf_event_open: pid 19784 cpu 2 group_fd -1 flags 0x8
sys_perf_event_open: pid 19784 cpu 3 group_fd -1 flags 0x8
------------------------------------------------------------
perf_event_attr:
type 2
size 112
config 10a
{ sample_period, sample_freq } 1
sample_type IP|TID|TIME|ID|CPU|PERIOD|RAW
read_format ID
disabled 1
inherit 1
enable_on_exec 1
sample_id_all 1
exclude_guest 1
{ wakeup_events, wakeup_watermark } 1
------------------------------------------------------------
sys_perf_event_open: pid 19784 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open: pid 19784 cpu 1 group_fd -1 flags 0x8
sys_perf_event_open: pid 19784 cpu 2 group_fd -1 flags 0x8
sys_perf_event_open: pid 19784 cpu 3 group_fd -1 flags 0x8
------------------------------------------------------------
perf_event_attr:
type 2
size 112
config 109
{ sample_period, sample_freq } 1
sample_type IP|TID|TIME|ID|CPU|PERIOD|RAW
read_format ID
disabled 1
inherit 1
enable_on_exec 1
sample_id_all 1
exclude_guest 1
{ wakeup_events, wakeup_watermark } 1
------------------------------------------------------------
sys_perf_event_open: pid 19784 cpu 0 group_fd -1 flags 0x8
sys_perf_event_open: pid 19784 cpu 1 group_fd -1 flags 0x8
sys_perf_event_open: pid 19784 cpu 2 group_fd -1 flags 0x8
sys_perf_event_open: pid 19784 cpu 3 group_fd -1 flags 0x8
------------------------------------------------------------
<SNIP>
mmap size 528384B
perf event ring buffer mmapped per cpu
PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
64 bytes from 127.0.0.1: icmp_seq=1 ttl=64 time=0.050 ms
--- 127.0.0.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.050/0.050/0.050/0.000 ms
0.00user 0.00system 0:00.00elapsed 50%CPU (0avgtext+0avgdata 2112maxresident)k
0inputs+0outputs (0major+100minor)pagefaults 0swaps
0.00user 0.00system 0:00.00elapsed 60%CPU (0avgtext+0avgdata 2112maxresident)k
0inputs+0outputs (0major+180minor)pagefaults 0swaps
[root@zoo ~]#
Ok, it works, but notice that it will create one file descriptor per event per
CPU (this machine has 4 CPUs), and then it will use an ioctl to ask the kernel
to send all events for an event on a CPU to the same ring buffer, so we end up
with just 4 ring buffers (perf mmaps), one per CPU:
From tools/perf/util/evlist.c, function perf_evlist__mmap_per_evsel():
if (ioctl(fd, PERF_EVENT_IOC_SET_OUTPUT, *output) != 0)
That is why I asked you about what you are monitoring, that is not clear so
far, for me.
Above, we are not asking the kernel for cpu == -1 and thread == -1, that will
result in that -EINVAL, that is there for scalability reasons.
System wide is done by using CPU = N and thread = -1, with one mmap per CPU.
- Arnaldo
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Sampling on sched:sched_switch
2015-04-14 14:22 ` Arnaldo Carvalho de Melo
@ 2015-04-14 14:55 ` sahil aggarwal
2015-04-15 6:17 ` sahil aggarwal
0 siblings, 1 reply; 10+ messages in thread
From: sahil aggarwal @ 2015-04-14 14:55 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo; +Cc: linux-perf-users
> My question stands: "Are you monitoring a specific thread? Or all
> threads in the system"?
I am monitoring a specific thread not systemwide.
> Above, we are not asking the kernel for cpu == -1 and thread == -1, that will
> result in that -EINVAL, that is there for scalability reasons.
Yes, this condition will give EINVAL according to the documentation,
but i pass the pid of thread i want to monitor so i definitely dont
ask kernel for cpu == -1 and pid == -1.
sys_perf_event_open(__NR_perf_event_open,2588,0,-1,0)
sys_perf_event_open(__NR_perf_event_open,2588,1,-1,0)
But, my actual problem still persist. Still not getting any counts on
sched:sched_switch for particular thread. But it works for systemwide
bash-4.1# perf stat -ae "sched:*" sleep 1
Performance counter stats for 'sleep 1':
0 sched:sched_kthread_stop
[100.00%]
0 sched:sched_kthread_stop_ret
[100.00%]
90 sched:sched_wakeup
[100.00%]
8 sched:sched_wakeup_new
[100.00%]
210 sched:sched_switch
[100.00%]
31 sched:sched_migrate_task
[100.00%]
6 sched:sched_process_free
[100.00%]
5 sched:sched_process_exit
[100.00%]
0 sched:sched_wait_task
[100.00%]
7 sched:sched_process_wait
[100.00%]
10 sched:sched_process_fork
[100.00%]
0 sched:sched_stat_wait
[100.00%]
0 sched:sched_stat_sleep
[100.00%]
0 sched:sched_stat_iowait
[100.00%]
81156012 sched:sched_stat_runtime
[100.00%]
0 sched:sched_pi_setprio
1.004944414 seconds time elapsed
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: Sampling on sched:sched_switch
2015-04-14 14:55 ` sahil aggarwal
@ 2015-04-15 6:17 ` sahil aggarwal
0 siblings, 0 replies; 10+ messages in thread
From: sahil aggarwal @ 2015-04-15 6:17 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo; +Cc: linux-perf-users
Update to kernel 4.0.0. Working fine now.
Thank you Arnaldo.
On 14 April 2015 at 20:25, sahil aggarwal <sahil.agg15@gmail.com> wrote:
>> My question stands: "Are you monitoring a specific thread? Or all
>> threads in the system"?
> I am monitoring a specific thread not systemwide.
>
>> Above, we are not asking the kernel for cpu == -1 and thread == -1, that will
>> result in that -EINVAL, that is there for scalability reasons.
>
> Yes, this condition will give EINVAL according to the documentation,
> but i pass the pid of thread i want to monitor so i definitely dont
> ask kernel for cpu == -1 and pid == -1.
>
> sys_perf_event_open(__NR_perf_event_open,2588,0,-1,0)
> sys_perf_event_open(__NR_perf_event_open,2588,1,-1,0)
>
> But, my actual problem still persist. Still not getting any counts on
> sched:sched_switch for particular thread. But it works for systemwide
>
> bash-4.1# perf stat -ae "sched:*" sleep 1
>
> Performance counter stats for 'sleep 1':
>
> 0 sched:sched_kthread_stop
> [100.00%]
> 0 sched:sched_kthread_stop_ret
> [100.00%]
> 90 sched:sched_wakeup
> [100.00%]
> 8 sched:sched_wakeup_new
> [100.00%]
> 210 sched:sched_switch
> [100.00%]
> 31 sched:sched_migrate_task
> [100.00%]
> 6 sched:sched_process_free
> [100.00%]
> 5 sched:sched_process_exit
> [100.00%]
> 0 sched:sched_wait_task
> [100.00%]
> 7 sched:sched_process_wait
> [100.00%]
> 10 sched:sched_process_fork
> [100.00%]
> 0 sched:sched_stat_wait
> [100.00%]
> 0 sched:sched_stat_sleep
> [100.00%]
> 0 sched:sched_stat_iowait
> [100.00%]
> 81156012 sched:sched_stat_runtime
> [100.00%]
> 0 sched:sched_pi_setprio
>
> 1.004944414 seconds time elapsed
^ permalink raw reply [flat|nested] 10+ messages in thread
end of thread, other threads:[~2015-04-15 6:17 UTC | newest]
Thread overview: 10+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2015-04-13 13:04 Sampling on sched:sched_switch sahil aggarwal
2015-04-13 15:11 ` Arnaldo Carvalho de Melo
2015-04-14 5:42 ` sahil aggarwal
2015-04-14 12:15 ` Arnaldo Carvalho de Melo
2015-04-14 12:30 ` sahil aggarwal
2015-04-14 12:59 ` Arnaldo Carvalho de Melo
2015-04-14 13:30 ` sahil aggarwal
2015-04-14 14:22 ` Arnaldo Carvalho de Melo
2015-04-14 14:55 ` sahil aggarwal
2015-04-15 6:17 ` sahil aggarwal
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).