On 10/5/22 18:23, Daniel Bristot de Oliveira wrote:
On 10/5/22 18:17, Florian Paul Schmidt wrote:
try:
# timerlat -a 100
wait for it to stop and save the trace. Then see what the trace points out at the
end of the trace.
What package contains the timerlat command? I gathered from searching
online for timerlat that it is part of the tracing machinery but I
didn't find the executable itself..
on fedora it is part of rtla, but you can compile it from the kernel source:
$ cd tools/tracing/rtla/
$ make
$ sudo make install
$ uname -a Linux ogfx86 5.17.0-rc1-rt1 #1-NixOS SMP PREEMPT_RT Sun Jan
23 08:12:53 UTC 2022 x86_64 GNU/Linux
I ran this command to produce a couple of traces (rtla timerlat from the
5.17-rc1 source didn't have an -a option(
$ for n in 1 2 3 4 5; do sudo ./rtla timerlat -T 100 -s 100 \
-t=trace"$n".txt; done
They are 13M each. Attached are just the tails for a start. Do you want
to see the whole thing?
FPS
<idle>-0 [002] dp..3.. 1052.612790: thread_noise: swapper/2:0 start 1052.612783310 duration 2426 ns
timerlat/2-5126 [002] .p..... 1052.612790: #10199 context thread timer_latency 9169 ns
<idle>-0 [003] dp.h1.. 1052.613487: #10199 context irq timer_latency 2817 ns
<idle>-0 [003] dN.h2.. 1052.613491: irq_noise: local_timer:236 start 1052.613486553 duration 3924 ns
<idle>-0 [003] dp..3.. 1052.613493: thread_noise: swapper/3:0 start 1052.613486797 duration 2583 ns
timerlat/3-5127 [003] .p..... 1052.613494: #10199 context thread timer_latency 9957 ns
<idle>-0 [000] dp.h1.. 1052.613672: #10200 context irq timer_latency 3153 ns
<idle>-0 [000] dN.h2.. 1052.613676: irq_noise: local_timer:236 start 1052.613671194 duration 4699 ns
<idle>-0 [000] dp..3.. 1052.613678: thread_noise: swapper/0:0 start 1052.613671411 duration 2449 ns
timerlat/0-5124 [000] .p..... 1052.613679: #10200 context thread timer_latency 10908 ns
<idle>-0 [001] dp.h1.. 1052.613727: #10200 context irq timer_latency 2296 ns
<idle>-0 [001] dN.h2.. 1052.613731: irq_noise: local_timer:236 start 1052.613726660 duration 4058 ns
<idle>-0 [001] dp..3.. 1052.613733: thread_noise: swapper/1:0 start 1052.613726886 duration 2255 ns
timerlat/1-5125 [001] .p..... 1052.613734: #10200 context thread timer_latency 9489 ns
<idle>-0 [002] dp.h1.. 1052.613784: #10200 context irq timer_latency 2332 ns
<idle>-0 [002] dN.h2.. 1052.613787: irq_noise: local_timer:236 start 1052.613783127 duration 3902 ns
<idle>-0 [002] dp..3.. 1052.613790: thread_noise: swapper/2:0 start 1052.613783359 duration 2358 ns
timerlat/2-5126 [002] .p..... 1052.613790: #10200 context thread timer_latency 9162 ns
<idle>-0 [003] dp.h1.. 1052.614487: #10200 context irq timer_latency 2748 ns
<idle>-0 [003] dN.h2.. 1052.614491: irq_noise: local_timer:236 start 1052.614486476 duration 3895 ns
<idle>-0 [003] dp..3.. 1052.614493: thread_noise: swapper/3:0 start 1052.614486712 duration 2475 ns
timerlat/3-5127 [003] .p..... 1052.614494: #10200 context thread timer_latency 9743 ns
<idle>-0 [000] dp.h1.. 1052.614671: #10201 context irq timer_latency 2387 ns
<idle>-0 [000] dN.h2.. 1052.614675: irq_noise: local_timer:236 start 1052.614670410 duration 4362 ns
<idle>-0 [000] dp..3.. 1052.614677: thread_noise: swapper/0:0 start 1052.614670629 duration 2428 ns
timerlat/0-5124 [000] .p..... 1052.614678: #10201 context thread timer_latency 9786 ns
<idle>-0 [001] dp.h1.. 1052.614727: #10201 context irq timer_latency 2327 ns
<idle>-0 [001] dN.h2.. 1052.614731: irq_noise: local_timer:236 start 1052.614726667 duration 4058 ns
<idle>-0 [001] dp..3.. 1052.614733: thread_noise: swapper/1:0 start 1052.614726901 duration 2329 ns
timerlat/1-5125 [001] .p..... 1052.614734: #10201 context thread timer_latency 9422 ns
<idle>-0 [002] dp.h1.. 1052.614784: #10201 context irq timer_latency 2351 ns
<idle>-0 [002] dN.h2.. 1052.614787: irq_noise: local_timer:236 start 1052.614783140 duration 3883 ns
<idle>-0 [002] dp..3.. 1052.614790: thread_noise: swapper/2:0 start 1052.614783362 duration 2406 ns
timerlat/2-5126 [002] .p..... 1052.614790: #10201 context thread timer_latency 9214 ns
<idle>-0 [003] dp.h1.. 1052.615487: #10201 context irq timer_latency 2791 ns
<idle>-0 [003] dN.h2.. 1052.615491: irq_noise: local_timer:236 start 1052.615486493 duration 3991 ns
<idle>-0 [003] dp..3.. 1052.615493: thread_noise: swapper/3:0 start 1052.615486739 duration 2535 ns
timerlat/3-5127 [003] .p..... 1052.615494: #10201 context thread timer_latency 9923 ns
<idle>-0 [000] dp.h1.. 1052.615672: #10202 context irq timer_latency 3156 ns
<idle>-0 [000] dN.h2.. 1052.615676: irq_noise: local_timer:236 start 1052.615671170 duration 4943 ns
<idle>-0 [000] dp..3.. 1052.615679: thread_noise: swapper/0:0 start 1052.615671382 duration 2401 ns
timerlat/0-5124 [000] .p..... 1052.615680: #10202 context thread timer_latency 11137 ns
<idle>-0 [001] dp.h1.. 1052.615727: #10202 context irq timer_latency 2314 ns
<idle>-0 [001] dN.h2.. 1052.615731: irq_noise: local_timer:236 start 1052.615726650 duration 3703 ns
<idle>-0 [001] dp..3.. 1052.615733: thread_noise: swapper/1:0 start 1052.615726872 duration 2245 ns
timerlat/1-5125 [001] .p..... 1052.615734: #10202 context thread timer_latency 8973 ns
<idle>-0 [002] dp.h1.. 1052.615784: #10202 context irq timer_latency 2287 ns
<idle>-0 [002] dN.h2.. 1052.615787: irq_noise: local_timer:236 start 1052.615783047 duration 3898 ns
<idle>-0 [002] dp..3.. 1052.615789: thread_noise: swapper/2:0 start 1052.615783282 duration 2378 ns
timerlat/2-5126 [002] .p..... 1052.615790: #10202 context thread timer_latency 9152 ns
<idle>-0 [003] dp.h1.. 1052.616487: #10202 context irq timer_latency 2803 ns
<idle>-0 [003] dN.h2.. 1052.616491: irq_noise: local_timer:236 start 1052.616486482 duration 4117 ns
<idle>-0 [003] dp..3.. 1052.616493: thread_noise: swapper/3:0 start 1052.616486735 duration 2420 ns
timerlat/3-5127 [003] .p..... 1052.616494: #10202 context thread timer_latency 10088 ns
<idle>-0 [000] dp.h1.. 1052.616672: #10203 context irq timer_latency 3202 ns
<idle>-0 [000] dN.h2.. 1052.616676: irq_noise: local_timer:236 start 1052.616671191 duration 4736 ns
<idle>-0 [000] dp..3.. 1052.616679: thread_noise: swapper/0:0 start 1052.616671412 duration 2401 ns
timerlat/0-5124 [000] .p..... 1052.616679: #10203 context thread timer_latency 10996 ns
<idle>-0 [001] dp.h1.. 1052.616727: #10203 context irq timer_latency 2275 ns
<idle>-0 [001] dN.h2.. 1052.616731: irq_noise: local_timer:236 start 1052.616726592 duration 4001 ns
<idle>-0 [001] dp..3.. 1052.616733: thread_noise: swapper/1:0 start 1052.616726817 duration 2240 ns
timerlat/1-5125 [001] .p..... 1052.616734: #10203 context thread timer_latency 9095 ns
<idle>-0 [002] dp.h1.. 1052.616784: #10203 context irq timer_latency 2331 ns
<idle>-0 [002] dN.h2.. 1052.616787: irq_noise: local_timer:236 start 1052.616783086 duration 3878 ns
<idle>-0 [002] dp..3.. 1052.616790: thread_noise: swapper/2:0 start 1052.616783310 duration 2430 ns
timerlat/2-5126 [002] .p..... 1052.616790: #10203 context thread timer_latency 9245 ns
<idle>-0 [003] dp.h1.. 1052.617487: #10203 context irq timer_latency 2746 ns
<idle>-0 [003] dN.h2.. 1052.617491: irq_noise: local_timer:236 start 1052.617486417 duration 3960 ns
<idle>-0 [003] dp..3.. 1052.617493: thread_noise: swapper/3:0 start 1052.617486662 duration 2491 ns
timerlat/3-5127 [003] .p..... 1052.617494: #10203 context thread timer_latency 10042 ns
<idle>-0 [000] dp.h1.. 1052.617672: #10204 context irq timer_latency 3123 ns
<idle>-0 [000] dN.h2.. 1052.617676: irq_noise: local_timer:236 start 1052.617671097 duration 4689 ns
<idle>-0 [000] dp..3.. 1052.617678: thread_noise: swapper/0:0 start 1052.617671317 duration 2471 ns
timerlat/0-5124 [000] .p..... 1052.617679: #10204 context thread timer_latency 10935 ns
<idle>-0 [001] dp.h1.. 1052.617727: #10204 context irq timer_latency 2313 ns
<idle>-0 [001] dN.h2.. 1052.617731: irq_noise: local_timer:236 start 1052.617726609 duration 4024 ns
<idle>-0 [001] dp..3.. 1052.617733: thread_noise: swapper/1:0 start 1052.617726840 duration 2274 ns
timerlat/1-5125 [001] .p..... 1052.617734: #10204 context thread timer_latency 9183 ns
<idle>-0 [002] dp.h1.. 1052.617784: #10204 context irq timer_latency 2320 ns
<idle>-0 [002] dN.h2.. 1052.617787: irq_noise: local_timer:236 start 1052.617783054 duration 3856 ns
<idle>-0 [002] dp..3.. 1052.617789: thread_noise: swapper/2:0 start 1052.617783283 duration 2400 ns
timerlat/2-5126 [002] .p..... 1052.617791: #10204 context thread timer_latency 9457 ns
<idle>-0 [003] dp.h1.. 1052.618487: #10204 context irq timer_latency 2784 ns
<idle>-0 [003] dN.h2.. 1052.618491: irq_noise: local_timer:236 start 1052.618486440 duration 3959 ns
<idle>-0 [003] dp..3.. 1052.618493: thread_noise: swapper/3:0 start 1052.618486684 duration 2487 ns
timerlat/3-5127 [003] .p..... 1052.618494: #10204 context thread timer_latency 9824 ns
<idle>-0 [000] dp.h1.. 1052.618672: #10205 context irq timer_latency 3165 ns
<idle>-0 [000] dN.h2.. 1052.618676: irq_noise: local_timer:236 start 1052.618671120 duration 4875 ns
<idle>-0 [000] dp..3.. 1052.618679: thread_noise: swapper/0:0 start 1052.618671343 duration 2418 ns
timerlat/0-5124 [000] .p..... 1052.618680: #10205 context thread timer_latency 11099 ns
<idle>-0 [001] dp.h1.. 1052.618727: #10205 context irq timer_latency 2308 ns
<idle>-0 [001] dN.h2.. 1052.618731: irq_noise: local_timer:236 start 1052.618726597 duration 3742 ns
<idle>-0 [001] dp..3.. 1052.618733: thread_noise: swapper/1:0 start 1052.618726818 duration 2281 ns
timerlat/1-5125 [001] .p..... 1052.618734: #10205 context thread timer_latency 8917 ns
<idle>-0 [002] dp.h1.. 1052.618784: #10205 context irq timer_latency 2320 ns
<idle>-0 [002] dN.h2.. 1052.618787: irq_noise: local_timer:236 start 1052.618783048 duration 3774 ns
<idle>-0 [002] dp..3.. 1052.618789: thread_noise: swapper/2:0 start 1052.618783267 duration 2437 ns
timerlat/2-5126 [002] .p..... 1052.618790: #10205 context thread timer_latency 9131 ns
<idle>-0 [001] dN.h2.. 1052.619470: irq_noise: local_timer:236 start 1052.619465345 duration 4728 ns
<idle>-0 [003] dp.h1.. 1052.619486: #10205 context irq timer_latency 2337 ns
<idle>-0 [003] dN.h2.. 1052.619490: irq_noise: local_timer:236 start 1052.619485831 duration 4376 ns
<idle>-0 [003] dp..3.. 1052.619493: thread_noise: swapper/3:0 start 1052.619486221 duration 2524 ns
timerlat/3-5127 [003] .p..... 1052.619494: #10205 context thread timer_latency 9793 ns
<idle>-0 [001] dp.h2.. 1052.619601: irq_noise: local_timer:236 start 1052.619600094 duration 571 ns
<idle>-0 [000] dp.h1.. 1052.619671: #10206 context irq timer_latency 2612 ns
<idle>-0 [000] dN.h2.. 1052.619676: irq_noise: local_timer:236 start 1052.619670525 duration 5078 ns
<idle>-0 [000] dp..3.. 1052.619678: thread_noise: swapper/0:0 start 1052.619670778 duration 2419 ns
timerlat/0-5124 [000] .p..... 1052.619679: #10206 context thread timer_latency 10866 ns
kworker/1:1-4654 [001] dp.h1.. 1052.619731: #10206 context irq timer_latency 5951 ns
kworker/1:1-4654 [001] dN.h2.. 1052.619752: irq_noise: local_timer:236 start 1052.619730100 duration 21299 ns
kworker/1:1-4654 [001] dN.h2.. 1052.619755: irq_noise: irq_work:246 start 1052.619752671 duration 1751 ns
<idle>-0 [002] dp.h1.. 1052.619783: #10206 context irq timer_latency 2254 ns
<idle>-0 [002] dN.h2.. 1052.619787: irq_noise: local_timer:236 start 1052.619782951 duration 3891 ns
<idle>-0 [002] dp..3.. 1052.619789: thread_noise: swapper/2:0 start 1052.619783185 duration 2428 ns
timerlat/2-5126 [002] .p..... 1052.619790: #10206 context thread timer_latency 9211 ns
kworker/1:1-4654 [001] dp..3.. 1052.620044: thread_noise: kworker/1:1:4654 start 1052.619730445 duration 290974 ns
timerlat/1-5125 [001] .p..... 1052.620046: #10206 context thread timer_latency 320780 ns
timerlat/1-5125 [001] .p..1.. 1052.620046: <stack trace>
=> timerlat_irq
=> __hrtimer_run_queues
=> hrtimer_interrupt
=> __sysvec_apic_timer_interrupt
=> sysvec_apic_timer_interrupt
=> asm_sysvec_apic_timer_interrupt
=> intel_dmc_load_program
=> intel_display_power_resume
=> intel_runtime_resume
=> pci_pm_runtime_resume
=> __rpm_callback
=> rpm_callback
=> rpm_resume
=> __pm_runtime_resume
=> intel_runtime_pm_get
=> intel_display_power_get
=> intel_digital_port_connected
=> intel_dp_detect
=> drm_helper_probe_detect_ctx
=> output_poll_execute
=> process_one_work
=> worker_thread
=> kthread
=> ret_from_fork
=> 0x00000832
=> 0
=> 0x1100006f08
=> 0x5786130000001405
=> 0x100000a1b
=> 0x219400000000
=> 0x1e5374800000000
=> 0x01090011
<idle>-0 [003] dN.h2.. 1073.604489: irq_noise: local_timer:236 start 1073.604484424 duration 4206 ns
<idle>-0 [003] dp..3.. 1073.604491: thread_noise: swapper/3:0 start 1073.604484661 duration 2395 ns
timerlat/3-5133 [003] .p..... 1073.604492: #19046 context thread timer_latency 9540 ns
<idle>-0 [000] dp.h1.. 1073.605324: #19047 context irq timer_latency 2750 ns
<idle>-0 [000] dN.h2.. 1073.605328: irq_noise: local_timer:236 start 1073.605323682 duration 4567 ns
<idle>-0 [000] dp..3.. 1073.605331: thread_noise: swapper/0:0 start 1073.605323912 duration 2572 ns
timerlat/0-5130 [000] .p..... 1073.605332: #19047 context thread timer_latency 10811 ns
<idle>-0 [001] dp.h1.. 1073.605380: #19047 context irq timer_latency 2354 ns
<idle>-0 [001] dN.h2.. 1073.605383: irq_noise: local_timer:236 start 1073.605379235 duration 3851 ns
<idle>-0 [001] dp..3.. 1073.605385: thread_noise: swapper/1:0 start 1073.605379455 duration 2256 ns
timerlat/1-5131 [001] .p..... 1073.605386: #19047 context thread timer_latency 9097 ns
<idle>-0 [002] dp.h1.. 1073.605430: #19047 context irq timer_latency 3012 ns
<idle>-0 [002] dN.h2.. 1073.605434: irq_noise: local_timer:236 start 1073.605429717 duration 4049 ns
<idle>-0 [002] dp..3.. 1073.605437: thread_noise: swapper/2:0 start 1073.605429942 duration 3009 ns
timerlat/2-5132 [002] .p..... 1073.605438: #19047 context thread timer_latency 10850 ns
<idle>-0 [003] dp.h1.. 1073.605486: #19047 context irq timer_latency 3092 ns
<idle>-0 [003] dN.h2.. 1073.605489: irq_noise: local_timer:236 start 1073.605485141 duration 3975 ns
<idle>-0 [003] dp..3.. 1073.605492: thread_noise: swapper/3:0 start 1073.605485376 duration 2712 ns
timerlat/3-5133 [003] .p..... 1073.605493: #19047 context thread timer_latency 10348 ns
<idle>-0 [000] dp.h1.. 1073.606324: #19048 context irq timer_latency 2857 ns
<idle>-0 [000] dN.h2.. 1073.606329: irq_noise: local_timer:236 start 1073.606323749 duration 4932 ns
<idle>-0 [000] dp..3.. 1073.606331: thread_noise: swapper/0:0 start 1073.606324007 duration 2655 ns
timerlat/0-5130 [000] .p..... 1073.606333: #19048 context thread timer_latency 11397 ns
<idle>-0 [001] dp.h1.. 1073.606380: #19048 context irq timer_latency 2225 ns
<idle>-0 [001] dN.h2.. 1073.606383: irq_noise: local_timer:236 start 1073.606379089 duration 3937 ns
<idle>-0 [001] dp..3.. 1073.606386: thread_noise: swapper/1:0 start 1073.606379309 duration 2325 ns
timerlat/1-5131 [001] .p..... 1073.606386: #19048 context thread timer_latency 9075 ns
<idle>-0 [002] dp.h1.. 1073.606429: #19048 context irq timer_latency 2265 ns
<idle>-0 [002] dN.h2.. 1073.606433: irq_noise: local_timer:236 start 1073.606428953 duration 3894 ns
<idle>-0 [002] dp..3.. 1073.606435: thread_noise: swapper/2:0 start 1073.606429179 duration 2364 ns
timerlat/2-5132 [002] .p..... 1073.606436: #19048 context thread timer_latency 9130 ns
<idle>-0 [003] dp.h1.. 1073.606485: #19048 context irq timer_latency 2358 ns
<idle>-0 [003] dN.h2.. 1073.606488: irq_noise: local_timer:236 start 1073.606484397 duration 3829 ns
<idle>-0 [003] dp..3.. 1073.606491: thread_noise: swapper/3:0 start 1073.606484624 duration 2409 ns
timerlat/3-5133 [003] .p..... 1073.606492: #19048 context thread timer_latency 9169 ns
<idle>-0 [000] dp.h1.. 1073.607324: #19049 context irq timer_latency 2804 ns
<idle>-0 [000] dN.h2.. 1073.607329: irq_noise: local_timer:236 start 1073.607323670 duration 4729 ns
<idle>-0 [000] dp..3.. 1073.607331: thread_noise: swapper/0:0 start 1073.607323933 duration 2545 ns
timerlat/0-5130 [000] .p..... 1073.607332: #19049 context thread timer_latency 11063 ns
<idle>-0 [001] dp.h1.. 1073.607380: #19049 context irq timer_latency 3056 ns
<idle>-0 [001] dN.h2.. 1073.607384: irq_noise: local_timer:236 start 1073.607379903 duration 3908 ns
<idle>-0 [001] dp..3.. 1073.607386: thread_noise: swapper/1:0 start 1073.607380124 duration 2337 ns
timerlat/1-5131 [001] .p..... 1073.607387: #19049 context thread timer_latency 9874 ns
<idle>-0 [002] dp.h1.. 1073.607429: #19049 context irq timer_latency 2300 ns
<idle>-0 [002] dN.h2.. 1073.607433: irq_noise: local_timer:236 start 1073.607428975 duration 3820 ns
<idle>-0 [002] dp..3.. 1073.607435: thread_noise: swapper/2:0 start 1073.607429198 duration 2419 ns
timerlat/2-5132 [002] .p..... 1073.607436: #19049 context thread timer_latency 9147 ns
<idle>-0 [003] dp.h1.. 1073.607485: #19049 context irq timer_latency 2314 ns
<idle>-0 [003] dN.h2.. 1073.607489: irq_noise: local_timer:236 start 1073.607484348 duration 4225 ns
<idle>-0 [003] dp..3.. 1073.607491: thread_noise: swapper/3:0 start 1073.607484564 duration 2430 ns
timerlat/3-5133 [003] .p..... 1073.607492: #19049 context thread timer_latency 9940 ns
<idle>-0 [000] dp.h1.. 1073.608324: #19050 context irq timer_latency 2817 ns
<idle>-0 [000] dN.h2.. 1073.608329: irq_noise: local_timer:236 start 1073.608323680 duration 4772 ns
<idle>-0 [000] dp..3.. 1073.608331: thread_noise: swapper/0:0 start 1073.608323929 duration 2605 ns
timerlat/0-5130 [000] .p..... 1073.608333: #19050 context thread timer_latency 11153 ns
<idle>-0 [001] dp.h1.. 1073.608380: #19050 context irq timer_latency 3033 ns
<idle>-0 [001] dN.h2.. 1073.608384: irq_noise: local_timer:236 start 1073.608379863 duration 3944 ns
<idle>-0 [001] dp..3.. 1073.608386: thread_noise: swapper/1:0 start 1073.608380084 duration 2325 ns
timerlat/1-5131 [001] .p..... 1073.608387: #19050 context thread timer_latency 9883 ns
<idle>-0 [002] dp.h1.. 1073.608429: #19050 context irq timer_latency 2293 ns
<idle>-0 [002] dN.h2.. 1073.608433: irq_noise: local_timer:236 start 1073.608428953 duration 4164 ns
<idle>-0 [002] dp..3.. 1073.608436: thread_noise: swapper/2:0 start 1073.608429174 duration 2401 ns
timerlat/2-5132 [002] .p..... 1073.608437: #19050 context thread timer_latency 9950 ns
<idle>-0 [003] dp.h1.. 1073.608485: #19050 context irq timer_latency 2331 ns
<idle>-0 [003] dN.h2.. 1073.608488: irq_noise: local_timer:236 start 1073.608484328 duration 3888 ns
<idle>-0 [003] dp..3.. 1073.608491: thread_noise: swapper/3:0 start 1073.608484565 duration 2432 ns
timerlat/3-5133 [003] .p..... 1073.608492: #19050 context thread timer_latency 9230 ns
<idle>-0 [000] dp.h1.. 1073.609324: #19051 context irq timer_latency 2792 ns
<idle>-0 [000] dN.h2.. 1073.609328: irq_noise: local_timer:236 start 1073.609323620 duration 4632 ns
<idle>-0 [000] dp..3.. 1073.609331: thread_noise: swapper/0:0 start 1073.609323888 duration 2922 ns
timerlat/0-5130 [000] .p..... 1073.609332: #19051 context thread timer_latency 11027 ns
<idle>-0 [001] dp.h1.. 1073.609380: #19051 context irq timer_latency 3009 ns
<idle>-0 [001] dN.h2.. 1073.609384: irq_noise: local_timer:236 start 1073.609379823 duration 4016 ns
<idle>-0 [001] dp..3.. 1073.609386: thread_noise: swapper/1:0 start 1073.609380044 duration 2286 ns
timerlat/1-5131 [001] .p..... 1073.609387: #19051 context thread timer_latency 10160 ns
<idle>-0 [002] dp.h1.. 1073.609429: #19051 context irq timer_latency 2349 ns
<idle>-0 [002] dN.h2.. 1073.609433: irq_noise: local_timer:236 start 1073.609428988 duration 3865 ns
<idle>-0 [002] dp..3.. 1073.609435: thread_noise: swapper/2:0 start 1073.609429214 duration 2406 ns
timerlat/2-5132 [002] .p..... 1073.609436: #19051 context thread timer_latency 9220 ns
<idle>-0 [003] dp.h1.. 1073.609485: #19051 context irq timer_latency 2379 ns
<idle>-0 [003] dN.h2.. 1073.609488: irq_noise: local_timer:236 start 1073.609484351 duration 3904 ns
<idle>-0 [003] dp..3.. 1073.609491: thread_noise: swapper/3:0 start 1073.609484596 duration 2432 ns
timerlat/3-5133 [003] .p..... 1073.609492: #19051 context thread timer_latency 9297 ns
<idle>-0 [000] dp.h1.. 1073.610324: #19052 context irq timer_latency 2736 ns
<idle>-0 [000] dN.h2.. 1073.610329: irq_noise: local_timer:236 start 1073.610323569 duration 4980 ns
<idle>-0 [000] dp..3.. 1073.610331: thread_noise: swapper/0:0 start 1073.610323816 duration 2622 ns
timerlat/0-5130 [000] .p..... 1073.610333: #19052 context thread timer_latency 11278 ns
<idle>-0 [001] dp.h1.. 1073.610380: #19052 context irq timer_latency 3043 ns
<idle>-0 [001] dN.h2.. 1073.610384: irq_noise: local_timer:236 start 1073.610379843 duration 3919 ns
<idle>-0 [001] dp..3.. 1073.610386: thread_noise: swapper/1:0 start 1073.610380062 duration 2314 ns
timerlat/1-5131 [001] .p..... 1073.610387: #19052 context thread timer_latency 9858 ns
<idle>-0 [002] dp.h1.. 1073.610429: #19052 context irq timer_latency 2302 ns
<idle>-0 [002] dN.h2.. 1073.610433: irq_noise: local_timer:236 start 1073.610428925 duration 3858 ns
<idle>-0 [002] dp..3.. 1073.610435: thread_noise: swapper/2:0 start 1073.610429150 duration 2425 ns
timerlat/2-5132 [002] .p..... 1073.610436: #19052 context thread timer_latency 9200 ns
<idle>-0 [003] dp.h1.. 1073.610485: #19052 context irq timer_latency 2311 ns
<idle>-0 [003] dN.h2.. 1073.610488: irq_noise: local_timer:236 start 1073.610484286 duration 3847 ns
<idle>-0 [003] dp..3.. 1073.610491: thread_noise: swapper/3:0 start 1073.610484512 duration 2398 ns
timerlat/3-5133 [003] .p..... 1073.610492: #19052 context thread timer_latency 9155 ns
<idle>-0 [001] dN.h2.. 1073.611129: irq_noise: local_timer:236 start 1073.611124279 duration 4745 ns
<idle>-0 [001] dp.h2.. 1073.611258: irq_noise: local_timer:236 start 1073.611257275 duration 577 ns
<idle>-0 [000] dp.h1.. 1073.611324: #19053 context irq timer_latency 2658 ns
<idle>-0 [000] dN.h2.. 1073.611329: irq_noise: local_timer:236 start 1073.611323457 duration 4990 ns
<idle>-0 [000] dp..3.. 1073.611331: thread_noise: swapper/0:0 start 1073.611323726 duration 2560 ns
timerlat/0-5130 [000] .p..... 1073.611332: #19053 context thread timer_latency 10926 ns
kworker/1:2-461 [001] dp.h1.. 1073.611383: #19053 context irq timer_latency 5589 ns
kworker/1:2-461 [001] dN.h2.. 1073.611404: irq_noise: local_timer:236 start 1073.611382286 duration 21070 ns
<idle>-0 [002] dp.h1.. 1073.611429: #19053 context irq timer_latency 2320 ns
<idle>-0 [002] dN.h2.. 1073.611433: irq_noise: local_timer:236 start 1073.611428926 duration 3955 ns
<idle>-0 [002] dp..3.. 1073.611435: thread_noise: swapper/2:0 start 1073.611429152 duration 2432 ns
timerlat/2-5132 [002] .p..... 1073.611437: #19053 context thread timer_latency 9380 ns
<idle>-0 [003] dp.h1.. 1073.611485: #19053 context irq timer_latency 2483 ns
<idle>-0 [003] dN.h2.. 1073.611489: irq_noise: local_timer:236 start 1073.611484439 duration 4040 ns
<idle>-0 [003] dp..3.. 1073.611491: thread_noise: swapper/3:0 start 1073.611484667 duration 2464 ns
timerlat/3-5133 [003] .p..... 1073.611492: #19053 context thread timer_latency 9800 ns
kworker/1:2-461 [001] dp..3.. 1073.611698: thread_noise: kworker/1:2:461 start 1073.611382591 duration 294270 ns
timerlat/1-5131 [001] .p..... 1073.611699: #19053 context thread timer_latency 321993 ns
timerlat/1-5131 [001] .p..1.. 1073.611700: <stack trace>
=> timerlat_irq
=> __hrtimer_run_queues
=> hrtimer_interrupt
=> __sysvec_apic_timer_interrupt
=> sysvec_apic_timer_interrupt
=> asm_sysvec_apic_timer_interrupt
=> intel_dmc_load_program
=> intel_display_power_resume
=> intel_runtime_resume
=> pci_pm_runtime_resume
=> __rpm_callback
=> rpm_callback
=> rpm_resume
=> __pm_runtime_resume
=> intel_runtime_pm_get
=> intel_display_power_get
=> intel_digital_port_connected
=> intel_dp_detect
=> drm_helper_probe_detect_ctx
=> output_poll_execute
=> process_one_work
=> worker_thread
=> kthread
=> ret_from_fork
=> 0x69745f6c61636f6c
=> 0x1084e0072656d
=> 0x030101cd
=> 0x7061777300001400
=> 0x312f726570
=> 0x270000000000
=> 0xf831ce7af2
=> 0x0000085e
<idle>-0 [002] dp.h1.. 1085.044263: #9350 context irq timer_latency 2308 ns
<idle>-0 [002] dN.h2.. 1085.044267: irq_noise: local_timer:236 start 1085.044262449 duration 3896 ns
<idle>-0 [002] dp..3.. 1085.044269: thread_noise: swapper/2:0 start 1085.044262682 duration 2399 ns
timerlat/2-5138 [002] .p..... 1085.044270: #9350 context thread timer_latency 9472 ns
<idle>-0 [003] dp.h1.. 1085.044313: #9350 context irq timer_latency 2279 ns
<idle>-0 [003] dN.h2.. 1085.044316: irq_noise: local_timer:236 start 1085.044312462 duration 3692 ns
<idle>-0 [003] dp..3.. 1085.044319: thread_noise: swapper/3:0 start 1085.044312685 duration 2233 ns
timerlat/3-5139 [003] .p..... 1085.044319: #9350 context thread timer_latency 8773 ns
<idle>-0 [000] dp.h1.. 1085.045158: #9351 context irq timer_latency 2836 ns
<idle>-0 [000] dN.h2.. 1085.045162: irq_noise: local_timer:236 start 1085.045157549 duration 4689 ns
<idle>-0 [000] dp..3.. 1085.045165: thread_noise: swapper/0:0 start 1085.045157864 duration 2411 ns
timerlat/0-5136 [000] .p..... 1085.045166: #9351 context thread timer_latency 10508 ns
<idle>-0 [001] dp.h1.. 1085.045209: #9351 context irq timer_latency 3017 ns
<idle>-0 [001] dN.h2.. 1085.045213: irq_noise: local_timer:236 start 1085.045208834 duration 4344 ns
<idle>-0 [001] dp..3.. 1085.045215: thread_noise: swapper/1:0 start 1085.045209060 duration 2177 ns
timerlat/1-5137 [001] .p..... 1085.045216: #9351 context thread timer_latency 10135 ns
<idle>-0 [002] dp.h1.. 1085.045263: #9351 context irq timer_latency 2343 ns
<idle>-0 [002] dN.h2.. 1085.045267: irq_noise: local_timer:236 start 1085.045262452 duration 3862 ns
<idle>-0 [002] dp..3.. 1085.045269: thread_noise: swapper/2:0 start 1085.045262701 duration 2428 ns
timerlat/2-5138 [002] .p..... 1085.045270: #9351 context thread timer_latency 9525 ns
<idle>-0 [003] dp.h1.. 1085.045313: #9351 context irq timer_latency 2304 ns
<idle>-0 [003] dN.h2.. 1085.045316: irq_noise: local_timer:236 start 1085.045312470 duration 3671 ns
<idle>-0 [003] dp..3.. 1085.045319: thread_noise: swapper/3:0 start 1085.045312694 duration 2224 ns
timerlat/3-5139 [003] .p..... 1085.045319: #9351 context thread timer_latency 8775 ns
<idle>-0 [000] dp.h1.. 1085.046158: #9352 context irq timer_latency 2858 ns
<idle>-0 [000] dN.h2.. 1085.046162: irq_noise: local_timer:236 start 1085.046157560 duration 4645 ns
<idle>-0 [000] dp..3.. 1085.046165: thread_noise: swapper/0:0 start 1085.046157869 duration 2355 ns
timerlat/0-5136 [000] .p..... 1085.046166: #9352 context thread timer_latency 10412 ns
<idle>-0 [001] dp.h1.. 1085.046209: #9352 context irq timer_latency 3048 ns
<idle>-0 [001] dN.h2.. 1085.046213: irq_noise: local_timer:236 start 1085.046208854 duration 4181 ns
<idle>-0 [001] dp..3.. 1085.046215: thread_noise: swapper/1:0 start 1085.046209075 duration 2223 ns
timerlat/1-5137 [001] .p..... 1085.046216: #9352 context thread timer_latency 10026 ns
<idle>-0 [002] dp.h1.. 1085.046263: #9352 context irq timer_latency 2338 ns
<idle>-0 [002] dN.h2.. 1085.046267: irq_noise: local_timer:236 start 1085.046262452 duration 3914 ns
<idle>-0 [002] dp..3.. 1085.046269: thread_noise: swapper/2:0 start 1085.046262679 duration 2392 ns
timerlat/2-5138 [002] .p..... 1085.046270: #9352 context thread timer_latency 9551 ns
<idle>-0 [003] dp.h1.. 1085.046313: #9352 context irq timer_latency 2250 ns
<idle>-0 [003] dN.h2.. 1085.046316: irq_noise: local_timer:236 start 1085.046312408 duration 3669 ns
<idle>-0 [003] dp..3.. 1085.046319: thread_noise: swapper/3:0 start 1085.046312622 duration 2200 ns
timerlat/3-5139 [003] .p..... 1085.046320: #9352 context thread timer_latency 9155 ns
<idle>-0 [000] dp.h1.. 1085.047158: #9353 context irq timer_latency 3186 ns
<idle>-0 [000] dN.h2.. 1085.047163: irq_noise: local_timer:236 start 1085.047157573 duration 5122 ns
<idle>-0 [000] dp..3.. 1085.047165: thread_noise: swapper/0:0 start 1085.047158180 duration 2482 ns
timerlat/0-5136 [000] .p..... 1085.047167: #9353 context thread timer_latency 11328 ns
<idle>-0 [001] dp.h1.. 1085.047209: #9353 context irq timer_latency 3085 ns
<idle>-0 [001] dN.h2.. 1085.047213: irq_noise: local_timer:236 start 1085.047208872 duration 4089 ns
<idle>-0 [001] dp..3.. 1085.047215: thread_noise: swapper/1:0 start 1085.047209095 duration 2186 ns
timerlat/1-5137 [001] .p..... 1085.047216: #9353 context thread timer_latency 9949 ns
<idle>-0 [002] dp.h1.. 1085.047263: #9353 context irq timer_latency 2249 ns
<idle>-0 [002] dN.h2.. 1085.047267: irq_noise: local_timer:236 start 1085.047262347 duration 4179 ns
<idle>-0 [002] dp..3.. 1085.047269: thread_noise: swapper/2:0 start 1085.047262574 duration 2407 ns
timerlat/2-5138 [002] .p..... 1085.047270: #9353 context thread timer_latency 9941 ns
<idle>-0 [003] dp.h1.. 1085.047313: #9353 context irq timer_latency 2314 ns
<idle>-0 [003] dN.h2.. 1085.047316: irq_noise: local_timer:236 start 1085.047312425 duration 3673 ns
<idle>-0 [003] dp..3.. 1085.047319: thread_noise: swapper/3:0 start 1085.047312672 duration 2251 ns
timerlat/3-5139 [003] .p..... 1085.047319: #9353 context thread timer_latency 8811 ns
<idle>-0 [002] dp.h2.. 1085.047350: irq_noise: iwlwifi:130 start 1085.047349685 duration 63 ns
<idle>-0 [000] dp.h1.. 1085.048158: #9354 context irq timer_latency 2967 ns
<idle>-0 [000] dN.h2.. 1085.048163: irq_noise: local_timer:236 start 1085.048157653 duration 5023 ns
<idle>-0 [000] dp..3.. 1085.048165: thread_noise: swapper/0:0 start 1085.048157945 duration 2388 ns
timerlat/0-5136 [000] .p..... 1085.048166: #9354 context thread timer_latency 11245 ns
<idle>-0 [001] dp.h1.. 1085.048210: #9354 context irq timer_latency 3179 ns
<idle>-0 [001] dN.h2.. 1085.048214: irq_noise: local_timer:236 start 1085.048208820 duration 5044 ns
<idle>-0 [001] dp..3.. 1085.048217: thread_noise: swapper/1:0 start 1085.048209177 duration 2954 ns
timerlat/1-5137 [001] .p..... 1085.048218: #9354 context thread timer_latency 11761 ns
<idle>-0 [002] dp.h1.. 1085.048263: #9354 context irq timer_latency 2460 ns
<idle>-0 [002] dN.h2.. 1085.048267: irq_noise: local_timer:236 start 1085.048262471 duration 4468 ns
<idle>-0 [002] dp..3.. 1085.048270: thread_noise: swapper/2:0 start 1085.048262774 duration 2780 ns
timerlat/2-5138 [002] .p..... 1085.048271: #9354 context thread timer_latency 10316 ns
<idle>-0 [003] dp.h1.. 1085.048313: #9354 context irq timer_latency 2285 ns
<idle>-0 [003] dN.h2.. 1085.048317: irq_noise: local_timer:236 start 1085.048312411 duration 4016 ns
<idle>-0 [003] dp..3.. 1085.048319: thread_noise: swapper/3:0 start 1085.048312625 duration 2240 ns
timerlat/3-5139 [003] .p..... 1085.048320: #9354 context thread timer_latency 9375 ns
<idle>-0 [000] dp.h1.. 1085.049158: #9355 context irq timer_latency 3196 ns
<idle>-0 [000] dN.h2.. 1085.049163: irq_noise: local_timer:236 start 1085.049157552 duration 5009 ns
<idle>-0 [000] dp..3.. 1085.049165: thread_noise: swapper/0:0 start 1085.049158157 duration 2425 ns
timerlat/0-5136 [000] .p..... 1085.049166: #9355 context thread timer_latency 10898 ns
<idle>-0 [001] dp.h1.. 1085.049209: #9355 context irq timer_latency 3050 ns
<idle>-0 [001] dN.h2.. 1085.049213: irq_noise: local_timer:236 start 1085.049208793 duration 4200 ns
<idle>-0 [001] dp..3.. 1085.049215: thread_noise: swapper/1:0 start 1085.049209027 duration 2259 ns
timerlat/1-5137 [001] .p..... 1085.049216: #9355 context thread timer_latency 10118 ns
<idle>-0 [002] dp.h1.. 1085.049263: #9355 context irq timer_latency 2402 ns
<idle>-0 [002] dN.h2.. 1085.049267: irq_noise: local_timer:236 start 1085.049262426 duration 4079 ns
<idle>-0 [002] dp..3.. 1085.049269: thread_noise: swapper/2:0 start 1085.049262693 duration 2405 ns
timerlat/2-5138 [002] .p..... 1085.049270: #9355 context thread timer_latency 9652 ns
<idle>-0 [003] dp.h1.. 1085.049313: #9355 context irq timer_latency 2283 ns
<idle>-0 [003] dN.h2.. 1085.049316: irq_noise: local_timer:236 start 1085.049312382 duration 3820 ns
<idle>-0 [003] dp..3.. 1085.049319: thread_noise: swapper/3:0 start 1085.049312606 duration 2261 ns
timerlat/3-5139 [003] .p..... 1085.049319: #9355 context thread timer_latency 8906 ns
<idle>-0 [000] dp.h1.. 1085.050158: #9356 context irq timer_latency 2857 ns
<idle>-0 [000] dN.h2.. 1085.050162: irq_noise: local_timer:236 start 1085.050157513 duration 4769 ns
<idle>-0 [000] dp..3.. 1085.050165: thread_noise: swapper/0:0 start 1085.050157801 duration 2388 ns
timerlat/0-5136 [000] .p..... 1085.050166: #9356 context thread timer_latency 10614 ns
<idle>-0 [001] dp.h1.. 1085.050209: #9356 context irq timer_latency 3085 ns
<idle>-0 [001] dN.h2.. 1085.050213: irq_noise: local_timer:236 start 1085.050208811 duration 3992 ns
<idle>-0 [001] dp..3.. 1085.050215: thread_noise: swapper/1:0 start 1085.050209045 duration 2107 ns
timerlat/1-5137 [001] .p..... 1085.050216: #9356 context thread timer_latency 9758 ns
<idle>-0 [002] dp.h1.. 1085.050263: #9356 context irq timer_latency 2237 ns
<idle>-0 [002] dN.h2.. 1085.050266: irq_noise: local_timer:236 start 1085.050262287 duration 3964 ns
<idle>-0 [002] dp..3.. 1085.050269: thread_noise: swapper/2:0 start 1085.050262512 duration 2402 ns
timerlat/2-5138 [002] .p..... 1085.050270: #9356 context thread timer_latency 9519 ns
<idle>-0 [003] dp.h1.. 1085.050313: #9356 context irq timer_latency 2266 ns
<idle>-0 [003] dN.h2.. 1085.050316: irq_noise: local_timer:236 start 1085.050312354 duration 3976 ns
<idle>-0 [003] dp..3.. 1085.050319: thread_noise: swapper/3:0 start 1085.050312573 duration 2239 ns
timerlat/3-5139 [003] .p..... 1085.050320: #9356 context thread timer_latency 9060 ns
<idle>-0 [001] dp.h2.. 1085.050937: irq_noise: local_timer:236 start 1085.050935953 duration 486 ns
<idle>-0 [000] dp.h1.. 1085.051157: #9357 context irq timer_latency 2241 ns
<idle>-0 [000] dN.h2.. 1085.051164: irq_noise: local_timer:236 start 1085.051156896 duration 6561 ns
<idle>-0 [000] dp..3.. 1085.051166: thread_noise: swapper/0:0 start 1085.051157168 duration 2346 ns
timerlat/0-5136 [000] .p..... 1085.051167: #9357 context thread timer_latency 11682 ns
<idle>-0 [002] dp.h1.. 1085.051263: #9357 context irq timer_latency 2131 ns
<idle>-0 [002] dN.h2.. 1085.051269: irq_noise: local_timer:236 start 1085.051262173 duration 6284 ns
<idle>-0 [002] dp..3.. 1085.051271: thread_noise: swapper/2:0 start 1085.051262389 duration 2370 ns
timerlat/2-5138 [002] .p..... 1085.051272: #9357 context thread timer_latency 11659 ns
<idle>-0 [003] dp.h1.. 1085.051313: #9357 context irq timer_latency 2241 ns
<idle>-0 [003] dN.h2.. 1085.051317: irq_noise: local_timer:236 start 1085.051312269 duration 4326 ns
<idle>-0 [003] dp..3.. 1085.051319: thread_noise: swapper/3:0 start 1085.051312535 duration 2482 ns
timerlat/3-5139 [003] .p..... 1085.051320: #9357 context thread timer_latency 9638 ns
kworker/1:1-4654 [001] dp.h... 1085.051458: #9357 context irq timer_latency 251709 ns
kworker/1:1-4654 [001] dN.h1.. 1085.051474: irq_noise: local_timer:236 start 1085.051457240 duration 16784 ns
kworker/1:1-4654 [001] dN.h2.. 1085.051478: irq_noise: irq_work:246 start 1085.051475602 duration 1651 ns
kworker/1:1-4654 [001] dp..3.. 1085.051479: thread_noise: kworker/1:1:4654 start 1085.051457657 duration 3600 ns
timerlat/1-5137 [001] .p..... 1085.051481: #9357 context thread timer_latency 274334 ns
timerlat/1-5137 [001] .p..1.. 1085.051481: <stack trace>
=> timerlat_irq
=> __hrtimer_run_queues
=> hrtimer_interrupt
=> __sysvec_apic_timer_interrupt
=> sysvec_apic_timer_interrupt
=> asm_sysvec_apic_timer_interrupt
=> intel_irq_reset
=> intel_runtime_pm_disable_interrupts
=> intel_runtime_suspend
=> pci_pm_runtime_suspend
=> __rpm_callback
=> rpm_callback
=> rpm_suspend
=> pm_runtime_work
=> process_one_work
=> worker_thread
=> kthread
=> ret_from_fork
=> 0x9b4000000fa
=> 0
=> 0x6f480001e12d
=> 0x141100000011
=> 0x6c7569cca00
=> 0x103900000001
=> 0x000027d4
=> 0x109001101e47d08
<idle>-0 [003] dp..3.. 1095.108138: thread_noise: swapper/3:0 start 1095.108132232 duration 2182 ns
timerlat/3-5145 [003] .p..... 1095.108139: #8280 context thread timer_latency 8931 ns
<idle>-0 [000] dp.h1.. 1095.108970: #8281 context irq timer_latency 2935 ns
<idle>-0 [000] dN.h2.. 1095.108974: irq_noise: local_timer:236 start 1095.108969009 duration 4635 ns
<idle>-0 [000] dp..3.. 1095.108976: thread_noise: swapper/0:0 start 1095.108969364 duration 2413 ns
timerlat/0-5142 [000] .p..... 1095.108977: #8281 context thread timer_latency 10527 ns
<idle>-0 [001] dp.h1.. 1095.109017: #8281 context irq timer_latency 2995 ns
<idle>-0 [001] dN.h2.. 1095.109021: irq_noise: local_timer:236 start 1095.109016579 duration 3910 ns
<idle>-0 [001] dp..3.. 1095.109023: thread_noise: swapper/1:0 start 1095.109016809 duration 2365 ns
timerlat/1-5143 [001] .p..... 1095.109024: #8281 context thread timer_latency 10159 ns
<idle>-0 [002] dp.h1.. 1095.109070: #8281 context irq timer_latency 2271 ns
<idle>-0 [002] dN.h2.. 1095.109074: irq_noise: local_timer:236 start 1095.109069923 duration 3758 ns
<idle>-0 [002] dp..3.. 1095.109076: thread_noise: swapper/2:0 start 1095.109070155 duration 2241 ns
timerlat/2-5144 [002] .p..... 1095.109077: #8281 context thread timer_latency 8835 ns
<idle>-0 [003] dp.h1.. 1095.109132: #8281 context irq timer_latency 2314 ns
<idle>-0 [003] dN.h2.. 1095.109136: irq_noise: local_timer:236 start 1095.109131998 duration 3853 ns
<idle>-0 [003] dp..3.. 1095.109138: thread_noise: swapper/3:0 start 1095.109132223 duration 2212 ns
timerlat/3-5145 [003] .p..... 1095.109139: #8281 context thread timer_latency 8977 ns
<idle>-0 [000] dp.h1.. 1095.109970: #8282 context irq timer_latency 2902 ns
<idle>-0 [000] dN.h2.. 1095.109974: irq_noise: local_timer:236 start 1095.109968978 duration 4608 ns
<idle>-0 [000] dp..3.. 1095.109976: thread_noise: swapper/0:0 start 1095.109969315 duration 2367 ns
timerlat/0-5142 [000] .p..... 1095.109977: #8282 context thread timer_latency 10444 ns
<idle>-0 [001] dp.h1.. 1095.110017: #8282 context irq timer_latency 3032 ns
<idle>-0 [001] dN.h2.. 1095.110021: irq_noise: local_timer:236 start 1095.110016599 duration 4253 ns
<idle>-0 [001] dp..3.. 1095.110023: thread_noise: swapper/1:0 start 1095.110016829 duration 2268 ns
timerlat/1-5143 [001] .p..... 1095.110024: #8282 context thread timer_latency 10432 ns
<idle>-0 [002] dp.h1.. 1095.110070: #8282 context irq timer_latency 2232 ns
<idle>-0 [002] dN.h2.. 1095.110074: irq_noise: local_timer:236 start 1095.110069884 duration 3754 ns
<idle>-0 [002] dp..3.. 1095.110076: thread_noise: swapper/2:0 start 1095.110070100 duration 2201 ns
timerlat/2-5144 [002] .p..... 1095.110077: #8282 context thread timer_latency 8771 ns
<idle>-0 [003] dp.h1.. 1095.110132: #8282 context irq timer_latency 2260 ns
<idle>-0 [003] dN.h2.. 1095.110136: irq_noise: local_timer:236 start 1095.110131935 duration 3820 ns
<idle>-0 [003] dp..3.. 1095.110138: thread_noise: swapper/3:0 start 1095.110132151 duration 2222 ns
timerlat/3-5145 [003] .p..... 1095.110139: #8282 context thread timer_latency 8899 ns
<idle>-0 [000] dp.h1.. 1095.110970: #8283 context irq timer_latency 2855 ns
<idle>-0 [000] dN.h2.. 1095.110974: irq_noise: local_timer:236 start 1095.110968916 duration 4609 ns
<idle>-0 [000] dp..3.. 1095.110976: thread_noise: swapper/0:0 start 1095.110969251 duration 2430 ns
timerlat/0-5142 [000] .p..... 1095.110977: #8283 context thread timer_latency 10433 ns
<idle>-0 [001] dp.h1.. 1095.111016: #8283 context irq timer_latency 2364 ns
<idle>-0 [001] dN.h2.. 1095.111020: irq_noise: local_timer:236 start 1095.111015914 duration 3675 ns
<idle>-0 [001] dp..3.. 1095.111022: thread_noise: swapper/1:0 start 1095.111016144 duration 2246 ns
timerlat/1-5143 [001] .p..... 1095.111023: #8283 context thread timer_latency 8850 ns
<idle>-0 [002] dp.h1.. 1095.111070: #8283 context irq timer_latency 2277 ns
<idle>-0 [002] dN.h2.. 1095.111074: irq_noise: local_timer:236 start 1095.111069911 duration 3679 ns
<idle>-0 [002] dp..3.. 1095.111076: thread_noise: swapper/2:0 start 1095.111070128 duration 2265 ns
timerlat/2-5144 [002] .p..... 1095.111077: #8283 context thread timer_latency 8789 ns
<idle>-0 [003] dp.h1.. 1095.111132: #8283 context irq timer_latency 2317 ns
<idle>-0 [003] dN.h2.. 1095.111136: irq_noise: local_timer:236 start 1095.111131976 duration 4123 ns
<idle>-0 [003] dp..3.. 1095.111138: thread_noise: swapper/3:0 start 1095.111132192 duration 2255 ns
timerlat/3-5145 [003] .p..... 1095.111140: #8283 context thread timer_latency 9401 ns
<idle>-0 [000] dp.h1.. 1095.111970: #8284 context irq timer_latency 2906 ns
<idle>-0 [000] dN.h2.. 1095.111974: irq_noise: local_timer:236 start 1095.111968949 duration 4614 ns
<idle>-0 [000] dp..3.. 1095.111977: thread_noise: swapper/0:0 start 1095.111969285 duration 2349 ns
timerlat/0-5142 [000] .p..... 1095.111978: #8284 context thread timer_latency 10940 ns
<idle>-0 [001] dp.h1.. 1095.112017: #8284 context irq timer_latency 3056 ns
<idle>-0 [001] dN.h2.. 1095.112021: irq_noise: local_timer:236 start 1095.112016590 duration 4181 ns
<idle>-0 [001] dp..3.. 1095.112023: thread_noise: swapper/1:0 start 1095.112016819 duration 2332 ns
timerlat/1-5143 [001] .p..... 1095.112024: #8284 context thread timer_latency 10439 ns
<idle>-0 [002] dp.h1.. 1095.112070: #8284 context irq timer_latency 2349 ns
<idle>-0 [002] dN.h2.. 1095.112074: irq_noise: local_timer:236 start 1095.112069967 duration 3756 ns
<idle>-0 [002] dp..3.. 1095.112076: thread_noise: swapper/2:0 start 1095.112070183 duration 2243 ns
timerlat/2-5144 [002] .p..... 1095.112077: #8284 context thread timer_latency 8930 ns
<idle>-0 [003] dp.h1.. 1095.112132: #8284 context irq timer_latency 2320 ns
<idle>-0 [003] dN.h2.. 1095.112136: irq_noise: local_timer:236 start 1095.112131962 duration 3821 ns
<idle>-0 [003] dp..3.. 1095.112138: thread_noise: swapper/3:0 start 1095.112132178 duration 2184 ns
timerlat/3-5145 [003] .p..... 1095.112139: #8284 context thread timer_latency 8921 ns
<idle>-0 [000] dp.h1.. 1095.112970: #8285 context irq timer_latency 3150 ns
<idle>-0 [000] dN.h2.. 1095.112974: irq_noise: local_timer:236 start 1095.112968888 duration 5086 ns
<idle>-0 [000] dp..3.. 1095.112977: thread_noise: swapper/0:0 start 1095.112969512 duration 2433 ns
timerlat/0-5142 [000] .p..... 1095.112978: #8285 context thread timer_latency 11265 ns
<idle>-0 [001] dp.h1.. 1095.113017: #8285 context irq timer_latency 3032 ns
<idle>-0 [001] dN.h2.. 1095.113021: irq_noise: local_timer:236 start 1095.113016549 duration 3908 ns
<idle>-0 [001] dp..3.. 1095.113023: thread_noise: swapper/1:0 start 1095.113016778 duration 2274 ns
timerlat/1-5143 [001] .p..... 1095.113024: #8285 context thread timer_latency 9767 ns
<idle>-0 [002] dp.h1.. 1095.113070: #8285 context irq timer_latency 2233 ns
<idle>-0 [002] dN.h2.. 1095.113074: irq_noise: local_timer:236 start 1095.113069826 duration 3745 ns
<idle>-0 [002] dp..3.. 1095.113076: thread_noise: swapper/2:0 start 1095.113070050 duration 2283 ns
timerlat/2-5144 [002] .p..... 1095.113077: #8285 context thread timer_latency 8829 ns
<idle>-0 [003] dp.h1.. 1095.113132: #8285 context irq timer_latency 2261 ns
<idle>-0 [003] dN.h2.. 1095.113136: irq_noise: local_timer:236 start 1095.113131877 duration 3839 ns
<idle>-0 [003] dp..3.. 1095.113138: thread_noise: swapper/3:0 start 1095.113132102 duration 2198 ns
timerlat/3-5145 [003] .p..... 1095.113139: #8285 context thread timer_latency 8872 ns
<idle>-0 [000] dp.h1.. 1095.113969: #8286 context irq timer_latency 2857 ns
<idle>-0 [000] dN.h2.. 1095.113974: irq_noise: local_timer:236 start 1095.113968866 duration 4543 ns
<idle>-0 [000] dp..3.. 1095.113976: thread_noise: swapper/0:0 start 1095.113969203 duration 2438 ns
timerlat/0-5142 [000] .p..... 1095.113977: #8286 context thread timer_latency 10404 ns
<idle>-0 [001] dp.h1.. 1095.114016: #8286 context irq timer_latency 2317 ns
<idle>-0 [001] dN.h2.. 1095.114020: irq_noise: local_timer:236 start 1095.114015818 duration 4111 ns
<idle>-0 [001] dp..3.. 1095.114022: thread_noise: swapper/1:0 start 1095.114016048 duration 2316 ns
timerlat/1-5143 [001] .p..... 1095.114024: #8286 context thread timer_latency 9613 ns
<idle>-0 [002] dp.h1.. 1095.114070: #8286 context irq timer_latency 2262 ns
<idle>-0 [002] dN.h2.. 1095.114074: irq_noise: local_timer:236 start 1095.114069838 duration 3675 ns
<idle>-0 [002] dp..3.. 1095.114076: thread_noise: swapper/2:0 start 1095.114070063 duration 2277 ns
timerlat/2-5144 [002] .p..... 1095.114077: #8286 context thread timer_latency 8776 ns
<idle>-0 [003] dp.h1.. 1095.114132: #8286 context irq timer_latency 2267 ns
<idle>-0 [003] dN.h2.. 1095.114136: irq_noise: local_timer:236 start 1095.114131876 duration 3724 ns
<idle>-0 [003] dp..3.. 1095.114138: thread_noise: swapper/3:0 start 1095.114132091 duration 2155 ns
timerlat/3-5145 [003] .p..... 1095.114139: #8286 context thread timer_latency 8741 ns
<idle>-0 [001] dN.h2.. 1095.114772: irq_noise: local_timer:236 start 1095.114767061 duration 5154 ns
<idle>-0 [001] dp.h2.. 1095.114901: irq_noise: local_timer:236 start 1095.114900485 duration 586 ns
<idle>-0 [000] dp.h1.. 1095.114969: #8287 context irq timer_latency 2733 ns
<idle>-0 [000] dN.h2.. 1095.114974: irq_noise: local_timer:236 start 1095.114968653 duration 5169 ns
<idle>-0 [000] dp..3.. 1095.114976: thread_noise: swapper/0:0 start 1095.114969063 duration 2360 ns
timerlat/0-5142 [000] .p..... 1095.114977: #8287 context thread timer_latency 10901 ns
kworker/1:2-461 [001] dp.h1.. 1095.115020: #8287 context irq timer_latency 5596 ns
kworker/1:2-461 [001] dN.h2.. 1095.115041: irq_noise: local_timer:236 start 1095.115018976 duration 21971 ns
kworker/1:2-461 [001] dN.h2.. 1095.115045: irq_noise: irq_work:246 start 1095.115042668 duration 1688 ns
<idle>-0 [002] dp.h1.. 1095.115070: #8287 context irq timer_latency 2291 ns
<idle>-0 [002] dN.h2.. 1095.115074: irq_noise: local_timer:236 start 1095.115069859 duration 4047 ns
<idle>-0 [002] dp..3.. 1095.115076: thread_noise: swapper/2:0 start 1095.115070075 duration 2263 ns
timerlat/2-5144 [002] .p..... 1095.115077: #8287 context thread timer_latency 9254 ns
<idle>-0 [003] dp.h1.. 1095.115132: #8287 context irq timer_latency 2435 ns
<idle>-0 [003] dN.h2.. 1095.115136: irq_noise: local_timer:236 start 1095.115132028 duration 3907 ns
<idle>-0 [003] dp..3.. 1095.115138: thread_noise: swapper/3:0 start 1095.115132243 duration 2221 ns
timerlat/3-5145 [003] .p..... 1095.115139: #8287 context thread timer_latency 9268 ns
kworker/1:2-461 [001] dp..3.. 1095.115347: thread_noise: kworker/1:2:461 start 1095.115019309 duration 304638 ns
timerlat/1-5143 [001] .p..... 1095.115349: #8287 context thread timer_latency 334878 ns
timerlat/1-5143 [001] .p..1.. 1095.115349: <stack trace>
=> timerlat_irq
=> __hrtimer_run_queues
=> hrtimer_interrupt
=> __sysvec_apic_timer_interrupt
=> sysvec_apic_timer_interrupt
=> asm_sysvec_apic_timer_interrupt
=> intel_dmc_load_program
=> intel_display_power_resume
=> intel_runtime_resume
=> pci_pm_runtime_resume
=> __rpm_callback
=> rpm_callback
=> rpm_resume
=> __pm_runtime_resume
=> intel_runtime_pm_get
=> intel_display_power_get
=> intel_digital_port_connected
=> intel_dp_detect
=> drm_helper_probe_detect_ctx
=> output_poll_execute
=> process_one_work
=> worker_thread
=> kthread
=> ret_from_fork
=> 0x76a9248cffff91d0
=> 0x781f3f5b5
=> 0
=> 0
=> 0
=> 0
=> 0
=> 0x6c61c9e000000000
<idle>-0 [002] dN.h2.. 1117.635734: irq_noise: local_timer:236 start 1117.635730302 duration 3805 ns
<idle>-0 [002] dp..3.. 1117.635736: thread_noise: swapper/2:0 start 1117.635730535 duration 2244 ns
timerlat/2-5150 [002] .p..... 1117.635737: #20676 context thread timer_latency 8956 ns
<idle>-0 [003] dp.h1.. 1117.636412: #20676 context irq timer_latency 2799 ns
<idle>-0 [003] dN.h2.. 1117.636416: irq_noise: local_timer:236 start 1117.636411102 duration 4325 ns
<idle>-0 [003] dp..3.. 1117.636418: thread_noise: swapper/3:0 start 1117.636411343 duration 2596 ns
timerlat/3-5151 [003] .p..... 1117.636419: #20676 context thread timer_latency 10347 ns
<idle>-0 [000] dp.h1.. 1117.636614: #20677 context irq timer_latency 2336 ns
<idle>-0 [000] dN.h2.. 1117.636618: irq_noise: local_timer:236 start 1117.636613430 duration 4488 ns
<idle>-0 [000] dp..3.. 1117.636620: thread_noise: swapper/0:0 start 1117.636613657 duration 2378 ns
timerlat/0-5148 [000] .p..... 1117.636622: #20677 context thread timer_latency 10012 ns
<idle>-0 [001] dp.h1.. 1117.636673: #20677 context irq timer_latency 2330 ns
<idle>-0 [001] dN.h2.. 1117.636677: irq_noise: local_timer:236 start 1117.636672785 duration 3844 ns
<idle>-0 [001] dp..3.. 1117.636679: thread_noise: swapper/1:0 start 1117.636673029 duration 2452 ns
timerlat/1-5149 [001] .p..... 1117.636680: #20677 context thread timer_latency 9195 ns
<idle>-0 [002] dp.h1.. 1117.636731: #20677 context irq timer_latency 2395 ns
<idle>-0 [002] dN.h2.. 1117.636734: irq_noise: local_timer:236 start 1117.636730337 duration 3899 ns
<idle>-0 [002] dp..3.. 1117.636737: thread_noise: swapper/2:0 start 1117.636730594 duration 2273 ns
timerlat/2-5150 [002] .p..... 1117.636738: #20677 context thread timer_latency 9160 ns
<idle>-0 [003] dp.h1.. 1117.637412: #20677 context irq timer_latency 2782 ns
<idle>-0 [003] dN.h2.. 1117.637415: irq_noise: local_timer:236 start 1117.637411038 duration 4118 ns
<idle>-0 [003] dp..3.. 1117.637418: thread_noise: swapper/3:0 start 1117.637411309 duration 2522 ns
timerlat/3-5151 [003] .p..... 1117.637419: #20677 context thread timer_latency 10044 ns
<idle>-0 [000] dp.h1.. 1117.637615: #20678 context irq timer_latency 3369 ns
<idle>-0 [000] dN.h2.. 1117.637619: irq_noise: local_timer:236 start 1117.637614287 duration 4594 ns
<idle>-0 [000] dp..3.. 1117.637621: thread_noise: swapper/0:0 start 1117.637614672 duration 2282 ns
timerlat/0-5148 [000] .p..... 1117.637623: #20678 context thread timer_latency 10975 ns
<idle>-0 [001] dp.h1.. 1117.637673: #20678 context irq timer_latency 2295 ns
<idle>-0 [001] dN.h2.. 1117.637677: irq_noise: local_timer:236 start 1117.637672738 duration 3827 ns
<idle>-0 [001] dp..3.. 1117.637679: thread_noise: swapper/1:0 start 1117.637672977 duration 2443 ns
timerlat/1-5149 [001] .p..... 1117.637680: #20678 context thread timer_latency 9156 ns
<idle>-0 [002] dp.h1.. 1117.637731: #20678 context irq timer_latency 2346 ns
<idle>-0 [002] dN.h2.. 1117.637734: irq_noise: local_timer:236 start 1117.637730295 duration 3863 ns
<idle>-0 [002] dp..3.. 1117.637737: thread_noise: swapper/2:0 start 1117.637730528 duration 2255 ns
timerlat/2-5150 [002] .p..... 1117.637737: #20678 context thread timer_latency 9079 ns
<idle>-0 [003] dp.h1.. 1117.638412: #20678 context irq timer_latency 2824 ns
<idle>-0 [003] dN.h2.. 1117.638415: irq_noise: local_timer:236 start 1117.638411068 duration 4021 ns
<idle>-0 [003] dp..3.. 1117.638418: thread_noise: swapper/3:0 start 1117.638411334 duration 2513 ns
timerlat/3-5151 [003] .p..... 1117.638419: #20678 context thread timer_latency 9979 ns
<idle>-0 [000] dp.h1.. 1117.638615: #20679 context irq timer_latency 3431 ns
<idle>-0 [000] dN.h2.. 1117.638619: irq_noise: local_timer:236 start 1117.638614310 duration 4656 ns
<idle>-0 [000] dp..3.. 1117.638621: thread_noise: swapper/0:0 start 1117.638614717 duration 2325 ns
timerlat/0-5148 [000] .p..... 1117.638623: #20679 context thread timer_latency 11043 ns
<idle>-0 [001] dp.h1.. 1117.638673: #20679 context irq timer_latency 2348 ns
<idle>-0 [001] dN.h2.. 1117.638677: irq_noise: local_timer:236 start 1117.638672772 duration 3882 ns
<idle>-0 [001] dp..3.. 1117.638679: thread_noise: swapper/1:0 start 1117.638673012 duration 2416 ns
timerlat/1-5149 [001] .p..... 1117.638680: #20679 context thread timer_latency 9229 ns
<idle>-0 [002] dp.h1.. 1117.638731: #20679 context irq timer_latency 2329 ns
<idle>-0 [002] dN.h2.. 1117.638734: irq_noise: local_timer:236 start 1117.638730257 duration 3901 ns
<idle>-0 [002] dp..3.. 1117.638737: thread_noise: swapper/2:0 start 1117.638730494 duration 2199 ns
timerlat/2-5150 [002] .p..... 1117.638737: #20679 context thread timer_latency 9029 ns
<idle>-0 [003] dp.h1.. 1117.639412: #20679 context irq timer_latency 2792 ns
<idle>-0 [003] dN.h2.. 1117.639416: irq_noise: local_timer:236 start 1117.639411022 duration 4442 ns
<idle>-0 [003] dp..3.. 1117.639418: thread_noise: swapper/3:0 start 1117.639411285 duration 2585 ns
timerlat/3-5151 [003] .p..... 1117.639419: #20679 context thread timer_latency 10447 ns
<idle>-0 [000] dp.h1.. 1117.639615: #20680 context irq timer_latency 3446 ns
<idle>-0 [000] dN.h2.. 1117.639619: irq_noise: local_timer:236 start 1117.639614333 duration 4796 ns
<idle>-0 [000] dp..3.. 1117.639622: thread_noise: swapper/0:0 start 1117.639614715 duration 2259 ns
timerlat/0-5148 [000] .p..... 1117.639623: #20680 context thread timer_latency 11243 ns
<idle>-0 [001] dp.h1.. 1117.639674: #20680 context irq timer_latency 2331 ns
<idle>-0 [001] dN.h2.. 1117.639677: irq_noise: local_timer:236 start 1117.639672744 duration 4537 ns
<idle>-0 [001] dp..3.. 1117.639680: thread_noise: swapper/1:0 start 1117.639672978 duration 2458 ns
timerlat/1-5149 [001] .p..... 1117.639681: #20680 context thread timer_latency 10236 ns
<idle>-0 [002] dp.h1.. 1117.639731: #20680 context irq timer_latency 2369 ns
<idle>-0 [002] dN.h2.. 1117.639736: irq_noise: local_timer:236 start 1117.639730278 duration 4623 ns
<idle>-0 [002] dp..3.. 1117.639738: thread_noise: swapper/2:0 start 1117.639730516 duration 2894 ns
timerlat/2-5150 [002] .p..... 1117.639739: #20680 context thread timer_latency 10713 ns
<idle>-0 [003] dp.h1.. 1117.640412: #20680 context irq timer_latency 2788 ns
<idle>-0 [003] dN.h2.. 1117.640416: irq_noise: local_timer:236 start 1117.640411013 duration 4884 ns
<idle>-0 [003] dp..3.. 1117.640419: thread_noise: swapper/3:0 start 1117.640411264 duration 2632 ns
timerlat/3-5151 [003] .p..... 1117.640420: #20680 context thread timer_latency 11233 ns
<idle>-0 [000] dp.h1.. 1117.640615: #20681 context irq timer_latency 3428 ns
<idle>-0 [000] dN.h2.. 1117.640619: irq_noise: local_timer:236 start 1117.640614284 duration 4550 ns
<idle>-0 [000] dp..3.. 1117.640621: thread_noise: swapper/0:0 start 1117.640614679 duration 2300 ns
timerlat/0-5148 [000] .p..... 1117.640622: #20681 context thread timer_latency 10682 ns
<idle>-0 [001] dp.h1.. 1117.640673: #20681 context irq timer_latency 2317 ns
<idle>-0 [001] dN.h2.. 1117.640677: irq_noise: local_timer:236 start 1117.640672703 duration 4194 ns
<idle>-0 [001] dp..3.. 1117.640679: thread_noise: swapper/1:0 start 1117.640672947 duration 2409 ns
timerlat/1-5149 [001] .p..... 1117.640681: #20681 context thread timer_latency 9975 ns
<idle>-0 [002] dp.h1.. 1117.640731: #20681 context irq timer_latency 2353 ns
<idle>-0 [002] dN.h2.. 1117.640734: irq_noise: local_timer:236 start 1117.640730249 duration 3953 ns
<idle>-0 [002] dp..3.. 1117.640737: thread_noise: swapper/2:0 start 1117.640730483 duration 2224 ns
timerlat/2-5150 [002] .p..... 1117.640737: #20681 context thread timer_latency 9127 ns
<idle>-0 [003] dp.h1.. 1117.641412: #20681 context irq timer_latency 2779 ns
<idle>-0 [003] dN.h2.. 1117.641415: irq_noise: local_timer:236 start 1117.641411007 duration 4150 ns
<idle>-0 [003] dp..3.. 1117.641418: thread_noise: swapper/3:0 start 1117.641411237 duration 2566 ns
timerlat/3-5151 [003] .p..... 1117.641419: #20681 context thread timer_latency 10115 ns
<idle>-0 [000] dp.h1.. 1117.641615: #20682 context irq timer_latency 3396 ns
<idle>-0 [000] dN.h2.. 1117.641619: irq_noise: local_timer:236 start 1117.641614247 duration 4696 ns
<idle>-0 [000] dp..3.. 1117.641621: thread_noise: swapper/0:0 start 1117.641614630 duration 2358 ns
timerlat/0-5148 [000] .p..... 1117.641623: #20682 context thread timer_latency 11197 ns
<idle>-0 [001] dp.h1.. 1117.641673: #20682 context irq timer_latency 2360 ns
<idle>-0 [001] dN.h2.. 1117.641677: irq_noise: local_timer:236 start 1117.641672735 duration 3854 ns
<idle>-0 [001] dp..3.. 1117.641679: thread_noise: swapper/1:0 start 1117.641672973 duration 2437 ns
timerlat/1-5149 [001] .p..... 1117.641680: #20682 context thread timer_latency 9255 ns
<idle>-0 [002] dp.h1.. 1117.641731: #20682 context irq timer_latency 2352 ns
<idle>-0 [002] dN.h2.. 1117.641734: irq_noise: local_timer:236 start 1117.641730231 duration 3922 ns
<idle>-0 [002] dp..3.. 1117.641737: thread_noise: swapper/2:0 start 1117.641730465 duration 2268 ns
timerlat/2-5150 [002] .p..... 1117.641737: #20682 context thread timer_latency 9150 ns
<idle>-0 [001] dN.h2.. 1117.642390: irq_noise: local_timer:236 start 1117.642384928 duration 5213 ns
<idle>-0 [003] dp.h1.. 1117.642411: #20682 context irq timer_latency 2285 ns
<idle>-0 [003] dN.h2.. 1117.642415: irq_noise: local_timer:236 start 1117.642410379 duration 4198 ns
<idle>-0 [003] dp..3.. 1117.642417: thread_noise: swapper/3:0 start 1117.642410726 duration 2485 ns
timerlat/3-5151 [003] .p..... 1117.642418: #20682 context thread timer_latency 9556 ns
<idle>-0 [001] dp.h2.. 1117.642520: irq_noise: local_timer:236 start 1117.642518932 duration 554 ns
<idle>-0 [000] dp.h1.. 1117.642614: #20683 context irq timer_latency 2440 ns
<idle>-0 [000] dN.h2.. 1117.642618: irq_noise: local_timer:236 start 1117.642613416 duration 4704 ns
<idle>-0 [000] dp..3.. 1117.642621: thread_noise: swapper/0:0 start 1117.642613661 duration 2388 ns
timerlat/0-5148 [000] .p..... 1117.642622: #20683 context thread timer_latency 10243 ns
kworker/1:3-499 [001] dp.h1.. 1117.642677: #20683 context irq timer_latency 5698 ns
kworker/1:3-499 [001] dN.h2.. 1117.642696: irq_noise: local_timer:236 start 1117.642675929 duration 19694 ns
<idle>-0 [002] dp.h1.. 1117.642731: #20683 context irq timer_latency 2447 ns
<idle>-0 [002] dN.h2.. 1117.642735: irq_noise: local_timer:236 start 1117.642730321 duration 4023 ns
<idle>-0 [002] dp..3.. 1117.642737: thread_noise: swapper/2:0 start 1117.642730543 duration 2260 ns
timerlat/2-5150 [002] .p..... 1117.642738: #20683 context thread timer_latency 9450 ns
kworker/1:3-499 [001] dp..3.. 1117.642961: thread_noise: kworker/1:3:499 start 1117.642676294 duration 264853 ns
timerlat/1-5149 [001] .p..... 1117.642962: #20683 context thread timer_latency 291305 ns
timerlat/1-5149 [001] .p..1.. 1117.642963: <stack trace>
=> timerlat_irq
=> __hrtimer_run_queues
=> hrtimer_interrupt
=> __sysvec_apic_timer_interrupt
=> sysvec_apic_timer_interrupt
=> asm_sysvec_apic_timer_interrupt
=> intel_dmc_load_program
=> intel_display_power_resume
=> intel_runtime_resume
=> pci_pm_runtime_resume
=> __rpm_callback
=> rpm_callback
=> rpm_resume
=> __pm_runtime_resume
=> intel_runtime_pm_get
=> intel_display_power_get
=> intel_digital_port_connected
=> intel_dp_detect
=> drm_helper_probe_detect_ctx
=> output_poll_execute
=> process_one_work
=> worker_thread
=> kthread
=> ret_from_fork
=> 0x69745f6c61636f6c
=> 0x130ce0072656d
=> 0x030101cd
=> 0x7061777300001400
=> 0x312f726570
=> 0x24bf00000000
=> 0x102730d21f9
=> 0x000009be
