preemption latency trace v1.0.6 on 2.6.9-rc1-bk12-VP-R6 -------------------------------------------------- latency: 4017 us, entries: 44 (44) [VP:1 KP:1 SP:1 HP:1 #CPUS:1] ----------------- | task: bzip2/12841, uid:0 nice:0 policy:0 rt_prio:0 ----------------- => started at: do_anonymous_page+0xbb/0x1c0 => ended at: do_anonymous_page+0x154/0x1c0 =======> 00000001 0.000ms (+0.000ms): do_anonymous_page (do_no_page) 00000001 0.000ms (+0.000ms): page_address (do_anonymous_page) 00000001 0.001ms (+0.000ms): lru_cache_add_active (do_anonymous_page) 00000001 0.001ms (+0.000ms): mark_page_accessed (do_anonymous_page) 00000001 0.002ms (+3.987ms): page_add_anon_rmap (do_anonymous_page) 00010001 3.989ms (+0.000ms): do_IRQ (mcount) 00010001 3.989ms (+0.000ms): do_IRQ (<00000000>) 00010002 3.990ms (+0.002ms): mask_and_ack_8259A (do_IRQ) 00010002 3.992ms (+0.000ms): generic_redirect_hardirq (do_IRQ) 00010001 3.993ms (+0.000ms): generic_handle_IRQ_event (do_IRQ) 00010001 3.993ms (+0.000ms): timer_interrupt (generic_handle_IRQ_event) 00010002 3.994ms (+0.006ms): mark_offset_tsc (timer_interrupt) 00010002 4.000ms (+0.000ms): do_timer (timer_interrupt) 00010002 4.000ms (+0.000ms): update_process_times (do_timer) 00010002 4.001ms (+0.000ms): update_one_process (update_process_times) 00010002 4.001ms (+0.000ms): run_local_timers (update_process_times) 00010002 4.002ms (+0.000ms): raise_softirq (update_process_times) 00010002 4.002ms (+0.000ms): scheduler_tick (update_process_times) 00010002 4.002ms (+0.001ms): sched_clock (scheduler_tick) 00010002 4.004ms (+0.000ms): update_wall_time (do_timer) 00010002 4.005ms (+0.000ms): update_wall_time_one_tick (update_wall_time) 00010002 4.005ms (+0.000ms): update_wall_time_one_tick (update_wall_time) 00010002 4.005ms (+0.000ms): update_wall_time_one_tick (update_wall_time) 00010002 4.006ms (+0.000ms): update_wall_time_one_tick (update_wall_time) 00010002 4.006ms (+0.000ms): profile_tick (timer_interrupt) 00010002 4.007ms (+0.000ms): profile_hook (profile_tick) 00010003 4.007ms (+0.000ms): notifier_call_chain (profile_hook) 00010002 4.007ms (+0.000ms): profile_hit (timer_interrupt) 00010002 4.008ms (+0.000ms): generic_note_interrupt (do_IRQ) 00010002 4.009ms (+0.000ms): end_8259A_irq (do_IRQ) 00010002 4.009ms (+0.001ms): enable_8259A_irq (do_IRQ) 00000002 4.010ms (+0.000ms): do_softirq (do_IRQ) 00000002 4.011ms (+0.000ms): __do_softirq (do_softirq) 00000002 4.011ms (+0.000ms): wake_up_process (do_softirq) 00000002 4.012ms (+0.000ms): try_to_wake_up (wake_up_process) 00000002 4.012ms (+0.000ms): task_rq_lock (try_to_wake_up) 00000003 4.012ms (+0.000ms): activate_task (try_to_wake_up) 00000003 4.013ms (+0.000ms): sched_clock (activate_task) 00000003 4.013ms (+0.000ms): recalc_task_prio (activate_task) 00000003 4.014ms (+0.000ms): effective_prio (recalc_task_prio) 00000003 4.014ms (+0.000ms): enqueue_task (activate_task) 00000002 4.015ms (+0.001ms): preempt_schedule (try_to_wake_up) 00000001 4.017ms (+0.000ms): sub_preempt_count (do_anonymous_page) 00000001 4.018ms (+0.000ms): update_max_trace (check_preempt_timing)