preemption latency trace v1.0.2
-------------------------------
 latency: 240 us, entries: 146 (146)
    -----------------
    | task: nfsd/3206, uid:0 nice:0 policy:0 rt_prio:0
    -----------------
 => started at: svc_udp_recvfrom+0x20e/0x2a0
 => ended at:   local_bh_enable+0x17/0xa0
=======>
00000100 0.000ms (+0.000ms): svc_udp_recvfrom (svc_recv)
00000100 0.000ms (+0.000ms): csum_partial_copy_to_xdr (svc_udp_recvfrom)
00000100 0.001ms (+0.000ms): xdr_partial_copy_from_skb (csum_partial_copy_to_xdr)
00000100 0.002ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000100 0.002ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000200 0.004ms (+0.001ms): kmap_atomic (skb_copy_bits)
00000201 0.004ms (+0.000ms): page_address (skb_copy_bits)
00000201 0.023ms (+0.018ms): kunmap_atomic (skb_copy_bits)
00000200 0.024ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000100 0.025ms (+0.001ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.025ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.026ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.026ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000201 0.027ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.027ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.028ms (+0.001ms): kunmap_atomic (skb_copy_bits)
00000201 0.028ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000201 0.029ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.029ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.049ms (+0.020ms): kunmap_atomic (skb_copy_bits)
00000201 0.050ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.050ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.050ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.051ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.051ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.052ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000201 0.052ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.052ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.053ms (+0.000ms): kunmap_atomic (skb_copy_bits)
00000201 0.054ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000201 0.054ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.055ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.074ms (+0.019ms): kunmap_atomic (skb_copy_bits)
00000201 0.075ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.075ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.075ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.076ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.076ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.077ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000201 0.077ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.077ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.078ms (+0.001ms): kunmap_atomic (skb_copy_bits)
00000201 0.079ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000201 0.079ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.080ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.100ms (+0.020ms): kunmap_atomic (skb_copy_bits)
00000201 0.100ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.101ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.101ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.101ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.102ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.102ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000201 0.103ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.103ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.103ms (+0.000ms): kunmap_atomic (skb_copy_bits)
00000201 0.104ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.104ms (+0.000ms): skb_copy_bits (skb_copy_bits)
00000201 0.105ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.105ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.106ms (+0.000ms): kunmap_atomic (skb_copy_bits)
00000201 0.106ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000201 0.107ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.107ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.129ms (+0.022ms): kunmap_atomic (skb_copy_bits)
00000201 0.130ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.130ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.130ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.131ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.131ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.132ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000101 0.132ms (+0.000ms): skb_copy_bits (skb_copy_bits)
00000201 0.133ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.133ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.134ms (+0.001ms): kunmap_atomic (skb_copy_bits)
00000201 0.134ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000201 0.135ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.135ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.155ms (+0.019ms): kunmap_atomic (skb_copy_bits)
00000201 0.155ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.156ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.156ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.157ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.157ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.157ms (+0.000ms): skb_copy_bits (skb_read_bits)
00010101 0.159ms (+0.001ms): do_IRQ (skb_copy_bits)
00010102 0.160ms (+0.000ms): mask_and_ack_8259A (do_IRQ)
00010102 0.162ms (+0.002ms): generic_redirect_hardirq (do_IRQ)
00010101 0.163ms (+0.000ms): generic_handle_IRQ_event (do_IRQ)
00010101 0.163ms (+0.000ms): timer_interrupt (generic_handle_IRQ_event)
00010102 0.164ms (+0.000ms): mark_offset_tsc (timer_interrupt)
00010102 0.171ms (+0.007ms): do_timer (timer_interrupt)
00010102 0.172ms (+0.000ms): update_process_times (do_timer)
00010102 0.172ms (+0.000ms): update_one_process (update_process_times)
00010102 0.173ms (+0.000ms): run_local_timers (update_process_times)
00010102 0.173ms (+0.000ms): raise_softirq (update_process_times)
00010102 0.174ms (+0.000ms): scheduler_tick (update_process_times)
00010102 0.174ms (+0.000ms): sched_clock (scheduler_tick)
00010103 0.176ms (+0.001ms): task_timeslice (scheduler_tick)
00010102 0.177ms (+0.001ms): update_wall_time (do_timer)
00010102 0.177ms (+0.000ms): update_wall_time_one_tick (update_wall_time)
00010102 0.178ms (+0.000ms): profile_hook (timer_interrupt)
00010103 0.178ms (+0.000ms): notifier_call_chain (profile_hook)
00010102 0.179ms (+0.001ms): generic_note_interrupt (do_IRQ)
00010102 0.180ms (+0.000ms): end_8259A_irq (do_IRQ)
00010102 0.180ms (+0.000ms): enable_8259A_irq (do_IRQ)
00000101 0.182ms (+0.001ms): skb_copy_bits (skb_copy_bits)
00000201 0.183ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.183ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.184ms (+0.001ms): kunmap_atomic (skb_copy_bits)
00000201 0.184ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000201 0.185ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.185ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.206ms (+0.020ms): kunmap_atomic (skb_copy_bits)
00000201 0.206ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.207ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.207ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.207ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.208ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.208ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000101 0.209ms (+0.000ms): skb_copy_bits (skb_copy_bits)
00000201 0.209ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.210ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.211ms (+0.001ms): kunmap_atomic (skb_copy_bits)
00000201 0.211ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000201 0.212ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.212ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.232ms (+0.019ms): kunmap_atomic (skb_copy_bits)
00000201 0.232ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.232ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.233ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.233ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.233ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.234ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000101 0.234ms (+0.000ms): skb_copy_bits (skb_copy_bits)
00000201 0.235ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.235ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.236ms (+0.000ms): kunmap_atomic (skb_copy_bits)
00000201 0.236ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.237ms (+0.000ms): skb_copy_bits (skb_copy_bits)
00000201 0.237ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.238ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.238ms (+0.000ms): kunmap_atomic (skb_copy_bits)
00000201 0.239ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.239ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.240ms (+0.000ms): local_bh_enable (svc_udp_recvfrom)
00000100 0.240ms (+0.000ms): sub_preempt_count (local_bh_enable)