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.ghid...@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-discussion@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.ghid...@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
