preemption latency trace v1.0.1 ------------------------------- latency: 4141 us, entries: 64 (64) ----------------- | task: ksoftirqd/0/2, uid:0 nice:-10 policy:0 rt_prio:0 ----------------- => started at: netif_receive_skb+0x71/0x250 => ended at: netif_receive_skb+0x1b4/0x250 =======> 00000001 0.000ms (+0.000ms): netif_receive_skb (process_backlog) 00000001 0.000ms (+0.000ms): ip_rcv (netif_receive_skb) 00000001 0.002ms (+0.001ms): ip_local_deliver (ip_rcv) 00000001 0.002ms (+0.000ms): nf_hook_slow (ip_local_deliver) 00000002 0.003ms (+0.000ms): nf_iterate (nf_hook_slow) 00000002 0.003ms (+0.000ms): ipt_hook (nf_iterate) 00000002 0.003ms (+0.000ms): ipt_do_table (ipt_hook) 00000102 0.005ms (+0.001ms): local_bh_enable (ipt_do_table) 00000002 0.005ms (+0.000ms): ip_local_deliver_finish (nf_hook_slow) 00000003 0.006ms (+0.000ms): tcp_v4_rcv (ip_local_deliver_finish) 00000003 0.008ms (+0.001ms): dummy_socket_sock_rcv_skb (tcp_v4_rcv) 00000004 0.008ms (+0.000ms): tcp_v4_do_rcv (tcp_v4_rcv) 00000004 0.009ms (+0.000ms): tcp_rcv_established (tcp_v4_do_rcv) 00010004 3.998ms (+3.989ms): do_IRQ (tcp_rcv_established) 00010005 3.999ms (+0.000ms): mask_and_ack_8259A (do_IRQ) 00010005 4.001ms (+0.002ms): generic_redirect_hardirq (do_IRQ) 00010004 4.002ms (+0.000ms): generic_handle_IRQ_event (do_IRQ) 00010004 4.002ms (+0.000ms): timer_interrupt (generic_handle_IRQ_event) 00010005 4.003ms (+0.000ms): mark_offset_tsc (timer_interrupt) 00010005 4.009ms (+0.006ms): do_timer (timer_interrupt) 00010005 4.010ms (+0.000ms): update_process_times (do_timer) 00010005 4.010ms (+0.000ms): update_one_process (update_process_times) 00010005 4.011ms (+0.000ms): run_local_timers (update_process_times) 00010005 4.011ms (+0.000ms): raise_softirq (update_process_times) 00010005 4.012ms (+0.000ms): scheduler_tick (update_process_times) 00010005 4.012ms (+0.000ms): sched_clock (scheduler_tick) 00010006 4.013ms (+0.001ms): task_timeslice (scheduler_tick) 00010005 4.014ms (+0.000ms): update_wall_time (do_timer) 00010005 4.015ms (+0.000ms): update_wall_time_one_tick (update_wall_time) 00010005 4.015ms (+0.000ms): update_wall_time_one_tick (update_wall_time) 00010005 4.016ms (+0.000ms): update_wall_time_one_tick (update_wall_time) 00010005 4.016ms (+0.000ms): update_wall_time_one_tick (update_wall_time) 00010005 4.017ms (+0.000ms): profile_hook (timer_interrupt) 00010006 4.017ms (+0.000ms): notifier_call_chain (profile_hook) 00010005 4.018ms (+0.001ms): generic_note_interrupt (do_IRQ) 00010005 4.019ms (+0.000ms): end_8259A_irq (do_IRQ) 00010005 4.019ms (+0.000ms): enable_8259A_irq (do_IRQ) 00000005 4.020ms (+0.001ms): do_softirq (do_IRQ) 00000005 4.021ms (+0.000ms): __do_softirq (do_softirq) 00000004 4.023ms (+0.001ms): tcp_ack (tcp_rcv_established) 00000004 4.023ms (+0.000ms): tcp_ack_update_window (tcp_ack) 00000004 4.025ms (+0.001ms): tcp_clean_rtx_queue (tcp_ack) 00000004 4.026ms (+0.001ms): __kfree_skb (tcp_clean_rtx_queue) 00000004 4.026ms (+0.000ms): kfree_skbmem (__kfree_skb) 00000004 4.027ms (+0.000ms): skb_release_data (kfree_skbmem) 00000004 4.027ms (+0.000ms): __page_cache_release (skb_release_data) 00000004 4.028ms (+0.000ms): free_hot_page (skb_release_data) 00000004 4.028ms (+0.000ms): free_hot_cold_page (skb_release_data) 00000004 4.030ms (+0.001ms): kfree (kfree_skbmem) 00000004 4.030ms (+0.000ms): kmem_cache_free (kfree_skbmem) 00000004 4.031ms (+0.000ms): __kfree_skb (tcp_clean_rtx_queue) 00000004 4.031ms (+0.000ms): kfree_skbmem (__kfree_skb) 00000004 4.032ms (+0.000ms): skb_release_data (kfree_skbmem) 00000004 4.032ms (+0.000ms): kmem_cache_free (kfree_skbmem) 00000004 4.033ms (+0.000ms): tcp_ack_saw_tstamp (tcp_clean_rtx_queue) 00000004 4.033ms (+0.000ms): tcp_rtt_estimator (tcp_ack_saw_tstamp) 00000004 4.035ms (+0.001ms): tcp_urg (tcp_rcv_established) 00000004 4.035ms (+0.000ms): tcp_data_queue (tcp_rcv_established) 00000004 4.036ms (+0.000ms): __kfree_skb (tcp_rcv_established) 00000004 4.036ms (+0.000ms): kfree_skbmem (__kfree_skb) 00000004 4.036ms (+0.000ms): skb_release_data (kfree_skbmem) 00000004 4.037ms (+0.000ms): kfree (kfree_skbmem) 00000004 4.037ms (+0.000ms): kmem_cache_free (kfree_skbmem) 00000001 4.039ms (+0.002ms): sub_preempt_count (netif_receive_skb)