Lines Matching +full:3 +full:d
395 If a non ftrace trampoline is attached (BPF) a 'D' will be displayed.
639 example in Documentation/trace/histogram.rst (Section 3.)
997 ps-6143 2d... 0us!: trace_hardirqs_off <-__lock_task_sighand
998 ps-6143 2d..1 259us+: trace_hardirqs_on <-_raw_spin_unlock_irqrestore
999 ps-6143 2d..1 263us+: time_hardirqs_on <-_raw_spin_unlock_irqrestore
1000 ps-6143 2d..1 306us : <stack trace>
1039 irqs-off: 'd' interrupts are disabled. '.' otherwise.
1501 <idle>-0 0d.s2 0us+: _raw_spin_lock_irq <-run_timer_softirq
1536 # latency: 71 us, #168/168, CPU#3 | (M:preempt VP:0, KP:0, SP:0 HP:0 #P:4)
1552 bash-2042 3d... 0us : _raw_spin_lock_irqsave <-ata_scsi_queuecmd
1553 bash-2042 3d... 0us : add_preempt_count <-_raw_spin_lock_irqsave
1554 bash-2042 3d..1 1us : ata_scsi_find_dev <-ata_scsi_queuecmd
1555 bash-2042 3d..1 1us : __ata_scsi_find_dev <-ata_scsi_find_dev
1556 bash-2042 3d..1 2us : ata_find_dev.part.14 <-__ata_scsi_find_dev
1557 bash-2042 3d..1 2us : ata_qc_new_init <-__ata_scsi_queuecmd
1558 bash-2042 3d..1 3us : ata_sg_init <-__ata_scsi_queuecmd
1559 bash-2042 3d..1 4us : ata_scsi_rw_xlat <-__ata_scsi_queuecmd
1560 bash-2042 3d..1 4us : ata_build_rw_tf <-ata_scsi_rw_xlat
1562 bash-2042 3d..1 67us : delay_tsc <-__delay
1563 bash-2042 3d..1 67us : add_preempt_count <-delay_tsc
1564 bash-2042 3d..2 67us : sub_preempt_count <-delay_tsc
1565 bash-2042 3d..1 67us : add_preempt_count <-delay_tsc
1566 bash-2042 3d..2 68us : sub_preempt_count <-delay_tsc
1567 bash-2042 3d..1 68us+: ata_bmdma_start <-ata_bmdma_qc_issue
1568 bash-2042 3d..1 71us : _raw_spin_unlock_irqrestore <-ata_scsi_queuecmd
1569 bash-2042 3d..1 71us : _raw_spin_unlock_irqrestore <-ata_scsi_queuecmd
1570 bash-2042 3d..1 72us+: trace_hardirqs_on <-ata_scsi_queuecmd
1571 bash-2042 3d..1 120us : <stack trace>
1629 0 us | 0) bash-1507 | d... | 0.000 us | _raw_spin_lock_irqsave();
1630 0 us | 0) bash-1507 | d..1 | 0.378 us | do_raw_spin_trylock();
1631 1 us | 0) bash-1507 | d..2 | | set_track() {
1632 2 us | 0) bash-1507 | d..2 | | save_stack_trace() {
1633 2 us | 0) bash-1507 | d..2 | | __save_stack_trace() {
1634 3 us | 0) bash-1507 | d..2 | | __unwind_start() {
1635 3 us | 0) bash-1507 | d..2 | | get_stack_info() {
1636 3 us | 0) bash-1507 | d..2 | 0.351 us | in_task_stack();
1637 4 us | 0) bash-1507 | d..2 | 1.107 us | }
1639 3750 us | 0) bash-1507 | d..1 | 0.516 us | do_raw_spin_unlock();
1640 3750 us | 0) bash-1507 | d..1 | 0.000 us | _raw_spin_unlock_irqrestore();
1641 3764 us | 0) bash-1507 | d..1 | 0.000 us | tracer_hardirqs_on();
1642 bash-1507 0d..1 3792us : <stack trace>
1700 sshd-1991 1d.h. 0us+: irq_enter <-do_IRQ
1701 sshd-1991 1d..1 46us : irq_exit <-do_IRQ
1702 sshd-1991 1d..1 47us+: trace_preempt_on <-do_IRQ
1703 sshd-1991 1d..1 52us : <stack trace>
1713 the preempt off section and leaving it (the 'd'). We do not know if
1738 bash-1994 1d..1 0us : _raw_spin_lock_irqsave <-wake_up_new_task
1739 bash-1994 1d..1 0us : select_task_rq_fair <-select_task_rq
1740 bash-1994 1d..1 1us : __rcu_read_lock <-select_task_rq_fair
1741 bash-1994 1d..1 1us : source_load <-select_task_rq_fair
1742 bash-1994 1d..1 1us : source_load <-select_task_rq_fair
1744 bash-1994 1d..1 12us : irq_enter <-smp_apic_timer_interrupt
1745 bash-1994 1d..1 12us : rcu_irq_enter <-irq_enter
1746 bash-1994 1d..1 13us : add_preempt_count <-irq_enter
1747 bash-1994 1d.h1 13us : exit_idle <-smp_apic_timer_interrupt
1748 bash-1994 1d.h1 13us : hrtimer_interrupt <-smp_apic_timer_interrupt
1749 bash-1994 1d.h1 13us : _raw_spin_lock <-hrtimer_interrupt
1750 bash-1994 1d.h1 14us : add_preempt_count <-_raw_spin_lock
1751 bash-1994 1d.h2 14us : ktime_get_update_offsets <-hrtimer_interrupt
1753 bash-1994 1d.h1 35us : lapic_next_event <-clockevents_program_event
1754 bash-1994 1d.h1 35us : irq_exit <-smp_apic_timer_interrupt
1755 bash-1994 1d.h1 36us : sub_preempt_count <-irq_exit
1756 bash-1994 1d..2 36us : do_softirq <-irq_exit
1757 bash-1994 1d..2 36us : __do_softirq <-call_softirq
1758 bash-1994 1d..2 36us : __local_bh_disable <-__do_softirq
1759 bash-1994 1d.s2 37us : add_preempt_count <-_raw_spin_lock_irq
1760 bash-1994 1d.s3 38us : _raw_spin_unlock <-run_timer_softirq
1761 bash-1994 1d.s3 39us : sub_preempt_count <-_raw_spin_unlock
1762 bash-1994 1d.s2 39us : call_timer_fn <-run_timer_softirq
1836 # latency: 100 us, #4/4, CPU#3 | (M:preempt VP:0, KP:0, SP:0 HP:0 #P:4)
1852 ls-2230 3d... 0us+: _raw_spin_lock_irqsave <-ata_scsi_queuecmd
1853 ls-2230 3...1 100us : _raw_spin_unlock_irqrestore <-ata_scsi_queuecmd
1854 ls-2230 3...1 101us+: trace_preempt_on <-ata_scsi_queuecmd
1855 ls-2230 3...1 111us : <stack trace>
1889 # latency: 161 us, #339/339, CPU#3 | (M:preempt VP:0, KP:0, SP:0 HP:0 #P:4)
1905 kworker/-59 3...1 0us : __schedule <-schedule
1906 kworker/-59 3d..1 0us : rcu_preempt_qs <-rcu_note_context_switch
1907 kworker/-59 3d..1 1us : add_preempt_count <-_raw_spin_lock_irq
1908 kworker/-59 3d..2 1us : deactivate_task <-__schedule
1909 kworker/-59 3d..2 1us : dequeue_task <-deactivate_task
1910 kworker/-59 3d..2 2us : update_rq_clock <-dequeue_task
1911 kworker/-59 3d..2 2us : dequeue_task_fair <-dequeue_task
1912 kworker/-59 3d..2 2us : update_curr <-dequeue_task_fair
1913 kworker/-59 3d..2 2us : update_min_vruntime <-update_curr
1914 kworker/-59 3d..2 3us : cpuacct_charge <-update_curr
1915 kworker/-59 3d..2 3us : __rcu_read_lock <-cpuacct_charge
1916 kworker/-59 3d..2 3us : __rcu_read_unlock <-cpuacct_charge
1917 kworker/-59 3d..2 3us : update_cfs_rq_blocked_load <-dequeue_task_fair
1918 kworker/-59 3d..2 4us : clear_buddies <-dequeue_task_fair
1919 kworker/-59 3d..2 4us : account_entity_dequeue <-dequeue_task_fair
1920 kworker/-59 3d..2 4us : update_min_vruntime <-dequeue_task_fair
1921 kworker/-59 3d..2 4us : update_cfs_shares <-dequeue_task_fair
1922 kworker/-59 3d..2 5us : hrtick_update <-dequeue_task_fair
1923 kworker/-59 3d..2 5us : wq_worker_sleeping <-__schedule
1924 kworker/-59 3d..2 5us : kthread_data <-wq_worker_sleeping
1925 kworker/-59 3d..2 5us : put_prev_task_fair <-__schedule
1926 kworker/-59 3d..2 6us : pick_next_task_fair <-pick_next_task
1927 kworker/-59 3d..2 6us : clear_buddies <-pick_next_task_fair
1928 kworker/-59 3d..2 6us : set_next_entity <-pick_next_task_fair
1929 kworker/-59 3d..2 6us : update_stats_wait_end <-set_next_entity
1930 ls-2269 3d..2 7us : finish_task_switch <-__schedule
1931 ls-2269 3d..2 7us : _raw_spin_unlock_irq <-finish_task_switch
1932 ls-2269 3d..2 8us : do_IRQ <-ret_from_intr
1933 ls-2269 3d..2 8us : irq_enter <-do_IRQ
1934 ls-2269 3d..2 8us : rcu_irq_enter <-irq_enter
1935 ls-2269 3d..2 9us : add_preempt_count <-irq_enter
1936 ls-2269 3d.h2 9us : exit_idle <-do_IRQ
1938 ls-2269 3d.h3 20us : sub_preempt_count <-_raw_spin_unlock
1939 ls-2269 3d.h2 20us : irq_exit <-do_IRQ
1940 ls-2269 3d.h2 21us : sub_preempt_count <-irq_exit
1941 ls-2269 3d..3 21us : do_softirq <-irq_exit
1942 ls-2269 3d..3 21us : __do_softirq <-call_softirq
1943 ls-2269 3d..3 21us+: __local_bh_disable <-__do_softirq
1944 ls-2269 3d.s4 29us : sub_preempt_count <-_local_bh_enable_ip
1945 ls-2269 3d.s5 29us : sub_preempt_count <-_local_bh_enable_ip
1946 ls-2269 3d.s5 31us : do_IRQ <-ret_from_intr
1947 ls-2269 3d.s5 31us : irq_enter <-do_IRQ
1948 ls-2269 3d.s5 31us : rcu_irq_enter <-irq_enter
1950 ls-2269 3d.s5 31us : rcu_irq_enter <-irq_enter
1951 ls-2269 3d.s5 32us : add_preempt_count <-irq_enter
1952 ls-2269 3d.H5 32us : exit_idle <-do_IRQ
1953 ls-2269 3d.H5 32us : handle_irq <-do_IRQ
1954 ls-2269 3d.H5 32us : irq_to_desc <-handle_irq
1955 ls-2269 3d.H5 33us : handle_fasteoi_irq <-handle_irq
1957 ls-2269 3d.s5 158us : _raw_spin_unlock_irqrestore <-rtl8139_poll
1958 ls-2269 3d.s3 158us : net_rps_action_and_irq_enable.isra.65 <-net_rx_action
1959 ls-2269 3d.s3 159us : __local_bh_enable <-__do_softirq
1960 ls-2269 3d.s3 159us : sub_preempt_count <-__local_bh_enable
1961 ls-2269 3d..3 159us : idle_cpu <-irq_exit
1962 ls-2269 3d..3 159us : rcu_irq_exit <-irq_exit
1963 ls-2269 3d..3 160us : sub_preempt_count <-irq_exit
1964 ls-2269 3d... 161us : __mutex_unlock_slowpath <-mutex_unlock
1965 ls-2269 3d... 162us+: trace_hardirqs_on <-mutex_unlock
1966 ls-2269 3d... 186us : <stack trace>
2005 # latency: 15 us, #4/4, CPU#3 | (M:preempt VP:0, KP:0, SP:0 HP:0 #P:4)
2007 # | task: kworker/3:1H-312 (uid:0 nice:-20 policy:0 rt_prio:0)
2018 <idle>-0 3dNs7 0us : 0:120:R + [003] 312:100:R kworker/3:1H
2019 <idle>-0 3dNs7 1us+: ttwu_do_activate.constprop.87 <-try_to_wake_up
2020 <idle>-0 3d..3 15us : __schedule <-schedule
2021 <idle>-0 3d..3 15us : 0:120:R ==> [003] 312:100:R kworker/3:1H
2074 # latency: 5 us, #4/4, CPU#3 | (M:preempt VP:0, KP:0, SP:0 HP:0 #P:4)
2087 <idle>-0 3d.h4 0us : 0:120:R + [003] 2389: 94:R sleep
2088 <idle>-0 3d.h4 1us+: ttwu_do_activate.constprop.87 <-try_to_wake_up
2089 <idle>-0 3d..3 5us : __schedule <-schedule
2090 <idle>-0 3d..3 5us : 0:120:R ==> [003] 2389: 94:R sleep
2107 <idle>-0 3d..3 5us : 0:120:R ==> [003] 2389: 94:R sleep
2123 # latency: 29 us, #85/85, CPU#3 | (M:preempt VP:0, KP:0, SP:0 HP:0 #P:4)
2136 <idle>-0 3d.h4 1us+: 0:120:R + [003] 2448: 94:R sleep
2137 <idle>-0 3d.h4 2us : ttwu_do_activate.constprop.87 <-try_to_wake_up
2138 <idle>-0 3d.h3 3us : check_preempt_curr <-ttwu_do_wakeup
2139 <idle>-0 3d.h3 3us : resched_curr <-check_preempt_curr
2140 <idle>-0 3dNh3 4us : task_woken_rt <-ttwu_do_wakeup
2141 <idle>-0 3dNh3 4us : _raw_spin_unlock <-try_to_wake_up
2142 <idle>-0 3dNh3 4us : sub_preempt_count <-_raw_spin_unlock
2143 <idle>-0 3dNh2 5us : ttwu_stat <-try_to_wake_up
2144 <idle>-0 3dNh2 5us : _raw_spin_unlock_irqrestore <-try_to_wake_up
2145 <idle>-0 3dNh2 6us : sub_preempt_count <-_raw_spin_unlock_irqrestore
2146 <idle>-0 3dNh1 6us : _raw_spin_lock <-__run_hrtimer
2147 <idle>-0 3dNh1 6us : add_preempt_count <-_raw_spin_lock
2148 <idle>-0 3dNh2 7us : _raw_spin_unlock <-hrtimer_interrupt
2149 <idle>-0 3dNh2 7us : sub_preempt_count <-_raw_spin_unlock
2150 <idle>-0 3dNh1 7us : tick_program_event <-hrtimer_interrupt
2151 <idle>-0 3dNh1 7us : clockevents_program_event <-tick_program_event
2152 <idle>-0 3dNh1 8us : ktime_get <-clockevents_program_event
2153 <idle>-0 3dNh1 8us : lapic_next_event <-clockevents_program_event
2154 <idle>-0 3dNh1 8us : irq_exit <-smp_apic_timer_interrupt
2155 <idle>-0 3dNh1 9us : sub_preempt_count <-irq_exit
2156 <idle>-0 3dN.2 9us : idle_cpu <-irq_exit
2157 <idle>-0 3dN.2 9us : rcu_irq_exit <-irq_exit
2158 <idle>-0 3dN.2 10us : rcu_eqs_enter_common.isra.45 <-rcu_irq_exit
2159 <idle>-0 3dN.2 10us : sub_preempt_count <-irq_exit
2160 <idle>-0 3.N.1 11us : rcu_idle_exit <-cpu_idle
2161 <idle>-0 3dN.1 11us : rcu_eqs_exit_common.isra.43 <-rcu_idle_exit
2162 <idle>-0 3.N.1 11us : tick_nohz_idle_exit <-cpu_idle
2163 <idle>-0 3dN.1 12us : menu_hrtimer_cancel <-tick_nohz_idle_exit
2164 <idle>-0 3dN.1 12us : ktime_get <-tick_nohz_idle_exit
2165 <idle>-0 3dN.1 12us : tick_do_update_jiffies64 <-tick_nohz_idle_exit
2166 <idle>-0 3dN.1 13us : cpu_load_update_nohz <-tick_nohz_idle_exit
2167 <idle>-0 3dN.1 13us : _raw_spin_lock <-cpu_load_update_nohz
2168 <idle>-0 3dN.1 13us : add_preempt_count <-_raw_spin_lock
2169 <idle>-0 3dN.2 13us : __cpu_load_update <-cpu_load_update_nohz
2170 <idle>-0 3dN.2 14us : sched_avg_update <-__cpu_load_update
2171 <idle>-0 3dN.2 14us : _raw_spin_unlock <-cpu_load_update_nohz
2172 <idle>-0 3dN.2 14us : sub_preempt_count <-_raw_spin_unlock
2173 <idle>-0 3dN.1 15us : calc_load_nohz_stop <-tick_nohz_idle_exit
2174 <idle>-0 3dN.1 15us : touch_softlockup_watchdog <-tick_nohz_idle_exit
2175 <idle>-0 3dN.1 15us : hrtimer_cancel <-tick_nohz_idle_exit
2176 <idle>-0 3dN.1 15us : hrtimer_try_to_cancel <-hrtimer_cancel
2177 <idle>-0 3dN.1 16us : lock_hrtimer_base.isra.18 <-hrtimer_try_to_cancel
2178 <idle>-0 3dN.1 16us : _raw_spin_lock_irqsave <-lock_hrtimer_base.isra.18
2179 <idle>-0 3dN.1 16us : add_preempt_count <-_raw_spin_lock_irqsave
2180 <idle>-0 3dN.2 17us : __remove_hrtimer <-remove_hrtimer.part.16
2181 <idle>-0 3dN.2 17us : hrtimer_force_reprogram <-__remove_hrtimer
2182 <idle>-0 3dN.2 17us : tick_program_event <-hrtimer_force_reprogram
2183 <idle>-0 3dN.2 18us : clockevents_program_event <-tick_program_event
2184 <idle>-0 3dN.2 18us : ktime_get <-clockevents_program_event
2185 <idle>-0 3dN.2 18us : lapic_next_event <-clockevents_program_event
2186 <idle>-0 3dN.2 19us : _raw_spin_unlock_irqrestore <-hrtimer_try_to_cancel
2187 <idle>-0 3dN.2 19us : sub_preempt_count <-_raw_spin_unlock_irqrestore
2188 <idle>-0 3dN.1 19us : hrtimer_forward <-tick_nohz_idle_exit
2189 <idle>-0 3dN.1 20us : ktime_add_safe <-hrtimer_forward
2190 <idle>-0 3dN.1 20us : ktime_add_safe <-hrtimer_forward
2191 <idle>-0 3dN.1 20us : hrtimer_start_range_ns <-hrtimer_start_expires.constprop.11
2192 <idle>-0 3dN.1 20us : __hrtimer_start_range_ns <-hrtimer_start_range_ns
2193 <idle>-0 3dN.1 21us : lock_hrtimer_base.isra.18 <-__hrtimer_start_range_ns
2194 <idle>-0 3dN.1 21us : _raw_spin_lock_irqsave <-lock_hrtimer_base.isra.18
2195 <idle>-0 3dN.1 21us : add_preempt_count <-_raw_spin_lock_irqsave
2196 <idle>-0 3dN.2 22us : ktime_add_safe <-__hrtimer_start_range_ns
2197 <idle>-0 3dN.2 22us : enqueue_hrtimer <-__hrtimer_start_range_ns
2198 <idle>-0 3dN.2 22us : tick_program_event <-__hrtimer_start_range_ns
2199 <idle>-0 3dN.2 23us : clockevents_program_event <-tick_program_event
2200 <idle>-0 3dN.2 23us : ktime_get <-clockevents_program_event
2201 <idle>-0 3dN.2 23us : lapic_next_event <-clockevents_program_event
2202 <idle>-0 3dN.2 24us : _raw_spin_unlock_irqrestore <-__hrtimer_start_range_ns
2203 <idle>-0 3dN.2 24us : sub_preempt_count <-_raw_spin_unlock_irqrestore
2204 <idle>-0 3dN.1 24us : account_idle_ticks <-tick_nohz_idle_exit
2205 <idle>-0 3dN.1 24us : account_idle_time <-account_idle_ticks
2206 <idle>-0 3.N.1 25us : sub_preempt_count <-cpu_idle
2207 <idle>-0 3.N.. 25us : schedule <-cpu_idle
2208 <idle>-0 3.N.. 25us : __schedule <-preempt_schedule
2209 <idle>-0 3.N.. 26us : add_preempt_count <-__schedule
2210 <idle>-0 3.N.1 26us : rcu_note_context_switch <-__schedule
2211 <idle>-0 3.N.1 26us : rcu_sched_qs <-rcu_note_context_switch
2212 <idle>-0 3dN.1 27us : rcu_preempt_qs <-rcu_note_context_switch
2213 <idle>-0 3.N.1 27us : _raw_spin_lock_irq <-__schedule
2214 <idle>-0 3dN.1 27us : add_preempt_count <-_raw_spin_lock_irq
2215 <idle>-0 3dN.2 28us : put_prev_task_idle <-__schedule
2216 <idle>-0 3dN.2 28us : pick_next_task_stop <-pick_next_task
2217 <idle>-0 3dN.2 28us : pick_next_task_rt <-pick_next_task
2218 <idle>-0 3dN.2 29us : dequeue_pushable_task <-pick_next_task_rt
2219 <idle>-0 3d..3 29us : __schedule <-preempt_schedule
2220 <idle>-0 3d..3 30us : 0:120:R ==> [003] 2448: 94:R sleep
2262 <idle>-0 2d.h4 0us : 0:120:R + [002] 5882: 94:R sleep
2263 <idle>-0 2d.h4 0us : ttwu_do_activate.constprop.87 <-try_to_wake_up
2264 <idle>-0 2d.h4 1us : sched_wakeup: comm=sleep pid=5882 prio=94 success=1 target_cpu=002
2267 <idle>-0 2.N.2 3us : cpu_idle: state=4294967295 cpu_id=2
2268 <idle>-0 2dN.3 4us : hrtimer_cancel: hrtimer=ffff88007d50d5e0
2269 …<idle>-0 2dN.3 4us : hrtimer_start: hrtimer=ffff88007d50d5e0 function=tick_sched_timer ex…
2272 <idle>-0 2d..3 6us : __schedule <-schedule
2273 <idle>-0 2d..3 6us : 0:120:R ==> [002] 5882: 94:R sleep
2299 …<...>-1729 [001] d... 678.473449: #1 inner/outer(us): 11/12 ts:1581527483.343962693 co…
2300 …<...>-1729 [004] d... 689.556542: #2 inner/outer(us): 16/9 ts:1581527494.889008092 co…
2301 …<...>-1729 [005] d... 714.756290: #3 inner/outer(us): 16/16 ts:1581527519.678961629 co…
2302 …<...>-1729 [001] d... 718.788247: #4 inner/outer(us): 9/17 ts:1581527523.889012713 co…
2303 …<...>-1729 [002] d... 719.796341: #5 inner/outer(us): 13/9 ts:1581527524.912872606 co…
2304 …<...>-1729 [006] d... 844.787091: #6 inner/outer(us): 9/12 ts:1581527649.889048502 co…
2305 …<...>-1729 [003] d... 849.827033: #7 inner/outer(us): 18/9 ts:1581527654.889013793 co…
2306 …<...>-1729 [007] d... 853.859002: #8 inner/outer(us): 9/12 ts:1581527658.889065736 co…
2307 …<...>-1729 [001] d... 855.874978: #9 inner/outer(us): 9/11 ts:1581527660.861991877 co…
2308 …<...>-1729 [001] d... 863.938932: #10 inner/outer(us): 9/11 ts:1581527668.970010500 co…
2309 …<...>-1729 [007] d... 878.050780: #11 inner/outer(us): 9/12 ts:1581527683.385002600 co…
2310 …<...>-1729 [007] d... 886.114702: #12 inner/outer(us): 9/12 ts:1581527691.385001600 co…
2314 interrupts disabled 'd'. Under the FUNCTION title there is:
2461 ##### CPU 3 buffer started ####
2501 "s %99s %*s %*d %*d\n",
2539 write(ffd, "nop", 3);
2542 s = sprintf(line, "%d\n", getpid());
2655 3) # 1837.709 us | } /* __switch_to */
2656 3) | finish_task_switch() {
2657 3) 0.313 us | _raw_spin_unlock_irq();
2658 3) 3.177 us | }
2659 3) # 1889.063 us | } /* __schedule */
2660 3) ! 140.417 us | } /* __schedule */
2661 3) # 2034.948 us | } /* schedule */
2662 3) * 33998.59 us | } /* schedule_preempt_disabled */
3019 <idle>-0 [001] d.h1 4186.475409: hrtimer_interrupt <-smp_apic_timer_interrupt
3020 usleep-2665 [001] d.h1 4186.475426: hrtimer_interrupt <-smp_apic_timer_interrupt
3021 <idle>-0 [003] d.h1 4186.475426: hrtimer_interrupt <-smp_apic_timer_interrupt
3022 <idle>-0 [002] d.h1 4186.475427: hrtimer_interrupt <-smp_apic_timer_interrupt
3070 <idle>-0 [003] d..1 4228.547858: hrtimer_get_next_event <-get_next_timer_interrupt
3071 <idle>-0 [003] d..1 4228.547859: hrtimer_start <-__tick_nohz_idle_enter
3072 <idle>-0 [003] d..2 4228.547860: hrtimer_force_reprogram <-__rem
3568 …<idle>-0 [005] d... 2440.603828: sched_switch: prev_comm=swapper/5 prev_pid=0 prev_prio=120 …
3569 …sleep-2242 [005] d... 2440.603846: sched_switch: prev_comm=snapshot-test-2 prev_pid=2242 prev_pr…
3571 …<idle>-0 [002] d... 2440.707230: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 p…
3585 …<idle>-0 [007] d... 2440.707395: sched_switch: prev_comm=swapper/7 prev_pid=0 prev_prio=120 p…
3586 …snapshot-test-2-2229 [002] d... 2440.707438: sched_switch: prev_comm=snapshot-test-2 prev_pid=22…
3649 bash-2044 [002] d... 10594.481032: add_preempt_count <-_raw_spin_lock_irqsave
3650 bash-2044 [002] d..1 10594.481032: __rmqueue <-get_page_from_freelist
3651 bash-2044 [002] d..1 10594.481033: _raw_spin_unlock <-get_page_from_freelist
3652 bash-2044 [002] d..1 10594.481033: sub_preempt_count <-_raw_spin_unlock
3653 … bash-2044 [002] d... 10594.481033: get_pageblock_flags_group <-get_pageblock_migratetype
3654 bash-2044 [002] d... 10594.481034: __mod_zone_page_state <-get_page_from_freelist
3655 bash-2044 [002] d... 10594.481034: zone_statistics <-get_page_from_freelist
3656 bash-2044 [002] d... 10594.481034: __inc_zone_state <-zone_statistics
3657 bash-2044 [002] d... 10594.481034: __inc_zone_state <-zone_statistics
3662 …bash-1998 [000] d..4 136.676759: sched_wakeup: comm=kworker/0:1 pid=59 prio=120 success=1 targe…
3664 …<idle>-0 [003] d.h3 136.676906: sched_wakeup: comm=rcu_preempt pid=9 prio=120 success=1 targ…
3665 …<idle>-0 [003] d..3 136.676909: sched_switch: prev_comm=swapper/3 prev_pid=0 prev_prio=120 p…
3666 …eempt-9 [003] d..3 136.676916: sched_switch: prev_comm=rcu_preempt prev_pid=9 prev_prio=120 …
3667 …bash-1998 [000] d..4 136.677014: sched_wakeup: comm=kworker/0:1 pid=59 prio=120 success=1 targe…
3669 …bash-1998 [000] d..3 136.677018: sched_switch: prev_comm=bash prev_pid=1998 prev_prio=120 prev_…
3670 …kworker/0:1-59 [000] d..4 136.677022: sched_wakeup: comm=sshd pid=1995 prio=120 success=1 tar…
3671 …kworker/0:1-59 [000] d..3 136.677025: sched_switch: prev_comm=kworker/0:1 prev_pid=59 prev_pr…
3675 migration/1-14 [001] d.h3 138.732674: softirq_raise: vec=3 [action=NET_RX]
3676 <idle>-0 [001] dNh3 138.732725: softirq_raise: vec=3 [action=NET_RX]
3677 bash-1998 [000] d.h1 138.733101: softirq_raise: vec=1 [action=TIMER]
3678 bash-1998 [000] d.h1 138.733102: softirq_raise: vec=9 [action=RCU]
3683 sshd-1995 [001] d.h1 138.733278: irq_handler_entry: irq=21 name=uhci_hcd:usb4
3684 sshd-1995 [001] d.h1 138.733280: irq_handler_exit: irq=21 ret=unhandled
3685 sshd-1995 [001] d.h1 138.733281: irq_handler_entry: irq=21 name=eth0
3686 sshd-1995 [001] d.h1 138.733283: irq_handler_exit: irq=21 ret=handled
3701 bash-1998 [000] d... 140.733501: sys_write -> 0x2
3702 bash-1998 [000] d... 140.733504: sys_dup2(oldfd: a, newfd: 1)
3703 bash-1998 [000] d... 140.733506: sys_dup2 -> 0x1
3704 bash-1998 [000] d... 140.733508: sys_fcntl(fd: a, cmd: 1, arg: 0)
3705 bash-1998 [000] d... 140.733509: sys_fcntl -> 0x1
3706 bash-1998 [000] d... 140.733510: sys_close(fd: a)
3707 bash-1998 [000] d... 140.733510: sys_close -> 0x0
3708 …bash-1998 [000] d... 140.733514: sys_rt_sigprocmask(how: 0, nset: 0, oset: 6e2768, sigsetsize: …
3709 bash-1998 [000] d... 140.733515: sys_rt_sigprocmask -> 0x0
3710 …bash-1998 [000] d... 140.733516: sys_rt_sigaction(sig: 2, act: 7fff718846f0, oact: 7fff71884650…
3711 bash-1998 [000] d... 140.733516: sys_rt_sigaction -> 0x0
3764 3) 2288 80 idle_balance+0xbb/0x130