# tracer: wakeup # wakeup latency trace v1.1.5 on 2.6.27-rc6skw-dirty -------------------------------------------------------------------- latency: 95 us, #134/134, CPU#0 | (M:preempt VP:0, KP:0, SP:0 HP:0) ----------------- | task: speaker-test-5719 (uid:1000 nice:0 policy:2 rt_prio:5) ----------------- # _------=> CPU# # / _-----=> irqs-off # | / _----=> need-resched # || / _---=> hardirq/softirq # ||| / _--=> preempt-depth # |||| / # ||||| delay # cmd pid ||||| time | caller # \ / ||||| \ | / -0 0d.h6 1us : try_to_wake_up (default_wake_function) -0 0.Nh2 2us : kill_fasync (snd_pcm_period_elapsed) -0 0.Nh2 3us+: i915_driver_irq_handler (handle_IRQ_event) -0 0.Nh2 7us : drm_vbl_send_signals (i915_driver_irq_handler) -0 0dNh2 8us : note_interrupt (handle_fasteoi_irq) -0 0dNh3 9us : ack_ioapic_quirk_irq (handle_fasteoi_irq) -0 0dNh2 9us : irq_exit (do_IRQ) -0 0dN.2 10us : do_IRQ (common_interrupt) -0 0dN.2 11us : irq_enter (do_IRQ) -0 0dN.2 11us : tick_nohz_stop_idle (irq_enter) -0 0dNh2 11us : tick_nohz_update_jiffies (irq_enter) -0 0dNh2 12us : ktime_get (tick_nohz_update_jiffies) -0 0dNh2 12us : ktime_get_ts (ktime_get) -0 0dNh2 12us : getnstimeofday (ktime_get_ts) -0 0dNh2 13us : read_hpet (getnstimeofday) -0 0dNh2 13us : hpet_readl (read_hpet) -0 0dNh2 14us : set_normalized_timespec (ktime_get_ts) -0 0dNh2 14us : tick_do_update_jiffies64 (tick_nohz_update_jiffies) -0 0dNh2 15us : handle_fasteoi_irq (do_IRQ) -0 0dNh2 15us : handle_IRQ_event (handle_fasteoi_irq) -0 0.Nh2 16us : acpi_irq (handle_IRQ_event) -0 0.Nh2 16us : acpi_ev_sci_xrupt_handler (acpi_irq) -0 0.Nh2 16us : acpi_ev_fixed_event_detect (acpi_ev_sci_xrupt_handler) -0 0.Nh2 17us : acpi_hw_register_read (acpi_ev_fixed_event_detect) -0 0.Nh2 17us : acpi_hw_low_level_read (acpi_hw_register_read) -0 0.Nh2 18us : acpi_os_read_port (acpi_hw_low_level_read) -0 0.Nh2 19us : acpi_hw_low_level_read (acpi_hw_register_read) -0 0.Nh2 19us : acpi_hw_register_read (acpi_ev_fixed_event_detect) -0 0.Nh2 20us : acpi_hw_low_level_read (acpi_hw_register_read) -0 0.Nh2 20us : acpi_os_read_port (acpi_hw_low_level_read) -0 0.Nh2 21us : acpi_hw_low_level_read (acpi_hw_register_read) -0 0.Nh2 22us : acpi_ev_gpe_detect (acpi_ev_sci_xrupt_handler) -0 0.Nh2 22us : acpi_os_acquire_lock (acpi_ev_gpe_detect) -0 0dNh3 23us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 23us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 24us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 25us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 26us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 26us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 28us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 28us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 29us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 30us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 31us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 31us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 33us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 33us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 34us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 35us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 36us : acpi_ev_gpe_dispatch (acpi_ev_gpe_detect) -0 0dNh3 36us : acpi_os_gpe_count (acpi_ev_gpe_dispatch) -0 0dNh3 37us : acpi_hw_clear_gpe (acpi_ev_gpe_dispatch) -0 0dNh3 37us : acpi_hw_low_level_write (acpi_hw_clear_gpe) -0 0dNh3 38us+: acpi_os_write_port (acpi_hw_low_level_write) -0 0dNh3 39us+: acpi_ec_gpe_handler (acpi_ev_gpe_dispatch) -0 0dNh3 41us : gpe_transaction (acpi_ec_gpe_handler) -0 0dNh3 41us : test_ti_thread_flag (gpe_transaction) -0 0dNh3 42us : ec_transaction_done (acpi_ec_gpe_handler) -0 0dNh3 42us : test_ti_thread_flag (ec_transaction_done) -0 0dNh4 43us : autoremove_wake_function (__wake_up_common) -0 0dNh5 44us : account_scheduler_latency (enqueue_task_fair) -0 0dNh5 45us : marker_probe_cb (try_to_wake_up) -0 0dNh3 45us : ec_check_sci (acpi_ec_gpe_handler) -0 0dNh3 46us : constant_test_bit (acpi_ec_gpe_handler) -0 0dNh3 46us : acpi_os_release_lock (acpi_ev_gpe_detect) -0 0.Nh2 47us : test_ti_thread_flag (acpi_os_release_lock) -0 0dNh2 47us : note_interrupt (handle_fasteoi_irq) -0 0dNh3 48us : ack_ioapic_quirk_irq (handle_fasteoi_irq) -0 0dNh2 48us : irq_exit (do_IRQ) -0 0.N.2 49us : acpi_state_timer_broadcast (acpi_idle_enter_bm) -0 0.N.2 49us : clockevents_notify (acpi_state_timer_broadcast) -0 0.N.3 50us : clockevents_do_notify (clockevents_notify) -0 0.N.3 50us+: raw_notifier_call_chain (clockevents_do_notify) -0 0.N.3 68us : __raw_notifier_call_chain (raw_notifier_call_chain) -0 0.N.3 69us : notifier_call_chain (__raw_notifier_call_chain) -0 0.N.3 69us : tick_notify (notifier_call_chain) -0 0.N.3 70us : tick_broadcast_oneshot_control (tick_notify) -0 0dN.4 70us : clockevents_set_mode (tick_broadcast_oneshot_control) -0 0dN.4 70us : lapic_timer_setup (clockevents_set_mode) -0 0dN.4 71us : __setup_APIC_LVTT (lapic_timer_setup) -0 0dN.4 71us : tick_program_event (tick_broadcast_oneshot_control) -0 0dN.4 72us : tick_dev_program_event (tick_program_event) -0 0dN.4 72us : ktime_get (tick_dev_program_event) -0 0dN.4 72us : ktime_get_ts (ktime_get) -0 0dN.4 73us : getnstimeofday (ktime_get_ts) -0 0dN.4 73us : read_hpet (getnstimeofday) -0 0dN.4 74us : hpet_readl (read_hpet) -0 0dN.4 75us : set_normalized_timespec (ktime_get_ts) -0 0dN.4 75us : clockevents_program_event (tick_dev_program_event) -0 0dN.4 76us : lapic_next_event (clockevents_program_event) -0 0.N.2 76us : ticks_elapsed_in_us (acpi_idle_enter_bm) -0 0.N.2 77us : menu_reflect (cpuidle_idle_call) -0 0.N.2 77us : tick_nohz_restart_sched_tick (cpu_idle) -0 0dN.2 78us : tick_nohz_stop_idle (tick_nohz_restart_sched_tick) -0 0dN.2 78us : ktime_get (tick_nohz_restart_sched_tick) -0 0dN.2 78us : ktime_get_ts (ktime_get) -0 0dN.2 79us : getnstimeofday (ktime_get_ts) -0 0dN.2 79us : read_hpet (getnstimeofday) -0 0dN.2 80us : hpet_readl (read_hpet) -0 0dN.2 80us : set_normalized_timespec (ktime_get_ts) -0 0dN.2 81us : tick_do_update_jiffies64 (tick_nohz_restart_sched_tick) -0 0dN.2 81us : hrtimer_cancel (tick_nohz_restart_sched_tick) -0 0dN.2 82us : hrtimer_try_to_cancel (hrtimer_cancel) -0 0dN.3 82us : __remove_hrtimer (hrtimer_try_to_cancel) -0 0dN.3 83us : hrtimer_force_reprogram (__remove_hrtimer) -0 0dN.3 83us : tick_program_event (hrtimer_force_reprogram) -0 0dN.3 83us : tick_dev_program_event (tick_program_event) -0 0dN.3 84us : ktime_get (tick_dev_program_event) -0 0dN.3 84us : ktime_get_ts (ktime_get) -0 0dN.3 84us : getnstimeofday (ktime_get_ts) -0 0dN.3 85us : read_hpet (getnstimeofday) -0 0dN.3 85us : hpet_readl (read_hpet) -0 0dN.3 86us : set_normalized_timespec (ktime_get_ts) -0 0dN.3 86us : clockevents_program_event (tick_dev_program_event) -0 0dN.3 87us : lapic_next_event (clockevents_program_event) -0 0dN.2 87us : hrtimer_forward (tick_nohz_restart_sched_tick) -0 0dN.2 88us : ktime_divns (hrtimer_forward) -0 0dN.2 88us : ktime_add_safe (hrtimer_forward) -0 0dN.2 89us : hrtimer_start (tick_nohz_restart_sched_tick) -0 0dN.3 89us : __timer_stats_hrtimer_set_start_info (hrtimer_start) -0 0dN.3 89us : enqueue_hrtimer (hrtimer_start) -0 0dN.3 90us : hrtimer_reprogram (enqueue_hrtimer) -0 0dN.3 90us : tick_program_event (hrtimer_reprogram) -0 0dN.3 90us : tick_dev_program_event (tick_program_event) -0 0dN.3 91us : ktime_get (tick_dev_program_event) -0 0dN.3 91us : ktime_get_ts (ktime_get) -0 0dN.3 91us : getnstimeofday (ktime_get_ts) -0 0dN.3 92us : read_hpet (getnstimeofday) -0 0dN.3 92us : hpet_readl (read_hpet) -0 0dN.3 93us : set_normalized_timespec (ktime_get_ts) -0 0dN.3 93us : clockevents_program_event (tick_dev_program_event) -0 0dN.3 94us : lapic_next_event (clockevents_program_event) -0 0d..3 95us : marker_probe_cb (schedule) -0 0d..3 96us : schedule (cpu_idle)