preemption latency trace v1.0.2 ------------------------------- latency: 410 us, entries: 282 (282) ----------------- | 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.001ms (+0.001ms): ip_rcv (netif_receive_skb) 00000001 0.004ms (+0.002ms): ip_route_input (ip_rcv) 00000001 0.004ms (+0.000ms): rt_hash_code (ip_route_input) 00000001 0.008ms (+0.003ms): ip_local_deliver (ip_rcv) 00000001 0.009ms (+0.001ms): nf_hook_slow (ip_local_deliver) 00000002 0.010ms (+0.001ms): nf_iterate (nf_hook_slow) 00000002 0.011ms (+0.001ms): ipt_hook (nf_iterate) 00000002 0.012ms (+0.001ms): ipt_do_table (ipt_hook) 00000102 0.018ms (+0.005ms): local_bh_enable (ipt_do_table) 00000002 0.019ms (+0.001ms): ip_local_deliver_finish (nf_hook_slow) 00000003 0.021ms (+0.002ms): tcp_v4_rcv (ip_local_deliver_finish) 00000003 0.022ms (+0.001ms): tcp_v4_checksum_init (tcp_v4_rcv) 00000003 0.023ms (+0.000ms): skb_checksum (tcp_v4_checksum_init) 00000004 0.029ms (+0.005ms): __tcp_v4_lookup_listener (tcp_v4_rcv) 00000003 0.032ms (+0.003ms): dummy_socket_sock_rcv_skb (tcp_v4_rcv) 00000004 0.034ms (+0.001ms): tcp_v4_do_rcv (tcp_v4_rcv) 00000004 0.035ms (+0.001ms): tcp_v4_hnd_req (tcp_v4_do_rcv) 00000004 0.036ms (+0.000ms): tcp_v4_search_req (tcp_v4_hnd_req) 00000004 0.040ms (+0.003ms): tcp_rcv_state_process (tcp_v4_do_rcv) 00000004 0.042ms (+0.002ms): tcp_v4_conn_request (tcp_rcv_state_process) 00000004 0.043ms (+0.001ms): kmem_cache_alloc (tcp_v4_conn_request) 00000004 0.044ms (+0.001ms): cache_alloc_refill (kmem_cache_alloc) 00000004 0.046ms (+0.001ms): cache_grow (cache_alloc_refill) 00000004 0.047ms (+0.000ms): kmem_flagcheck (cache_grow) 00000004 0.047ms (+0.000ms): kmem_getpages (cache_grow) 00000004 0.048ms (+0.000ms): __get_free_pages (kmem_getpages) 00000004 0.048ms (+0.000ms): __alloc_pages (__get_free_pages) 00000004 0.049ms (+0.000ms): buffered_rmqueue (__alloc_pages) 00000004 0.050ms (+0.000ms): bad_range (buffered_rmqueue) 00000004 0.051ms (+0.000ms): prep_new_page (buffered_rmqueue) 00000004 0.052ms (+0.000ms): zone_statistics (__alloc_pages) 00000004 0.052ms (+0.000ms): page_address (__get_free_pages) 00000004 0.053ms (+0.000ms): alloc_slabmgmt (cache_grow) 00000004 0.053ms (+0.000ms): set_slab_attr (cache_grow) 00000004 0.054ms (+0.000ms): cache_init_objs (cache_grow) 00000004 0.057ms (+0.003ms): tcp_parse_options (tcp_v4_conn_request) 00000004 0.064ms (+0.006ms): secure_tcp_sequence_number (tcp_v4_conn_request) 00000004 0.064ms (+0.000ms): do_gettimeofday (secure_tcp_sequence_number) 00000004 0.065ms (+0.000ms): get_offset_tsc (do_gettimeofday) 00000004 0.066ms (+0.001ms): __check_and_rekey (secure_tcp_sequence_number) 00000105 0.067ms (+0.000ms): get_random_bytes (__check_and_rekey) 00000105 0.068ms (+0.001ms): extract_entropy (get_random_bytes) 00000105 0.070ms (+0.001ms): extract_entropy (extract_entropy) 00000105 0.071ms (+0.001ms): SHATransform (extract_entropy) 00000105 0.072ms (+0.000ms): memcpy (SHATransform) 00000105 0.092ms (+0.020ms): add_entropy_words (extract_entropy) 00000105 0.095ms (+0.002ms): SHATransform (extract_entropy) 00000105 0.095ms (+0.000ms): memcpy (SHATransform) 00000105 0.098ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.099ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.099ms (+0.000ms): memcpy (SHATransform) 00000105 0.102ms (+0.003ms): add_entropy_words (extract_entropy) 00000105 0.103ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.103ms (+0.000ms): memcpy (SHATransform) 00000105 0.106ms (+0.003ms): add_entropy_words (extract_entropy) 00000105 0.107ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.107ms (+0.000ms): memcpy (SHATransform) 00000105 0.110ms (+0.003ms): add_entropy_words (extract_entropy) 00000105 0.111ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.111ms (+0.000ms): memcpy (SHATransform) 00000105 0.114ms (+0.003ms): add_entropy_words (extract_entropy) 00000105 0.115ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.115ms (+0.000ms): memcpy (SHATransform) 00000105 0.118ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.119ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.119ms (+0.000ms): memcpy (SHATransform) 00000105 0.122ms (+0.003ms): add_entropy_words (extract_entropy) 00000105 0.123ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.123ms (+0.000ms): memcpy (SHATransform) 00000105 0.126ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.127ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.127ms (+0.000ms): memcpy (SHATransform) 00000105 0.130ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.131ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.131ms (+0.000ms): memcpy (SHATransform) 00000105 0.134ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.134ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.135ms (+0.000ms): memcpy (SHATransform) 00000105 0.138ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.138ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.138ms (+0.000ms): memcpy (SHATransform) 00000105 0.141ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.142ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.142ms (+0.000ms): memcpy (SHATransform) 00000105 0.145ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.146ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.146ms (+0.000ms): memcpy (SHATransform) 00000105 0.149ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.149ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.150ms (+0.000ms): memcpy (SHATransform) 00000105 0.153ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.153ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.154ms (+0.000ms): memcpy (SHATransform) 00000105 0.157ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.157ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.157ms (+0.000ms): memcpy (SHATransform) 00000105 0.160ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.161ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.161ms (+0.000ms): memcpy (SHATransform) 00000105 0.164ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.165ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.165ms (+0.000ms): memcpy (SHATransform) 00000105 0.168ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.168ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.169ms (+0.000ms): memcpy (SHATransform) 00000105 0.172ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.172ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.172ms (+0.000ms): memcpy (SHATransform) 00000105 0.175ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.176ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.176ms (+0.000ms): memcpy (SHATransform) 00000105 0.179ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.180ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.180ms (+0.000ms): memcpy (SHATransform) 00000105 0.183ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.184ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.184ms (+0.000ms): memcpy (SHATransform) 00000105 0.187ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.188ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.188ms (+0.000ms): memcpy (SHATransform) 00000105 0.191ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.191ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.192ms (+0.000ms): memcpy (SHATransform) 00000105 0.194ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.195ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.195ms (+0.000ms): memcpy (SHATransform) 00000105 0.198ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.199ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.199ms (+0.000ms): memcpy (SHATransform) 00000105 0.202ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.203ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.203ms (+0.000ms): memcpy (SHATransform) 00000105 0.206ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.206ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.207ms (+0.000ms): memcpy (SHATransform) 00000105 0.209ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.210ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.210ms (+0.000ms): memcpy (SHATransform) 00000105 0.213ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.214ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.214ms (+0.000ms): memcpy (SHATransform) 00000105 0.217ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.218ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.218ms (+0.000ms): memcpy (SHATransform) 00000105 0.221ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.222ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.222ms (+0.000ms): memcpy (SHATransform) 00000105 0.225ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.225ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.226ms (+0.000ms): memcpy (SHATransform) 00000105 0.228ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.229ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.229ms (+0.000ms): memcpy (SHATransform) 00000105 0.232ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.233ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.233ms (+0.000ms): memcpy (SHATransform) 00000105 0.236ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.237ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.237ms (+0.000ms): memcpy (SHATransform) 00000105 0.240ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.240ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.241ms (+0.000ms): memcpy (SHATransform) 00000105 0.244ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.245ms (+0.001ms): add_entropy_words (extract_entropy) 00000105 0.250ms (+0.005ms): credit_entropy_store (extract_entropy) 00000106 0.252ms (+0.001ms): __wake_up (extract_entropy) 00000107 0.252ms (+0.000ms): __wake_up_common (__wake_up) 00000105 0.253ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.253ms (+0.000ms): memcpy (SHATransform) 00000105 0.256ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.257ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.257ms (+0.000ms): memcpy (SHATransform) 00000105 0.260ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.261ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.261ms (+0.000ms): memcpy (SHATransform) 00000105 0.264ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.265ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.265ms (+0.000ms): memcpy (SHATransform) 00000105 0.268ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.269ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.269ms (+0.000ms): memcpy (SHATransform) 00000105 0.272ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.272ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.273ms (+0.000ms): memcpy (SHATransform) 00000105 0.276ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.276ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.277ms (+0.000ms): memcpy (SHATransform) 00000105 0.280ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.280ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.280ms (+0.000ms): memcpy (SHATransform) 00000105 0.283ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.284ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.284ms (+0.000ms): memcpy (SHATransform) 00000105 0.287ms (+0.002ms): add_entropy_words (extract_entropy) 00000105 0.288ms (+0.000ms): SHATransform (extract_entropy) 00000105 0.288ms (+0.000ms): memcpy (SHATransform) 00000105 0.291ms (+0.002ms): add_entropy_words (extract_entropy) 00000104 0.292ms (+0.001ms): local_bh_enable (__check_and_rekey) 00000004 0.294ms (+0.001ms): halfMD4Transform (secure_tcp_sequence_number) 00000004 0.297ms (+0.003ms): tcp_v4_send_synack (tcp_v4_conn_request) 00000004 0.298ms (+0.001ms): tcp_v4_route_req (tcp_v4_send_synack) 00000004 0.300ms (+0.001ms): ip_route_output_flow (tcp_v4_route_req) 00000004 0.300ms (+0.000ms): __ip_route_output_key (ip_route_output_flow) 00000004 0.301ms (+0.000ms): rt_hash_code (__ip_route_output_key) 00000004 0.302ms (+0.000ms): ip_route_output_slow (ip_route_output_flow) 00000004 0.304ms (+0.001ms): ip_dev_find (ip_route_output_slow) 00000004 0.304ms (+0.000ms): fn_hash_lookup (ip_dev_find) 00000005 0.306ms (+0.001ms): fib_semantic_match (fn_hash_lookup) 00000004 0.308ms (+0.002ms): fib_lookup (ip_route_output_slow) 00000005 0.310ms (+0.001ms): fn_hash_lookup (fib_lookup) 00000005 0.311ms (+0.001ms): fn_hash_lookup (fib_lookup) 00000006 0.312ms (+0.000ms): fib_semantic_match (fn_hash_lookup) 00000004 0.315ms (+0.003ms): dst_alloc (ip_route_output_slow) 00000004 0.316ms (+0.000ms): kmem_cache_alloc (dst_alloc) 00000004 0.317ms (+0.000ms): cache_alloc_refill (kmem_cache_alloc) 00000004 0.322ms (+0.005ms): rt_set_nexthop (ip_route_output_slow) 00000004 0.322ms (+0.000ms): memcpy (rt_set_nexthop) 00000004 0.324ms (+0.001ms): fib_rules_tclass (rt_set_nexthop) 00000004 0.325ms (+0.000ms): set_class_tag (rt_set_nexthop) 00000004 0.325ms (+0.000ms): set_class_tag (rt_set_nexthop) 00000004 0.325ms (+0.000ms): rt_hash_code (ip_route_output_slow) 00000004 0.326ms (+0.000ms): rt_intern_hash (ip_route_output_slow) 00000105 0.328ms (+0.001ms): arp_bind_neighbour (rt_intern_hash) 00000105 0.329ms (+0.000ms): neigh_lookup (arp_bind_neighbour) 00000105 0.329ms (+0.000ms): arp_hash (neigh_lookup) 00000205 0.330ms (+0.000ms): local_bh_enable (neigh_lookup) 00000104 0.331ms (+0.000ms): local_bh_enable (rt_intern_hash) 00000004 0.332ms (+0.000ms): fib_rule_put (ip_route_output_slow) 00000004 0.333ms (+0.000ms): xfrm_lookup (tcp_v4_route_req) 00000004 0.335ms (+0.001ms): tcp_make_synack (tcp_v4_send_synack) 00000004 0.335ms (+0.000ms): sock_wmalloc (tcp_make_synack) 00000004 0.336ms (+0.000ms): alloc_skb (sock_wmalloc) 00000004 0.336ms (+0.000ms): kmem_cache_alloc (alloc_skb) 00000004 0.337ms (+0.000ms): __kmalloc (alloc_skb) 00000004 0.344ms (+0.007ms): ip_build_and_send_pkt (tcp_v4_send_synack) 00000004 0.348ms (+0.003ms): nf_hook_slow (ip_build_and_send_pkt) 00000005 0.348ms (+0.000ms): nf_iterate (nf_hook_slow) 00000005 0.349ms (+0.000ms): ipt_local_out_hook (nf_iterate) 00000005 0.350ms (+0.000ms): ipt_do_table (ipt_local_out_hook) 00000105 0.352ms (+0.002ms): local_bh_enable (ipt_do_table) 00000005 0.353ms (+0.000ms): dst_output (nf_hook_slow) 00000005 0.353ms (+0.000ms): ip_output (dst_output) 00000005 0.354ms (+0.000ms): ip_finish_output (dst_output) 00000005 0.355ms (+0.001ms): neigh_resolve_output (ip_finish_output) 00000106 0.357ms (+0.002ms): neigh_hh_init (neigh_resolve_output) 00000106 0.359ms (+0.001ms): eth_header (neigh_resolve_output) 00000105 0.361ms (+0.002ms): local_bh_enable (neigh_resolve_output) 00000005 0.362ms (+0.000ms): dev_queue_xmit (neigh_resolve_output) 00000107 0.364ms (+0.001ms): pfifo_fast_enqueue (dev_queue_xmit) 00000107 0.365ms (+0.001ms): qdisc_restart (dev_queue_xmit) 00000107 0.365ms (+0.000ms): pfifo_fast_dequeue (qdisc_restart) 00000107 0.367ms (+0.001ms): e100_xmit_frame (qdisc_restart) 00000108 0.368ms (+0.001ms): e100_xmit_prepare (e100_xmit_frame) 00000107 0.371ms (+0.003ms): qdisc_restart (dev_queue_xmit) 00000107 0.372ms (+0.000ms): pfifo_fast_dequeue (qdisc_restart) 00000106 0.372ms (+0.000ms): local_bh_enable (dev_queue_xmit) 00000004 0.374ms (+0.001ms): tcp_v4_synq_add (tcp_v4_conn_request) 00000004 0.376ms (+0.001ms): tcp_reset_keepalive_timer (tcp_v4_synq_add) 00000004 0.377ms (+0.000ms): sk_reset_timer (tcp_reset_keepalive_timer) 00000004 0.377ms (+0.000ms): mod_timer (sk_reset_timer) 00000004 0.378ms (+0.000ms): __mod_timer (sk_reset_timer) 00000006 0.379ms (+0.001ms): internal_add_timer (__mod_timer) 00000004 0.381ms (+0.001ms): init_westwood (tcp_rcv_state_process) 00010004 0.383ms (+0.002ms): do_IRQ (init_westwood) 00010005 0.383ms (+0.000ms): mask_and_ack_8259A (do_IRQ) 00010005 0.386ms (+0.002ms): generic_redirect_hardirq (do_IRQ) 00010005 0.387ms (+0.000ms): wake_up_process (generic_redirect_hardirq) 00010005 0.388ms (+0.000ms): try_to_wake_up (wake_up_process) 00010005 0.388ms (+0.000ms): task_rq_lock (try_to_wake_up) 00010006 0.389ms (+0.000ms): activate_task (try_to_wake_up) 00010006 0.389ms (+0.000ms): sched_clock (activate_task) 00010006 0.390ms (+0.000ms): recalc_task_prio (activate_task) 00010006 0.390ms (+0.000ms): effective_prio (recalc_task_prio) 00010006 0.391ms (+0.000ms): enqueue_task (activate_task) 00000004 0.393ms (+0.001ms): init_bictcp (tcp_rcv_state_process) 00000004 0.394ms (+0.001ms): __kfree_skb (tcp_rcv_state_process) 00000004 0.395ms (+0.001ms): kfree_skbmem (__kfree_skb) 00000004 0.395ms (+0.000ms): skb_release_data (kfree_skbmem) 00000004 0.396ms (+0.000ms): kfree (kfree_skbmem) 00000004 0.397ms (+0.000ms): kmem_cache_free (kfree_skbmem) 00000001 0.400ms (+0.003ms): sub_preempt_count (netif_receive_skb)