# tracer: wakeup # wakeup latency trace v1.1.5 on 2.6.27-rc6skw-dirty -------------------------------------------------------------------- latency: 104 us, #182/182, CPU#0 | (M:preempt VP:0, KP:0, SP:0 HP:0) ----------------- | task: speaker-test-4086 (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 0us : try_to_wake_up (default_wake_function) -0 0.Nh2 1us : kill_fasync (snd_pcm_period_elapsed) -0 0.Nh2 3us+: i915_driver_irq_handler (handle_IRQ_event) -0 0.Nh2 5us : drm_vbl_send_signals (i915_driver_irq_handler) -0 0dNh2 6us : note_interrupt (handle_fasteoi_irq) -0 0dNh3 7us : ack_ioapic_quirk_irq (handle_fasteoi_irq) -0 0dNh2 7us : irq_exit (do_IRQ) -0 0.N.2 8us : acpi_state_timer_broadcast (acpi_idle_enter_bm) -0 0.N.2 8us : clockevents_notify (acpi_state_timer_broadcast) -0 0.N.3 9us : clockevents_do_notify (clockevents_notify) -0 0.N.3 9us : raw_notifier_call_chain (clockevents_do_notify) -0 0.N.3 9us : __raw_notifier_call_chain (raw_notifier_call_chain) -0 0.N.3 10us : notifier_call_chain (__raw_notifier_call_chain) -0 0.N.3 10us : tick_notify (notifier_call_chain) -0 0.N.3 10us : tick_broadcast_oneshot_control (tick_notify) -0 0dN.4 11us : clockevents_set_mode (tick_broadcast_oneshot_control) -0 0dN.4 11us : lapic_timer_setup (clockevents_set_mode) -0 0dN.4 12us : __setup_APIC_LVTT (lapic_timer_setup) -0 0dN.4 12us : tick_program_event (tick_broadcast_oneshot_control) -0 0dN.4 12us : tick_dev_program_event (tick_program_event) -0 0dN.4 13us : ktime_get (tick_dev_program_event) -0 0dN.4 13us : ktime_get_ts (ktime_get) -0 0dN.4 13us : getnstimeofday (ktime_get_ts) -0 0dN.4 14us : read_hpet (getnstimeofday) -0 0dN.4 14us : hpet_readl (read_hpet) -0 0dN.4 15us : set_normalized_timespec (ktime_get_ts) -0 0dN.4 15us : clockevents_program_event (tick_dev_program_event) -0 0dN.4 16us : lapic_next_event (clockevents_program_event) -0 0.N.2 16us : ticks_elapsed_in_us (acpi_idle_enter_bm) -0 0.N.2 17us : menu_reflect (cpuidle_idle_call) -0 0dN.3 17us : do_IRQ (common_interrupt) -0 0dN.3 18us : irq_enter (do_IRQ) -0 0dN.3 18us : tick_nohz_stop_idle (irq_enter) -0 0dNh3 18us : tick_nohz_update_jiffies (irq_enter) -0 0dNh3 19us : ktime_get (tick_nohz_update_jiffies) -0 0dNh3 19us : ktime_get_ts (ktime_get) -0 0dNh3 20us : getnstimeofday (ktime_get_ts) -0 0dNh3 20us : read_hpet (getnstimeofday) -0 0dNh3 20us : hpet_readl (read_hpet) -0 0dNh3 21us : set_normalized_timespec (ktime_get_ts) -0 0dNh3 22us : tick_do_update_jiffies64 (tick_nohz_update_jiffies) -0 0dNh3 22us : handle_fasteoi_irq (do_IRQ) -0 0dNh3 22us : handle_IRQ_event (handle_fasteoi_irq) -0 0.Nh3 23us : acpi_irq (handle_IRQ_event) -0 0.Nh3 23us : acpi_ev_sci_xrupt_handler (acpi_irq) -0 0.Nh3 23us : acpi_ev_fixed_event_detect (acpi_ev_sci_xrupt_handler) -0 0.Nh3 24us : acpi_hw_register_read (acpi_ev_fixed_event_detect) -0 0.Nh3 24us : acpi_hw_low_level_read (acpi_hw_register_read) -0 0.Nh3 25us : acpi_os_read_port (acpi_hw_low_level_read) -0 0.Nh3 26us : acpi_hw_low_level_read (acpi_hw_register_read) -0 0.Nh3 26us : acpi_hw_register_read (acpi_ev_fixed_event_detect) -0 0.Nh3 27us : acpi_hw_low_level_read (acpi_hw_register_read) -0 0.Nh3 27us : acpi_os_read_port (acpi_hw_low_level_read) -0 0.Nh3 28us : acpi_hw_low_level_read (acpi_hw_register_read) -0 0.Nh3 29us : acpi_ev_gpe_detect (acpi_ev_sci_xrupt_handler) -0 0.Nh3 29us : acpi_os_acquire_lock (acpi_ev_gpe_detect) -0 0dNh4 30us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh4 30us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh4 31us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh4 32us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh4 33us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh4 34us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh4 35us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh4 35us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh4 37us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh4 37us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh4 38us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh4 39us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh4 40us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh4 40us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh4 42us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh4 42us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh4 43us : acpi_ev_gpe_dispatch (acpi_ev_gpe_detect) -0 0dNh4 44us : acpi_os_gpe_count (acpi_ev_gpe_dispatch) -0 0dNh4 44us : acpi_hw_clear_gpe (acpi_ev_gpe_dispatch) -0 0dNh4 44us : acpi_hw_low_level_write (acpi_hw_clear_gpe) -0 0dNh4 45us : acpi_os_write_port (acpi_hw_low_level_write) -0 0dNh4 46us+: acpi_ec_gpe_handler (acpi_ev_gpe_dispatch) -0 0dNh4 48us+: gpe_transaction (acpi_ec_gpe_handler) -0 0dNh4 50us : test_ti_thread_flag (gpe_transaction) -0 0dNh4 50us : ec_transaction_done (acpi_ec_gpe_handler) -0 0dNh4 51us : test_ti_thread_flag (ec_transaction_done) -0 0dNh4 51us : ec_check_sci (acpi_ec_gpe_handler) -0 0dNh4 52us : constant_test_bit (acpi_ec_gpe_handler) -0 0dNh4 52us : acpi_os_release_lock (acpi_ev_gpe_detect) -0 0.Nh3 53us : test_ti_thread_flag (acpi_os_release_lock) -0 0dNh3 53us : note_interrupt (handle_fasteoi_irq) -0 0dNh4 53us : ack_ioapic_quirk_irq (handle_fasteoi_irq) -0 0dNh3 54us : irq_exit (do_IRQ) -0 0.N.2 55us : tick_nohz_restart_sched_tick (cpu_idle) -0 0dN.2 55us : tick_nohz_stop_idle (tick_nohz_restart_sched_tick) -0 0dN.2 55us : ktime_get (tick_nohz_restart_sched_tick) -0 0dN.2 56us : ktime_get_ts (ktime_get) -0 0dN.2 56us : getnstimeofday (ktime_get_ts) -0 0dN.2 56us : read_hpet (getnstimeofday) -0 0dN.2 57us : hpet_readl (read_hpet) -0 0dN.2 58us : set_normalized_timespec (ktime_get_ts) -0 0dN.2 58us : tick_do_update_jiffies64 (tick_nohz_restart_sched_tick) -0 0dN.2 59us : hrtimer_cancel (tick_nohz_restart_sched_tick) -0 0dN.2 59us : hrtimer_try_to_cancel (hrtimer_cancel) -0 0dN.3 59us : __remove_hrtimer (hrtimer_try_to_cancel) -0 0dN.3 60us : hrtimer_force_reprogram (__remove_hrtimer) -0 0dN.3 60us : tick_program_event (hrtimer_force_reprogram) -0 0dN.3 61us : tick_dev_program_event (tick_program_event) -0 0dN.3 61us : ktime_get (tick_dev_program_event) -0 0dN.3 61us : ktime_get_ts (ktime_get) -0 0dN.3 62us : getnstimeofday (ktime_get_ts) -0 0dN.3 62us : read_hpet (getnstimeofday) -0 0dN.3 62us : hpet_readl (read_hpet) -0 0dN.3 63us : set_normalized_timespec (ktime_get_ts) -0 0dN.3 64us : clockevents_program_event (tick_dev_program_event) -0 0dN.3 64us : lapic_next_event (clockevents_program_event) -0 0dN.2 65us : hrtimer_forward (tick_nohz_restart_sched_tick) -0 0dN.2 65us : ktime_add_safe (hrtimer_forward) -0 0dN.2 65us : hrtimer_start (tick_nohz_restart_sched_tick) -0 0dN.3 66us : __timer_stats_hrtimer_set_start_info (hrtimer_start) -0 0dN.3 66us : enqueue_hrtimer (hrtimer_start) -0 0dN.3 66us : hrtimer_reprogram (enqueue_hrtimer) -0 0dN.3 67us : tick_program_event (hrtimer_reprogram) -0 0dN.3 67us : tick_dev_program_event (tick_program_event) -0 0dN.3 68us : ktime_get (tick_dev_program_event) -0 0dN.3 68us : ktime_get_ts (ktime_get) -0 0dN.3 68us : getnstimeofday (ktime_get_ts) -0 0dN.3 69us : read_hpet (getnstimeofday) -0 0dN.3 69us : hpet_readl (read_hpet) -0 0dN.3 70us : set_normalized_timespec (ktime_get_ts) -0 0dN.3 70us : clockevents_program_event (tick_dev_program_event) -0 0dN.3 71us : lapic_next_event (clockevents_program_event) -0 0dN.2 71us : do_IRQ (common_interrupt) -0 0dN.2 72us : irq_enter (do_IRQ) -0 0dN.2 72us : tick_nohz_stop_idle (irq_enter) -0 0dNh2 72us : tick_nohz_update_jiffies (irq_enter) -0 0dNh2 73us : handle_fasteoi_irq (do_IRQ) -0 0dNh2 73us : handle_IRQ_event (handle_fasteoi_irq) -0 0.Nh2 74us : acpi_irq (handle_IRQ_event) -0 0.Nh2 74us : acpi_ev_sci_xrupt_handler (acpi_irq) -0 0.Nh2 74us : acpi_ev_fixed_event_detect (acpi_ev_sci_xrupt_handler) -0 0.Nh2 75us : acpi_hw_register_read (acpi_ev_fixed_event_detect) -0 0.Nh2 75us : acpi_hw_low_level_read (acpi_hw_register_read) -0 0.Nh2 75us : acpi_os_read_port (acpi_hw_low_level_read) -0 0.Nh2 77us : acpi_hw_low_level_read (acpi_hw_register_read) -0 0.Nh2 77us : acpi_hw_register_read (acpi_ev_fixed_event_detect) -0 0.Nh2 77us : acpi_hw_low_level_read (acpi_hw_register_read) -0 0.Nh2 78us : acpi_os_read_port (acpi_hw_low_level_read) -0 0.Nh2 79us : acpi_hw_low_level_read (acpi_hw_register_read) -0 0.Nh2 80us : acpi_ev_gpe_detect (acpi_ev_sci_xrupt_handler) -0 0.Nh2 80us : acpi_os_acquire_lock (acpi_ev_gpe_detect) -0 0dNh3 80us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 81us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 82us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 82us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 84us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 84us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 85us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 86us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 87us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 88us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 89us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 89us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 91us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 91us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 92us : acpi_hw_low_level_read (acpi_ev_gpe_detect) -0 0dNh3 93us : acpi_os_read_port (acpi_hw_low_level_read) -0 0dNh3 94us : acpi_ev_gpe_dispatch (acpi_ev_gpe_detect) -0 0dNh3 94us : acpi_os_gpe_count (acpi_ev_gpe_dispatch) -0 0dNh3 95us : acpi_hw_clear_gpe (acpi_ev_gpe_dispatch) -0 0dNh3 95us : acpi_hw_low_level_write (acpi_hw_clear_gpe) -0 0dNh3 95us : acpi_os_write_port (acpi_hw_low_level_write) -0 0dNh3 97us+: acpi_ec_gpe_handler (acpi_ev_gpe_dispatch) -0 0dNh3 99us : gpe_transaction (acpi_ec_gpe_handler) -0 0dNh3 99us : test_ti_thread_flag (gpe_transaction) -0 0dNh3 99us : ec_transaction_done (acpi_ec_gpe_handler) -0 0dNh3 100us : test_ti_thread_flag (ec_transaction_done) -0 0dNh3 100us : ec_check_sci (acpi_ec_gpe_handler) -0 0dNh3 101us : constant_test_bit (acpi_ec_gpe_handler) -0 0dNh3 101us : acpi_os_release_lock (acpi_ev_gpe_detect) -0 0.Nh2 101us : test_ti_thread_flag (acpi_os_release_lock) -0 0dNh2 102us : note_interrupt (handle_fasteoi_irq) -0 0dNh3 102us : ack_ioapic_quirk_irq (handle_fasteoi_irq) -0 0dNh2 103us : irq_exit (do_IRQ) -0 0d..3 104us : marker_probe_cb (schedule) -0 0d..3 104us : schedule (cpu_idle)