WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()

WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()

[Jack Stone]

Hi All,

The following warning keeps hitting me. I couldn't get the first one - it had already left dmesg hence the W taint.
The C taint is from r8712u from staging.

I've seen it with 3.4.0-076444-g07acfc2 (recent Linus tree) and 3.4.0-rc3-00089-gc6f5c93.

I am going to attempt to bisect it now.

[ 3896.037489] ------------[ cut here ]------------
[ 3896.037490] WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()
[ 3896.037491] Hardware name: System Product Name
[ 3896.037491] recvmsg bug 2: copied 3F1199D7 seq 3F1199D7 rcvnxt 3F119A71 fl 0
[ 3896.037511] Modules linked in: fuse ebtable_nat ebtables ipt_MASQUERADE iptable_nat nf_nat xt_CHECKSUM iptable_mangle bridge rfcomm lockd 8021q garp stp llc bnep nf_conntrack_netbios_ns nf_conntrack_broadcast ip6t_REJECT nf_conntrack_ipv4 nf_conntrack_ipv6 nf_defrag_ipv6 nf_defrag_ipv4 xt_state nf_conntrack ip6table_filter ip6_tables vhost_net snd_hda_codec_hdmi macvtap macvlan tun snd_hda_codec_realtek virtio_net btusb bluetooth coretemp kvm_intel kvm snd_hda_intel r8712u(C) snd_hda_codec snd_hwdep e1000e joydev snd_seq snd_seq_device snd_pcm snd_timer snd sunrpc eeepc_wmi asus_wmi hid_logitech_dj sparse_keymap mxm_wmi soundcore iTCO_wdt rfkill snd_page_alloc wmi i2c_i801 pcspkr iTCO_vendor_support serio_raw binfmt_misc uinput microcode crc32c_intel ghash_clmulni_intel firewire_ohci fi
 rewire_core crc_itu_t [last unloaded: scsi_wait_scan]
[ 3896.037512] Pid: 3926, comm: spotify Tainted: G        WC   3.4.0-07644-g07acfc2 #2
[ 3896.037513] Call Trace:
[ 3896.037514]  [<ffffffff8106010f>] warn_slowpath_common+0x7f/0xc0
[ 3896.037515]  [<ffffffff81060206>] warn_slowpath_fmt+0x46/0x50
[ 3896.037517]  [<ffffffff8163f4c5>] ? tcp_recvmsg+0x35/0xc70
[ 3896.037518]  [<ffffffff812c130f>] ? avc_has_perm_flags+0xef/0x230
[ 3896.037519]  [<ffffffff812c125c>] ? avc_has_perm_flags+0x3c/0x230
[ 3896.037520]  [<ffffffff8163ffab>] tcp_recvmsg+0xb1b/0xc70
[ 3896.037522]  [<ffffffff8166a8c0>] ? inet_sendmsg+0x230/0x230
[ 3896.037523]  [<ffffffff8166a9f7>] inet_recvmsg+0x137/0x250
[ 3896.037525]  [<ffffffff815d7f58>] ? sock_update_classid+0x128/0x310
[ 3896.037526]  [<ffffffff815cfe40>] do_sock_read+0xf0/0x110
[ 3896.037527]  [<ffffffff815d0b8c>] sock_aio_read.part.5+0x4c/0x70
[ 3896.037528]  [<ffffffff812c130f>] ? avc_has_perm_flags+0xef/0x230
[ 3896.037530]  [<ffffffff815d0bb0>] ? sock_aio_read.part.5+0x70/0x70
[ 3896.037531]  [<ffffffff815d0bdd>] sock_aio_read+0x2d/0x40
[ 3896.037532]  [<ffffffff811bc2b3>] do_sync_readv_writev+0xd3/0x110
[ 3896.037534]  [<ffffffff812beca6>] ? security_file_permission+0x96/0xb0
[ 3896.037535]  [<ffffffff811bb9a1>] ? rw_verify_area+0x61/0x100
[ 3896.037537]  [<ffffffff811bc584>] do_readv_writev+0xd4/0x1d0
[ 3896.037538]  [<ffffffff811bdad8>] ? fget_light+0x48/0x4f0
[ 3896.037540]  [<ffffffff811bdad8>] ? fget_light+0x48/0x4f0
[ 3896.037541]  [<ffffffff811bc71c>] vfs_readv+0x3c/0x50
[ 3896.037543]  [<ffffffff811bc77d>] sys_readv+0x4d/0xc0
[ 3896.037544]  [<ffffffff8174c829>] system_call_fastpath+0x16/0x1b
[ 3896.037545] ---[ end trace 762b4689c56af7ab ]---

The relevant code from tcp.c is:

		/* Next get a buffer. */

                skb_queue_walk(&sk->sk_receive_queue, skb) {
                        /* Now that we have two receive queues this
                         * shouldn't happen.
                         */
                        if (WARN(before(*seq, TCP_SKB_CB(skb)->seq),
                                 "recvmsg bug: copied %X seq %X rcvnxt %X fl %X\n",
                                 *seq, TCP_SKB_CB(skb)->seq, tp->rcv_nxt,
                                 flags))
                                break;

                        offset = *seq - TCP_SKB_CB(skb)->seq;
                        if (tcp_hdr(skb)->syn)
                                offset--;
                        if (offset < skb->len)
                                goto found_ok_skb;
                        if (tcp_hdr(skb)->fin)
                                goto found_fin_ok;
This warn here ----->        WARN(!(flags & MSG_PEEK),
                             "recvmsg bug 2: copied %X seq %X rcvnxt %X fl %X\n",
                             *seq, TCP_SKB_CB(skb)->seq, tp->rcv_nxt, flags);
                }

Thanks,

Jack

Re: WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()

[Eric Dumazet]

On Fri, 2012-05-25 at 21:25 +0100, Jack Stone wrote:
> Hi All,
> 
> The following warning keeps hitting me. I couldn't get the first one - it had already left dmesg hence the W taint.
> The C taint is from r8712u from staging.
> 
> I've seen it with 3.4.0-076444-g07acfc2 (recent Linus tree) and 3.4.0-rc3-00089-gc6f5c93.
> 
> I am going to attempt to bisect it now.

No need, update your tree.

Re: WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()

[Eric Dumazet]

On Fri, 2012-05-25 at 22:45 +0200, Eric Dumazet wrote:
> On Fri, 2012-05-25 at 21:25 +0100, Jack Stone wrote:
> > Hi All,
> > 
> > The following warning keeps hitting me. I couldn't get the first one - it had already left dmesg hence the W taint.
> > The C taint is from r8712u from staging.
> > 
> > I've seen it with 3.4.0-076444-g07acfc2 (recent Linus tree) and 3.4.0-rc3-00089-gc6f5c93.
> > 
> > I am going to attempt to bisect it now.
> 
> No need, update your tree.
> 
> 


http://git.kernel.org/?p=linux/kernel/git/torvalds/linux.git;a=commitdiff;h=1ca7ee30630e1022dbcf1b51be20580815ffab73

Re: WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()

[Jack Stone]

On 05/25/2012 09:55 PM, Eric Dumazet wrote:
> On Fri, 2012-05-25 at 22:45 +0200, Eric Dumazet wrote:
>> No need, update your tree.
> 
> http://git.kernel.org/?p=linux/kernel/git/torvalds/linux.git;a=commitdiff;h=1ca7ee30630e1022dbcf1b51be20580815ffab73
> 

Thank you. Rebuilding now.

Jack

Re: WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()

[Jack Stone]

On 05/25/2012 09:55 PM, Eric Dumazet wrote:
> On Fri, 2012-05-25 at 22:45 +0200, Eric Dumazet wrote:
>> On Fri, 2012-05-25 at 21:25 +0100, Jack Stone wrote:
>>> Hi All,
>>>
>>> The following warning keeps hitting me. I couldn't get the first one - it had already left dmesg hence the W taint.
>>> The C taint is from r8712u from staging.
>>>
>>> I've seen it with 3.4.0-076444-g07acfc2 (recent Linus tree) and 3.4.0-rc3-00089-gc6f5c93.
>>>
>>> I am going to attempt to bisect it now.
>>
>> No need, update your tree.
>>
>>
> 
> 
> http://git.kernel.org/?p=linux/kernel/git/torvalds/linux.git;a=commitdiff;h=1ca7ee30630e1022dbcf1b51be20580815ffab73
> 
> 
> 

I'm still getting this with da89fb1 which includes the above

Linux hover1 3.4.0-07797-gda89fb1 #4 SMP Fri May 25 22:23:14 BST 2012 x86_64 x86_64 x86_64 GNU/Linux

Re: WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()

[Eric Dumazet]

On Sat, 2012-05-26 at 12:22 +0100, Jack Stone wrote:

> I'm still getting this with da89fb1 which includes the above
> 
> Linux hover1 3.4.0-07797-gda89fb1 #4 SMP Fri May 25 22:23:14 BST 2012 x86_64 x86_64 x86_64 GNU/Linux

Thanks

Could you add following debugging patch ?

diff --git a/net/ipv4/tcp.c b/net/ipv4/tcp.c
index 3ba605f..b56c63c 100644
--- a/net/ipv4/tcp.c
+++ b/net/ipv4/tcp.c
@@ -1606,8 +1606,9 @@ int tcp_recvmsg(struct kiocb *iocb, struct sock *sk, struct msghdr *msg,
 			if (tcp_hdr(skb)->fin)
 				goto found_fin_ok;
 			WARN(!(flags & MSG_PEEK),
-			     "recvmsg bug 2: copied %X seq %X rcvnxt %X fl %X\n",
-			     *seq, TCP_SKB_CB(skb)->seq, tp->rcv_nxt, flags);
+			     "recvmsg bug 2: copied %X seq %X end_seq %X rcvnxt %X fl %X offset %u len %u syn %d\n",
+			     *seq, TCP_SKB_CB(skb)->seq, TCP_SKB_CB(skb)->end_seq,
+			     tp->rcv_nxt, flags, offset, skb->len, tcp_hdr(skb)->syn);
 		}
 
 		/* Well, if we have backlog, try to process it now yet. */

Re: WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()

[Jack Stone]

On 05/27/2012 02:59 PM, Eric Dumazet wrote:
> On Sat, 2012-05-26 at 12:22 +0100, Jack Stone wrote:
> 
>> I'm still getting this with da89fb1 which includes the above
>>
>> Linux hover1 3.4.0-07797-gda89fb1 #4 SMP Fri May 25 22:23:14 BST 2012 x86_64 x86_64 x86_64 GNU/Linux
> 
> Thanks
> 
> Could you add following debugging patch ?
> 
> diff --git a/net/ipv4/tcp.c b/net/ipv4/tcp.c
> index 3ba605f..b56c63c 100644
> --- a/net/ipv4/tcp.c
> +++ b/net/ipv4/tcp.c
> @@ -1606,8 +1606,9 @@ int tcp_recvmsg(struct kiocb *iocb, struct sock *sk, struct msghdr *msg,
>  			if (tcp_hdr(skb)->fin)
>  				goto found_fin_ok;
>  			WARN(!(flags & MSG_PEEK),
> -			     "recvmsg bug 2: copied %X seq %X rcvnxt %X fl %X\n",
> -			     *seq, TCP_SKB_CB(skb)->seq, tp->rcv_nxt, flags);
> +			     "recvmsg bug 2: copied %X seq %X end_seq %X rcvnxt %X fl %X offset %u len %u syn %d\n",
> +			     *seq, TCP_SKB_CB(skb)->seq, TCP_SKB_CB(skb)->end_seq,
> +			     tp->rcv_nxt, flags, offset, skb->len, tcp_hdr(skb)->syn);
>  		}
>  
>  		/* Well, if we have backlog, try to process it now yet. */
> 
> 

uname: Linux hover1 3.4.0-07822-g786f02b-dirty #1 SMP Sun May 27 15:23:39 BST 2012 x86_64 x86_64 x86_64 GNU/Linux

Here's the new output:


May 27 16:32:30 hover1 kernel: [ 1907.804613] ------------[ cut here ]------------
May 27 16:32:30 hover1 kernel: [ 1907.804622] WARNING: at net/ipv4/tcp.c:1611 tcp_recvmsg+0xb36/0xc90()
May 27 16:32:30 hover1 kernel: [ 1907.804624] Hardware name: System Product Name
May 27 16:32:30 hover1 kernel: [ 1907.804626] recvmsg bug 2: copied 8F322DEB seq 8F322DEB end_seq 8F322F2A rcvnxt 8F322F2A fl 0 offset 4294967295 len 319 syn 1
May 27 16:32:30 hover1 kernel: [ 1907.804665] Modules linked in: fuse ebtable_nat ebtables ipt_MASQUERADE iptable_nat nf_nat xt_CHECKSUM iptable_mangle bridge rfcomm lockd 8021q garp stp llc bnep ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 nf_conntrack_netbios_ns nf_conntrack_broadcast ip6table_filter ip6_tables nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack snd_hda_codec_hdmi snd_hda_codec_realtek coretemp vhost_net macvtap macvlan tun virtio_net kvm_intel snd_hda_intel kvm snd_hda_codec btusb bluetooth snd_hwdep e1000e snd_seq eeepc_wmi asus_wmi sparse_keymap microcode r8712u(C) snd_seq_device rfkill snd_pcm joydev sunrpc snd_timer snd mxm_wmi hid_logitech_dj iTCO_wdt wmi iTCO_vendor_support i2c_i801 soundcore snd_page_alloc binfmt_misc serio_raw pcspkr uinput crc32c_intel ghash
 _clmulni_intel firewire_ohci firewire_core crc_itu_t [last unloaded: scsi_wait_scan]
May 27 16:32:30 hover1 kernel: [ 1907.804669] Pid: 2275, comm: thunderbird-bin Tainted: G         C   3.4.0-07822-g786f02b-dirty #1
May 27 16:32:30 hover1 kernel: [ 1907.804670] Call Trace:
May 27 16:32:30 hover1 kernel: [ 1907.804674]  [<ffffffff8106010f>] warn_slowpath_common+0x7f/0xc0
May 27 16:32:30 hover1 kernel: [ 1907.804676]  [<ffffffff81060206>] warn_slowpath_fmt+0x46/0x50
May 27 16:32:30 hover1 kernel: [ 1907.804679]  [<ffffffff8163f7f5>] ? tcp_recvmsg+0x35/0xc90
May 27 16:32:30 hover1 kernel: [ 1907.804681]  [<ffffffff816402f6>] tcp_recvmsg+0xb36/0xc90
May 27 16:32:30 hover1 kernel: [ 1907.804685]  [<ffffffff8166ac10>] ? inet_sendmsg+0x230/0x230
May 27 16:32:30 hover1 kernel: [ 1907.804687]  [<ffffffff8166ad47>] inet_recvmsg+0x137/0x250
May 27 16:32:30 hover1 kernel: [ 1907.804691]  [<ffffffff815d8288>] ? sock_update_classid+0x128/0x310
May 27 16:32:30 hover1 kernel: [ 1907.804693]  [<ffffffff815d04ed>] sock_recvmsg+0x11d/0x140
May 27 16:32:30 hover1 kernel: [ 1907.804697]  [<ffffffff811d85ff>] ? file_update_time+0xdf/0x140
May 27 16:32:30 hover1 kernel: [ 1907.804701]  [<ffffffff811bdcb8>] ? fget_light+0x48/0x4f0
May 27 16:32:30 hover1 kernel: [ 1907.804703]  [<ffffffff811bdd76>] ? fget_light+0x106/0x4f0
May 27 16:32:30 hover1 kernel: [ 1907.804705]  [<ffffffff811bdcb8>] ? fget_light+0x48/0x4f0
May 27 16:32:30 hover1 kernel: [ 1907.804708]  [<ffffffff815d3941>] sys_recvfrom+0xf1/0x170
May 27 16:32:30 hover1 kernel: [ 1907.804712]  [<ffffffff810f6ddc>] ? __audit_syscall_entry+0xcc/0x310
May 27 16:32:30 hover1 kernel: [ 1907.804715]  [<ffffffff8132dfce>] ? trace_hardirqs_on_thunk+0x3a/0x3f
May 27 16:32:30 hover1 kernel: [ 1907.804719]  [<ffffffff8174cc69>] system_call_fastpath+0x16/0x1b
May 27 16:32:30 hover1 kernel: [ 1907.804720] ---[ end trace 4797381fbdf33b5d ]---

Thanks,

Jack

Re: WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()

[Eric Dumazet]

On Sun, 2012-05-27 at 16:34 +0100, Jack Stone wrote:
> On 05/27/2012 02:59 PM, Eric Dumazet wrote:
> > On Sat, 2012-05-26 at 12:22 +0100, Jack Stone wrote:
> > 
> >> I'm still getting this with da89fb1 which includes the above
> >>
> >> Linux hover1 3.4.0-07797-gda89fb1 #4 SMP Fri May 25 22:23:14 BST 2012 x86_64 x86_64 x86_64 GNU/Linux
> > 
> > Thanks
> > 
> > Could you add following debugging patch ?
> > 
> > diff --git a/net/ipv4/tcp.c b/net/ipv4/tcp.c
> > index 3ba605f..b56c63c 100644
> > --- a/net/ipv4/tcp.c
> > +++ b/net/ipv4/tcp.c
> > @@ -1606,8 +1606,9 @@ int tcp_recvmsg(struct kiocb *iocb, struct sock *sk, struct msghdr *msg,
> >  			if (tcp_hdr(skb)->fin)
> >  				goto found_fin_ok;
> >  			WARN(!(flags & MSG_PEEK),
> > -			     "recvmsg bug 2: copied %X seq %X rcvnxt %X fl %X\n",
> > -			     *seq, TCP_SKB_CB(skb)->seq, tp->rcv_nxt, flags);
> > +			     "recvmsg bug 2: copied %X seq %X end_seq %X rcvnxt %X fl %X offset %u len %u syn %d\n",
> > +			     *seq, TCP_SKB_CB(skb)->seq, TCP_SKB_CB(skb)->end_seq,
> > +			     tp->rcv_nxt, flags, offset, skb->len, tcp_hdr(skb)->syn);
> >  		}
> >  
> >  		/* Well, if we have backlog, try to process it now yet. */
> > 
> > 
> 
> uname: Linux hover1 3.4.0-07822-g786f02b-dirty #1 SMP Sun May 27 15:23:39 BST 2012 x86_64 x86_64 x86_64 GNU/Linux
> 
> Here's the new output:
> 
> 
> May 27 16:32:30 hover1 kernel: [ 1907.804613] ------------[ cut here ]------------
> May 27 16:32:30 hover1 kernel: [ 1907.804622] WARNING: at net/ipv4/tcp.c:1611 tcp_recvmsg+0xb36/0xc90()
> May 27 16:32:30 hover1 kernel: [ 1907.804624] Hardware name: System Product Name
> May 27 16:32:30 hover1 kernel: [ 1907.804626] recvmsg bug 2: copied 8F322DEB seq 8F322DEB end_seq 8F322F2A rcvnxt 8F322F2A fl 0 offset 4294967295 len 319 syn 1

So it seems we can queue in sk_receive_queue a packet with SYN flag set.

(A SYN or SYNACK packet contains DATA payload...)

The sequence number of such frames should be tweaked (seq++) instead of
games we do in fast path :

if (tcp_hdr(skb)->syn)
    offset--;


Oh well this can wait linux-3.6, please test following patch in the
meantime.

diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c
index b224eb8..34c8dcc 100644
--- a/net/ipv4/tcp_input.c
+++ b/net/ipv4/tcp_input.c
@@ -4553,7 +4553,7 @@ static bool tcp_try_coalesce(struct sock *sk,
 
 	*fragstolen = false;
 
-	if (tcp_hdr(from)->fin)
+	if (tcp_hdr(from)->fin || tcp_hdr(to)->syn)
 		return false;
 
 	/* Its possible this segment overlaps with prior segment in queue */

Re: WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()

[Jack Stone]

On 05/27/2012 06:35 PM, Eric Dumazet wrote:
> So it seems we can queue in sk_receive_queue a packet with SYN flag set.
> 
> (A SYN or SYNACK packet contains DATA payload...)
> 
> The sequence number of such frames should be tweaked (seq++) instead of
> games we do in fast path :
> 
> if (tcp_hdr(skb)->syn)
>     offset--;
> 
> 
> Oh well this can wait linux-3.6, please test following patch in the
> meantime.
> 
> diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c
> index b224eb8..34c8dcc 100644
> --- a/net/ipv4/tcp_input.c
> +++ b/net/ipv4/tcp_input.c
> @@ -4553,7 +4553,7 @@ static bool tcp_try_coalesce(struct sock *sk,
>  
>  	*fragstolen = false;
>  
> -	if (tcp_hdr(from)->fin)
> +	if (tcp_hdr(from)->fin || tcp_hdr(to)->syn)
>  		return false;
>  
>  	/* Its possible this segment overlaps with prior segment in queue */
> 
> 

Still seems to fire with the above applied, it also sets of the warn just above it...

Could it be something to do with my staging network driver?

[ 2605.769938] ------------[ cut here ]------------
[ 2605.769942] WARNING: at net/ipv4/tcp.c:1611 tcp_recvmsg+0xb36/0xc90()
[ 2605.769943] Hardware name: System Product Name
[ 2605.769944] recvmsg bug 2: copied 84322A4D seq 84322A4D end_seq 84322A86 rcvnxt 843233B3 fl 0 offset 4294967295 len 57 syn 1
[ 2605.769982] Modules linked in: fuse ebtable_nat ebtables ipt_MASQUERADE iptable_nat nf_nat xt_CHECKSUM iptable_mangle bridge lockd rfcomm 8021q garp stp llc bnep ip6t_REJECT nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_ipv6 nf_defrag_ipv6 nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack ip6table_filter ip6_tables snd_hda_codec_hdmi snd_hda_codec_realtek vhost_net macvtap macvlan tun coretemp virtio_net kvm_intel kvm btusb bluetooth snd_hda_intel snd_hda_codec snd_hwdep snd_seq sunrpc r8712u(C) snd_seq_device snd_pcm snd_timer eeepc_wmi asus_wmi sparse_keymap e1000e mxm_wmi snd soundcore joydev wmi rfkill i2c_i801 snd_page_alloc iTCO_wdt serio_raw hid_logitech_dj pcspkr iTCO_vendor_support binfmt_misc microcode uinput crc32c_intel ghash_clmulni_intel firewire_ohci fi
 rewire_core crc_itu_t [last unloaded: scsi_wait_scan]
[ 2605.769985] Pid: 3305, comm: firefox Tainted: G        WC   3.4.0-07822-g786f02b-dirty #2
[ 2605.769986] Call Trace:
[ 2605.769988]  [<ffffffff8106010f>] warn_slowpath_common+0x7f/0xc0
[ 2605.769990]  [<ffffffff81060206>] warn_slowpath_fmt+0x46/0x50
[ 2605.769993]  [<ffffffff8163f7f5>] ? tcp_recvmsg+0x35/0xc90
[ 2605.769996]  [<ffffffff816402f6>] tcp_recvmsg+0xb36/0xc90
[ 2605.769998]  [<ffffffff8166ac20>] ? inet_sendmsg+0x230/0x230
[ 2605.770001]  [<ffffffff8166ad57>] inet_recvmsg+0x137/0x250
[ 2605.770004]  [<ffffffff815d8288>] ? sock_update_classid+0x128/0x310
[ 2605.770006]  [<ffffffff815d04ed>] sock_recvmsg+0x11d/0x140
[ 2605.770009]  [<ffffffff811bdcb8>] ? fget_light+0x48/0x4f0
[ 2605.770012]  [<ffffffff811d1920>] ? __pollwait+0xf0/0xf0
[ 2605.770014]  [<ffffffff811bdd76>] ? fget_light+0x106/0x4f0
[ 2605.770017]  [<ffffffff811bdcb8>] ? fget_light+0x48/0x4f0
[ 2605.770020]  [<ffffffff815d3941>] sys_recvfrom+0xf1/0x170
[ 2605.770022]  [<ffffffff810f6ddc>] ? __audit_syscall_entry+0xcc/0x310
[ 2605.770025]  [<ffffffff8132dfce>] ? trace_hardirqs_on_thunk+0x3a/0x3f
[ 2605.770028]  [<ffffffff8174cc69>] system_call_fastpath+0x16/0x1b
[ 2605.770029] ---[ end trace f86533e3bdc5b326 ]---
------------[ cut here ]------------
[ 2605.770032] WARNING: at net/ipv4/tcp.c:1598 tcp_recvmsg+0x409/0xc90()
[ 2605.770034] Hardware name: System Product Name
[ 2605.770082] recvmsg bug: copied 84322A4D seq 84322A86 rcvnxt 843233B3 fl 0
[ 2605.770119] Modules linked in: fuse ebtable_nat ebtables ipt_MASQUERADE iptable_nat nf_nat xt_CHECKSUM iptable_mangle bridge lockd rfcomm 8021q garp stp llc bnep ip6t_REJECT nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_ipv6 nf_defrag_ipv6 nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack ip6table_filter ip6_tables snd_hda_codec_hdmi snd_hda_codec_realtek vhost_net macvtap macvlan tun coretemp virtio_net kvm_intel kvm btusb bluetooth snd_hda_intel snd_hda_codec snd_hwdep snd_seq sunrpc r8712u(C) snd_seq_device snd_pcm snd_timer eeepc_wmi asus_wmi sparse_keymap e1000e mxm_wmi snd soundcore joydev wmi rfkill i2c_i801 snd_page_alloc iTCO_wdt serio_raw hid_logitech_dj pcspkr iTCO_vendor_support binfmt_misc microcode uinput crc32c_intel ghash_clmulni_intel firewire_ohci fi
 rewire_core crc_itu_t [last unloaded: scsi_wait_scan]
[ 2605.770122] Pid: 3305, comm: firefox Tainted: G        WC   3.4.0-07822-g786f02b-dirty #2
[ 2605.770123] Call Trace:
[ 2605.770125]  [<ffffffff8106010f>] warn_slowpath_common+0x7f/0xc0
[ 2605.770128]  [<ffffffff81060206>] warn_slowpath_fmt+0x46/0x50
[ 2605.770130]  [<ffffffff8163f7f5>] ? tcp_recvmsg+0x35/0xc90
[ 2605.770132]  [<ffffffff8163fbc9>] tcp_recvmsg+0x409/0xc90
[ 2605.770135]  [<ffffffff8166ac20>] ? inet_sendmsg+0x230/0x230
[ 2605.770138]  [<ffffffff8166ad57>] inet_recvmsg+0x137/0x250
[ 2605.770140]  [<ffffffff815d8288>] ? sock_update_classid+0x128/0x310
[ 2605.770143]  [<ffffffff815d04ed>] sock_recvmsg+0x11d/0x140
[ 2605.770146]  [<ffffffff811bdcb8>] ? fget_light+0x48/0x4f0
[ 2605.770148]  [<ffffffff811d1920>] ? __pollwait+0xf0/0xf0
[ 2605.770150]  [<ffffffff811bdd76>] ? fget_light+0x106/0x4f0
[ 2605.770152]  [<ffffffff811bdcb8>] ? fget_light+0x48/0x4f0
[ 2605.770154]  [<ffffffff815d3941>] sys_recvfrom+0xf1/0x170
[ 2605.770157]  [<ffffffff810f6ddc>] ? __audit_syscall_entry+0xcc/0x310
[ 2605.770160]  [<ffffffff8132dfce>] ? trace_hardirqs_on_thunk+0x3a/0x3f
[ 2605.770163]  [<ffffffff8174cc69>] system_call_fastpath+0x16/0x1b
[ 2605.770164] ---[ end trace f86533e3bdc5b327 ]---

Thanks,

Jack

Re: WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()

[Eric Dumazet]

On Sun, 2012-05-27 at 20:13 +0100, Jack Stone wrote:
> On 05/27/2012 06:35 PM, Eric Dumazet wrote:
> > So it seems we can queue in sk_receive_queue a packet with SYN flag set.
> > 
> > (A SYN or SYNACK packet contains DATA payload...)
> > 
> > The sequence number of such frames should be tweaked (seq++) instead of
> > games we do in fast path :
> > 
> > if (tcp_hdr(skb)->syn)
> >     offset--;
> > 
> > 
> > Oh well this can wait linux-3.6, please test following patch in the
> > meantime.
> > 
> > diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c
> > index b224eb8..34c8dcc 100644
> > --- a/net/ipv4/tcp_input.c
> > +++ b/net/ipv4/tcp_input.c
> > @@ -4553,7 +4553,7 @@ static bool tcp_try_coalesce(struct sock *sk,
> >  
> >  	*fragstolen = false;
> >  
> > -	if (tcp_hdr(from)->fin)
> > +	if (tcp_hdr(from)->fin || tcp_hdr(to)->syn)
> >  		return false;
> >  
> >  	/* Its possible this segment overlaps with prior segment in queue */
> > 
> > 
> 
> Still seems to fire with the above applied, it also sets of the warn just above it...
> 
> Could it be something to do with my staging network driver?


Yes it could be memory corruption.

(making tcp _think_ tcp_hdr(skb)->syn is set, while it was not at all.

Please replace debugging patch by following, because tcp flags are
copied elsewhere, so we can double check.

diff --git a/net/ipv4/tcp.c b/net/ipv4/tcp.c
index 3ba605f..22e4c9a 100644
--- a/net/ipv4/tcp.c
+++ b/net/ipv4/tcp.c
@@ -1606,8 +1606,10 @@ int tcp_recvmsg(struct kiocb *iocb, struct sock *sk, struct msghdr *msg,
 			if (tcp_hdr(skb)->fin)
 				goto found_fin_ok;
 			WARN(!(flags & MSG_PEEK),
-			     "recvmsg bug 2: copied %X seq %X rcvnxt %X fl %X\n",
-			     *seq, TCP_SKB_CB(skb)->seq, tp->rcv_nxt, flags);
+			     "recvmsg bug 2: copied %X seq %X end_seq %X rcvnxt %X fl %X offset %u len %u syn %d tcp_flags %X\n",
+			     *seq, TCP_SKB_CB(skb)->seq, TCP_SKB_CB(skb)->end_seq,
+			     tp->rcv_nxt, flags, offset, skb->len, tcp_hdr(skb)->syn,
+				 TCP_SKB_CB(skb)->tcp_flags);
 		}
 
 		/* Well, if we have backlog, try to process it now yet. */

Re: WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()

[Eric Dumazet]

On Sun, 2012-05-27 at 21:36 +0200, Eric Dumazet wrote:
> pied elsewhere, so we can double check.
> 
> diff --git a/net/ipv4/tcp.c b/net/ipv4/tcp.c
> index 3ba605f..22e4c9a 100644
> --- a/net/ipv4/tcp.c
> +++ b/net/ipv4/tcp.c
> @@ -1606,8 +1606,10 @@ int tcp_recvmsg(struct kiocb *iocb, struct sock *sk, struct msghdr *msg,
>  			if (tcp_hdr(skb)->fin)
>  				goto found_fin_ok;
>  			WARN(!(flags & MSG_PEEK),
> -			     "recvmsg bug 2: copied %X seq %X rcvnxt %X fl %X\n",
> -			     *seq, TCP_SKB_CB(skb)->seq, tp->rcv_nxt, flags);
> +			     "recvmsg bug 2: copied %X seq %X end_seq %X rcvnxt %X fl %X offset %u len %u syn %d tcp_flags %X\n",
> +			     *seq, TCP_SKB_CB(skb)->seq, TCP_SKB_CB(skb)->end_seq,
> +			     tp->rcv_nxt, flags, offset, skb->len, tcp_hdr(skb)->syn,
> +				 TCP_SKB_CB(skb)->tcp_flags);
>  		}
>  
>  		/* Well, if we have backlog, try to process it now yet. */
> 

Oh well, ignore this, as tcp_flags is only set in output path.

Re: WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()

[Eric Dumazet]

On Sun, 2012-05-27 at 20:13 +0100, Jack Stone wrote:

> Could it be something to do with my staging network driver?

drivers/staging/rtl8712/rtl8712_recv.c

line 1096

precvframe->u.hdr.pkt = skb_clone(pskb, GFP_ATOMIC);

This looks very wrong.
Make sure you never _never_ hit this path.

Re: WARNING: at net/ipv4/tcp.c:1610 tcp_recvmsg+0xb1b/0xc70()

[Jack Stone]

On 05/28/2012 01:25 AM, Eric Dumazet wrote:
> On Sun, 2012-05-27 at 20:13 +0100, Jack Stone wrote:
> 
>> Could it be something to do with my staging network driver?
> 
> drivers/staging/rtl8712/rtl8712_recv.c
> 
> line 1096
> 
> precvframe->u.hdr.pkt = skb_clone(pskb, GFP_ATOMIC);
> 
> This looks very wrong.
> Make sure you never _never_ hit this path.
> 

I've applied the following debugging patch. Thanks for the suggestion.

diff --git a/drivers/staging/rtl8712/rtl8712_recv.c b/drivers/staging/rtl8712/rtl8712_recv.c
index 8e82ce2..fed62f8 100644
--- a/drivers/staging/rtl8712/rtl8712_recv.c
+++ b/drivers/staging/rtl8712/rtl8712_recv.c
@@ -1082,23 +1082,16 @@ static int recvbuf2recvframe(struct _adapter *padapter, struct sk_buff *pskb)
                 * 4 is for skb->data 4 bytes alignment. */
                alloc_sz += 6;
                pkt_copy = netdev_alloc_skb(padapter->pnetdev, alloc_sz);
-               if (pkt_copy) {
-                       pkt_copy->dev = padapter->pnetdev;
-                       precvframe->u.hdr.pkt = pkt_copy;
-                       skb_reserve(pkt_copy, 4 - ((addr_t)(pkt_copy->data)
-                                   % 4));
-                       skb_reserve(pkt_copy, shift_sz);
-                       memcpy(pkt_copy->data, pbuf, tmp_len);
-                       precvframe->u.hdr.rx_head = precvframe->u.hdr.rx_data =
-                                precvframe->u.hdr.rx_tail = pkt_copy->data;
-                       precvframe->u.hdr.rx_end = pkt_copy->data + alloc_sz;
-               } else {
-                       precvframe->u.hdr.pkt = skb_clone(pskb, GFP_ATOMIC);
-                       precvframe->u.hdr.rx_head = pbuf;
-                       precvframe->u.hdr.rx_data = pbuf;
-                       precvframe->u.hdr.rx_tail = pbuf;
-                       precvframe->u.hdr.rx_end = pbuf + alloc_sz;
-               }
+               WARN_ON(!pkt_copy)
+               pkt_copy->dev = padapter->pnetdev;
+               precvframe->u.hdr.pkt = pkt_copy;
+               skb_reserve(pkt_copy, 4 - ((addr_t)(pkt_copy->data)
+                           % 4));
+               skb_reserve(pkt_copy, shift_sz);
+               memcpy(pkt_copy->data, pbuf, tmp_len);
+               precvframe->u.hdr.rx_head = precvframe->u.hdr.rx_data =
+                        precvframe->u.hdr.rx_tail = pkt_copy->data;
+               precvframe->u.hdr.rx_end = pkt_copy->data + alloc_sz;
                recvframe_put(precvframe, tmp_len);
                recvframe_pull(precvframe, drvinfo_sz + RXDESC_SIZE);
                /* because the endian issue, driver avoid reference to the