Hi Tung Nguyen, I said we first encountered the problem when migrating to 5.4. But the backtrace dump and the ftrace log are done with kernel 5.10.0-rc4-17824. So we were able to reproduce this behavior with latest mainline kernel, without any local modification of the kernel.
Best regards Holger Brunck > -----Original Message----- > From: Tung Quang Nguyen <tung.q.ngu...@dektech.com.au> > Sent: Dienstag, 24. November 2020 11:05 > To: Holger Brunck <holger.bru...@hitachi-powergrids.com> > Cc: CC: Xin Long <lucien....@gmail.com>; Matteo Ghidoni > <matteo.ghid...@hitachi-powergrids.com>; Jon Maloy > <jma...@redhat.com>; tipc-discussion@lists.sourceforge.net > Subject: RE: refcount warnings with TIPC in combination with a TAP device > and fragmented messages > > > Hi Holger, > > You said you met this stack trace after migrating to "kernel 5.4". Can you > give > us a full version ? > > Thanks. > Tung Nguyen > > -----Original Message----- > From: Holger Brunck <holger.bru...@hitachi-powergrids.com> > Sent: Monday, November 23, 2020 10:00 PM > To: Jon Maloy <jma...@redhat.com>; tipc-discussion@lists.sourceforge.net > Cc: Tung Quang Nguyen <tung.q.ngu...@dektech.com.au>; CC: Xin Long > <lucien....@gmail.com>; Matteo Ghidoni <matteo.ghidoni@hitachi- > powergrids.com> > Subject: Re: refcount warnings with TIPC in combination with a TAP device > and fragmented messages > > Hi Jon, > thanks. To add some more information I was now using ftrace to see the call > stack within TIPC/TAP and the related skb operations to narrow this down. > Maybe someone more familiar with the receive flow in the TIPC stack sees > already something suspicious. > > Here is the trace starting from our program (main) sending the first fragment > to the TAP device until the first WARN_ON sequence is written out when our > client (tipc_ping) is receiving the reassembled packet: > > main-91 .... 84.4851: tun_chr_write_iter <-vfs_write > <-- first > fragment arrives > main-91 .... 84.4851: tun_get_user <-tun_chr_write_iter > main-91 .... 84.4851: sock_alloc_send_pskb <-tun_get_user > main-91 .... 84.4851: skb_set_owner_w > <-sock_alloc_send_pskb > <-- refcount add > main-91 .... 84.4851: skb_put <-tun_get_user > main-91 .... 84.4852: skb_copy_datagram_from_iter > <-tun_get_user > <-- copy data > main-91 .... 84.4852: tipc_l2_rcv_msg > <-__netif_receive_skb_one_core > main-91 .... 84.4852: tipc_rcv <-tipc_l2_rcv_msg > main-91 ...2 84.4852: tipc_link_rcv <-tipc_rcv > main-91 ...2 84.4852: tipc_link_advance_transmq > <-tipc_link_rcv > main-91 ...2 84.4852: kfree_skb > <-tipc_link_advance_transmq > main-91 ...2 84.4852: skb_release_all <-kfree_skb > main-91 ...2 84.4852: skb_release_head_state <- > skb_release_all > main-91 ...2 84.4852: skb_release_data > <-skb_release_all > main-91 ...2 84.4852: skb_free_head > <-skb_release_data > main-91 ...2 84.4852: kfree_skbmem <-kfree_skb > main-91 ...2 84.4852: kfree_skb > <-tipc_link_advance_transmq > main-91 ...2 84.4852: skb_release_all <-kfree_skb > main-91 ...2 84.4852: skb_release_head_state <- > skb_release_all > main-91 ...2 84.4852: skb_release_data > <-skb_release_all > main-91 ...2 84.4852: skb_free_head > <-skb_release_data > main-91 ...2 84.4852: kfree_skbmem <-kfree_skb > main-91 ...2 84.4852: tipc_data_input <-tipc_link_rcv > main-91 ...2 84.4852: tipc_link_input <-tipc_link_rcv > main-91 ...2 84.4852: tipc_buf_append <-tipc_link_input > main-91 ...2 84.4852: skb_pull <-tipc_buf_append > main-91 ...2 84.4853: tipc_link_advance_backlog > <-tipc_link_rcv > main-91 .... 84.4853: kfree_skb <-tipc_rcv > main-91 .... 84.4854: tun_chr_write_iter <-vfs_write <--- > second > fragment > main-91 .... 84.4854: tun_get_user <-tun_chr_write_iter > main-91 .... 84.4854: sock_alloc_send_pskb <-tun_get_user > main-91 .... 84.4854: skb_set_owner_w > <-sock_alloc_send_pskb > main-91 .... 84.4854: skb_put <-tun_get_user > main-91 .... 84.4854: skb_copy_datagram_from_iter > <-tun_get_user > main-91 .... 84.4854: tipc_l2_rcv_msg > <-__netif_receive_skb_one_core > main-91 .... 84.4854: tipc_rcv <-tipc_l2_rcv_msg > main-91 ...2 84.4854: tipc_link_advance_transmq > <-tipc_link_rcv > main-91 ...2 84.4854: tipc_data_input <-tipc_link_rcv > main-91 ...2 84.4854: tipc_link_input <-tipc_link_rcv > main-91 ...2 84.4854: tipc_buf_append <-tipc_link_input > main-91 ...2 84.4854: skb_pull <-tipc_buf_append > main-91 ...2 84.4854: skb_try_coalesce > <-tipc_buf_append > main-91 ...2 84.4854: tipc_data_input <-tipc_link_input > main-91 ...2 84.4854: skb_queue_tail <-tipc_data_input > main-91 .... 84.4854: tipc_sk_rcv <-tipc_rcv > main-91 .... 84.4854: tipc_sk_lookup <-tipc_sk_rcv > main-91 ...1 84.4854: tipc_sk_filter_rcv <-tipc_sk_rcv > main-91 ...1 84.4854: sock_wfree <-tipc_sk_filter_rcv > main-91 ...1 84.4854: tun_sock_write_space <-sock_wfree > main-91 ...1 84.4854: tipc_data_ready > <-tipc_sk_filter_rcv > main-91 .... 84.4855: tipc_node_distr_xmit <-tipc_sk_rcv > main-91 .... 84.4855: kfree_skb <-tipc_rcv > tipc_ping-97 .... 84.4855: tipc_poll <-sock_poll <-- > tipc_ping > receives the packet > tipc_ping-97 .... 84.4859: tipc_recvmsg <-__sys_recvfrom > tipc_ping-97 .... 84.4859: tipc_wait_for_rcvmsg <-tipc_recvmsg > tipc_ping-97 .... 84.4859: tipc_sk_set_orig_addr <-tipc_recvmsg > skb_copy_datagram_msg > tipc_ping-97 .... 84.4859: skb_copy_datagram_iter <-tipc_recvmsg > tipc_ping-97 .... 84.4859: kfree_skb <-tsk_advance_rx_queue > tipc_ping-97 .... 84.4859: skb_release_all <-kfree_skb > tipc_ping-97 .... 84.4859: skb_release_head_state > <-skb_release_all > tipc_ping-97 .... 84.4859: skb_release_data <-skb_release_all > tipc_ping-97 .... 84.4859: kfree_skb <-skb_release_data > tipc_ping-97 .... 84.4859: skb_release_all <-kfree_skb > tipc_ping-97 .... 84.4859: skb_release_head_state <- > skb_release_all > tipc_ping-97 .... 84.4859: sock_wfree > <-skb_release_head_state > tipc_ping-97 .... 84.4859: warn_slowpath_fmt <- > refcount_warn_saturate <--- first WARN_ON dump > tipc_ping-97 .... 84.4897: __warn <-warn_slowpath_fmt > tipc_ping-97 .... 84.5227: dump_backtrace <-show_stack > > > Best regards > Holger Brunck > > > From: Jon Maloy <jma...@redhat.com> > Sent: 23 November 2020 15:25 > To: Holger Brunck <holger.bru...@hitachi-powergrids.com>; tipc- > discuss...@lists.sourceforge.net <tipc-discussion@lists.sourceforge.net> > Cc: CC: Tung Nguyen <tung.q.ngu...@dektech.com.au>; CC: Xin Long > <lucien....@gmail.com>; Matteo Ghidoni <matteo.ghidoni@hitachi- > powergrids.com> > Subject: Re: refcount warnings with TIPC in combination with a TAP device > and fragmented messages > > > > > Hi Holger, > We will look into this. It is a new setup for us, so it has to be prepared > first. > > ///jon > > > On 11/19/20 9:33 AM, Holger Brunck wrote: > > Hi all, > > we have currently problems with TIPC in combination with a TAP > > interface and fragmented messages. We have a Kirkwood board getting > > TIPC ethernet packets from a third party stack in user space which we > > fill into a TAP device to pass this packets to the kernel. On the > > remote side we have another board with a physical ethernet device. > > After migrating to kernel 5.4 we saw kernel crashes as soon as we send > fragmented TIPC messages via this link. Before the kernel crash we see > "refcount_t: underflow; use-after-free" > > warnings coming either from the TIPC or the driver/net/tun. > > For smaller packets everything work fine. To track this down we wrote > > a small test program which receives raw ethernet packets in user space > > and send them back to kernel space via a TAP interface, to be able to > reproduce it with a mainline kernel only. > > So instead of a link e.g. eth0:eth0 we have a link from eth0:tap0. > > > > I now tested this on latest mainline kernel and still see warnings > > coming from the kernel, but not the crash. > > So in the testcase we have TIPC server running on a remote board > > having a ethernet bearer on a interface. The ethernet interface is > > connected to the ethernet interface of the kirkwood board. The incoming > messages are passed to user space and filled into the TAP device. > > So we have a TIPC link between tap0 and eth0. If I send now back and > > forth TIPC connectionless messages to the server via the TAP device > > the kernel print the following messages as soon as the packets are > > larger then the MTU and TIPC need to reassemble the fragmented > messages coming from the TAP driver: > > > > root@km_kirkwood:~# > > ------------[ cut here ]------------ > > WARNING: CPU: 0 PID: 94 at lib/refcount.c:28 sock_wfree+0xd8/0xe0 > > refcount_t: underflow; use-after-free. > > Modules linked in: > > CPU: 0 PID: 94 Comm: tipc_ping Tainted: G W 5.10.0-rc4-17824- > g0fa8ee0d9ab9 #112 > > Hardware name: Marvell Kirkwood (Flattened Device Tree) [<c000f924>] > > (unwind_backtrace) from [<c000c980>] (show_stack+0x10/0x14) > > [<c000c980>] (show_stack) from [<c001c27c>] (__warn+0xe8/0xfc) > > [<c001c27c>] (__warn) from [<c001c2fc>] (warn_slowpath_fmt+0x6c/0xb8) > > [<c001c2fc>] (warn_slowpath_fmt) from [<c0564b78>] > > (sock_wfree+0xd8/0xe0) [<c0564b78>] (sock_wfree) from [<c056b730>] > > (skb_release_all+0xc/0x28) [<c056b730>] (skb_release_all) from > > [<c056b784>] (kfree_skb+0x20/0x6c) [<c056b784>] (kfree_skb) from > > [<c056be44>] (skb_release_data+0xc0/0x140) [<c056be44>] > > (skb_release_data) from [<c056b784>] (kfree_skb+0x20/0x6c) > > [<c056b784>] (kfree_skb) from [<c0720ea4>] (tipc_recvmsg+0x270/0x3c4) > > [<c0720ea4>] (tipc_recvmsg) from [<c0560428>] > > (__sys_recvfrom+0xb0/0x128) [<c0560428>] (__sys_recvfrom) from > > [<c05604bc>] (sys_recv+0x18/0x20) [<c05604bc>] (sys_recv) from > [<c0008240>] (ret_fast_syscall+0x0/0x50) Exception stack(0xc1615fa8 to > 0xc1615ff0) > > 5fa0: 00000001 00000000 00000003 00025010 0000fa00 > 00000000 > > 5fc0: 00000001 00000000 00010888 00000123 00000000 00000000 > 49cb0000 > > be939bec > > 5fe0: 00000000 be93997c 00011114 49d9666c ---[ end trace > > e7c3a1366c544d79 ]--- ------------[ cut here ]------------ > > WARNING: CPU: 0 PID: 74 at lib/refcount.c:22 > > sock_alloc_send_pskb+0x240/0x258 > > refcount_t: saturated; leaking memory. > > Modules linked in: > > CPU: 0 PID: 74 Comm: main Tainted: G W 5.10.0-rc4-17824- > g0fa8ee0d9ab9 #112 > > Hardware name: Marvell Kirkwood (Flattened Device Tree) [<c000f924>] > > (unwind_backtrace) from [<c000c980>] (show_stack+0x10/0x14) > > [<c000c980>] (show_stack) from [<c001c27c>] (__warn+0xe8/0xfc) > > [<c001c27c>] (__warn) from [<c001c2fc>] (warn_slowpath_fmt+0x6c/0xb8) > > [<c001c2fc>] (warn_slowpath_fmt) from [<c0563b40>] > > (sock_alloc_send_pskb+0x240/0x258) > > [<c0563b40>] (sock_alloc_send_pskb) from [<c043d500>] > > (tun_get_user+0x224/0x13f8) [<c043d500>] (tun_get_user) from > > [<c043e718>] (tun_chr_write_iter+0x44/0x78) [<c043e718>] > > (tun_chr_write_iter) from [<c012f1bc>] (vfs_write+0x1fc/0x448) > > [<c012f1bc>] (vfs_write) from [<c012f52c>] (ksys_write+0x54/0xcc) > > [<c012f52c>] (ksys_write) from [<c0008240>] (ret_fast_syscall+0x0/0x50) > Exception stack(0xc158bfa8 to 0xc158bff0) > > bfa0: 00011244 00000000 00000004 00022098 000005c2 > 00000004 > > bfc0: 00011244 00000000 000108bc 00000004 00000000 00000000 > 49cb0000 > > becf3c94 > > bfe0: 00000000 becf3bb0 49e21ce0 49e223e4 ---[ end trace > > e7c3a1366c544d7a ]--- > > > > Kernel version: > > root@km_kirkwood:~# cat /proc/version > > Linux version 5.10.0-rc4-17824-g0fa8ee0d9ab9 > > > > If I simply use ethernet bearer on both sides everything works fine, > > so I need the TAP interface to be involved to see the problem. > > > > It seems that we have a problem in the skb_buf allocation or handling > > between the TAP driver and the TIPC layer as soon it comes to > fragmentation. > > Does anyone have an idea what could cause the problem and how to track > > this down? Any help is appreciated. > > > > Best regards > > Holger Brunck _______________________________________________ tipc-discussion mailing list tipc-discussion@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/tipc-discussion
