Skip to content

selftests: connect: "poll timed out" (POLLERR/POLLNVAL) with syncookies #198

@matttbe

Description

@matttbe

When trying to repro #192, I found a similar issue.

This was done using this script on 3ebd090 :

# cat .virtme-exec-run
perf probe -a tcp_send_active_reset
perf probe -a tcp_v4_send_reset
perf probe -a tcp_v6_send_reset
cd tools/testing/selftests/net/mptcp
i=1
while true; do
        perf record -ag -e probe:tcp_send_active_reset -e probe:tcp_v4_send_reset -e probe:tcp_v6_send_reset ./mptcp_connect.sh -l "0.99%" -d 4 -r "94% 99%" || break
        has_call_trace && break
        date -R
        echo "=== $i ==="
        i=$((i+1))
done

Here is the output:

=== 2556 ===
++ i=2557
++ true
++ perf record -ag -e probe:tcp_send_active_reset -e probe:tcp_v4_send_reset -e probe:tcp_v6_send_reset ./mptcp_connect.sh -l 0.99% -d 4 -r '94% 99%'
Couldn't synthesize bpf events.
[191570.880139] IPv6: ADDRCONF(NETDEV_CHANGE): ns1eth2: link becomes ready
[191571.239268] IPv6: ADDRCONF(NETDEV_CHANGE): ns2eth3: link becomes ready
[191571.581670] IPv6: ADDRCONF(NETDEV_CHANGE): ns2eth1: link becomes ready
[191571.601311] IPv6: ADDRCONF(NETDEV_CHANGE): ns4eth3: link becomes ready
[191571.607443] IPv6: ADDRCONF(NETDEV_CHANGE): ns3eth4: link becomes ready
INFO: set ns3-60afc5f4-8gmNJy dev ns3eth2: ethtool -K tso off
INFO: set ns4-60afc5f4-8gmNJy dev ns4eth3: ethtool -K  gso off gro off
Created /tmp/tmp.zMISX2g1ka (size 4576284       /tmp/tmp.zMISX2g1ka) containing data sent by client
Created /tmp/tmp.9WyphPCbnd (size 6240284       /tmp/tmp.9WyphPCbnd) containing data sent by server
New MPTCP socket can be blocked via sysctl              [ OK ]
setsockopt(..., TCP_ULP, "mptcp", ...) blocked  [ OK ]
INFO: validating network environment with pings
INFO: Using loss of 0.99% delay 4 ms reorder 94% 99% with delay 1ms on ns3eth4
ns1 MPTCP -> ns1 (10.0.1.1:10000      ) MPTCP   (duration   143ms) [ OK ]
ns1 MPTCP -> ns1 (10.0.1.1:10001      ) TCP     (duration   113ms) [ OK ]
ns1 TCP   -> ns1 (10.0.1.1:10002      ) MPTCP   (duration   126ms) [ OK ]
ns1 MPTCP -> ns1 (dead:beef:1::1:10003) MPTCP   (duration   163ms) [ OK ]
ns1 MPTCP -> ns1 (dead:beef:1::1:10004) TCP     (duration   111ms) [ OK ]
ns1 TCP   -> ns1 (dead:beef:1::1:10005) MPTCP   (duration   120ms) [ OK ]
ns1 MPTCP -> ns2 (10.0.1.2:10006      ) MPTCP   (duration   139ms) [ OK ]
ns1 MPTCP -> ns2 (dead:beef:1::2:10007) MPTCP   (duration   175ms) [ OK ]
ns1 MPTCP -> ns2 (10.0.2.1:10008      ) MPTCP   (duration   151ms) [ OK ]
ns1 MPTCP -> ns2 (dead:beef:2::1:10009) MPTCP   (duration   139ms) [ OK ]
ns1 MPTCP -> ns3 (10.0.2.2:10010      ) MPTCP   (duration   199ms) [ OK ]
ns1 MPTCP -> ns3 (dead:beef:2::2:10011) MPTCP   (duration   606ms) [ OK ]
ns1 MPTCP -> ns3 (10.0.3.2:10012      ) MPTCP   (duration   179ms) [ OK ]
ns1 MPTCP -> ns3 (dead:beef:3::2:10013) MPTCP   (duration   203ms) [ OK ]
ns1 MPTCP -> ns4 (10.0.3.1:10014      ) MPTCP   (duration   199ms) [ OK ]
ns1 MPTCP -> ns4 (dead:beef:3::1:10015) MPTCP   (duration   268ms) [ OK ]
ns2 MPTCP -> ns1 (10.0.1.1:10016      ) MPTCP   (duration   127ms) [ OK ]
ns2 MPTCP -> ns1 (dead:beef:1::1:10017) MPTCP   (duration   134ms) [ OK ]
ns2 MPTCP -> ns3 (10.0.2.2:10018      ) MPTCP   (duration   169ms) [ OK ]
ns2 MPTCP -> ns3 (dead:beef:2::2:10019) MPTCP   (duration   208ms) [ OK ]
ns2 MPTCP -> ns3 (10.0.3.2:10020      ) MPTCP   (duration   188ms) [ OK ]
ns2 MPTCP -> ns3 (dead:beef:3::2:10021) MPTCP   (duration   175ms) [ OK ]
ns2 MPTCP -> ns4 (10.0.3.1:10022      ) MPTCP   (duration   229ms) [ OK ]
ns2 MPTCP -> ns4 (dead:beef:3::1:10023) MPTCP   (duration   285ms) [ OK ]
ns3 MPTCP -> ns1 (10.0.1.1:10024      ) MPTCP   (duration   172ms) [ OK ]
ns3 MPTCP -> ns1 (dead:beef:1::1:10025) MPTCP   (duration   183ms) [ OK ]
ns3 MPTCP -> ns2 (10.0.1.2:10026      ) MPTCP   (duration   218ms) [ OK ]
ns3 MPTCP -> ns2 (dead:beef:1::2:10027) MPTCP   (duration   365ms) [ OK ]
ns3 MPTCP -> ns2 (10.0.2.1:10028      ) MPTCP   (duration  1071ms) [ OK ]
ns3 MPTCP -> ns2 (dead:beef:2::1:10029) MPTCP   (duration   160ms) [ OK ]
ns3 MPTCP -> ns4 (10.0.3.1:10030      ) MPTCP   (duration   126ms) [ OK ]
ns3 MPTCP -> ns4 (dead:beef:3::1:10031) MPTCP   (duration   138ms) [ OK ]
ns4 MPTCP -> ns1 (10.0.1.1:10032      ) MPTCP   (duration   275ms) [ OK ]
ns4 MPTCP -> ns1 (dead:beef:1::1:10033) MPTCP   (duration   188ms) [ OK ]
ns4 MPTCP -> ns2 (10.0.1.2:10034      ) MPTCP   (duration   174ms) [ OK ]
ns4 MPTCP -> ns2 (dead:beef:1::2:10035) MPTCP   (duration   188ms) [ OK ]
ns4 MPTCP -> ns2 (10.0.2.1:10036      ) MPTCP   Unexpected revents: POLLERR/POLLNVAL(18)
copyfd_io_poll: poll timed out (events: POLLIN 1, POLLOUT 4)
(duration 30121ms) [ FAIL ] client exit code 5, server 2
netns ns2-60afc5f4-8gmNJy socket stat for 10036:
Netid State Recv-Q Send-Q Local Address:Port Peer Address:PortProcess
TcpPassiveOpens                 1                  0.0
TcpEstabResets                  1                  0.0
TcpInSegs                       20                 0.0
TcpOutSegs                      16                 0.0
TcpOutRsts                      1                  0.0
TcpExtSyncookiesSent            1                  0.0
TcpExtSyncookiesRecv            2                  0.0
TcpExtSyncookiesFailed          1                  0.0
TcpExtTW                        4                  0.0
TcpExtTCPPureAcks               1                  0.0
TcpExtTCPReqQFullDoCookies      1                  0.0
TcpExtTCPRcvCoalesce            5                  0.0
TcpExtTCPOFOQueue               7                  0.0
TcpExtTCPOrigDataSent           10                 0.0
TcpExtTCPAckCompressed          3                  0.0
MPTcpExtMPCapableSYNRX          1                  0.0
MPTcpExtMPCapableACKRX          1                  0.0
netns ns4-60afc5f4-8gmNJy socket stat for 10036:
Netid State Recv-Q Send-Q Local Address:Port Peer Address:PortProcess
TcpActiveOpens                  1                  0.0
TcpEstabResets                  1                  0.0
TcpInSegs                       11                 0.0
TcpOutSegs                      20                 0.0
TcpOutRsts                      9                  0.0
TcpExtTCPOrigDataSent           9                  0.0
TcpExtTCPDelivered              1                  0.0
MPTcpExtMPCapableSYNTX          1                  0.0
MPTcpExtMPCapableSYNACKRX       1                  0.0
ns4 MPTCP -> ns2 (dead:beef:2::1:10037) MPTCP   (duration   192ms) [ OK ]
ns4 MPTCP -> ns3 (10.0.2.2:10038      ) MPTCP   (duration   138ms) [ OK ]
ns4 MPTCP -> ns3 (dead:beef:2::2:10039) MPTCP   (duration   144ms) [ OK ]
ns4 MPTCP -> ns3 (10.0.3.2:10040      ) MPTCP   (duration   124ms) [ OK ]
ns4 MPTCP -> ns3 (dead:beef:3::2:10041) MPTCP   (duration   141ms) [ OK ]
INFO: with peek mode: saveWithPeek
ns1 MPTCP -> ns1 (10.0.1.1:10042      ) MPTCP   (duration   173ms) [ OK ]
ns1 MPTCP -> ns1 (10.0.1.1:10043      ) TCP     (duration   124ms) [ OK ]
ns1 TCP   -> ns1 (10.0.1.1:10044      ) MPTCP   (duration   106ms) [ OK ]
ns1 MPTCP -> ns1 (dead:beef:1::1:10045) MPTCP   (duration   162ms) [ OK ]
ns1 MPTCP -> ns1 (dead:beef:1::1:10046) TCP     (duration   124ms) [ OK ]
ns1 TCP   -> ns1 (dead:beef:1::1:10047) MPTCP   (duration    98ms) [ OK ]
INFO: with peek mode: saveAfterPeek
ns1 MPTCP -> ns1 (10.0.1.1:10048      ) MPTCP   (duration   206ms) [ OK ]
ns1 MPTCP -> ns1 (10.0.1.1:10049      ) TCP     (duration   122ms) [ OK ]
ns1 TCP   -> ns1 (10.0.1.1:10050      ) MPTCP   (duration   126ms) [ OK ]
ns1 MPTCP -> ns1 (dead:beef:1::1:10051) MPTCP   (duration   160ms) [ OK ]
ns1 MPTCP -> ns1 (dead:beef:1::1:10052) TCP     (duration   113ms) [ OK ]
ns1 TCP   -> ns1 (dead:beef:1::1:10053) MPTCP   (duration   115ms) [ OK ]
Time: 100 seconds
[ perf record: Woken up 14 times to write data ]
failed to mmap file
[ perf record: Captured and wrote 3.731 MB perf.data ]

And info from perf:

# ./.virtme/perf/perf report -i tools/testing/selftests/net/mptcp/perf.data -k .virtme/build/vmlinux --stdio --header
# ========
# captured on    : Thu May 27 16:18:33 2021
# header version : 1
# data offset    : 712
# data size      : 3911616
# feat offset    : 3912328
# hostname : (none)
# os release : 5.12.0+
# perf version : 5.12.g3ebd090a8fbc
# arch : x86_64
# nrcpus online : 2
# nrcpus avail : 2
# cpudesc : AMD EPYC 7401P 24-Core Processor
# cpuid : AuthenticAMD,23,1,2
# total memory : 2029280 kB
# cmdline : /usr/bin/perf record -ag -e probe:tcp_send_active_reset -e probe:tcp_v4_send_reset -e probe:tcp_v6_send_reset ./mptcp_connect.sh -l 0.99% -d 4 -r 94% 99% 
# event : name = probe:tcp_send_active_reset, , id = { 38346, 38347 }, type = 2, size = 120, config = 0x847, { sample_period, sample_freq } = 1, sample_type = IP|TID|TIME|CALLCHAIN|CPU|PERIOD|RAW|IDENTIFIER, read_format = ID, disabled = 1, inherit = 1, sample_id_all = 1, exclude_guest = 1
# event : name = probe:tcp_v4_send_reset, , id = { 38348, 38349 }, type = 2, size = 120, config = 0x848, { sample_period, sample_freq } = 1, sample_type = IP|TID|TIME|CALLCHAIN|CPU|PERIOD|RAW|IDENTIFIER, read_format = ID, disabled = 1, inherit = 1, sample_id_all = 1, exclude_guest = 1
# event : name = probe:tcp_v6_send_reset, , id = { 38350, 38351 }, type = 2, size = 120, config = 0x849, { sample_period, sample_freq } = 1, sample_type = IP|TID|TIME|CALLCHAIN|CPU|PERIOD|RAW|IDENTIFIER, read_format = ID, disabled = 1, inherit = 1, sample_id_all = 1, exclude_guest = 1
# event : name = dummy:HG, , id = { 38352, 38353 }, type = 1, size = 120, config = 0x9, { sample_period, sample_freq } = 4000, sample_type = IP|TID|TIME|CALLCHAIN|CPU|PERIOD|IDENTIFIER, read_format = ID, inherit = 1, mmap = 1, comm = 1, freq = 1, task = 1, sample_id_all = 1, mmap2 = 1, comm_exec = 1, ksymbol = 1, bpf_event = 1
# CPU_TOPOLOGY info available, use -I to display
# NUMA_TOPOLOGY info available, use -I to display
# pmu mappings: software = 1, uprobe = 7, cpu = 4, breakpoint = 5, tracepoint = 2, kprobe = 6, msr = 8
# CACHE info available, use -I to display
# time of first sample : 0.000000
# time of last sample : 0.000000
# sample duration :      0.000 ms
# cpu pmu capabilities: max_precise=0
# missing features: BUILD_ID BRANCH_STACK GROUP_DESC AUXTRACE STAT MEM_TOPOLOGY CLOCKID DIR_FORMAT COMPRESSED CLOCK_DATA 
# ========
#
#
# Total Lost Samples: 0
#
# Samples: 15  of event 'probe:tcp_v4_send_reset'
# Event count (approx.): 15
#
# Children      Self  Command        Shared Object      Symbol                             
# ........  ........  .............  .................  ...................................
#
    60.00%    60.00%  swapper        [kernel.kallsyms]  [k] tcp_v4_send_reset
            |
            ---secondary_startup_64_no_verify
               start_secondary
               cpu_startup_entry
               do_idle
               default_idle_call
               default_idle
               asm_sysvec_apic_timer_interrupt
               sysvec_apic_timer_interrupt
               irq_exit_rcu
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] secondary_startup_64_no_verify
            |
            ---secondary_startup_64_no_verify
               start_secondary
               cpu_startup_entry
               do_idle
               default_idle_call
               default_idle
               asm_sysvec_apic_timer_interrupt
               sysvec_apic_timer_interrupt
               irq_exit_rcu
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] start_secondary
            |
            ---start_secondary
               cpu_startup_entry
               do_idle
               default_idle_call
               default_idle
               asm_sysvec_apic_timer_interrupt
               sysvec_apic_timer_interrupt
               irq_exit_rcu
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] cpu_startup_entry
            |
            ---cpu_startup_entry
               do_idle
               default_idle_call
               default_idle
               asm_sysvec_apic_timer_interrupt
               sysvec_apic_timer_interrupt
               irq_exit_rcu
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] do_idle
            |
            ---do_idle
               default_idle_call
               default_idle
               asm_sysvec_apic_timer_interrupt
               sysvec_apic_timer_interrupt
               irq_exit_rcu
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] default_idle_call
            |
            ---default_idle_call
               default_idle
               asm_sysvec_apic_timer_interrupt
               sysvec_apic_timer_interrupt
               irq_exit_rcu
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] default_idle
            |
            ---default_idle
               asm_sysvec_apic_timer_interrupt
               sysvec_apic_timer_interrupt
               irq_exit_rcu
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] asm_sysvec_apic_timer_interrupt
            |
            ---asm_sysvec_apic_timer_interrupt
               sysvec_apic_timer_interrupt
               irq_exit_rcu
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] sysvec_apic_timer_interrupt
            |
            ---sysvec_apic_timer_interrupt
               irq_exit_rcu
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] irq_exit_rcu
            |
            ---irq_exit_rcu
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] __do_softirq
            |
            ---__do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] net_rx_action
            |
            ---net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] __napi_poll
            |
            ---__napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] process_backlog
            |
            ---process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] __netif_receive_skb_one_core
            |
            ---__netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] ip_rcv
            |
            ---ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] ip_local_deliver
            |
            ---ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] ip_local_deliver_finish
            |
            ---ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] ip_protocol_deliver_rcu
            |
            ---ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_send_reset

    60.00%     0.00%  swapper        [kernel.kallsyms]  [k] tcp_v4_rcv
            |
            ---tcp_v4_rcv
               tcp_v4_send_reset

    33.33%    33.33%  ksoftirqd/0    [kernel.kallsyms]  [k] tcp_v4_send_reset
            |
            ---ret_from_fork
               kthread
               smpboot_thread_fn
               run_ksoftirqd
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

    33.33%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] ret_from_fork
            |
            ---ret_from_fork
               kthread
               smpboot_thread_fn
               run_ksoftirqd
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

    33.33%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] kthread
            |
            ---kthread
               smpboot_thread_fn
               run_ksoftirqd
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

    33.33%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] smpboot_thread_fn
            |
            ---smpboot_thread_fn
               run_ksoftirqd
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

    33.33%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] run_ksoftirqd
            |
            ---run_ksoftirqd
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

    33.33%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] __do_softirq
            |
            ---__do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

    33.33%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] net_rx_action
            |
            ---net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

    33.33%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] __napi_poll
            |
            ---__napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

    33.33%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] process_backlog
            |
            ---process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

    33.33%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] __netif_receive_skb_one_core
            |
            ---__netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

    33.33%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] ip_rcv
            |
            ---ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

    33.33%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] ip_local_deliver
            |
            ---ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

    33.33%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] ip_local_deliver_finish
            |
            ---ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

    33.33%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] ip_protocol_deliver_rcu
            |
            ---ip_protocol_deliver_rcu
               tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

    33.33%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] tcp_v4_rcv
            |
            ---tcp_v4_rcv
               |          
               |--26.67%--tcp_v4_send_reset
               |          
                --6.67%--tcp_v4_do_rcv
                          tcp_v4_send_reset

     6.67%     6.67%  mptcp_connect  [kernel.kallsyms]  [k] tcp_v4_send_reset
            |
            ---write
               entry_SYSCALL_64_after_hwframe
               do_syscall_64
               ksys_write
               vfs_write
               new_sync_write
               sock_write_iter
               sock_sendmsg
               mptcp_sendmsg
               __mptcp_push_pending
               mptcp_push_release.isra.0
               __tcp_push_pending_frames
               tcp_write_xmit
               __tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  ksoftirqd/0    [kernel.kallsyms]  [k] tcp_v4_do_rcv
            |
            ---tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  libc-2.31.so       [.] write
            |
            ---write
               entry_SYSCALL_64_after_hwframe
               do_syscall_64
               ksys_write
               vfs_write
               new_sync_write
               sock_write_iter
               sock_sendmsg
               mptcp_sendmsg
               __mptcp_push_pending
               mptcp_push_release.isra.0
               __tcp_push_pending_frames
               tcp_write_xmit
               __tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] entry_SYSCALL_64_after_hwframe
            |
            ---entry_SYSCALL_64_after_hwframe
               do_syscall_64
               ksys_write
               vfs_write
               new_sync_write
               sock_write_iter
               sock_sendmsg
               mptcp_sendmsg
               __mptcp_push_pending
               mptcp_push_release.isra.0
               __tcp_push_pending_frames
               tcp_write_xmit
               __tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] do_syscall_64
            |
            ---do_syscall_64
               ksys_write
               vfs_write
               new_sync_write
               sock_write_iter
               sock_sendmsg
               mptcp_sendmsg
               __mptcp_push_pending
               mptcp_push_release.isra.0
               __tcp_push_pending_frames
               tcp_write_xmit
               __tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] ksys_write
            |
            ---ksys_write
               vfs_write
               new_sync_write
               sock_write_iter
               sock_sendmsg
               mptcp_sendmsg
               __mptcp_push_pending
               mptcp_push_release.isra.0
               __tcp_push_pending_frames
               tcp_write_xmit
               __tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] vfs_write
            |
            ---vfs_write
               new_sync_write
               sock_write_iter
               sock_sendmsg
               mptcp_sendmsg
               __mptcp_push_pending
               mptcp_push_release.isra.0
               __tcp_push_pending_frames
               tcp_write_xmit
               __tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] new_sync_write
            |
            ---new_sync_write
               sock_write_iter
               sock_sendmsg
               mptcp_sendmsg
               __mptcp_push_pending
               mptcp_push_release.isra.0
               __tcp_push_pending_frames
               tcp_write_xmit
               __tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] sock_write_iter
            |
            ---sock_write_iter
               sock_sendmsg
               mptcp_sendmsg
               __mptcp_push_pending
               mptcp_push_release.isra.0
               __tcp_push_pending_frames
               tcp_write_xmit
               __tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] sock_sendmsg
            |
            ---sock_sendmsg
               mptcp_sendmsg
               __mptcp_push_pending
               mptcp_push_release.isra.0
               __tcp_push_pending_frames
               tcp_write_xmit
               __tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] mptcp_sendmsg
            |
            ---mptcp_sendmsg
               __mptcp_push_pending
               mptcp_push_release.isra.0
               __tcp_push_pending_frames
               tcp_write_xmit
               __tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] __mptcp_push_pending
            |
            ---__mptcp_push_pending
               mptcp_push_release.isra.0
               __tcp_push_pending_frames
               tcp_write_xmit
               __tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] mptcp_push_release.isra.0
            |
            ---mptcp_push_release.isra.0
               __tcp_push_pending_frames
               tcp_write_xmit
               __tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] __tcp_push_pending_frames
            |
            ---__tcp_push_pending_frames
               tcp_write_xmit
               __tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] tcp_write_xmit
            |
            ---tcp_write_xmit
               __tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] __tcp_transmit_skb
            |
            ---__tcp_transmit_skb
               __ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] __ip_queue_xmit
            |
            ---__ip_queue_xmit
               ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] ip_output
            |
            ---ip_output
               ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] ip_finish_output2
            |
            ---ip_finish_output2
               __local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] __local_bh_enable_ip
            |
            ---__local_bh_enable_ip
               do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] do_softirq
            |
            ---do_softirq
               __do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] __do_softirq
            |
            ---__do_softirq
               net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] net_rx_action
            |
            ---net_rx_action
               __napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] __napi_poll
            |
            ---__napi_poll
               process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] process_backlog
            |
            ---process_backlog
               __netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] __netif_receive_skb_one_core
            |
            ---__netif_receive_skb_one_core
               ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] ip_rcv
            |
            ---ip_rcv
               ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] ip_local_deliver
            |
            ---ip_local_deliver
               ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] ip_local_deliver_finish
            |
            ---ip_local_deliver_finish
               ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] ip_protocol_deliver_rcu
            |
            ---ip_protocol_deliver_rcu
               tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] tcp_v4_rcv
            |
            ---tcp_v4_rcv
               tcp_v4_do_rcv
               tcp_v4_send_reset

     6.67%     0.00%  mptcp_connect  [kernel.kallsyms]  [k] tcp_v4_do_rcv
            |
            ---tcp_v4_do_rcv
               tcp_v4_send_reset



#
# (Tip: Skip collecting build-id when recording: perf record -B)
#

Originally posted in #192 (comment)

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions