Hello, I've been trying to measure the per-task CPU time spent in the kernel function ip_queue_xmit by attaching an entry and exit probe to said function in the form of fentry/fexit programs, but I've noticed that under heavy traffic conditions this solution breaks. I first observed this as the exit program was occasionally being called more times than the entry, which of course shouldn't be possible. Below is the stack trace (most recent call last) of one such event: 0xffffffffb8800099 entry_SYSCALL_64_after_hwframe 0xffffffffb879fb49 do_syscall_64 0xffffffffb7d8ff49 __x64_sys_read 0xffffffffb7d8fef5 ksys_read 0xffffffffb7d8d3d3 vfs_read 0xffffffffb7d8caae new_sync_read 0xffffffffb84c0f1f sock_read_iter 0xffffffffb84c0e81 sock_recvmsg 0xffffffffb85ef8bc inet_recvmsg 0xffffffffb85b13f4 tcp_recvmsg 0xffffffffb84ca5b0 release_sock 0xffffffffb84ca535 __release_sock 0xffffffffb85ce0a7 tcp_v4_do_rcv 0xffffffffb85bfd2a tcp_rcv_established 0xffffffffb85b5d32 __tcp_ack_snd_check 0xffffffffb85c8dcc tcp_send_ack 0xffffffffb85c5d0f __tcp_send_ack.part.0 0xffffffffb85a0e75 ip_queue_xmit 0xffffffffc0f3b044 rapl_msr_priv [intel_rapl_msr] 0xffffffffc0c769aa bpf_prog_6deef7357e7b4530 [bpf] 0xffffffffb7c6707e __htab_map_lookup_elem 0xffffffffb7c66fe0 lookup_nulls_elem_raw 0xffffffffb8800da7 asm_common_interrupt 0xffffffffb87a11ae common_interrupt 0xffffffffb7ac57b4 irq_exit_rcu 0xffffffffb8a000d6 __softirqentry_text_start 0xffffffffb84f1fd6 net_rx_action 0xffffffffb84f1bf0 __napi_poll 0xffffffffc02af547 i40e_napi_poll [i40e] 0xffffffffb84f1a7a napi_complete_done 0xffffffffb84f158e netif_receive_skb_list_internal 0xffffffffb84f12ba __netif_receive_skb_list_core 0xffffffffb84f04fa __netif_receive_skb_core.constprop.0 0xffffffffc079e192 br_handle_frame [bridge] 0xffffffffc03f9ce5 br_nf_pre_routing [br_netfilter] 0xffffffffc03f979c br_nf_pre_routing_finish [br_netfilter] 0xffffffffc03f95db br_nf_hook_thresh [br_netfilter] 0xffffffffc079dc07 br_handle_frame_finish [bridge] 0xffffffffc079da28 br_pass_frame_up [bridge] 0xffffffffb84f2fa3 netif_receive_skb 0xffffffffb84f2f15 __netif_receive_skb 0xffffffffb84f2eba __netif_receive_skb_one_core 0xffffffffb859aefa ip_rcv 0xffffffffb858eb61 nf_hook_slow 0xffffffffc03f88ec ip_sabotage_in [br_netfilter] 0xffffffffb859ae5e ip_rcv_finish 0xffffffffb859ab0b ip_local_deliver 0xffffffffb859a9f8 ip_local_deliver_finish 0xffffffffb859a79c ip_protocol_deliver_rcu 0xffffffffb85d137e tcp_v4_rcv 0xffffffffb85ce0a7 tcp_v4_do_rcv 0xffffffffb85bf9cb tcp_rcv_established 0xffffffffb85c6fe7 __tcp_push_pending_frames 0xffffffffb85c6859 tcp_write_xmit 0xffffffffb85a0e75 ip_queue_xmit 0xffffffffc0f3b090 rapl_msr_priv [intel_rapl_msr] 0xffffffffc00f0fb5 __this_module [linear] 0xffffffffc00f0fb5 __this_module [linear] As I interpret this, it appears that after the first invocation of ip_queue_xmit the entry function is called, but it's then interrupted by an irq which eventually leads back to ip_queue_xmit, where the entry's bpf_prog->active field is still 1, preventing its invocation (whereas the exit program can instead be executed). Inspecting bpftool seems to confirm this, as I can see an unbalanced, slowly increasing recursion_misses counter for both programs. I'm not even sure this would qualify as a bug, but - even though I've only been able to reproduce this consistently with a 40G iperf3 --bidir - the chance of it happening render fentry/fexit unreliable for the job.
