# tracer: wakeup_rt
#
# wakeup_rt latency trace v1.1.5 on 6.15.1-dirty
# --------------------------------------------------------------------
# latency: 411 us, #89/89, CPU#1 | (M:PREEMPT_RT VP:0, KP:0, SP:0 HP:0 #P:2)
#    -----------------
#    | task: cyclictest-218784 (uid:0 nice:0 policy:1 rt_prio:95)
#    -----------------
#
#                    _------=> CPU#            
#                   / _-----=> irqs-off/BH-disabled
#                  | / _----=> need-resched    
#                  || / _---=> hardirq/softirq 
#                  ||| / _--=> preempt-depth   
#                  |||| / _-=> migrate-disable 
#                  ||||| /     delay           
#  cmd     pid     |||||| time  |   caller     
#     \   /        ||||||  \    |    /       
  <idle>-0         1dNh5.    0us :        0:120:R   + [001]  218784:  4:R cyclictest
  <idle>-0         1dNh5.    8us : <stack trace>
 => __ftrace_trace_stack
 => probe_wakeup
 => __traceiter_sched_wakeup
 => ttwu_do_activate
 => try_to_wake_up
 => hrtimer_wakeup
 => __hrtimer_run_queues
 => hrtimer_interrupt
 => __sysvec_apic_timer_interrupt
 => sysvec_apic_timer_interrupt
 => asm_sysvec_apic_timer_interrupt
 => cpu_idle_poll.isra.0
 => do_idle
 => cpu_startup_entry
 => start_secondary
 => common_startup_64
  <idle>-0         1dNh5.    8us : 0
  <idle>-0         1dNh4.    8us : task_woken_rt(rq=0xffff983497d2b400, p=0xffff9833c394a000) <-ttwu_do_activate
  <idle>-0         1dNh4.    8us : _raw_spin_unlock(lock=0xffff983497d2b400) <-try_to_wake_up
  <idle>-0         1dNh4.    8us+: preempt_count_sub(val=1) <-_raw_spin_unlock
  <idle>-0         1dNh3.   74us : _raw_spin_unlock_irqrestore(lock=0xffff9833c394a8d8, flags=134) <-try_to_wake_up
  <idle>-0         1dNh3.   74us : preempt_count_sub(val=1) <-_raw_spin_unlock_irqrestore
  <idle>-0         1dNh1.   75us : hrtimer_expire_exit: hrtimer=00000000129a7594
  <idle>-0         1dNh1.   75us+: _raw_spin_lock_irq(lock=0xffff983497d1b700) <-__hrtimer_run_queues
  <idle>-0         1dNh1.  112us : preempt_count_add(val=1) <-_raw_spin_lock_irq
  <idle>-0         1dNh2.  112us : hrtimer_update_next_event(cpu_base=0xffff983497d1b700) <-hrtimer_interrupt
  <idle>-0         1dNh2.  112us : __hrtimer_next_event_base(cpu_base=0xffff983497d1b700, exclude=0x0, active=1, expires_next=9223372036854775807) <-hrtimer_interrupt
  <idle>-0         1dNh2.  112us : _raw_spin_unlock_irqrestore(lock=0xffff983497d1b700, flags=134) <-hrtimer_interrupt
  <idle>-0         1dNh2.  112us : preempt_count_sub(val=1) <-_raw_spin_unlock_irqrestore
  <idle>-0         1dNh1.  113us : tick_program_event(expires=57049782000000, force=0) <-hrtimer_interrupt
  <idle>-0         1dNh1.  113us : clockevents_program_event(dev=0xffff983497d17380, expires=57049782000000, force=0) <-hrtimer_interrupt
  <idle>-0         1dNh1.  113us : ktime_get() <-clockevents_program_event
  <idle>-0         1dNh1.  113us : lapic_next_event(delta=838, evt=0xffff983497d17380) <-clockevents_program_event
  <idle>-0         1dNh1.  113us : local_timer_exit: vector=236
  <idle>-0         1dNh1.  113us : irq_exit_rcu() <-sysvec_apic_timer_interrupt
  <idle>-0         1dNh1.  113us : preempt_count_sub(val=65536) <-__irq_exit_rcu
  <idle>-0         1dN.1.  113us : wake_up_process(p=0xffff9833c0366000) <-__irq_exit_rcu
  <idle>-0         1dN.1.  113us : try_to_wake_up(p=0xffff9833c0366000, state=3, wake_flags=0) <-__irq_exit_rcu
  <idle>-0         1dN.2.  114us : _raw_spin_lock_irqsave(lock=0xffff9833c03668d8) <-try_to_wake_up
  <idle>-0         1dN.2.  114us : preempt_count_add(val=1) <-_raw_spin_lock_irqsave
  <idle>-0         1dN.3.  114us : sched_waking: comm=ktimers/1 pid=31 prio=98 target_cpu=001
  <idle>-0         1dN.3.  114us : kthread_is_per_cpu(p=0xffff9833c0366000) <-try_to_wake_up
  <idle>-0         1dN.3.  114us : ttwu_queue_wakelist(p=0xffff9833c0366000, cpu=1, wake_flags=8) <-try_to_wake_up
  <idle>-0         1dN.4.  114us : _raw_spin_lock(lock=0xffff983497d2b400) <-try_to_wake_up
  <idle>-0         1dN.4.  114us : preempt_count_add(val=1) <-_raw_spin_lock
  <idle>-0         1dN.4.  114us+: update_rq_clock(rq=0xffff983497d2b400) <-try_to_wake_up
  <idle>-0         1dN.4.  149us : ttwu_do_activate(rq=0xffff983497d2b400, p=0xffff9833c0366000, wake_flags=8, rf=0xffffb7c340160f88) <-try_to_wake_up
  <idle>-0         1dN.4.  149us : enqueue_task(rq=0xffff983497d2b400, p=0xffff9833c0366000, flags=9) <-ttwu_do_activate
  <idle>-0         1dN.4.  149us+: enqueue_task_rt(rq=0xffff983497d2b400, p=0xffff9833c0366000, flags=9) <-enqueue_task
  <idle>-0         1dN.4.  185us : dequeue_rt_stack(rt_se=0xffff9833c0366180, flags=9) <-enqueue_task_rt
  <idle>-0         1dN.4.  186us : wakeup_preempt(rq=0xffff983497d2b400, p=0xffff9833c0366000, flags=8) <-ttwu_do_activate
  <idle>-0         1dN.4.  186us : __resched_curr.constprop.0() <-wakeup_preempt
  <idle>-0         1dN.5.  186us : __traceiter_sched_wakeup(__data=0x0, p=0xffff9833c0366000) <-ttwu_do_activate
  <idle>-0         1dN.4.  186us : sched_wakeup: comm=ktimers/1 pid=31 prio=98 target_cpu=001
  <idle>-0         1dN.4.  186us : task_woken_rt(rq=0xffff983497d2b400, p=0xffff9833c0366000) <-ttwu_do_activate
  <idle>-0         1dN.4.  186us : _raw_spin_unlock(lock=0xffff983497d2b400) <-try_to_wake_up
  <idle>-0         1dN.4.  186us : preempt_count_sub(val=1) <-_raw_spin_unlock
  <idle>-0         1dN.3.  187us : _raw_spin_unlock_irqrestore(lock=0xffff9833c03668d8, flags=146) <-try_to_wake_up
  <idle>-0         1dN.3.  187us : preempt_count_sub(val=1) <-_raw_spin_unlock_irqrestore
  <idle>-0         1dN.1.  187us : idle_cpu(cpu=1) <-__irq_exit_rcu
  <idle>-0         1dN.1.  187us : irq_enable: caller=irqentry_exit+0x50/0x70 parent=0x0
  <idle>-0         1dN.1.  187us!: rcu_watching: Endirq 1 0 0x5cc
  <idle>-0         1dN.1.  295us : rcu_watching: Start 0 1 0x5d4
  <idle>-0         1dN.1.  295us : cpu_idle: state=4294967295 cpu_id=1
  <idle>-0         1dN.2.  295us : irq_disable: caller=wakeup_tracer_call+0xbb/0xe0 parent=0x0
  <idle>-0         1.N.1.  295us : arch_cpu_idle_exit() <-do_idle
  <idle>-0         1dN.2.  296us : irq_enable: caller=wakeup_tracer_call+0xd4/0xe0 parent=0x0
  <idle>-0         1dN.2.  296us : irq_disable: caller=wakeup_tracer_call+0xbb/0xe0 parent=0x0
  <idle>-0         1.N.1.  296us : tick_nohz_idle_exit() <-do_idle
  <idle>-0         1dN.2.  296us : irq_enable: caller=wakeup_tracer_call+0xd4/0xe0 parent=0x0
  <idle>-0         1dN.1.  296us : irq_disable: caller=tick_nohz_idle_exit+0x75/0x140 parent=0x0
  <idle>-0         1dN.1.  296us : irq_enable: caller=tick_nohz_idle_exit+0x64/0x140 parent=0x0
  <idle>-0         1dN.2.  296us : irq_disable: caller=wakeup_tracer_call+0xbb/0xe0 parent=0x0
  <idle>-0         1.N.1.  296us!: flush_smp_call_function_queue() <-do_idle
  <idle>-0         1dN.2.  404us : irq_enable: caller=wakeup_tracer_call+0xd4/0xe0 parent=0x0
  <idle>-0         1dN.2.  405us : irq_disable: caller=wakeup_tracer_call+0xbb/0xe0 parent=0x0
  <idle>-0         1.N.1.  405us : schedule_idle() <-cpu_startup_entry
  <idle>-0         1dN.2.  405us : irq_enable: caller=wakeup_tracer_call+0xd4/0xe0 parent=0x0
  <idle>-0         1dN.2.  405us : irq_disable: caller=wakeup_tracer_call+0xbb/0xe0 parent=0x0
  <idle>-0         1.N.1.  405us : hrtimer_active(timer=0xffff983497d2bfe0) <-__schedule
  <idle>-0         1dN.2.  405us : irq_enable: caller=wakeup_tracer_call+0xd4/0xe0 parent=0x0
  <idle>-0         1dN.1.  405us : irq_disable: caller=__schedule+0x67f/0x1080 parent=0x0
  <idle>-0         1dN.1.  405us : rcu_note_context_switch(preempt=0) <-__schedule
  <idle>-0         1dN.1.  405us : rcu_utilization: Start context switch
  <idle>-0         1dN.1.  405us : rcu_qs() <-rcu_note_context_switch
  <idle>-0         1dN.1.  406us : rcu_utilization: End context switch
  <idle>-0         1dN.1.  406us : raw_spin_rq_lock_nested.constprop.0() <-__schedule
  <idle>-0         1dN.2.  406us : _raw_spin_lock(lock=0xffff983497d2b400) <-raw_spin_rq_lock_nested.constprop.0
  <idle>-0         1dN.2.  406us : preempt_count_add(val=1) <-_raw_spin_lock
  <idle>-0         1dN.2.  406us : update_rq_clock(rq=0xffff983497d2b400) <-__schedule
  <idle>-0         1dN.2.  406us : pick_task_stop(rq=0xffff983497d2b400) <-__schedule
  <idle>-0         1dN.2.  406us : pick_task_dl(rq=0xffff983497d2b400) <-__schedule
  <idle>-0         1dN.2.  406us : pick_task_rt(rq=0xffff983497d2b400) <-__schedule
  <idle>-0         1dN.2.  407us : put_prev_task_idle(rq=0xffff983497d2b400, prev=0xffff9833c035a000, next=0xffff9833c394a000) <-__schedule
  <idle>-0         1dN.2.  407us : dl_scaled_delta_exec(rq=0xffff983497d2b400, dl_se=0xffff983497d2bce8, delta_exec=332332) <-put_prev_task_idle
  <idle>-0         1dN.2.  407us : arch_scale_cpu_capacity(cpu=1) <-dl_scaled_delta_exec
  <idle>-0         1dN.2.  407us : dequeue_pushable_task(rq=0xffff983497d2b400, p=0xffff9833c394a000) <-set_next_task_rt
  <idle>-0         1dN.2.  407us : update_rt_rq_load_avg(now=57049782342572, rq=0xffff983497d2b400, running=0) <-set_next_task_rt
  <idle>-0         1d..3.  407us : __traceiter_sched_switch(__data=0x0, preempt=0, prev=0xffff9833c035a000, next=0xffff9833c394a000, prev_state=0) <-__schedule
  <idle>-0         1d..2.  407us : sched_switch: prev_comm=swapper/1 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=cyclictest next_pid=218784 next_prio=4
  <idle>-0         1d..3.  407us : __traceiter_sched_switch
  <idle>-0         1d..3.  408us :        0:120:R ==> [001]  218784:  4:R cyclictest
  <idle>-0         1d..3.  412us : <stack trace>
 => __ftrace_trace_stack
 => probe_wakeup_sched_switch
 => __traceiter_sched_switch
 => __schedule
 => schedule_idle
 => cpu_startup_entry
 => start_secondary
 => common_startup_64