* Random abnormal high CPU sys usage related to timer
@ 2016-08-26 17:10 Mac Lin
2016-08-26 21:12 ` Vegard Nossum
0 siblings, 1 reply; 5+ messages in thread
From: Mac Lin @ 2016-08-26 17:10 UTC (permalink / raw)
To: John Stultz, Thomas Gleixner; +Cc: linux-kernel
[-- Attachment #1: Type: text/plain, Size: 1469 bytes --]
Hi all,
We were having issue with our userspace application which
__sometimes__ result in high CPU sys usage at each execution. The high
sys CPU usage persist until the application is killed.
We simplified the application to just creating a timer and its handler
then does nothing, but looping and sleeping for the timer to be
triggered. With top, the CPU that running the application usually
takes almost 0% for sys usage. But sometimes it will occupy certain
amount of sys usage, up to 100% at most of the time on my embedded
device.
On my laptop, Intel Core i5-4200U, running Ubuntu 14.02.2, Linux
3.13.0-45-generic and 4.4.0-34-generic, the issue can be reproduced
with lower sys usage (7~50%). The same can be reproduced with
buildroot+vanilla kernel 4.7 and 3.13.
Restart the application could temporarily fix the the issue, but there
are chances to happen again.
Googling found one issue that seems related, but no further action.
Keystone II Linux: Random High CPU usage - userspace application using
1 full core - Linux forum - Linux - TI E2E Community
http://e2e.ti.com/support/embedded/linux/f/354/p/433791/1553204
I've checked the /proc/timer_stats, /proc/interrupts, and perf, all
the irq counter, timer counter, timer/irq event didn't show any
abnormal value or useful clue. I'm looking forward for any suggestion
desperately.
Attached the test code and log, and script to detect the issue, which
require dstat and taskset.
Best Regards,
Mac Lin
[-- Attachment #2: test.c --]
[-- Type: text/x-csrc, Size: 795 bytes --]
#include <stdio.h>
#include <stdlib.h>
#include <sys/time.h>
#include <pthread.h>
#include <semaphore.h>
#include <signal.h>
#include <unistd.h>
void timer_handler(void)
{
return;
}
void main(){
unsigned int period=100;
struct itimerval it_val; /* for setting itimer */
int i=0;
if (signal(SIGALRM, (void (*)(int)) timer_handler) == SIG_ERR)
{
perror("Unable to catch SIGALRM");
return;
}
it_val.it_value.tv_sec = 0;
it_val.it_value.tv_usec = period;
it_val.it_interval = it_val.it_value;
if (setitimer(ITIMER_REAL, &it_val, NULL) == -1)
{
perror("error calling setitimer()");
return ;
}
printf("test started period=%d\n", period);
while(1){
usleep(1000);
if((i%10000)==0) printf("%s: hello, i=%d\n", __func__, i);
i++;
}
printf("exited.\n");
return ;
}
[-- Attachment #3: test.log --]
[-- Type: text/x-log, Size: 10145 bytes --]
# ./test.sh
TH=10
test-host: no process found
cnt=0
test started period=100
main: hello, i=0
-------cpu3-usage------
usr sys idl wai hiq siq
13 2 84 0 0 0
main: hello, i=10000
0 0 100 0 0 0
main: hello, i=20000
0 0 100 0 0 0
main: hello, i=30000
0 0 100 0 0 0
main: hello, i=40000
1 0 85 13 0 0
main: hello, i=50000
0 0 100 0 0 0
main: hello, i=60000
0 0 96 4 0 0
main: hello, i=70000
0 0 100 0 0 0
main: hello, i=80000
0 0 100 0 0 0
main: hello, i=90000
0 0 100 0 0 0
main: hello, i=100000
0 1 99 0 0 0
AVG=0
./test.sh: line 22: 10583 Terminated taskset -c 3 ./test-host
test-host: no process found
cnt=1
test started period=100
main: hello, i=0
-------cpu3-usage------
usr sys idl wai hiq siq
13 2 84 0 0 0
main: hello, i=10000
0 0 100 0 0 0
main: hello, i=20000
0 1 97 2 0 0
main: hello, i=30000
1 0 99 0 0 0
main: hello, i=40000
3 0 97 0 0 0
0 0 100 0 0 0
main: hello, i=50000
1 0 99 0 0 0
main: hello, i=60000
3 1 96 0 0 0
main: hello, i=70000
1 0 94 4 0 0
main: hello, i=80000
0 0 100 0 0 0
main: hello, i=90000
0 0 100 0 0 0
AVG=0
./test.sh: line 22: 10591 Terminated taskset -c 3 ./test-host
test-host: no process found
cnt=2
test started period=100
main: hello, i=0
-------cpu3-usage------
usr sys idl wai hiq siq
13 2 84 0 0 0
main: hello, i=10000
0 0 100 0 0 0
main: hello, i=20000
0 0 100 0 0 0
main: hello, i=30000
0 0 100 0 0 0
main: hello, i=40000
0 0 97 3 0 0
main: hello, i=50000
0 0 100 0 0 0
main: hello, i=60000
0 0 100 0 0 0
main: hello, i=70000
0 0 100 0 0 0
main: hello, i=80000
0 0 100 0 0 0
main: hello, i=90000
0 0 100 0 0 0
main: hello, i=100000
1 0 94 4 0 0
AVG=0
./test.sh: line 22: 10599 Terminated taskset -c 3 ./test-host
test-host: no process found
cnt=3
test started period=100
main: hello, i=0
-------cpu3-usage------
usr sys idl wai hiq siq
13 2 84 0 0 0
main: hello, i=10000
0 0 100 0 0 0
main: hello, i=20000
0 0 100 0 0 0
main: hello, i=30000
0 0 100 0 0 0
main: hello, i=40000
0 0 100 0 0 0
main: hello, i=50000
1 0 99 0 0 0
main: hello, i=60000
0 0 100 0 0 0
main: hello, i=70000
0 0 100 0 0 0
main: hello, i=80000
0 0 100 0 0 0
main: hello, i=90000
0 0 100 0 0 0
main: hello, i=100000
0 0 90 10 0 0
AVG=0
./test.sh: line 22: 10607 Terminated taskset -c 3 ./test-host
test-host: no process found
cnt=4
test started period=100
main: hello, i=0
-------cpu3-usage------
usr sys idl wai hiq siq
13 2 84 0 0 0
main: hello, i=10000
0 0 100 0 0 0
main: hello, i=20000
0 0 100 0 0 0
main: hello, i=30000
0 0 100 0 0 0
main: hello, i=40000
0 0 100 0 0 0
main: hello, i=50000
0 0 100 0 0 0
main: hello, i=60000
0 0 97 3 0 0
main: hello, i=70000
0 0 100 0 0 0
main: hello, i=80000
0 0 100 0 0 0
main: hello, i=90000
0 0 100 0 0 0
main: hello, i=100000
0 0 100 0 0 0
AVG=0
./test.sh: line 22: 10615 Terminated taskset -c 3 ./test-host
test-host: no process found
cnt=5
test started period=100
main: hello, i=0
-------cpu3-usage------
usr sys idl wai hiq siq
13 2 84 0 0 0
main: hello, i=10000
0 0 100 0 0 0
main: hello, i=20000
0 0 97 3 0 0
main: hello, i=30000
0 0 100 0 0 0
main: hello, i=40000
0 0 100 0 0 0
main: hello, i=50000
0 0 100 0 0 0
main: hello, i=60000
0 0 100 0 0 0
main: hello, i=70000
0 0 100 0 0 0
main: hello, i=80000
0 0 97 3 0 0
main: hello, i=90000
0 0 100 0 0 0
main: hello, i=100000
0 0 100 0 0 0
AVG=0
./test.sh: line 22: 10623 Terminated taskset -c 3 ./test-host
test-host: no process found
cnt=6
test started period=100
main: hello, i=0
-------cpu3-usage------
usr sys idl wai hiq siq
13 2 84 0 0 0
main: hello, i=10000
0 0 100 0 0 0
main: hello, i=20000
0 1 99 0 0 0
main: hello, i=30000
1 1 98 0 0 0
main: hello, i=40000
2 0 98 0 0 0
main: hello, i=50000
0 0 100 0 0 0
0 1 99 0 0 0
main: hello, i=60000
0 0 100 0 0 0
main: hello, i=70000
0 0 100 0 0 0
main: hello, i=80000
0 0 100 0 0 0
main: hello, i=90000
0 0 100 0 0 0
main: hello, i=100000
AVG=0
./test.sh: line 22: 10633 Terminated taskset -c 3 ./test-host
test-host: no process found
cnt=7
test started period=100
main: hello, i=0
-------cpu3-usage------
usr sys idl wai hiq siq
13 2 84 0 0 0
main: hello, i=10000
3 0 97 0 0 0
main: hello, i=20000
0 1 99 0 0 0
main: hello, i=30000
0 0 100 0 0 0
main: hello, i=40000
0 0 96 4 0 0
main: hello, i=50000
1 0 99 0 0 0
main: hello, i=60000
0 0 100 0 0 0
main: hello, i=70000
0 0 100 0 0 0
main: hello, i=80000
0 0 100 0 0 0
main: hello, i=90000
1 1 98 0 0 0
1 3 96 0 0 0
main: hello, i=100000
AVG=0
./test.sh: line 22: 10641 Terminated taskset -c 3 ./test-host
test-host: no process found
cnt=8
test started period=100
main: hello, i=0
-------cpu3-usage------
usr sys idl wai hiq siq
13 2 84 0 0 0
main: hello, i=10000
0 0 100 0 0 0
main: hello, i=20000
1 3 95 0 0 0
main: hello, i=30000
0 0 100 0 0 0
1 1 98 0 0 0
main: hello, i=40000
2 2 95 1 0 0
main: hello, i=50000
0 2 97 1 0 0
main: hello, i=60000
1 0 99 0 0 0
main: hello, i=70000
0 1 99 0 0 0
main: hello, i=80000
1 2 97 0 0 0
main: hello, i=90000
2 2 96 0 0 0
AVG=1
test-host: no process found
./test.sh: line 22: 10650 Terminated taskset -c 3 ./test-host
cnt=9
test started period=100
main: hello, i=0
-------cpu3-usage------
usr sys idl wai hiq siq
13 2 84 0 0 0
main: hello, i=10000
2 1 97 0 0 0
main: hello, i=20000
0 2 98 0 0 0
main: hello, i=30000
2 1 94 3 0 0
main: hello, i=40000
1 0 99 0 0 0
main: hello, i=50000
0 0 100 0 0 0
main: hello, i=60000
1 0 96 3 0 0
main: hello, i=70000
0 0 100 0 0 0
main: hello, i=80000
1 0 99 0 0 0
4 0 63 33 0 0
main: hello, i=90000
2 1 97 0 0 0
AVG=0
./test.sh: line 22: 10658 Terminated taskset -c 3 ./test-host
test-host: no process found
cnt=10
test started period=100
main: hello, i=0
-------cpu3-usage------
usr sys idl wai hiq siq
13 2 84 0 0 0
main: hello, i=10000
1 0 99 0 0 0
main: hello, i=20000
0 0 96 4 0 0
main: hello, i=30000
0 0 86 14 0 0
main: hello, i=40000
0 0 100 0 0 0
main: hello, i=50000
0 0 100 0 0 0
main: hello, i=60000
0 0 100 0 0 0
main: hello, i=70000
0 0 100 0 0 0
main: hello, i=80000
0 0 100 0 0 0
main: hello, i=90000
0 0 100 0 0 0
main: hello, i=100000
0 0 100 0 0 0
AVG=0
./test.sh: line 22: 10666 Terminated taskset -c 3 ./test-host
test-host: no process found
cnt=11
test started period=100
main: hello, i=0
-------cpu3-usage------
usr sys idl wai hiq siq
13 2 84 0 0 0
main: hello, i=10000
0 1 99 0 0 0
main: hello, i=20000
0 0 100 0 0 0
main: hello, i=30000
1 0 99 0 0 0
main: hello, i=40000
1 0 95 4 0 0
main: hello, i=50000
0 0 100 0 0 0
main: hello, i=60000
0 0 100 0 0 0
main: hello, i=70000
2 0 98 0 0 0
main: hello, i=80000
0 0 100 0 0 0
main: hello, i=90000
0 0 100 0 0 0
main: hello, i=100000
0 0 97 3 0 0
AVG=0
./test.sh: line 22: 10674 Terminated taskset -c 3 ./test-host
test-host: no process found
cnt=12
test started period=100
main: hello, i=0
-------cpu3-usage------
usr sys idl wai hiq siq
13 2 84 0 0 0
main: hello, i=10000
1 42 57 0 0 0
main: hello, i=20000
0 47 53 0 0 0
main: hello, i=30000
2 20 78 0 0 0
main: hello, i=40000
1 37 62 0 0 0
main: hello, i=50000
0 20 74 7 0 0
6 30 61 3 0 0
main: hello, i=60000
4 31 66 0 0 0
main: hello, i=70000
0 52 48 0 0 0
main: hello, i=80000
1 52 48 0 0 0
main: hello, i=90000
0 46 48 5 0 0
AVG=37
high cpu sys usage....
main: hello, i=100000
-------cpu3-usage------
usr sys idl wai hiq siq
13 2 84 0 0 0main: hello, i=110000
0 52 48 0 0 0main: hello, i=120000
1 42 55 2 0 0main: hello, i=130000
0 49 51 0 0 0main: hello, i=140000
1 51 48 0 0 0main: hello, i=150000
0 46 54 0 0 0main: hello, i=160000
2 14 81 3 0 0main: hello, i=170000
1 49 50 0 0 0^Z
[1]+ Stopped ./test.sh
root@test-Vostro-5470:/var/lib/tftpboot# bg
[1]+ ./test.sh &
root@test-Vostro-5470:/var/lib/tftpboot# main: hello, i=180000
4 27 68 1 0 0
0 50 50 0 0 0main: hello, i=190000
0 51 49 0 0 0main: hello, i=200000
3 48 48 0 0 0main: hello, i=210000
9 34 57 0 0 0
1 46 54 0 0 0main: hello, i=220000
1 42 57 0 0 0main: hello, i=230000
1 51 48 0 0 0main: hello, i=240000
1 48 51 0 0 0main: hello, i=250000
1 51 48 0 0 0main: hello, i=260000
0 35 65 0 0 0main: hello, i=270000
1 51 49 0 0 0main: hello, i=280000
1 32 67 0 0 0main: hello, i=290000
1 49 50 0 0 0main: hello, i=300000
root@test-Vostro-5470:/var/lib/tftpboot# killall test-host
1 21 78 0 0 0
-------cpu3-usage------
usr sys idl wai hiq siq
1 0 99 0 0 0
1 0 99 0 0 0
1 1 93 5 0 0
0 0 100 0 0 0
1 0 99 0 0 0
[-- Attachment #4: Makefile --]
[-- Type: application/octet-stream, Size: 46 bytes --]
all:
gcc test.c -o test-host -pthread -lrt
[-- Attachment #5: test.sh --]
[-- Type: application/x-sh, Size: 493 bytes --]
^ permalink raw reply [flat|nested] 5+ messages in thread* Re: Random abnormal high CPU sys usage related to timer
2016-08-26 17:10 Random abnormal high CPU sys usage related to timer Mac Lin
@ 2016-08-26 21:12 ` Vegard Nossum
2016-08-27 15:13 ` Mac Lin
0 siblings, 1 reply; 5+ messages in thread
From: Vegard Nossum @ 2016-08-26 21:12 UTC (permalink / raw)
To: Mac Lin; +Cc: John Stultz, Thomas Gleixner, LKML
On 26 August 2016 at 19:10, Mac Lin <mkl0301@gmail.com> wrote:
> We were having issue with our userspace application which
> __sometimes__ result in high CPU sys usage at each execution. The high
> sys CPU usage persist until the application is killed.
[...]
> Googling found one issue that seems related, but no further action.
Was it this one? https://lkml.org/lkml/2016/8/23/360
If so you may try to revert commit ff9a9b4c4334 ("sched, time: Switch
VIRT_CPU_ACCOUNTING_GEN to jiffy granularity") to see if it helps.
Vegard
^ permalink raw reply [flat|nested] 5+ messages in thread* Re: Random abnormal high CPU sys usage related to timer
2016-08-26 21:12 ` Vegard Nossum
@ 2016-08-27 15:13 ` Mac Lin
2016-08-29 10:45 ` Thomas Gleixner
0 siblings, 1 reply; 5+ messages in thread
From: Mac Lin @ 2016-08-27 15:13 UTC (permalink / raw)
To: Vegard Nossum; +Cc: John Stultz, Thomas Gleixner, LKML
Hi Vegard,
Thanks for the prompt response.
The commit is introduced since 4.6, but the issue can be reproduced at
3.10 (earliest I have ever test). And testing on buildroot+4.7 with
the commit reverted, the issue still happen.
In fact, I did a test that ran a script that keep increase a counter
for 10 seconds on the same CPU. If I ran 2 of it, the number is half
of running 1. But if I ran it while the issue happened, the counter
reported is around the same value as the 1 process case. So I doubt
that it might be an issue of reported number.
Is there other way to ensure the CPU is "really" doing something?
x=0
trap 'echo x=$x;exit 1' SIGHUP SIGINT SIGTERM
while : ; do
x=$(($x+1));
# echo $x;
done
On Sat, Aug 27, 2016 at 5:12 AM, Vegard Nossum <vegard.nossum@gmail.com> wrote:
> On 26 August 2016 at 19:10, Mac Lin <mkl0301@gmail.com> wrote:
>> We were having issue with our userspace application which
>> __sometimes__ result in high CPU sys usage at each execution. The high
>> sys CPU usage persist until the application is killed.
> [...]
>> Googling found one issue that seems related, but no further action.
>
> Was it this one? https://lkml.org/lkml/2016/8/23/360
>
> If so you may try to revert commit ff9a9b4c4334 ("sched, time: Switch
> VIRT_CPU_ACCOUNTING_GEN to jiffy granularity") to see if it helps.
>
>
> Vegard
^ permalink raw reply [flat|nested] 5+ messages in thread* Re: Random abnormal high CPU sys usage related to timer
2016-08-27 15:13 ` Mac Lin
@ 2016-08-29 10:45 ` Thomas Gleixner
2016-08-29 16:26 ` Mac Lin
0 siblings, 1 reply; 5+ messages in thread
From: Thomas Gleixner @ 2016-08-29 10:45 UTC (permalink / raw)
To: Mac Lin; +Cc: Vegard Nossum, John Stultz, LKML
On Sat, 27 Aug 2016, Mac Lin wrote:
> Hi Vegard,
> Thanks for the prompt response.
> The commit is introduced since 4.6, but the issue can be reproduced at
> 3.10 (earliest I have ever test). And testing on buildroot+4.7 with
> the commit reverted, the issue still happen.
>
> In fact, I did a test that ran a script that keep increase a counter
> for 10 seconds on the same CPU. If I ran 2 of it, the number is half
> of running 1. But if I ran it while the issue happened, the counter
> reported is around the same value as the 1 process case. So I doubt
> that it might be an issue of reported number.
>
> Is there other way to ensure the CPU is "really" doing something?
Tracing will tell you exactly what's going on in the system.
Thanks,
tglx
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: Random abnormal high CPU sys usage related to timer
2016-08-29 10:45 ` Thomas Gleixner
@ 2016-08-29 16:26 ` Mac Lin
0 siblings, 0 replies; 5+ messages in thread
From: Mac Lin @ 2016-08-29 16:26 UTC (permalink / raw)
To: Thomas Gleixner; +Cc: Vegard Nossum, John Stultz, LKML
[-- Attachment #1: Type: text/plain, Size: 1714 bytes --]
On Mon, Aug 29, 2016 at 6:45 PM, Thomas Gleixner <tglx@linutronix.de> wrote:
> Tracing will tell you exactly what's going on in the system.
Will, it seems that I lost my direction. But anyway, there are some
gains to revisit the old tests.
>>> I've checked the /proc/timer_stats, /proc/interrupts, and perf, all
>>> the irq counter, timer counter, timer/irq event didn't show any
>>> abnormal value or useful clue.
I have to take that back. The above result is with another test code
which is harder to reproduce the issue.
Attached the debug info get with and without the issue. Comparing the
two got the following:
* The /proc/timer_stats is almost the same, but perf events shows
extra softirq/timer events.
* The perf sample of the failed case is much more than the good case,
but the ratio of the sampled functions are basically the same.
On Mon, Aug 29, 2016 at 6:45 PM, Thomas Gleixner <tglx@linutronix.de> wrote:
> On Sat, 27 Aug 2016, Mac Lin wrote:
>> Hi Vegard,
>> Thanks for the prompt response.
>> The commit is introduced since 4.6, but the issue can be reproduced at
>> 3.10 (earliest I have ever test). And testing on buildroot+4.7 with
>> the commit reverted, the issue still happen.
>>
>> In fact, I did a test that ran a script that keep increase a counter
>> for 10 seconds on the same CPU. If I ran 2 of it, the number is half
>> of running 1. But if I ran it while the issue happened, the counter
>> reported is around the same value as the 1 process case. So I doubt
>> that it might be an issue of reported number.
>>
>> Is there other way to ensure the CPU is "really" doing something?
>
> Tracing will tell you exactly what's going on in the system.
>
> Thanks,
>
> tglx
[-- Attachment #2: debug-fail.log --]
[-- Type: text/x-log, Size: 26422 bytes --]
# echo 1 > /proc/timer_stats;sleep 10;
# echo 0 > /proc/timer_stats; cat /proc/timer_stats | sort -t ',' -b -k 2 -n | grep test
6, 25294 test-host do_nanosleep (hrtimer_wakeup)
99717, 25294 test-host hrtimer_start (it_real_fn)
# sudo perf stat -e irq:*,timer:* -p $(pidof test-host) sleep 10
Warning: unknown op '{'
Warning: unknown op '{'
Performance counter stats for process id '25294':
0 irq:irq_handler_entry
0 irq:irq_handler_exit
2,706 irq:softirq_entry
2,712 irq:softirq_exit
2,716 irq:softirq_raise
0 timer:timer_init
5 timer:timer_start
648 timer:timer_expire_entry
649 timer:timer_expire_exit
650 timer:timer_cancel
101,175 timer:hrtimer_init
204,365 timer:hrtimer_start
1,865 timer:hrtimer_expire_entry
1,867 timer:hrtimer_expire_exit
103,351 timer:hrtimer_cancel
0 timer:itimer_state
5 timer:itimer_expire
0 timer:tick_stop
10.000852806 seconds time elapsed
# sudo perf stat -p $(pidof test-host) sleep 10
Performance counter stats for process id '25294':
786.097515 task-clock (msec) # 0.079 CPUs utilized
100,425 context-switches # 0.128 M/sec
0 cpu-migrations # 0.000 K/sec
<not counted> page-faults
614,752,853 cycles # 0.782 GHz [100.00%]
<not supported> stalled-cycles-frontend
<not supported> stalled-cycles-backend
708,966,076 instructions # 1.15 insns per cycle
132,275,374 branches # 168.268 M/sec
901,980 branch-misses # 0.68% of all branches
10.001767161 seconds time elapsed
# sudo perf record -p $(pidof test-host) -s -T -R sleep 10
[ perf record: Woken up 8 times to write data ]
[ perf record: Captured and wrote 1.865 MB perf.data (~81471 samples) ]
# sudo perf report -I -n | grep xxxxxxxxxxa -v
# ========
# captured on: Mon Aug 29 23:13:13 2016
# hostname : test-Vostro-5470
# os release : 3.13.0-45-generic
# perf version : 3.13.11-ckt13
# arch : x86_64
# nrcpus online : 4
# nrcpus avail : 4
# cpudesc : Intel(R) Core(TM) i5-4200U CPU @ 1.60GHz
# cpuid : GenuineIntel,6,69,1
# total memory : 3953448 kB
# cmdline : /usr/lib/linux-tools-3.13.0-45/perf record -p 25294 -s -T -R sleep 10
# event : name = cycles, type = 0, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, excl_host = 0, excl_guest = 1, precise_ip = 0, attr_mmap2 = 0, attr_mmap = 1, attr_mmap_data = 0
# sibling cores : 0-3
# sibling threads : 0-1
# sibling threads : 2-3
# node0 meminfo : total = 3953448 kB, free = 207796 kB
# node0 cpu list : 0-3
# pmu mappings: cpu = 4, software = 1, tracepoint = 2, breakpoint = 5
# ========
#
# Samples: 34K of event 'cycles'
# Event count (approx.): 597604549
#
# Overhead Samples Command Shared Object Symbol
# ........ ............ ......... ................. ..........................................
#
11.12% 3641 test-host [kernel.kallsyms] [k] native_write_msr_safe
7.20% 2443 test-host test-host [.] timer_handler
6.88% 2426 test-host libc-2.19.so [.] __GI___libc_nanosleep
4.06% 1417 test-host [kernel.kallsyms] [k] update_cfs_shares
3.54% 1243 test-host [kernel.kallsyms] [k] do_signal
2.41% 747 test-host [kernel.kallsyms] [k] __restore_xstate_sig
2.33% 761 test-host [kernel.kallsyms] [k] do_nanosleep
2.13% 772 test-host [kernel.kallsyms] [k] update_curr
2.06% 730 test-host [kernel.kallsyms] [k] save_xstate_sig
2.05% 744 test-host [kernel.kallsyms] [k] dequeue_entity
1.96% 718 test-host [kernel.kallsyms] [k] __calc_delta
1.87% 600 test-host [kernel.kallsyms] [k] hrtimer_nanosleep
1.83% 638 test-host [kernel.kallsyms] [k] _raw_spin_lock_irq
1.58% 561 test-host [kernel.kallsyms] [k] cpuacct_charge
1.58% 568 test-host [kernel.kallsyms] [k] __schedule
1.58% 486 test-host [kernel.kallsyms] [k] _raw_spin_lock_irqsave
1.57% 571 test-host [kernel.kallsyms] [k] native_read_tsc
1.57% 496 test-host [kernel.kallsyms] [k] __hrtimer_start_range_ns
1.41% 497 test-host [kernel.kallsyms] [k] copy_user_enhanced_fast_string
1.34% 485 test-host [kernel.kallsyms] [k] _raw_spin_unlock_irqrestore
1.32% 487 test-host [kernel.kallsyms] [k] timerqueue_add
1.28% 462 test-host [kernel.kallsyms] [k] system_call
1.25% 443 test-host [kernel.kallsyms] [k] _raw_spin_lock
1.22% 444 test-host [kernel.kallsyms] [k] setup_sigcontext
1.17% 408 test-host [kernel.kallsyms] [k] system_call_after_swapgs
1.15% 329 test-host test-host [.] main
1.14% 420 test-host [kernel.kallsyms] [k] recalc_sigpending
1.11% 410 test-host [kernel.kallsyms] [k] dequeue_task_fair
1.00% 367 test-host [kernel.kallsyms] [k] kmem_cache_free
0.92% 340 test-host [kernel.kallsyms] [k] free_uid
0.89% 318 test-host [kernel.kallsyms] [k] ktime_get
0.85% 305 test-host [kernel.kallsyms] [k] get_signal_to_deliver
0.84% 300 test-host [kernel.kallsyms] [k] account_entity_dequeue
0.83% 301 test-host [kernel.kallsyms] [k] clockevents_program_event
0.82% 299 test-host [kernel.kallsyms] [k] update_min_vruntime
0.76% 276 test-host libc-2.19.so [.] __restore_rt
0.71% 176 test-host [kernel.kallsyms] [k] __dequeue_signal
0.66% 160 test-host [kernel.kallsyms] [k] perf_event_context_sched_in
0.60% 212 test-host libc-2.19.so [.] usleep
0.59% 224 test-host [kernel.kallsyms] [k] hrtimer_init
0.58% 200 test-host [kernel.kallsyms] [k] schedule
0.56% 207 test-host [kernel.kallsyms] [k] sys_nanosleep
0.55% 204 test-host [kernel.kallsyms] [k] _atomic_dec_and_lock
0.54% 200 test-host [kernel.kallsyms] [k] rb_insert_color
0.54% 205 test-host [kernel.kallsyms] [k] put_prev_task_fair
0.54% 190 test-host [kernel.kallsyms] [k] system_call_fastpath
0.54% 189 test-host [kernel.kallsyms] [k] __sigqueue_free.part.11
0.52% 189 test-host [kernel.kallsyms] [k] sched_clock_cpu
0.51% 185 test-host [kernel.kallsyms] [k] local_clock
0.48% 174 test-host [kernel.kallsyms] [k] do_sigaltstack
0.46% 155 test-host [kernel.kallsyms] [k] finish_task_switch
0.44% 155 test-host [kernel.kallsyms] [k] dequeue_signal
0.43% 158 test-host [kernel.kallsyms] [k] perf_pmu_rotate_start.isra.39
0.40% 149 test-host [kernel.kallsyms] [k] native_sched_clock
0.40% 142 test-host [kernel.kallsyms] [k] update_cfs_rq_blocked_load
0.38% 140 test-host [kernel.kallsyms] [k] __set_current_blocked
0.38% 131 test-host [kernel.kallsyms] [k] enqueue_hrtimer
0.38% 132 test-host [kernel.kallsyms] [k] pick_next_task_stop
0.36% 51 test-host [kernel.kallsyms] [k] int_with_check
0.36% 133 test-host [kernel.kallsyms] [k] ctx_sched_out
0.35% 120 test-host [kernel.kallsyms] [k] recalc_sigpending_tsk
0.35% 124 test-host [kernel.kallsyms] [k] restore_sigcontext
0.33% 124 test-host [kernel.kallsyms] [k] hrtimer_try_to_cancel
0.32% 117 test-host [kernel.kallsyms] [k] __clear_user
0.32% 39 test-host [kernel.kallsyms] [k] uprobe_deny_signal
0.31% 112 test-host [kernel.kallsyms] [k] perf_pmu_disable
0.31% 111 test-host [kernel.kallsyms] [k] lock_hrtimer_base.isra.19
0.31% 102 test-host [kernel.kallsyms] [k] _cond_resched
0.30% 102 test-host [kernel.kallsyms] [k] __remove_hrtimer
0.29% 107 test-host [kernel.kallsyms] [k] account_entity_enqueue
0.28% 105 test-host [kernel.kallsyms] [k] sysret_signal
0.26% 90 test-host [kernel.kallsyms] [k] read_tsc
0.25% 91 test-host [kernel.kallsyms] [k] pick_next_task_fair
0.24% 88 test-host [kernel.kallsyms] [k] hrtimer_force_reprogram
0.24% 89 test-host [kernel.kallsyms] [k] sys_rt_sigreturn
0.24% 86 test-host [kernel.kallsyms] [k] __perf_event_task_sched_out
0.24% 83 test-host [kernel.kallsyms] [k] stub_rt_sigreturn
0.23% 83 test-host [kernel.kallsyms] [k] __set_task_blocked
0.23% 85 test-host [kernel.kallsyms] [k] dequeue_task
0.23% 82 test-host [kernel.kallsyms] [k] tick_program_event
0.22% 82 test-host [kernel.kallsyms] [k] _raw_spin_unlock
0.22% 79 test-host [kernel.kallsyms] [k] ctx_sched_in
0.20% 75 test-host [kernel.kallsyms] [k] lapic_next_deadline
0.20% 78 test-host [kernel.kallsyms] [k] ret_from_sys_call
0.19% 67 test-host [kernel.kallsyms] [k] hrtimer_forward
0.18% 64 test-host [kernel.kallsyms] [k] signal_delivered
0.17% 61 test-host [kernel.kallsyms] [k] do_notify_resume
0.17% 63 test-host [kernel.kallsyms] [k] __perf_event_task_sched_in
0.17% 63 test-host [kernel.kallsyms] [k] idle_cpu
0.16% 56 test-host [kernel.kallsyms] [k] idle_balance
0.16% 55 test-host [kernel.kallsyms] [k] rb_erase
0.15% 58 test-host [kernel.kallsyms] [k] clear_buddies
0.15% 50 test-host [kernel.kallsyms] [k] x86_pmu_enable
0.14% 50 test-host [kernel.kallsyms] [k] int_check_syscall_exit_work
0.13% 51 test-host [kernel.kallsyms] [k] apic_timer_interrupt
0.12% 42 test-host [kernel.kallsyms] [k] pick_next_task_rt
0.11% 40 test-host [kernel.kallsyms] [k] perf_event_sched_in
0.11% 41 test-host [kernel.kallsyms] [k] retint_swapgs
0.11% 40 test-host [kernel.kallsyms] [k] perf_pmu_enable
0.10% 36 test-host [kernel.kallsyms] [k] restore_args
0.10% 37 test-host [kernel.kallsyms] [k] update_rq_clock.part.63
0.10% 35 test-host [kernel.kallsyms] [k] restore_altstack
0.10% 33 test-host [kernel.kallsyms] [k] perf_pmu_nop_void
0.09% 33 test-host [kernel.kallsyms] [k] timerqueue_del
0.08% 31 test-host [kernel.kallsyms] [k] rcu_note_context_switch
0.08% 27 test-host [kernel.kallsyms] [k] rb_next
0.08% 29 test-host [kernel.kallsyms] [k] perf_event_task_sched_out
0.08% 28 test-host [kernel.kallsyms] [k] int_restore_rest
0.07% 27 test-host [kernel.kallsyms] [k] signal_setup_done
0.07% 23 test-host [kernel.kallsyms] [k] x86_pmu_disable
0.07% 24 test-host [kernel.kallsyms] [k] task_tick_fair
0.06% 23 test-host [kernel.kallsyms] [k] intel_pmu_enable_all
0.06% 22 test-host [kernel.kallsyms] [k] intel_pmu_disable_all
0.06% 19 test-host [kernel.kallsyms] [k] hrtimer_start_range_ns
0.06% 21 test-host [kernel.kallsyms] [k] sysret_check
0.06% 21 test-host [kernel.kallsyms] [k] update_wall_time
0.05% 16 test-host [kernel.kallsyms] [k] native_irq_return_iret
0.05% 17 test-host [kernel.kallsyms] [k] __do_softirq
0.05% 19 test-host [kernel.kallsyms] [k] run_timer_softirq
0.04% 15 test-host [kernel.kallsyms] [k] set_current_blocked
0.04% 15 test-host [kernel.kallsyms] [k] cpu_needs_another_gp
0.04% 14 test-host [kernel.kallsyms] [k] rcu_check_callbacks
0.04% 15 test-host [kernel.kallsyms] [k] pick_next_task_idle
0.04% 15 test-host [kernel.kallsyms] [k] irq_exit
0.04% 12 test-host [kernel.kallsyms] [k] trigger_load_balance
0.03% 13 test-host [kernel.kallsyms] [k] deactivate_task
0.03% 11 test-host [kernel.kallsyms] [k] sched_clock
0.03% 11 test-host [kernel.kallsyms] [k] int_ret_from_sys_call
0.03% 8 test-host [kernel.kallsyms] [k] _copy_from_user
0.03% 11 test-host [kernel.kallsyms] [k] rcu_irq_enter
0.03% 10 test-host [kernel.kallsyms] [k] perf_event_task_tick
0.03% 7 test-host [kernel.kallsyms] [k] enqueue_task_fair
0.02% 9 test-host [kernel.kallsyms] [k] account_system_time
0.02% 9 test-host [kernel.kallsyms] [k] hrtick_update
0.02% 8 test-host [kernel.kallsyms] [k] notifier_call_chain
0.02% 8 test-host [kernel.kallsyms] [k] int_signal
0.02% 7 test-host [kernel.kallsyms] [k] check_preempt_wakeup
0.02% 8 test-host [kernel.kallsyms] [k] nohz_balance_exit_idle.part.53
0.02% 8 test-host [kernel.kallsyms] [k] calc_global_load
0.02% 8 test-host [kernel.kallsyms] [k] enqueue_entity
0.02% 7 test-host [kernel.kallsyms] [k] account_process_tick
0.02% 4 test-host [kernel.kallsyms] [k] wq_worker_waking_up
0.02% 7 test-host test-host [.] usleep@plt
0.02% 7 test-host [kernel.kallsyms] [k] sysret_careful
0.02% 7 test-host [kernel.kallsyms] [k] hrtimer_interrupt
0.02% 7 test-host [kernel.kallsyms] [k] __update_cpu_load
0.02% 7 test-host [kernel.kallsyms] [k] pvclock_gtod_notify
0.02% 6 test-host [kernel.kallsyms] [k] update_cpu_load_active
0.02% 6 test-host [kernel.kallsyms] [k] tick_do_update_jiffies64
0.02% 6 test-host [kernel.kallsyms] [k] raise_softirq
0.02% 6 test-host [kernel.kallsyms] [k] cpumask_clear_cpu
0.02% 6 test-host [kernel.kallsyms] [k] update_vsyscall
0.02% 6 test-host [kernel.kallsyms] [k] rcu_irq_exit
0.01% 6 test-host [kernel.kallsyms] [k] kthread_data
0.01% 3 test-host [kernel.kallsyms] [k] msecs_to_jiffies
0.01% 5 test-host [kernel.kallsyms] [k] rcu_process_callbacks
0.01% 5 test-host [kernel.kallsyms] [k] __acct_update_integrals
0.01% 5 test-host [kernel.kallsyms] [k] profile_tick
0.01% 5 test-host [kernel.kallsyms] [k] run_posix_cpu_timers
0.01% 4 test-host [kernel.kallsyms] [k] insert_work
0.01% 4 test-host [kernel.kallsyms] [k] __irq_work_run
0.01% 4 test-host [kernel.kallsyms] [k] cpuacct_account_field
0.01% 4 test-host [kernel.kallsyms] [k] perf_adjust_freq_unthr_context.part.79
0.01% 4 test-host [kernel.kallsyms] [k] ret_from_intr
0.01% 4 test-host [kernel.kallsyms] [k] rcu_bh_qs
0.01% 2 test-host [kernel.kallsyms] [k] wake_up_process
0.01% 4 test-host [kernel.kallsyms] [k] update_process_times
0.01% 4 test-host [kernel.kallsyms] [k] update_blocked_averages
0.01% 3 test-host [kernel.kallsyms] [k] scheduler_tick
0.01% 3 test-host [kernel.kallsyms] [k] fget_light
0.01% 3 test-host [kernel.kallsyms] [k] __local_bh_enable
0.01% 3 test-host [kernel.kallsyms] [k] timekeeping_update.constprop.9
0.01% 3 test-host [kernel.kallsyms] [k] local_apic_timer_interrupt
0.01% 3 test-host [kernel.kallsyms] [k] ktime_get_update_offsets
0.01% 3 test-host [kernel.kallsyms] [k] native_apic_mem_write
0.01% 3 test-host [kernel.kallsyms] [k] hrtimer_run_pending
0.01% 2 test-host [kernel.kallsyms] [k] invoke_rcu_core
0.01% 2 test-host [kernel.kallsyms] [k] note_gp_changes
0.01% 2 test-host [kernel.kallsyms] [k] find_busiest_group
0.01% 2 test-host [kernel.kallsyms] [k] tty_write
0.01% 2 test-host [kernel.kallsyms] [k] check_preempt_curr
0.01% 1 test-host [kernel.kallsyms] [k] tick_sched_do_timer
0.01% 2 test-host [kernel.kallsyms] [k] __queue_work
0.01% 2 test-host [kernel.kallsyms] [k] hrtimer_run_queues
0.01% 2 test-host [kernel.kallsyms] [k] ntp_tick_length
0.01% 2 test-host [kernel.kallsyms] [k] fetch_task_cputime
0.01% 2 test-host libc-2.19.so [.] _IO_file_write@@GLIBC_2.2.5
0.01% 2 test-host [kernel.kallsyms] [k] irq_enter
0.01% 2 test-host [kernel.kallsyms] [k] __enqueue_entity
0.01% 2 test-host [kernel.kallsyms] [k] load_balance
0.01% 2 test-host [kernel.kallsyms] [k] tick_sched_handle.isra.17
0.01% 2 test-host [kernel.kallsyms] [k] rcu_report_qs_rnp
0.00% 2 test-host [kernel.kallsyms] [k] set_next_buddy
0.00% 2 test-host [kernel.kallsyms] [k] __run_hrtimer
0.00% 2 test-host [kernel.kallsyms] [k] get_work_pool
0.00% 1 test-host [kernel.kallsyms] [k] prepare_signal
0.00% 1 test-host [kernel.kallsyms] [k] retint_careful
0.00% 1 test-host [kernel.kallsyms] [k] smp_apic_timer_interrupt
0.00% 1 test-host libc-2.19.so [.] _IO_do_write@@GLIBC_2.2.5
0.00% 1 test-host [kernel.kallsyms] [k] _raw_spin_trylock
0.00% 1 test-host [kernel.kallsyms] [k] raw_notifier_call_chain
0.00% 1 test-host [kernel.kallsyms] [k] update_stats_wait_end
0.00% 1 test-host [kernel.kallsyms] [k] int_careful
0.00% 1 test-host [kernel.kallsyms] [k] tty_insert_flip_string_fixed_flag
0.00% 1 test-host [kernel.kallsyms] [k] update_group_power
0.00% 1 test-host [kernel.kallsyms] [k] rcu_sysidle_exit
0.00% 1 test-host [kernel.kallsyms] [k] kmem_cache_alloc
0.00% 1 test-host [kernel.kallsyms] [k] wakeup_gran.isra.47
0.00% 1 test-host [kernel.kallsyms] [k] account_user_time
0.00% 1 test-host [kernel.kallsyms] [k] acct_account_cputime
0.00% 1 test-host [kernel.kallsyms] [k] __note_gp_changes
0.00% 1 test-host [kernel.kallsyms] [k] wake_up_worker
0.00% 1 test-host [kernel.kallsyms] [k] resched_task
0.00% 1 test-host [kernel.kallsyms] [k] find_next_bit
0.00% 1 test-host [kernel.kallsyms] [k] rcu_sysidle_enter
0.00% 1 test-host [kernel.kallsyms] [k] ttwu_stat
0.00% 1 test-host [kernel.kallsyms] [k] do_timer
0.00% 1 test-host [kernel.kallsyms] [k] set_next_entity
0.00% 1 test-host [kernel.kallsyms] [k] rebalance_domains
0.00% 1 test-host [kernel.kallsyms] [k] delayed_work_timer_fn
0.00% 1 test-host [kernel.kallsyms] [k] set_normalized_timespec
0.00% 1 test-host [kernel.kallsyms] [k] schedule_user
0.00% 1 test-host [kernel.kallsyms] [k] tick_sched_timer
0.00% 1 test-host [kernel.kallsyms] [k] place_entity
0.00% 1 test-host libc-2.19.so [.] vfprintf
#
# (For a higher level overview, try: perf report --sort comm,dso)
#
[-- Attachment #3: debug-good.log --]
[-- Type: text/x-log, Size: 12165 bytes --]
# echo 1 > /proc/timer_stats;sleep 10;
# echo 0 > /proc/timer_stats; cat /proc/timer_stats | sort -t ',' -b -k 2 -n | grep test
6, 25115 test-host do_nanosleep (hrtimer_wakeup)
99867, 25115 test-host hrtimer_start (it_real_fn)
# sudo perf stat -e irq:*,timer:* -p $(pidof test-host) sleep 10
Warning: unknown op '{'
Warning: unknown op '{'
Performance counter stats for process id '25115':
0 irq:irq_handler_entry
0 irq:irq_handler_exit
0 irq:softirq_entry
0 irq:softirq_exit
0 irq:softirq_raise
0 timer:timer_init
0 timer:timer_start
0 timer:timer_expire_entry
0 timer:timer_expire_exit
0 timer:timer_cancel
100,745 timer:hrtimer_init
201,652 timer:hrtimer_start
4 timer:hrtimer_expire_entry
4 timer:hrtimer_expire_exit
101,065 timer:hrtimer_cancel
0 timer:itimer_state
2 timer:itimer_expire
0 timer:tick_stop
10.000763356 seconds time elapsed
# sudo perf stat -p $(pidof test-host) sleep 10
Performance counter stats for process id '25115':
847.348719 task-clock (msec) # 0.085 CPUs utilized
99,981 context-switches # 0.118 M/sec
0 cpu-migrations # 0.000 K/sec
0 page-faults # 0.000 K/sec
607,782,792 cycles # 0.717 GHz
<not supported> stalled-cycles-frontend
<not supported> stalled-cycles-backend
700,673,778 instructions # 1.15 insns per cycle
130,516,259 branches # 154.029 M/sec
887,230 branch-misses # 0.68% of all branches
10.000683870 seconds time elapsed
# sudo perf record -p $(pidof test-host) -s -T -R sleep 10
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.039 MB perf.data (~1685 samples) ]
# sudo perf report -I -n | grep xxxxxxxxxxa -v
# ========
# captured on: Mon Aug 29 23:09:44 2016
# hostname : test-Vostro-5470
# os release : 3.13.0-45-generic
# perf version : 3.13.11-ckt13
# arch : x86_64
# nrcpus online : 4
# nrcpus avail : 4
# cpudesc : Intel(R) Core(TM) i5-4200U CPU @ 1.60GHz
# cpuid : GenuineIntel,6,69,1
# total memory : 3953448 kB
# cmdline : /usr/lib/linux-tools-3.13.0-45/perf record -p 25115 -s -T -R sleep 10
# event : name = cycles, type = 0, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, excl_host = 0, excl_guest = 1, precise_ip = 0, attr_mmap2 = 0, attr_mmap = 1, attr_mmap_data = 0
# sibling cores : 0-3
# sibling threads : 0-1
# sibling threads : 2-3
# node0 meminfo : total = 3953448 kB, free = 182324 kB
# node0 cpu list : 0-3
# pmu mappings: cpu = 4, software = 1, tracepoint = 2, breakpoint = 5
# ========
#
# Samples: 442 of event 'cycles'
# Event count (approx.): 534240571
#
# Overhead Samples Command Shared Object Symbol
# ........ ............ ......... ................. ..................................
#
11.78% 68 test-host [kernel.kallsyms] [k] native_write_msr_safe
5.29% 22 test-host test-host [.] timer_handler
5.29% 22 test-host libc-2.19.so [.] __GI___libc_nanosleep
3.85% 16 test-host [kernel.kallsyms] [k] do_signal
3.60% 15 test-host [kernel.kallsyms] [k] update_cfs_shares
2.88% 12 test-host [kernel.kallsyms] [k] dequeue_entity
2.40% 10 test-host [kernel.kallsyms] [k] __restore_xstate_sig
2.40% 10 test-host [kernel.kallsyms] [k] hrtimer_nanosleep
2.40% 10 test-host [kernel.kallsyms] [k] kmem_cache_free
2.16% 9 test-host [kernel.kallsyms] [k] hrtimer_init
2.16% 9 test-host [kernel.kallsyms] [k] do_nanosleep
1.92% 8 test-host [kernel.kallsyms] [k] save_xstate_sig
1.70% 7 test-host [kernel.kallsyms] [k] system_call_after_swapgs
1.68% 7 test-host [kernel.kallsyms] [k] recalc_sigpending
1.68% 7 test-host [kernel.kallsyms] [k] __hrtimer_start_range_ns
1.68% 7 test-host [kernel.kallsyms] [k] __calc_delta
1.68% 7 test-host [kernel.kallsyms] [k] update_curr
1.68% 7 test-host [kernel.kallsyms] [k] dequeue_task_fair
1.68% 7 test-host [kernel.kallsyms] [k] ktime_get
1.44% 6 test-host [kernel.kallsyms] [k] timerqueue_add
1.44% 6 test-host [kernel.kallsyms] [k] _raw_spin_lock
1.44% 6 test-host [kernel.kallsyms] [k] _raw_spin_lock_irq
1.20% 5 test-host libc-2.19.so [.] usleep
1.20% 5 test-host [kernel.kallsyms] [k] setup_sigcontext
1.20% 5 test-host [kernel.kallsyms] [k] native_read_tsc
1.20% 5 test-host [kernel.kallsyms] [k] do_sigaltstack
1.20% 5 test-host [kernel.kallsyms] [k] update_min_vruntime
1.20% 5 test-host [kernel.kallsyms] [k] cpuacct_charge
1.20% 5 test-host [kernel.kallsyms] [k] ctx_sched_out
1.20% 5 test-host [kernel.kallsyms] [k] copy_user_enhanced_fast_string
1.20% 5 test-host [kernel.kallsyms] [k] _raw_spin_unlock_irqrestore
1.20% 5 test-host [kernel.kallsyms] [k] int_check_syscall_exit_work
1.20% 5 test-host [kernel.kallsyms] [k] __schedule
0.96% 7 test-host [kernel.kallsyms] [k] perf_event_context_sched_in
0.96% 4 test-host [kernel.kallsyms] [k] get_signal_to_deliver
0.96% 4 test-host [kernel.kallsyms] [k] sched_clock_cpu
0.96% 4 test-host [kernel.kallsyms] [k] finish_task_switch
0.96% 4 test-host [kernel.kallsyms] [k] system_call
0.72% 4 test-host [kernel.kallsyms] [k] perf_pmu_rotate_start.isra.39
0.72% 3 test-host [kernel.kallsyms] [k] hrtimer_try_to_cancel
0.72% 3 test-host [kernel.kallsyms] [k] sys_nanosleep
0.72% 3 test-host [kernel.kallsyms] [k] account_entity_dequeue
0.72% 3 test-host [kernel.kallsyms] [k] put_prev_task_fair
0.72% 3 test-host [kernel.kallsyms] [k] perf_event_sched_in
0.72% 3 test-host [kernel.kallsyms] [k] _raw_spin_lock_irqsave
0.72% 3 test-host [kernel.kallsyms] [k] stub_rt_sigreturn
0.48% 2 test-host test-host [.] main
0.48% 2 test-host libc-2.19.so [.] __restore_rt
0.48% 2 test-host [kernel.kallsyms] [k] sys_rt_sigreturn
0.48% 2 test-host [kernel.kallsyms] [k] read_tsc
0.48% 2 test-host [kernel.kallsyms] [k] native_sched_clock
0.48% 2 test-host [kernel.kallsyms] [k] free_uid
0.48% 2 test-host [kernel.kallsyms] [k] __sigqueue_free.part.11
0.48% 2 test-host [kernel.kallsyms] [k] restore_altstack
0.48% 2 test-host [kernel.kallsyms] [k] pick_next_task_fair
0.48% 2 test-host [kernel.kallsyms] [k] perf_pmu_disable
0.48% 2 test-host [kernel.kallsyms] [k] __perf_event_task_sched_in
0.48% 2 test-host [kernel.kallsyms] [k] __perf_event_task_sched_out
0.48% 2 test-host [kernel.kallsyms] [k] schedule
0.48% 2 test-host [kernel.kallsyms] [k] system_call_fastpath
0.48% 2 test-host [kernel.kallsyms] [k] sysret_signal
0.48% 2 test-host [kernel.kallsyms] [k] __set_current_blocked
0.48% 2 test-host [kernel.kallsyms] [k] __remove_hrtimer
0.48% 2 test-host [kernel.kallsyms] [k] clockevents_program_event
0.25% 2 test-host [kernel.kallsyms] [k] _atomic_dec_and_lock
0.24% 1 test-host [kernel.kallsyms] [k] restore_sigcontext
0.24% 1 test-host [kernel.kallsyms] [k] do_notify_resume
0.24% 1 test-host [kernel.kallsyms] [k] x86_pmu_disable
0.24% 1 test-host [kernel.kallsyms] [k] intel_pmu_disable_all
0.24% 1 test-host [kernel.kallsyms] [k] __dequeue_signal
0.24% 1 test-host [kernel.kallsyms] [k] dequeue_signal
0.24% 1 test-host [kernel.kallsyms] [k] __set_task_blocked
0.24% 1 test-host [kernel.kallsyms] [k] enqueue_hrtimer
0.24% 1 test-host [kernel.kallsyms] [k] idle_cpu
0.24% 1 test-host [kernel.kallsyms] [k] local_clock
0.24% 1 test-host [kernel.kallsyms] [k] pick_next_task_idle
0.24% 1 test-host [kernel.kallsyms] [k] update_cfs_rq_blocked_load
0.24% 1 test-host [kernel.kallsyms] [k] clear_buddies
0.24% 1 test-host [kernel.kallsyms] [k] pick_next_task_rt
0.24% 1 test-host [kernel.kallsyms] [k] pick_next_task_stop
0.24% 1 test-host [kernel.kallsyms] [k] perf_pmu_enable
0.24% 1 test-host [kernel.kallsyms] [k] rb_insert_color
0.24% 1 test-host [kernel.kallsyms] [k] __clear_user
0.24% 1 test-host [kernel.kallsyms] [k] retint_swapgs
0.24% 1 test-host [kernel.kallsyms] [k] sysret_check
0.24% 1 test-host [kernel.kallsyms] [k] hrtimer_start_range_ns
0.00% 1 test-host [kernel.kallsyms] [k] _raw_spin_unlock
0.00% 1 test-host [kernel.kallsyms] [k] x86_pmu_enable
#
# (For a higher level overview, try: perf report --sort comm,dso)
#
^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2016-08-29 16:27 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2016-08-26 17:10 Random abnormal high CPU sys usage related to timer Mac Lin
2016-08-26 21:12 ` Vegard Nossum
2016-08-27 15:13 ` Mac Lin
2016-08-29 10:45 ` Thomas Gleixner
2016-08-29 16:26 ` Mac Lin
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).