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

13 messages, 2 authors, 2012-05-28 · open the first message on its own page

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

From: Jack Stone <hidden>
Date: 2012-05-25 20:26:06

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()

From: Eric Dumazet <hidden>
Date: 2012-05-25 20:45:31

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()

From: Eric Dumazet <hidden>
Date: 2012-05-25 20:55:39

On Fri, 2012-05-25 at 22:45 +0200, Eric Dumazet wrote:
On Fri, 2012-05-25 at 21:25 +0100, Jack Stone wrote:
quoted
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()

From: Jack Stone <hidden>
Date: 2012-05-25 21:31:50

On 05/25/2012 09:55 PM, Eric Dumazet wrote:
On Fri, 2012-05-25 at 22:45 +0200, Eric Dumazet wrote:
quoted
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()

From: Jack Stone <hidden>
Date: 2012-05-26 11:22:34

On 05/25/2012 09:55 PM, Eric Dumazet wrote:
On Fri, 2012-05-25 at 22:45 +0200, Eric Dumazet wrote:
quoted
On Fri, 2012-05-25 at 21:25 +0100, Jack Stone wrote:
quoted
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()

From: Eric Dumazet <hidden>
Date: 2012-05-27 13:59:51

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()

From: Jack Stone <hidden>
Date: 2012-05-27 15:35:05

On 05/27/2012 02:59 PM, Eric Dumazet wrote:
quoted hunk
On Sat, 2012-05-26 at 12:22 +0100, Jack Stone wrote:
quoted
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()

From: Eric Dumazet <hidden>
Date: 2012-05-27 17:36:08

On Sun, 2012-05-27 at 16:34 +0100, Jack Stone wrote:
On 05/27/2012 02:59 PM, Eric Dumazet wrote:
quoted
On Sat, 2012-05-26 at 12:22 +0100, Jack Stone wrote:
quoted
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()

From: Jack Stone <hidden>
Date: 2012-05-27 19:13:47

On 05/27/2012 06:35 PM, Eric Dumazet wrote:
quoted hunk
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()

From: Eric Dumazet <hidden>
Date: 2012-05-27 19:36:20

On Sun, 2012-05-27 at 20:13 +0100, Jack Stone wrote:
On 05/27/2012 06:35 PM, Eric Dumazet wrote:
quoted
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()

From: Eric Dumazet <hidden>
Date: 2012-05-27 19:46:18

On Sun, 2012-05-27 at 21:36 +0200, Eric Dumazet wrote:
quoted hunk
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()

From: Eric Dumazet <hidden>
Date: 2012-05-28 00:25:36

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()

From: Jack Stone <hidden>
Date: 2012-05-28 08:34:10

On 05/28/2012 01:25 AM, Eric Dumazet wrote:
On Sun, 2012-05-27 at 20:13 +0100, Jack Stone wrote:
quoted
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
Keyboard shortcuts
hback out one level
jnext message in thread
kprevious message in thread
ldrill in
Escclose help / fold thread tree
?toggle this help