preemption latency trace v1.0.2
-------------------------------
 latency: 253 us, entries: 146 (146)
    -----------------
    | task: nfsd/3210, 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.001ms): 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.024ms (+0.019ms): kunmap_atomic (skb_copy_bits)
00000200 0.025ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000100 0.025ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.026ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.026ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.027ms (+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.029ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000201 0.029ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.030ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.051ms (+0.021ms): kunmap_atomic (skb_copy_bits)
00000201 0.051ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.052ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.052ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.052ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.053ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.053ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000201 0.054ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.054ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.055ms (+0.001ms): kunmap_atomic (skb_copy_bits)
00000201 0.055ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000201 0.056ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.056ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.078ms (+0.021ms): kunmap_atomic (skb_copy_bits)
00000201 0.078ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.079ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.079ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.079ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.080ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.080ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000201 0.081ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.081ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.082ms (+0.001ms): kunmap_atomic (skb_copy_bits)
00000201 0.083ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000201 0.083ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.084ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.106ms (+0.022ms): kunmap_atomic (skb_copy_bits)
00000201 0.106ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.107ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.107ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.108ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.108ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.108ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000201 0.109ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.109ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.110ms (+0.000ms): kunmap_atomic (skb_copy_bits)
00000201 0.110ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.111ms (+0.000ms): skb_copy_bits (skb_copy_bits)
00000201 0.111ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.111ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.113ms (+0.001ms): kunmap_atomic (skb_copy_bits)
00000201 0.113ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000201 0.114ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.114ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.141ms (+0.027ms): kunmap_atomic (skb_copy_bits)
00000201 0.141ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.142ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.142ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.142ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.143ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.143ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000101 0.144ms (+0.000ms): skb_copy_bits (skb_copy_bits)
00000201 0.144ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.145ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.146ms (+0.001ms): kunmap_atomic (skb_copy_bits)
00000201 0.147ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000201 0.147ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.147ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.168ms (+0.020ms): kunmap_atomic (skb_copy_bits)
00000201 0.168ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.168ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.169ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.169ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.170ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.170ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000101 0.170ms (+0.000ms): skb_copy_bits (skb_copy_bits)
00000201 0.171ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.171ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.172ms (+0.000ms): kunmap_atomic (skb_copy_bits)
00000201 0.172ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000201 0.173ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.173ms (+0.000ms): page_address (skb_copy_bits)
00010202 0.188ms (+0.015ms): do_IRQ (skb_copy_bits)
00010203 0.189ms (+0.000ms): mask_and_ack_8259A (do_IRQ)
00010203 0.192ms (+0.002ms): generic_redirect_hardirq (do_IRQ)
00010202 0.192ms (+0.000ms): generic_handle_IRQ_event (do_IRQ)
00010202 0.193ms (+0.000ms): timer_interrupt (generic_handle_IRQ_event)
00010203 0.193ms (+0.000ms): mark_offset_tsc (timer_interrupt)
00010203 0.201ms (+0.007ms): do_timer (timer_interrupt)
00010203 0.201ms (+0.000ms): update_process_times (do_timer)
00010203 0.201ms (+0.000ms): update_one_process (update_process_times)
00010203 0.202ms (+0.000ms): run_local_timers (update_process_times)
00010203 0.203ms (+0.000ms): raise_softirq (update_process_times)
00010203 0.203ms (+0.000ms): scheduler_tick (update_process_times)
00010203 0.203ms (+0.000ms): sched_clock (scheduler_tick)
00010204 0.205ms (+0.001ms): task_timeslice (scheduler_tick)
00010203 0.206ms (+0.000ms): update_wall_time (do_timer)
00010203 0.206ms (+0.000ms): update_wall_time_one_tick (update_wall_time)
00010203 0.206ms (+0.000ms): profile_hook (timer_interrupt)
00010204 0.207ms (+0.000ms): notifier_call_chain (profile_hook)
00010203 0.208ms (+0.000ms): generic_note_interrupt (do_IRQ)
00010203 0.208ms (+0.000ms): end_8259A_irq (do_IRQ)
00010203 0.209ms (+0.000ms): enable_8259A_irq (do_IRQ)
00000202 0.217ms (+0.008ms): kunmap_atomic (skb_copy_bits)
00000201 0.218ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.218ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.218ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.219ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.219ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.220ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000101 0.220ms (+0.000ms): skb_copy_bits (skb_copy_bits)
00000201 0.221ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.221ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.222ms (+0.001ms): kunmap_atomic (skb_copy_bits)
00000201 0.223ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000201 0.223ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.224ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.244ms (+0.020ms): kunmap_atomic (skb_copy_bits)
00000201 0.245ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.245ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.245ms (+0.000ms): kmap_atomic (xdr_partial_copy_from_skb)
00000101 0.246ms (+0.000ms): page_address (xdr_partial_copy_from_skb)
00000101 0.246ms (+0.000ms): skb_read_bits (xdr_partial_copy_from_skb)
00000101 0.247ms (+0.000ms): skb_copy_bits (skb_read_bits)
00000101 0.247ms (+0.000ms): skb_copy_bits (skb_copy_bits)
00000201 0.248ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.248ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.248ms (+0.000ms): kunmap_atomic (skb_copy_bits)
00000201 0.249ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.249ms (+0.000ms): skb_copy_bits (skb_copy_bits)
00000201 0.250ms (+0.000ms): kmap_atomic (skb_copy_bits)
00000202 0.250ms (+0.000ms): page_address (skb_copy_bits)
00000202 0.251ms (+0.000ms): kunmap_atomic (skb_copy_bits)
00000201 0.251ms (+0.000ms): local_bh_enable (skb_copy_bits)
00000101 0.252ms (+0.000ms): kunmap_atomic (xdr_partial_copy_from_skb)
00000100 0.252ms (+0.000ms): local_bh_enable (svc_udp_recvfrom)
00000100 0.253ms (+0.000ms): sub_preempt_count (local_bh_enable)