RE: Endless loop in udp with MSG_SPLICE_READ - Re: [syzbot] [fs?] INFO: task hung in pipe_release (4)

[Willem de Bruijn <willemdebruijn.kernel@gmail.com>]

Willem de Bruijn wrote:
> David Howells wrote:
> > Hi Jakub, Willem,
> > 
> > I think I'm going to need your help with this one.
> > 
> > > > syzbot has bisected this issue to:
> > > > 
> > > > commit 7ac7c987850c3ec617c778f7bd871804dc1c648d
> > > > Author: David Howells <dhowells@redhat.com>
> > > > Date:   Mon May 22 12:11:22 2023 +0000
> > > > 
> > > >     udp: Convert udp_sendpage() to use MSG_SPLICE_PAGES
> > > > 
> > > > bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=15853bcaa80000
> > > > start commit:   3f01e9fed845 Merge tag 'linux-watchdog-6.5-rc2' of git://w..
> > > > git tree:       upstream
> > > > final oops:     https://syzkaller.appspot.com/x/report.txt?x=17853bcaa80000
> > > > console output: https://syzkaller.appspot.com/x/log.txt?x=13853bcaa80000
> > > > kernel config:  https://syzkaller.appspot.com/x/.config?x=150188feee7071a7
> > > > dashboard link: https://syzkaller.appspot.com/bug?extid=f527b971b4bdc8e79f9e
> > > > syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=12a86682a80000
> > > > C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=1520ab6ca80000
> > > > 
> > > > Reported-by: syzbot+f527b971b4bdc8e79f9e@syzkaller.appspotmail.com
> > > > Fixes: 7ac7c987850c ("udp: Convert udp_sendpage() to use MSG_SPLICE_PAGES")
> > > > 
> > > > For information about bisection process see: https://goo.gl/tpsmEJ#bisection
> > 
> > The issue that syzbot is triggering seems to be something to do with the
> > calculations in the "if (copy <= 0) { ... }" chunk in __ip_append_data() when
> > MSG_SPLICE_PAGES is in operation.
> > 
> > What seems to happen is that the test program uses sendmsg() + MSG_MORE to
> > loads a UDP packet with 1406 bytes of data to the MTU size (1434) and then
> > splices in 8 extra bytes.
> > 
> > 	r3 = socket$inet_udp(0x2, 0x2, 0x0)
> > 	setsockopt$sock_int(r3, 0x1, 0x6, &(0x7f0000000140)=0x32, 0x4)
> > 	bind$inet(r3, &(0x7f0000000000)={0x2, 0x0, @dev={0xac, 0x14, 0x14, 0x15}}, 0x10)
> > 	connect$inet(r3, &(0x7f0000000200)={0x2, 0x0, @broadcast}, 0x10)
> > 	sendmmsg(r3, &(0x7f0000000180)=[{{0x0, 0x0, 0x0}}, {{0x0, 0xfffffffffffffed3, &(0x7f0000000940)=[{&(0x7f00000006c0)='O', 0x57e}], 0x1}}], 0x4000000000003bd, 0x8800)
> > 	write$binfmt_misc(r1, &(0x7f0000000440)=ANY=[], 0x8)
> > 	splice(r0, 0x0, r2, 0x0, 0x4ffe0, 0x0)
> > 
> > This results in some negative intermediate values turning up in the
> > calculations - and this results in the remaining length being made longer
> > from 8 to 14.
> > 
> > I added some printks (patch attached), resulting in the attached tracelines:
> > 
> > 	==>splice_to_socket() 7099
> > 	udp_sendmsg(8,8)
> > 	__ip_append_data(copy=-6,len=8, mtu=1434 skblen=1434 maxfl=1428)
> > 	pagedlen 14 = 14 - 0
> > 	copy -6 = 14 - 0 - 6 - 14
> > 	length 8 -= -6 + 0
> > 	__ip_append_data(copy=1414,len=14, mtu=1434 skblen=20 maxfl=1428)
> > 	copy=1414 len=14
> > 	skb_splice_from_iter(8,14)
> > 	__ip_append_data(copy=1406,len=6, mtu=1434 skblen=28 maxfl=1428)
> > 	copy=1406 len=6
> > 	skb_splice_from_iter(0,6)
> > 	__ip_append_data(copy=1406,len=6, mtu=1434 skblen=28 maxfl=1428)
> > 	copy=1406 len=6
> > 	skb_splice_from_iter(0,6)
> > 	__ip_append_data(copy=1406,len=6, mtu=1434 skblen=28 maxfl=1428)
> > 	copy=1406 len=6
> > 	skb_splice_from_iter(0,6)
> > 	__ip_append_data(copy=1406,len=6, mtu=1434 skblen=28 maxfl=1428)
> > 	copy=1406 len=6
> > 	skb_splice_from_iter(0,6)
> > 	copy=1406 len=6
> > 	skb_splice_from_iter(0,6)
> > 	...
> > 
> > 'copy' gets calculated as -6 because the maxfraglen (maxfl=1428) is 8 bytes
> > less than the amount of data then in the packet (skblen=1434).
> > 
> > 'copy' gets recalculated part way down as -6 from datalen (14) - transhdrlen
> > (0) - fraggap (6) - pagedlen (14).
> > 
> > datalen is 14 because it was length (8) + fraggap (6).
> > 
> > Inside skb_splice_from_iter(), we eventually end up in an enless loop in which
> > msg_iter.count is 0 and the length to be copied is 6.  It always returns 0
> > because there's nothing to copy, and so __ip_append_data() cycles round the
> > loop endlessly.
> > 
> > Any suggestion as to how to fix this?
> 
> Still ingesting.
> 
> The syzkaller repro runs in threaded mode, so syscalls should not be
> interpreted in order.
> 
> There are two seemingly (but evidently not really) independent
> operations:
> 
> One involving splicing
> 
>     pipe(&(0x7f0000000100)={<r0=>0xffffffffffffffff, <r1=>0xffffffffffffffff})
>     r2 = socket$inet_udp(0x2, 0x2, 0x0)
>     write$binfmt_misc(r1, &(0x7f0000000440)=ANY=[], 0x8)
>     splice(r0, 0x0, r2, 0x0, 0x4ffe0, 0x0)
>     close(r2)
> 
> And separately the MSG_MORE transmission that you mentioned
> 
>     r3 = socket$inet_udp(0x2, 0x2, 0x0)
>     setsockopt$sock_int(r3, 0x1, 0x6, &(0x7f0000000140)=0x32, 0x4)
>     bind$inet(r3, &(0x7f0000000000)={0x2, 0x0, @dev={0xac, 0x14, 0x14, 0x15}}, 0x10)
>     connect$inet(r3, &(0x7f0000000200)={0x2, 0x0, @broadcast}, 0x10)
>     sendmmsg(r3, &(0x7f0000000180)=[{{0x0, 0x0, 0x0}}, {{0x0, 0xfffffffffffffed3, &(0x7f0000000940)=[{&(0x7f00000006c0)='O', 0x57e}], 0x1}}], 0x4000000000003bd, 0x8800)
> 
> This second program also sets setsockopt SOL_SOCKET/SO_BROADCAST. That
> is likely not some random noise in the program (but that can be easily
> checked, by removing it -- assuming the repro triggers quickly).
> 
> Question is whether the infinite loop happens on the r2, the socket
> involving MSG_SPLICE_PAGES, or r3, the socket involving SO_BROADCAST.
> If the second, on the surface it would seem that splicing is entirely
> unrelated.

I still don't entirely follow how the splice and sendmmsg end up on
the same socket.

Also, the sendmmsg in the case on the dashboard is very odd, a vlen of
0x4000000000003bd and flags MSG_MORE | MSG_CONFIRM. But maybe other
runs have more sensible flags here.

The issue appears to be with appending through splicing to an skb that
exceeds the length with fragments, triggering the if (fraggap) branch
to copy some trailer from skb_prev to skb, then appending the spliced
data.

Perhaps not an true fix based on understanding in detail, but one way
out may be to disable splicing if !transhdrlen (which ip_append_data
clears if appending).