bond: take rcu lock in netpoll_send_skb_on_dev

[Dave Jones]

The bonding driver lacks the rcu lock when it calls down into
netdev_lower_get_next_private_rcu from bond_poll_controller, which
results in a trace like:

WARNING: CPU: 2 PID: 179 at net/core/dev.c:6567 
netdev_lower_get_next_private_rcu+0x34/0x40
CPU: 2 PID: 179 Comm: kworker/u16:15 Not tainted 4.19.0-rc5-backup+ #1
Workqueue: bond0 bond_mii_monitor
RIP: 0010:netdev_lower_get_next_private_rcu+0x34/0x40
Code: 48 89 fb e8 fe 29 63 ff 85 c0 74 1e 48 8b 45 00 48 81 c3 c0 00 00 00 48 
8b 00 48 39 d8 74 0f 48 89 45 00 48 8b 40 f8 5b 5d c3 <0f> 0b eb de 31 c0 eb f5 
0f 1f 40 00 0f 1f 44 00 00 48 8>
RSP: 0018:c987fa68 EFLAGS: 00010046
RAX:  RBX: 880429614560 RCX: 
RDX: 0001 RSI:  RDI: a184ada0
RBP: c987fa80 R08: 0001 R09: 
R10: c987f9f0 R11: 880429798040 R12: 8804289d5980
R13: a1511f60 R14: 00c8 R15: 
FS:  () GS:88042f88() knlGS:
CS:  0010 DS:  ES:  CR0: 80050033
CR2: 7f4b78fce180 CR3: 00018180f006 CR4: 001606e0
Call Trace:
 bond_poll_controller+0x52/0x170
 netpoll_poll_dev+0x79/0x290
 netpoll_send_skb_on_dev+0x158/0x2c0
 netpoll_send_udp+0x2d5/0x430
 write_ext_msg+0x1e0/0x210
 console_unlock+0x3c4/0x630
 vprintk_emit+0xfa/0x2f0
 printk+0x52/0x6e
 ? __netdev_printk+0x12b/0x220
 netdev_info+0x64/0x80
 ? bond_3ad_set_carrier+0xe9/0x180
 bond_select_active_slave+0x1fc/0x310
 bond_mii_monitor+0x709/0x9b0
 process_one_work+0x221/0x5e0
 worker_thread+0x4f/0x3b0
 kthread+0x100/0x140
 ? process_one_work+0x5e0/0x5e0
 ? kthread_delayed_work_timer_fn+0x90/0x90
 ret_from_fork+0x24/0x30

We're also doing rcu dereferences a layer up in netpoll_send_skb_on_dev
before we call down into netpoll_poll_dev, so just take the lock there.

Suggested-by: Cong Wang 
Signed-off-by: Dave Jones 

diff --git a/net/core/netpoll.c b/net/core/netpoll.c
index 3219a2932463..692367d7c280 100644
--- a/net/core/netpoll.c
+++ b/net/core/netpoll.c
@@ -330,6 +330,7 @@ void netpoll_send_skb_on_dev(struct netpoll *np, struct 
sk_buff *skb,
/* It is up to the caller to keep npinfo alive. */
struct netpoll_info *npinfo;
 
+   rcu_read_lock_bh();
lockdep_assert_irqs_disabled();
 
npinfo = rcu_dereference_bh(np->dev->npinfo);
@@ -374,6 +375,7 @@ void netpoll_send_skb_on_dev(struct netpoll *np, struct 
sk_buff *skb,
skb_queue_tail(>txq, skb);
schedule_delayed_work(>tx_work,0);
}
+   rcu_read_unlock_bh();
 }
 EXPORT_SYMBOL(netpoll_send_skb_on_dev);
 

Re: bond: take rcu lock in bond_poll_controller

[Dave Jones]

On Fri, Sep 28, 2018 at 12:03:22PM -0700, Cong Wang wrote:
 > On Fri, Sep 28, 2018 at 12:02 PM Cong Wang  wrote:
 > >
 > > On Fri, Sep 28, 2018 at 11:26 AM Dave Jones  
 > > wrote:
 > > > diff --git a/net/core/netpoll.c b/net/core/netpoll.c
 > > > index 3219a2932463..4f9494381635 100644
 > > > --- a/net/core/netpoll.c
 > > > +++ b/net/core/netpoll.c
 > > > @@ -330,6 +330,7 @@ void netpoll_send_skb_on_dev(struct netpoll *np, 
 > > > struct sk_buff *skb,
 > > > /* It is up to the caller to keep npinfo alive. */
 > > > struct netpoll_info *npinfo;
 > > >
 > > > +   rcu_read_lock();
 > > > lockdep_assert_irqs_disabled();
 > > >
 > > > npinfo = rcu_dereference_bh(np->dev->npinfo);
 > >
 > > I think you probably need rcu_read_lock_bh() to satisfy
 > > rcu_deference_bh()...
 > 
 > But irq is disabled here, so not sure if rcu_read_lock_bh()
 > could cause trouble... Interesting...

I was wondering for a moment why I never got a warning, then I
remembered I disabled lockdep for that machine because nfs spews stuff.

I'll doublecheck, and post v4. lol, this looked like a 2 minute fix at first.

Dave

bond: take rcu lock in bond_poll_controller

[Dave Jones]

Callers of bond_for_each_slave_rcu are expected to hold the rcu lock,
otherwise a trace like below is shown

WARNING: CPU: 2 PID: 179 at net/core/dev.c:6567 
netdev_lower_get_next_private_rcu+0x34/0x40
CPU: 2 PID: 179 Comm: kworker/u16:15 Not tainted 4.19.0-rc5-backup+ #1
Workqueue: bond0 bond_mii_monitor
RIP: 0010:netdev_lower_get_next_private_rcu+0x34/0x40
Code: 48 89 fb e8 fe 29 63 ff 85 c0 74 1e 48 8b 45 00 48 81 c3 c0 00 00 00 48 
8b 00 48 39 d8 74 0f 48 89 45 00 48 8b 40 f8 5b 5d c3 <0f> 0b eb de 31 c0 eb f5 
0f 1f 40 00 0f 1f 44 00 00 48 8>
RSP: 0018:c987fa68 EFLAGS: 00010046
RAX:  RBX: 880429614560 RCX: 
RDX: 0001 RSI:  RDI: a184ada0
RBP: c987fa80 R08: 0001 R09: 
R10: c987f9f0 R11: 880429798040 R12: 8804289d5980
R13: a1511f60 R14: 00c8 R15: 
FS:  () GS:88042f88() knlGS:
CS:  0010 DS:  ES:  CR0: 80050033
CR2: 7f4b78fce180 CR3: 00018180f006 CR4: 001606e0
Call Trace:
 bond_poll_controller+0x52/0x170
 netpoll_poll_dev+0x79/0x290
 netpoll_send_skb_on_dev+0x158/0x2c0
 netpoll_send_udp+0x2d5/0x430
 write_ext_msg+0x1e0/0x210
 console_unlock+0x3c4/0x630
 vprintk_emit+0xfa/0x2f0
 printk+0x52/0x6e
 ? __netdev_printk+0x12b/0x220
 netdev_info+0x64/0x80
 ? bond_3ad_set_carrier+0xe9/0x180
 bond_select_active_slave+0x1fc/0x310
 bond_mii_monitor+0x709/0x9b0
 process_one_work+0x221/0x5e0
 worker_thread+0x4f/0x3b0
 kthread+0x100/0x140
 ? process_one_work+0x5e0/0x5e0
 ? kthread_delayed_work_timer_fn+0x90/0x90
 ret_from_fork+0x24/0x30

Suggested-by: Cong Wang 
Signed-off-by: Dave Jones 

-- 
v3: Do this in netpoll_send_skb_on_dev as Cong suggests.

diff --git a/net/core/netpoll.c b/net/core/netpoll.c
index 3219a2932463..4f9494381635 100644
--- a/net/core/netpoll.c
+++ b/net/core/netpoll.c
@@ -330,6 +330,7 @@ void netpoll_send_skb_on_dev(struct netpoll *np, struct 
sk_buff *skb,
/* It is up to the caller to keep npinfo alive. */
struct netpoll_info *npinfo;
 
+   rcu_read_lock();
lockdep_assert_irqs_disabled();
 
npinfo = rcu_dereference_bh(np->dev->npinfo);
@@ -374,6 +375,7 @@ void netpoll_send_skb_on_dev(struct netpoll *np, struct 
sk_buff *skb,
skb_queue_tail(>txq, skb);
schedule_delayed_work(>tx_work,0);
}
+   rcu_read_unlock();
 }
 EXPORT_SYMBOL(netpoll_send_skb_on_dev);
 

Re: bond: take rcu lock in bond_poll_controller

[Dave Jones]

On Fri, Sep 28, 2018 at 10:31:39AM -0700, Cong Wang wrote:
 > On Fri, Sep 28, 2018 at 10:25 AM Dave Jones  wrote:
 > >
 > > On Fri, Sep 28, 2018 at 09:55:52AM -0700, Cong Wang wrote:
 > >  > On Fri, Sep 28, 2018 at 9:18 AM Dave Jones  
 > > wrote:
 > >  > >
 > >  > > Callers of bond_for_each_slave_rcu are expected to hold the rcu lock,
 > >  > > otherwise a trace like below is shown
 > >  >
 > >  > So why not take rcu read lock in netpoll_send_skb_on_dev() where
 > >  > RCU is also assumed?
 > >
 > > that does seem to solve the backtrace spew I saw too, so if that's
 > > preferable I can respin the patch.
 > 
 > 
 > >From my observations, netpoll_send_skb_on_dev() does not take
 > RCU read lock _and_ it relies on rcu read lock because it calls
 > rcu_dereference_bh().
 > 
 > If my observation is correct, you should catch a RCU warning like
 > this but within netpoll_send_skb_on_dev().
 >
 > >  > As I said, I can't explain why you didn't trigger the RCU warning in
 > >  > netpoll_send_skb_on_dev()...
 > >
 > > netpoll_send_skb_on_dev takes the rcu lock itself.
 > 
 > Could you please point me where exactly is the rcu lock here?
 > 
 > I am too stupid to see it. :)

No, I'm the stupid one. I looked at the tree I had just edited to try your
proposed change. 

Now that I've untangled myself, I'll repost with your suggested change.

Dave

Re: bond: take rcu lock in bond_poll_controller

[Dave Jones]

On Fri, Sep 28, 2018 at 09:55:52AM -0700, Cong Wang wrote:
 > On Fri, Sep 28, 2018 at 9:18 AM Dave Jones  wrote:
 > >
 > > Callers of bond_for_each_slave_rcu are expected to hold the rcu lock,
 > > otherwise a trace like below is shown
 > 
 > So why not take rcu read lock in netpoll_send_skb_on_dev() where
 > RCU is also assumed?

that does seem to solve the backtrace spew I saw too, so if that's
preferable I can respin the patch.

 > As I said, I can't explain why you didn't trigger the RCU warning in
 > netpoll_send_skb_on_dev()...

netpoll_send_skb_on_dev takes the rcu lock itself.

Dave

bond: take rcu lock in bond_poll_controller

[Dave Jones]

Callers of bond_for_each_slave_rcu are expected to hold the rcu lock,
otherwise a trace like below is shown

WARNING: CPU: 2 PID: 179 at net/core/dev.c:6567 
netdev_lower_get_next_private_rcu+0x34/0x40
CPU: 2 PID: 179 Comm: kworker/u16:15 Not tainted 4.19.0-rc5-backup+ #1
Workqueue: bond0 bond_mii_monitor
RIP: 0010:netdev_lower_get_next_private_rcu+0x34/0x40
Code: 48 89 fb e8 fe 29 63 ff 85 c0 74 1e 48 8b 45 00 48 81 c3 c0 00 00 00 48 
8b 00 48 39 d8 74 0f 48 89 45 00 48 8b 40 f8 5b 5d c3 <0f> 0b eb de 31 c0 eb f5 
0f 1f 40 00 0f 1f 44 00 00 48 8>
RSP: 0018:c987fa68 EFLAGS: 00010046
RAX:  RBX: 880429614560 RCX: 
RDX: 0001 RSI:  RDI: a184ada0
RBP: c987fa80 R08: 0001 R09: 
R10: c987f9f0 R11: 880429798040 R12: 8804289d5980
R13: a1511f60 R14: 00c8 R15: 
FS:  () GS:88042f88() knlGS:
CS:  0010 DS:  ES:  CR0: 80050033
CR2: 7f4b78fce180 CR3: 00018180f006 CR4: 001606e0
Call Trace:
 bond_poll_controller+0x52/0x170
 netpoll_poll_dev+0x79/0x290
 netpoll_send_skb_on_dev+0x158/0x2c0
 netpoll_send_udp+0x2d5/0x430
 write_ext_msg+0x1e0/0x210
 console_unlock+0x3c4/0x630
 vprintk_emit+0xfa/0x2f0
 printk+0x52/0x6e
 ? __netdev_printk+0x12b/0x220
 netdev_info+0x64/0x80
 ? bond_3ad_set_carrier+0xe9/0x180
 bond_select_active_slave+0x1fc/0x310
 bond_mii_monitor+0x709/0x9b0
 process_one_work+0x221/0x5e0
 worker_thread+0x4f/0x3b0
 kthread+0x100/0x140
 ? process_one_work+0x5e0/0x5e0
 ? kthread_delayed_work_timer_fn+0x90/0x90
 ret_from_fork+0x24/0x30

Signed-off-by: Dave Jones 

diff --git a/drivers/net/bonding/bond_main.c b/drivers/net/bonding/bond_main.c
index c05c01a00755..77a3607a7099 100644
--- a/drivers/net/bonding/bond_main.c
+++ b/drivers/net/bonding/bond_main.c
@@ -977,6 +977,7 @@ static void bond_poll_controller(struct net_device 
*bond_dev)
if (bond_3ad_get_active_agg_info(bond, _info))
return;
 
+   rcu_read_lock();
bond_for_each_slave_rcu(bond, slave, iter) {
if (!bond_slave_is_up(slave))
continue;
@@ -992,6 +993,7 @@ static void bond_poll_controller(struct net_device 
*bond_dev)
 
netpoll_poll_dev(slave->dev);
}
+   rcu_read_unlock();
 }
 
 static void bond_netpoll_cleanup(struct net_device *bond_dev)

bond: take rcu lock in bond_poll_controller

[Dave Jones]

Callers of bond_for_each_slave_rcu are expected to hold the rcu lock,
otherwise a trace like below is shown

WARNING: CPU: 2 PID: 179 at net/core/dev.c:6567 
netdev_lower_get_next_private_rcu+0x34/0x40
CPU: 2 PID: 179 Comm: kworker/u16:15 Not tainted 4.19.0-rc5-backup+ #1
Workqueue: bond0 bond_mii_monitor
RIP: 0010:netdev_lower_get_next_private_rcu+0x34/0x40
Code: 48 89 fb e8 fe 29 63 ff 85 c0 74 1e 48 8b 45 00 48 81 c3 c0 00 00 00 48 
8b 00 48 39 d8 74 0f 48 89 45 00 48 8b 40 f8 5b 5d c3 <0f> 0b eb de 31 c0 eb f5 
0f 1f 40 00 0f 1f 44 00 00 48 8>
RSP: 0018:c987fa68 EFLAGS: 00010046
RAX:  RBX: 880429614560 RCX: 
RDX: 0001 RSI:  RDI: a184ada0
RBP: c987fa80 R08: 0001 R09: 
R10: c987f9f0 R11: 880429798040 R12: 8804289d5980
R13: a1511f60 R14: 00c8 R15: 
FS:  () GS:88042f88() knlGS:
CS:  0010 DS:  ES:  CR0: 80050033
CR2: 7f4b78fce180 CR3: 00018180f006 CR4: 001606e0
Call Trace:
 bond_poll_controller+0x52/0x170
 netpoll_poll_dev+0x79/0x290
 netpoll_send_skb_on_dev+0x158/0x2c0
 netpoll_send_udp+0x2d5/0x430
 write_ext_msg+0x1e0/0x210
 console_unlock+0x3c4/0x630
 vprintk_emit+0xfa/0x2f0
 printk+0x52/0x6e
 ? __netdev_printk+0x12b/0x220
 netdev_info+0x64/0x80
 ? bond_3ad_set_carrier+0xe9/0x180
 bond_select_active_slave+0x1fc/0x310
 bond_mii_monitor+0x709/0x9b0
 process_one_work+0x221/0x5e0
 worker_thread+0x4f/0x3b0
 kthread+0x100/0x140
 ? process_one_work+0x5e0/0x5e0
 ? kthread_delayed_work_timer_fn+0x90/0x90
 ret_from_fork+0x24/0x30

Signed-off-by: Dave Jones 

diff --git a/drivers/net/bonding/bond_main.c b/drivers/net/bonding/bond_main.c
index a764a83f99da..519968d4513b 100644
--- a/drivers/net/bonding/bond_main.c
+++ b/drivers/net/bonding/bond_main.c
@@ -978,6 +978,7 @@ static void bond_poll_controller(struct net_device 
*bond_dev)
if (bond_3ad_get_active_agg_info(bond, _info))
return;
 
+   rcu_read_lock();
bond_for_each_slave_rcu(bond, slave, iter) {
ops = slave->dev->netdev_ops;
if (!bond_slave_is_up(slave) || !ops->ndo_poll_controller)
@@ -998,6 +999,7 @@ static void bond_poll_controller(struct net_device 
*bond_dev)
ops->ndo_poll_controller(slave->dev);
up(>dev_lock);
}
+   rcu_read_unlock();
 }
 
 static void bond_netpoll_cleanup(struct net_device *bond_dev)

ipset: suspicious RCU usage

[Dave Jones]

=
WARNING: suspicious RCU usage
4.16.0-rc3-firewall+ #1 Not tainted
-
net/netfilter/ipset/ip_set_core.c:1354 suspicious rcu_dereference_protected() 
usage!
\x0aother info that might help us debug this:\x0a
\x0arcu_scheduler_active = 2, debug_locks = 1
2 locks held by ipset/16323:
 #0: nlk_cb_mutex-NETFILTER ){+.+.} , at: [<5e54683c>] 
netlink_dump+0x1c/0x2b0
 #1: (ip_set_ref_lock){++..} , at: [<89f25f26>] 
ip_set_dump_start+0x133/0x7a0

stack backtrace:
CPU: 0 PID: 16323 Comm: ipset Not tainted 4.16.0-rc3-firewall+ #1 
Call Trace:
 dump_stack+0x67/0x8e
 ip_set_dump_start+0x5f0/0x7a0
 ? ip_set_dump_start+0x5/0x7a0
 ? __kmalloc_reserve.isra.38+0x29/0x70
 ? ksize+0x10/0xa0
 ? __alloc_skb+0x90/0x1b0
 netlink_dump+0x106/0x2b0
 netlink_recvmsg+0x337/0x380
 ? copy_msghdr_from_user+0xdb/0x150
 ___sys_recvmsg+0xc6/0x160
 ? netlink_sendmsg+0x129/0x420
 ? SYSC_sendto+0x11b/0x180
 __sys_recvmsg+0x51/0x90
 do_syscall_64+0x84/0x735
 ? trace_hardirqs_off_thunk+0x1a/0x1c
 entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x7fa78e00ca57
RSP: 002b:7fff61cfad78 EFLAGS: 0246
ORIG_RAX: 002f
RAX: ffda RBX: 55f22c7c06f0 RCX: 7fa78e00ca57
RDX:  RSI: 7fff61cfada0 RDI: 0003
RBP: 55f22c7bf4b8 R08: 7fa78dd1fbe0 R09: 000c
R10:  R11: 0246 R12: 1000
R13: 55f22c7c04d0 R14:  R15: 55f22bf13908

Re: [4.15-rc9] fs_reclaim lockdep trace

[Dave Jones]

On Sun, Jan 28, 2018 at 02:55:28PM +0900, Tetsuo Handa wrote:
 > Dave, would you try below patch?
 > 
 > >From cae2cbf389ae3cdef1b492622722b4aeb07eb284 Mon Sep 17 00:00:00 2001
 > From: Tetsuo Handa <penguin-ker...@i-love.sakura.ne.jp>
 > Date: Sun, 28 Jan 2018 14:17:14 +0900
 > Subject: [PATCH] lockdep: Fix fs_reclaim warning.


Seems to suppress the warning for me.

Tested-by: Dave Jones <da...@codemonkey.org.uk>

Re: [4.15-rc9] fs_reclaim lockdep trace

[Dave Jones]

On Tue, Jan 23, 2018 at 08:36:51PM -0500, Dave Jones wrote:
 > Just triggered this on a server I was rsync'ing to.

Actually, I can trigger this really easily, even with an rsync from one
disk to another.  Though that also smells a little like networking in
the traces. Maybe netdev has ideas.

 
The first instance:

 > 
 > WARNING: possible recursive locking detected
 > 4.15.0-rc9-backup-debug+ #1 Not tainted
 > 
 > sshd/24800 is trying to acquire lock:
 >  (fs_reclaim){+.+.}, at: [<84f438c2>] 
 > fs_reclaim_acquire.part.102+0x5/0x30
 > 
 > but task is already holding lock:
 >  (fs_reclaim){+.+.}, at: [<84f438c2>] 
 > fs_reclaim_acquire.part.102+0x5/0x30
 > 
 > other info that might help us debug this:
 >  Possible unsafe locking scenario:
 > 
 >CPU0
 >
 >   lock(fs_reclaim);
 >   lock(fs_reclaim);
 > 
 >  *** DEADLOCK ***
 > 
 >  May be due to missing lock nesting notation
 > 
 > 2 locks held by sshd/24800:
 >  #0:  (sk_lock-AF_INET6){+.+.}, at: [<1a069652>] 
 > tcp_sendmsg+0x19/0x40
 >  #1:  (fs_reclaim){+.+.}, at: [<84f438c2>] 
 > fs_reclaim_acquire.part.102+0x5/0x30
 > 
 > stack backtrace:
 > CPU: 3 PID: 24800 Comm: sshd Not tainted 4.15.0-rc9-backup-debug+ #1
 > Call Trace:
 >  dump_stack+0xbc/0x13f
 >  ? _atomic_dec_and_lock+0x101/0x101
 >  ? fs_reclaim_acquire.part.102+0x5/0x30
 >  ? print_lock+0x54/0x68
 >  __lock_acquire+0xa09/0x2040
 >  ? debug_show_all_locks+0x2f0/0x2f0
 >  ? mutex_destroy+0x120/0x120
 >  ? hlock_class+0xa0/0xa0
 >  ? kernel_text_address+0x5c/0x90
 >  ? __kernel_text_address+0xe/0x30
 >  ? unwind_get_return_address+0x2f/0x50
 >  ? __save_stack_trace+0x92/0x100
 >  ? graph_lock+0x8d/0x100
 >  ? check_noncircular+0x20/0x20
 >  ? __lock_acquire+0x616/0x2040
 >  ? debug_show_all_locks+0x2f0/0x2f0
 >  ? __lock_acquire+0x616/0x2040
 >  ? debug_show_all_locks+0x2f0/0x2f0
 >  ? print_irqtrace_events+0x110/0x110
 >  ? active_load_balance_cpu_stop+0x7b0/0x7b0
 >  ? debug_show_all_locks+0x2f0/0x2f0
 >  ? mark_lock+0x1b1/0xa00
 >  ? lock_acquire+0x12e/0x350
 >  lock_acquire+0x12e/0x350
 >  ? fs_reclaim_acquire.part.102+0x5/0x30
 >  ? lockdep_rcu_suspicious+0x100/0x100
 >  ? set_next_entity+0x20e/0x10d0
 >  ? mark_lock+0x1b1/0xa00
 >  ? match_held_lock+0x8d/0x440
 >  ? mark_lock+0x1b1/0xa00
 >  ? save_trace+0x1e0/0x1e0
 >  ? print_irqtrace_events+0x110/0x110
 >  ? alloc_extent_state+0xa7/0x410
 >  fs_reclaim_acquire.part.102+0x29/0x30
 >  ? fs_reclaim_acquire.part.102+0x5/0x30
 >  kmem_cache_alloc+0x3d/0x2c0
 >  ? rb_erase+0xe63/0x1240
 >  alloc_extent_state+0xa7/0x410
 >  ? lock_extent_buffer_for_io+0x3f0/0x3f0
 >  ? find_held_lock+0x6d/0xd0
 >  ? test_range_bit+0x197/0x210
 >  ? lock_acquire+0x350/0x350
 >  ? do_raw_spin_unlock+0x147/0x220
 >  ? do_raw_spin_trylock+0x100/0x100
 >  ? iotree_fs_info+0x30/0x30
 >  __clear_extent_bit+0x3ea/0x570
 >  ? clear_state_bit+0x270/0x270
 >  ? count_range_bits+0x2f0/0x2f0
 >  ? lock_acquire+0x350/0x350
 >  ? rb_prev+0x21/0x90
 >  try_release_extent_mapping+0x21a/0x260
 >  __btrfs_releasepage+0xb0/0x1c0
 >  ? btrfs_submit_direct+0xca0/0xca0
 >  ? check_new_page_bad+0x1f0/0x1f0
 >  ? match_held_lock+0xa5/0x440
 >  ? debug_show_all_locks+0x2f0/0x2f0
 >  btrfs_releasepage+0x161/0x170
 >  ? __btrfs_releasepage+0x1c0/0x1c0
 >  ? page_rmapping+0xd0/0xd0
 >  ? rmap_walk+0x100/0x100
 >  try_to_release_page+0x162/0x1c0
 >  ? generic_file_write_iter+0x3c0/0x3c0
 >  ? page_evictable+0xcc/0x110
 >  ? lookup_address_in_pgd+0x107/0x190
 >  shrink_page_list+0x1d5a/0x2fb0
 >  ? putback_lru_page+0x3f0/0x3f0
 >  ? save_trace+0x1e0/0x1e0
 >  ? _lookup_address_cpa.isra.13+0x40/0x60
 >  ? debug_show_all_locks+0x2f0/0x2f0
 >  ? kmem_cache_free+0x8c/0x280
 >  ? free_extent_state+0x1c8/0x3b0
 >  ? mark_lock+0x1b1/0xa00
 >  ? page_rmapping+0xd0/0xd0
 >  ? print_irqtrace_events+0x110/0x110
 >  ? shrink_node_memcg.constprop.88+0x4c9/0x5e0
 >  ? shrink_node+0x12d/0x260
 >  ? try_to_free_pages+0x418/0xaf0
 >  ? __alloc_pages_slowpath+0x976/0x1790
 >  ? __alloc_pages_nodemask+0x52c/0x5c0
 >  ? delete_node+0x28d/0x5c0
 >  ? find_held_lock+0x6d/0xd0
 >  ? free_pcppages_bulk+0x381/0x570
 >  ? lock_acquire+0x350/0x350
 >  ? do_raw_spin_unlock+0x147/0x220
 >  ? do_raw_spin_trylock+0x100/0x100
 >  ? __lock_is_held+0x51/0xc0
 >  ? _raw_spin_unlock+0x24/0x30
 >  ? free_pcppages_bulk+0x381/0x570
 >  ? mark_lock+0x1b1/0xa00
 >  ? free_compound_page+0x30/0x30
 >  ? print_irqtrace_events+0x110/0x110
 >  ? __kernel_map_pages+0x2c9/0x310
 >  ? mark_lock+0

ipset related DEBUG_VIRTUAL crash.

[Dave Jones]

I have a script that hourly replaces an ipset list. This has been in
place for a year or so, but last night it triggered this on 4.14-rc7

[455951.731181] kernel BUG at arch/x86/mm/physaddr.c:26!
[455951.737016] invalid opcode:  [#1] PREEMPT SMP DEBUG_PAGEALLOC KASAN
[455951.742525] CPU: 0 PID: 3850 Comm: ipset Not tainted 4.14.0-rc7-firewall+ 
#1 
[455951.753293] task: 88013033cfc0 task.stack: 8801c3d48000
[455951.758567] RIP: 0010:__phys_addr+0x5b/0x80
[455951.763742] RSP: 0018:8801c3d4f528 EFLAGS: 00010287
[455951.768838] RAX: 7800849b62b6 RBX: 849b62b6 RCX: 
9f072a5d
[455951.773881] RDX: dc00 RSI: dc00 RDI: 
a06917e0
[455951.778844] RBP: 7800049b62b6 R08: 0002 R09: 

[455951.783729] R10:  R11:  R12: 
9fca8b05
[455951.788524] R13: 8801ce844268 R14: 049b62b6 R15: 
8801ce8442ea
[455951.793239] FS:  7fb44e656c80() GS:8801d320() 
knlGS:
[455951.797904] CS:  0010 DS:  ES:  CR0: 80050033
[455951.802479] CR2: 7ffeeafd70a8 CR3: 0001b6cd2001 CR4: 
000606f0
[455951.806998] Call Trace:
[455951.811404]  kfree+0x4c/0x310
[455951.815714]  hash_ip4_ahash_destroy+0x85/0xd0
[455951.819944]  hash_ip4_destroy+0x64/0x90
[455951.824069]  ip_set_destroy+0x4f0/0x500
[455951.828098]  ? ip_set_destroy+0x5/0x500
[455951.832029]  ? __rcu_read_unlock+0xd3/0x190
[455951.835867]  ? ip_set_utest+0x560/0x560
[455951.839610]  ? ip_set_utest+0x560/0x560
[455951.843239]  nfnetlink_rcv_msg+0x73e/0x770
[455951.846780]  ? nfnetlink_rcv_msg+0x352/0x770
[455951.850229]  ? nfnetlink_rcv+0xe90/0xe90
[455951.853571]  ? native_sched_clock+0xe8/0x190
[455951.856822]  ? lock_release+0x5d3/0x7d0
[455951.859976]  netlink_rcv_skb+0x121/0x230
[455951.863037]  ? nfnetlink_rcv+0xe90/0xe90
[455951.865999]  ? netlink_ack+0x4c0/0x4c0
[455951.868866]  ? ns_capable_common+0x68/0xc0
[455951.871638]  nfnetlink_rcv+0x1ad/0xe90
[455951.874312]  ? lock_acquire+0x380/0x380
[455951.876891]  ? __rcu_read_unlock+0xd3/0x190
[455951.879378]  ? __rcu_read_lock+0x30/0x30
[455951.881764]  ? rcu_is_watching+0xa4/0xf0
[455951.884048]  ? netlink_connect+0x1e0/0x1e0
[455951.886236]  ? nfnl_err_reset+0x180/0x180
[455951.888329]  ? netlink_deliver_tap+0x128/0x560
[455951.890333]  ? netlink_deliver_tap+0x5/0x560
[455951.892229]  ? iov_iter_advance+0x172/0x7f0
[455951.894029]  ? netlink_getname+0x150/0x150
[455951.895736]  ? can_nice.part.77+0x20/0x20
[455951.897342]  ? iov_iter_copy_from_user_atomic+0x7d0/0x7d0
[455951.898877]  ? netlink_trim+0x111/0x1b0
[455951.900394]  ? netlink_skb_destructor+0xf0/0xf0
[455951.901908]  netlink_unicast+0x2b1/0x340
[455951.903397]  ? netlink_detachskb+0x30/0x30
[455951.904862]  ? lock_acquire+0x380/0x380
[455951.906299]  ? lockdep_rcu_suspicious+0x100/0x100
[455951.907729]  netlink_sendmsg+0x4f2/0x650
[455951.909141]  ? netlink_broadcast_filtered+0x9e0/0x9e0
[455951.910565]  ? _copy_from_user+0x86/0xc0
[455951.911964]  ? netlink_broadcast_filtered+0x9e0/0x9e0
[455951.913364]  SYSC_sendto+0x2f0/0x3c0
[455951.914741]  ? SYSC_connect+0x210/0x210
[455951.916111]  ? bad_area_access_error+0x230/0x230
[455951.917479]  ? ___sys_recvmsg+0x320/0x320
[455951.918811]  ? sock_wake_async+0xc0/0xc0
[455951.920112]  ? SyS_brk+0x3ae/0x3d0
[455951.921381]  ? prepare_exit_to_usermode+0xde/0x230
[455951.922642]  ? enter_from_user_mode+0x30/0x30
[455951.923913]  ? mark_held_locks+0x1b/0xa0
[455951.925179]  ? entry_SYSCALL_64_fastpath+0x5/0xad
[455951.926459]  ? trace_hardirqs_on_caller+0x185/0x260
[455951.927747]  ? trace_hardirqs_on_thunk+0x1a/0x1c
[455951.929031]  entry_SYSCALL_64_fastpath+0x18/0xad
[455951.930314] RIP: 0033:0x7fb44df4ac53
[455951.931592] RSP: 002b:7ffeeafb6a08 EFLAGS: 0246
[455951.932914]  ORIG_RAX: 002c
[455951.934231] RAX: ffda RBX: 55b8f35d26d0 RCX: 
7fb44df4ac53
[455951.935603] RDX: 002c RSI: 55b8f35d14b8 RDI: 
0003
[455951.936991] RBP: 55b8f35cf010 R08: 7fb44dc5dbe0 R09: 
000c
[455951.938387] R10:  R11: 0246 R12: 
7fb44e43b020
[455951.939795] R13: 7ffeeafb6acc R14:  R15: 
55b8f1ca68e0
[455951.941208] Code: 80 48 39 eb 72 25 48 c7 c7 09 d6 a4 a0 e8 3e 28 2c 00 0f 
b6 0d 80 ab 9d 01 48 8d 45 00 48 d3 e8 48 85 c0 75 06 5b 48 89 e8 5d c3 <0f> 0b 
48 c7 c7 10 c0 62 a0 e8 a7 2a 2c 00 48 8b 2d 60 95 5b 01 
[455951.993251] RIP: __phys_addr+0x5b/0x80 RSP: 8801c3d4f528
[455982.040898] ---[ end trace dfb8a0f07b7c5316 ]---
[459428.674105] 
==
[459428.679829] BUG: KASAN: use-after-free in __mutex_lock+0x26c/0xf30
[459428.685463] Read of size 4 at addr 88013033d020 by task ipset/4611
[459428.696474] CPU: 0 PID: 4611 Comm: ipset Tainted: G  D 
4.14.0-rc7-firewall+ #1 
[459428.707271] Call Trace:
[459428.712489]  

Re: [4.14rc6] __tcp_select_window divide by zero.

[Dave Jones]

On Tue, Oct 24, 2017 at 09:00:30AM -0400, Dave Jones wrote:
 > divide error:  [#1] SMP KASAN
 > CPU: 0 PID: 31140 Comm: trinity-c12 Not tainted 4.14.0-rc6-think+ #1 
 > RIP: 0010:__tcp_select_window+0x21f/0x400
 > Call Trace:
 >  tcp_cleanup_rbuf+0x27d/0x2a0
 >  tcp_recvmsg+0x7a9/0x1430
 >  inet_recvmsg+0x10b/0x360
 >  sock_read_iter+0x19d/0x240
 >  do_iter_readv_writev+0x2e4/0x320
 >  do_iter_read+0x149/0x280
 >  vfs_readv+0x107/0x180
 >  do_readv+0xc0/0x1b0
 >  do_syscall_64+0x182/0x400
 >  entry_SYSCALL64_slow_path+0x25/0x25
 > Code: 41 5e 41 5f c3 48 8d bb 48 09 00 00 e8 4b 2b 30 ff 8b 83 48 09 00 00 
 > 89 ea 44 29 f2 39 c2 7d 08 39 c5 0f 8d 86 01 00 00 89 e8 99 <41> f7 fe 89 e8 
 > 29 d0 eb 8c 41 f7 df 48 89 c7 44 89 f9 d3 fd e8 
 > RIP: __tcp_select_window+0x21f/0x400 RSP: 8803df54f418
 > 
 >
 >if (window <= free_space - mss || window > free_space)
 >window = rounddown(free_space, mss);

I'm still hitting this fairly often, so I threw in a debug patch, and
when this happens..

[53182.361210] window: 0 free_space: 0 mss: 0

Any suggestions on what we should default the window size to be in
this situation to avoid the rounddown ?


Dave

[net-next] tcp_delack_timer circular locking dependancy

[Dave Jones]

[  105.316650] ==
[  105.316818] WARNING: possible circular locking dependency detected
[  105.316986] 4.14.0-rc7-think+ #1 Not tainted
[  105.317108] --
[  105.317273] swapper/2/0 is trying to acquire lock:
[  105.317407]  (
[  105.317476] slock-AF_INET6
[  105.317564] ){+.-.}
[  105.317642] , at: [] tcp_delack_timer+0x26/0x130
[  105.317807] 
   but task is already holding lock:
[  105.317961]  (
[  105.318024] (timer)
[  105.318097] #5
[  105.318168] ){+.-.}
[  105.318241] , at: [] call_timer_fn+0x5/0x5e0
[  105.318393] 
   which lock already depends on the new lock.

[  105.318594] 
   the existing dependency chain (in reverse order) is:
[  105.318781] 
   -> #1
[  105.318879]  (
[  105.318939] (timer)
[  105.319009] #5
[  105.319068] ){+.-.}
[  105.319137] :
[  105.319195]del_timer_sync+0x3c/0xb0
[  105.319313]inet_csk_reqsk_queue_drop+0x26c/0x4e0
[  105.319459]inet_csk_complete_hashdance+0x1e/0x90
[  105.319598]tcp_check_req+0x787/0x9a0
[  105.319716]tcp_v6_rcv+0x914/0x1060
[  105.319828]ip6_input_finish+0x291/0xba0
[  105.319950]ip6_input+0xb2/0x380
[  105.320059]ip6_rcv_finish+0x103/0x350
[  105.320180]ipv6_rcv+0x93f/0xff0
[  105.320291]__netif_receive_skb_core+0x13ef/0x1900
[  105.320436]netif_receive_skb_internal+0xea/0x4c0
[  105.320579]napi_gro_receive+0x28e/0x320
[  105.320705]e1000_clean_rx_irq+0x3e9/0x6f0
[  105.320838]e1000e_poll+0x14e/0x570
[  105.320954]net_rx_action+0x4db/0xc80
[  105.321075]__do_softirq+0x1ca/0x7bf
[  105.321194]irq_exit+0x104/0x110
[  105.321303]do_IRQ+0xb2/0x130
[  105.321407]ret_from_intr+0x0/0x19
[  105.321523]cpuidle_enter_state+0x223/0x5b0
[  105.321655]do_idle+0x110/0x1b0
[  105.321766]cpu_startup_entry+0xdb/0xe0
[  105.321891]start_secondary+0x2e9/0x360
[  105.322014]verify_cpu+0x0/0xf1
[  105.322121] 
   -> #0
[  105.322215]  (
[  105.322276] slock-AF_INET6
[  105.322359] ){+.-.}
[  105.322428] :
[  105.322487]lock_acquire+0x12e/0x350
[  105.322602]_raw_spin_lock+0x30/0x70
[  105.322722]tcp_delack_timer+0x26/0x130
[  105.322846]call_timer_fn+0x188/0x5e0
[  105.322966]__run_timers+0x54d/0x670
[  105.323084]run_timer_softirq+0x2a/0x50
[  105.323208]__do_softirq+0x1ca/0x7bf
[  105.323325]irq_exit+0x104/0x110
[  105.323435]smp_apic_timer_interrupt+0x14b/0x510
[  105.323576]apic_timer_interrupt+0x9a/0xa0
[  105.323705]cpuidle_enter_state+0x223/0x5b0
[  105.323836]do_idle+0x110/0x1b0
[  105.323944]cpu_startup_entry+0xdb/0xe0
[  105.324067]start_secondary+0x2e9/0x360
[  105.324189]verify_cpu+0x0/0xf1
[  105.324295] 
   other info that might help us debug this:

[  105.324489]  Possible unsafe locking scenario:

[  105.324644]CPU0CPU1
[  105.324767]
[  105.324890]   lock(
[  105.324963] (timer)
[  105.325033] #5
[  105.325093] );
[  105.325152]lock(
[  105.325278] slock-AF_INET6
[  105.325360] );
[  105.325419]lock(
[  105.325544] (timer)
[  105.325612] #5
[  105.325670] );
[  105.325729]   lock(
[  105.325797] slock-AF_INET6
[  105.325879] );
[  105.325938] 
*** DEADLOCK ***

[  105.326086] 1 lock held by swapper/2/0:
[  105.326193]  #0: 
[  105.326257]  (
[  105.331697] (timer)
[  105.337038] #5
[  105.342339] ){+.-.}
[  105.347620] , at: [] call_timer_fn+0x5/0x5e0
[  105.353021] 
   stack backtrace:
[  105.363515] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 4.14.0-rc7-think+ #1
[  105.368886] Hardware name: LENOVO ThinkServer TS140/ThinkServer TS140, BIOS 
FBKTB3AUS 06/16/2015
[  105.374330] Call Trace:
[  105.379697]  
[  105.384997]  dump_stack+0xbc/0x145
[  105.390339]  ? dma_virt_map_sg+0xfb/0xfb
[  105.395733]  ? call_timer_fn+0x5/0x5e0
[  105.401076]  ? print_lock+0x54/0x68
[  105.406344]  print_circular_bug.isra.42+0x283/0x2bc
[  105.411695]  ? print_circular_bug_header+0xda/0xda
[  105.417054]  ? graph_lock+0x8d/0x100
[  105.422419]  ? check_noncircular+0x20/0x20
[  105.427857]  ? sched_clock_cpu+0x14/0xf0
[  105.433309]  __lock_acquire+0x1f4a/0x2050
[  105.438725]  ? debug_check_no_locks_freed+0x1a0/0x1a0
[  105.444160]  ? __lock_acquire+0x6b3/0x2050
[  105.449580]  ? debug_check_no_locks_freed+0x1a0/0x1a0
[  105.455015]  ? sched_clock_cpu+0x14/0xf0
[  105.460514]  ? __lock_acquire+0x6b3/0x2050
[  105.465984]  ? cyc2ns_read_end+0x10/0x10
[  105.471395]  ? debug_check_no_locks_freed+0x1a0/0x1a0
[  105.476934]  ? mark_lock+0x16f/0x9b0
[  105.482507]  ? print_irqtrace_events+0x110/0x110
[  105.488150]  ? 

[4.14rc6] __tcp_select_window divide by zero.

[Dave Jones]

divide error:  [#1] SMP KASAN
CPU: 0 PID: 31140 Comm: trinity-c12 Not tainted 4.14.0-rc6-think+ #1 
task: 8803c0d08040 task.stack: 8803df548000
RIP: 0010:__tcp_select_window+0x21f/0x400
RSP: 0018:8803df54f418 EFLAGS: 00010246
RAX:  RBX: 880458fd3140 RCX: 82120ea5
RDX:  RSI: dc00 RDI: 880458fd3a88
RBP:  R08: 0001 R09: 
R10:  R11:  R12: 00098968
R13: 11007bea9e87 R14:  R15: 
FS:  7f76da1db700() GS:88046ae0() knlGS:
CS:  0010 DS:  ES:  CR0: 80050033
CR2:  CR3: 0003f67cd002 CR4: 001606f0
DR0: 7f76d819f000 DR1: 7f75a29f5000 DR2: 
DR3:  DR6: 0ff0 DR7: 0600
Call Trace:
 ? tcp_schedule_loss_probe+0x270/0x270
 ? lock_acquire+0x12e/0x350
 ? tcp_recvmsg+0x124/0x1430
 ? lock_release+0x890/0x890
 ? do_raw_spin_trylock+0x100/0x100
 ? do_raw_spin_trylock+0x40/0x100
 tcp_cleanup_rbuf+0x27d/0x2a0
 ? tcp_recv_skb+0x180/0x180
 ? mark_held_locks+0x70/0xa0
 ? __local_bh_enable_ip+0x60/0x90
 tcp_recvmsg+0x7a9/0x1430
 ? tcp_recv_timestamp+0x250/0x250
 ? __free_insn_slot+0x390/0x390
 ? rcu_is_watching+0x88/0xd0
 ? entry_SYSCALL64_slow_path+0x25/0x25
 ? is_bpf_text_address+0x86/0xf0
 ? kernel_text_address+0xec/0x100
 ? __kernel_text_address+0xe/0x30
 ? unwind_get_return_address+0x2f/0x50
 ? __save_stack_trace+0x92/0x100
 ? memcmp+0x45/0x70
 ? match_held_lock+0x93/0x410
 ? save_trace+0x1c0/0x1c0
 ? save_stack+0x89/0xb0
 ? save_stack+0x32/0xb0
 ? kasan_kmalloc+0xa0/0xd0
 ? native_sched_clock+0xf9/0x1a0
 ? rw_copy_check_uvector+0x15e/0x180
 inet_recvmsg+0x10b/0x360
 ? inet_create+0x770/0x770
 ? sched_clock_cpu+0x14/0xf0
 ? sched_clock_cpu+0x14/0xf0
 sock_read_iter+0x19d/0x240
 ? sock_recvmsg+0x60/0x60
 do_iter_readv_writev+0x2e4/0x320
 ? vfs_dedupe_file_range+0x3e0/0x3e0
 do_iter_read+0x149/0x280
 vfs_readv+0x107/0x180
 ? compat_rw_copy_check_uvector+0x1d0/0x1d0
 ? fget_raw+0x10/0x10
 ? __lock_is_held+0x2e/0xd0
 ? do_preadv+0xf0/0xf0
 ? __fdget_pos+0x82/0x110
 ? __fdget_raw+0x10/0x10
 ? do_readv+0xc0/0x1b0
 do_readv+0xc0/0x1b0
 ? vfs_readv+0x180/0x180
 ? mark_held_locks+0x1b/0xa0
 ? do_syscall_64+0xae/0x400
 ? do_preadv+0xf0/0xf0
 do_syscall_64+0x182/0x400
 ? syscall_return_slowpath+0x270/0x270
 ? rcu_read_lock_sched_held+0x90/0xa0
 ? __context_tracking_exit.part.4+0x223/0x290
 ? mark_held_locks+0x1b/0xa0
 ? return_from_SYSCALL_64+0x2d/0x7a
 ? trace_hardirqs_on_caller+0x17a/0x250
 ? trace_hardirqs_on_thunk+0x1a/0x1c
 entry_SYSCALL64_slow_path+0x25/0x25
RIP: 0033:0x7f76d9b05219
RSP: 002b:7ffd41fd30d8 EFLAGS: 0246  ORIG_RAX: 0013
RAX: ffda RBX: 0013 RCX: 7f76d9b05219
RDX: 0016 RSI: 5611ca731c70 RDI: 0179
RBP: 7ffd41fd3180 R08: 00a07395 R09: 000a10d65a68
R10: 0001 R11: 0246 R12: 0002
R13: 7f76da180058 R14: 7f76da1db698 R15: 7f76da18
Code: 41 5e 41 5f c3 48 8d bb 48 09 00 00 e8 4b 2b 30 ff 8b 83 48 09 00 00 89 
ea 44 29 f2 39 c2 7d 08 39 c5 0f 8d 86 01 00 00 89 e8 99 <41> f7 fe 89 e8 29 d0 
eb 8c 41 f7 df 48 89 c7 44 89 f9 d3 fd e8 
RIP: __tcp_select_window+0x21f/0x400 RSP: 8803df54f418



window = rounddown(free_space, mss);
45ec:   89 e8   mov%ebp,%eax
45ee:   99  cltd   
45ef:   41 f7 feidiv   %r14d
45f2:   89 e8   mov%ebp,%eax
45f4:   29 d0   sub%edx,%eax
45f6:   eb 8c   jmp4584 <__tcp_select_window+0x1b4>
45f8:   41 f7 dfneg%r15d

BUG_ON(sg->sg_magic != SG_MAGIC) on tls socket.

[Dave Jones]

kernel BUG at ./include/linux/scatterlist.h:189!
invalid opcode:  [#1] SMP KASAN
CPU: 3 PID: 20890 Comm: trinity-c51 Not tainted 4.13.0-rc4-think+ #5 
task: 88036e3d1cc0 task.stack: 88033e9d8000
RIP: 0010:tls_push_record+0x675/0x680
RSP: 0018:88033e9df630 EFLAGS: 00010287
RAX:  RBX: 8802ee3b8968 RCX: 82226754
RDX: dc00 RSI: dc00 RDI: 8802ee3b8c10
RBP: 88033e9df6d0 R08:  R09: ed005d107004
R10: 0004 R11: ed005d107003 R12: 880341b30668
R13: 8802ee3b8c10 R14: 8802ee3b8c38 R15: 87654321
FS:  7f465ced2700() GS:88046b60() knlGS:
CS:  0010 DS:  ES:  CR0: 80050033
CR2: 0029cbf021f8 CR3: 00045abd CR4: 001406e0
DR0: 7f8f17bd2000 DR1: 7f8c27d0f000 DR2: 
DR3:  DR6: 0ff0 DR7: 0600
Call Trace:
 ? copy_page_to_iter+0x6c0/0x6c0
 tls_sw_sendmsg+0x6d8/0x9c0
 ? alloc_sg+0x510/0x510
 ? cyc2ns_read_end+0x10/0x10
 ? import_iovec+0xa8/0x1f0
 ? do_syscall_64+0x1bc/0x3e0
 ? entry_SYSCALL64_slow_path+0x25/0x25
 inet_sendmsg+0xce/0x310
 ? inet_recvmsg+0x3a0/0x3a0
 ? inet_recvmsg+0x3a0/0x3a0
 sock_write_iter+0x1b0/0x280
 ? kernel_sendmsg+0x70/0x70
 ? __might_sleep+0x72/0xe0
 do_iter_readv_writev+0x29a/0x370
 ? vfs_dedupe_file_range+0x3f0/0x3f0
 ? rw_verify_area+0x65/0x150
 do_iter_write+0xd7/0x2a0
 ? __hrtimer_run_queues+0x980/0x980
 vfs_writev+0x142/0x220
 ? __fget_light+0x1ae/0x230
 ? vfs_iter_write+0x70/0x70
 ? syscall_exit_register+0x3f0/0x3f0
 ? rcutorture_record_progress+0x20/0x20
 ? __fdget_pos+0x88/0x120
 ? __fdget_raw+0x20/0x20
 do_writev+0xd2/0x1c0
 ? do_writev+0xd2/0x1c0
 ? vfs_writev+0x220/0x220
 ? mark_held_locks+0x23/0xb0
 ? do_syscall_64+0xc0/0x3e0
 ? SyS_readv+0x20/0x20
 SyS_writev+0x10/0x20
 do_syscall_64+0x1bc/0x3e0
 ? syscall_return_slowpath+0x240/0x240
 ? __context_tracking_exit.part.5+0x23d/0x2a0
 ? cpumask_check.part.2+0x10/0x10
 ? mark_held_locks+0x23/0xb0
 ? return_from_SYSCALL_64+0x2d/0x7a
 ? trace_hardirqs_on_caller+0x182/0x260
 ? trace_hardirqs_on_thunk+0x1a/0x1c
 entry_SYSCALL64_slow_path+0x25/0x25
RIP: 0033:0x7f465c7fd219
RSP: 002b:7ffda332a238 EFLAGS: 0246
 ORIG_RAX: 0014
RAX: ffda RBX: 0014 RCX: 7f465c7fd219
RDX: 0047 RSI: 0029cbef1b50 RDI: 0137
RBP: 7ffda332a2e0 R08: 0100 R09: fff8
R10: fff9 R11: 0246 R12: 0002
R13: 7f465cd66058 R14: 7f465ced2698 R15: 7f465cd66000
Code: 8d bb 58 04 00 00 e8 3b d5 20 ff 48 8b 83 58 04 00 00 f0 80 48 08 04 48 
83 c4 78 44 89 f0 5b 41 5c 41 5d 41 5e 41 5f 5d c3 0f 0b <0f> 0b 0f 0b 0f 0b 0f 
1f 44 00 00 0f 1f 44 00 00 55 ba 17 00 00 
RIP: tls_push_record+0x675/0x680 RSP: 88033e9df630



186 static inline void sg_mark_end(struct scatterlist *sg)
187 {
188 #ifdef CONFIG_DEBUG_SG
189 BUG_ON(sg->sg_magic != SG_MAGIC);
190 #endif

KASAN: slab-out-of-bounds from net_namespace.c:ops_init

[Dave Jones]

==
BUG: KASAN: slab-out-of-bounds in ops_init+0x201/0x330
Write of size 8 at addr 88045744c448 by task trinity-c4/1499

CPU: 2 PID: 1499 Comm: trinity-c4 Not tainted 4.13.0-rc4-think+ #5 
Call Trace:
 dump_stack+0xc5/0x151
 ? dma_virt_map_sg+0xff/0xff
 ? show_regs_print_info+0x41/0x41
 print_address_description+0xd9/0x260
 kasan_report+0x27a/0x370
 ? ops_init+0x201/0x330
 __asan_store8+0x57/0x90
 ops_init+0x201/0x330
 ? net_alloc_generic+0x50/0x50
 ? __raw_spin_lock_init+0x21/0x80
 ? trace_hardirqs_on_caller+0x182/0x260
 ? lockdep_init_map+0xb2/0x2b0
 setup_net+0x208/0x400
 ? ops_init+0x330/0x330
 ? copy_net_ns+0x151/0x390
 ? can_nice.part.81+0x20/0x20
 ? rcu_is_watching+0x8d/0xd0
 ? __lock_is_held+0x30/0xd0
 ? rcutorture_record_progress+0x20/0x20
 ? copy_net_ns+0x151/0x390
 copy_net_ns+0x200/0x390
 ? net_drop_ns+0x20/0x20
 ? do_mount+0x19d0/0x19d0
 ? create_new_namespaces+0x97/0x450
 ? rcu_read_lock_sched_held+0x96/0xa0
 ? kmem_cache_alloc+0x28a/0x2f0
 create_new_namespaces+0x317/0x450
 ? sys_ni_syscall+0x20/0x20
 ? cap_capable+0x7f/0xf0
 unshare_nsproxy_namespaces+0x77/0xf0
 SyS_unshare+0x573/0xbb0
 ? walk_process_tree+0x2a0/0x2a0
 ? lock_release+0x920/0x920
 ? lock_release+0x920/0x920
 ? mntput_no_expire+0x117/0x620
 ? rcu_is_watching+0x8d/0xd0
 ? exit_to_usermode_loop+0x1b0/0x1b0
 ? rcu_read_lock_sched_held+0x96/0xa0
 ? __context_tracking_exit.part.5+0x23d/0x2a0
 ? cpumask_check.part.2+0x10/0x10
 ? context_tracking_user_exit+0x30/0x30
 ? __f_unlock_pos+0x15/0x20
 ? SyS_read+0x146/0x160
 ? do_syscall_64+0xc0/0x3e0
 ? walk_process_tree+0x2a0/0x2a0
 do_syscall_64+0x1bc/0x3e0
 ? syscall_return_slowpath+0x240/0x240
 ? mark_held_locks+0x23/0xb0
 ? return_from_SYSCALL_64+0x2d/0x7a
 ? trace_hardirqs_on_caller+0x182/0x260
 ? trace_hardirqs_on_thunk+0x1a/0x1c
 entry_SYSCALL64_slow_path+0x25/0x25
RIP: 0033:0x7f9e1c454219
RSP: 002b:7fff180f9c88 EFLAGS: 0246
 ORIG_RAX: 0110
RAX: ffda RBX: 0110 RCX: 7f9e1c454219
RDX: 00c4 RSI: 800ff000 RDI: 74060700
RBP: 7fff180f9d30 R08: 0002 R09: 2fa420810090095e
R10: 880ffb40 R11: 0246 R12: 0002
R13: 7f9e1cb06058 R14: 7f9e1cb29698 R15: 7f9e1cb06000

Allocated by task 1499:
 save_stack_trace+0x1b/0x20
 save_stack+0x43/0xd0
 kasan_kmalloc+0xad/0xe0
 __kmalloc+0x14b/0x370
 net_alloc_generic+0x25/0x50
 copy_net_ns+0x130/0x390
 create_new_namespaces+0x317/0x450
 unshare_nsproxy_namespaces+0x77/0xf0
 SyS_unshare+0x573/0xbb0
 do_syscall_64+0x1bc/0x3e0
 return_from_SYSCALL_64+0x0/0x7a

Freed by task 504:
 save_stack_trace+0x1b/0x20
 save_stack+0x43/0xd0
 kasan_slab_free+0x72/0xc0
 kfree+0xe1/0x2f0
 rcu_process_callbacks+0x5a6/0x1dc0
 __do_softirq+0x1e7/0x817

The buggy address belongs to the object at 88045744c3c8
 which belongs to the cache kmalloc-128 of size 128
The buggy address is located 0 bytes to the right of
 128-byte region [88045744c3c8, 88045744c448)
The buggy address belongs to the page:
page:ea00115d1300 count:1 mapcount:0 mapping:  (null) index:0x0
 compound_mapcount: 0
flags: 0x80008100(slab|head)
raw: 80008100   000100110011
raw: ea00113f2b20 ea0011328a20 880467c0f140 
page dumped because: kasan: bad access detected

Memory state around the buggy address:
 88045744c300: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
 88045744c380: fc fc fc fc fc fc fc fc fc 00 00 00 00 00 00 00
>88045744c400: 00 00 00 00 00 00 00 00 00 fc fc fc fc fc fc fc
  ^
 88045744c480: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
 88045744c500: fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc fc
==

Re: sctp refcount bug.

[Dave Jones]

On Thu, Jul 13, 2017 at 11:38:34AM -0300, Marcelo Ricardo Leitner wrote:
 > On Thu, Jul 13, 2017 at 10:36:39AM -0400, Dave Jones wrote:
 > > Hit this on Linus' current tree.
 > > 
 > > 
 > > refcount_t: underflow; use-after-free.
 > 
 > Any tips on how to reproduce this?

Only seen it once so far. Will see if I can narrow it down if it
reproduces.  It took ~12 hours of fuzzing to find overnight.

Dave

sctp refcount bug.

[Dave Jones]

Hit this on Linus' current tree.


refcount_t: underflow; use-after-free.
[ cut here ]
WARNING: CPU: 2 PID: 14455 at lib/refcount.c:186 refcount_sub_and_test+0x45/0x50
CPU: 2 PID: 14455 Comm: trinity-c46 Tainted: G  D 4.12.0-think+ #11 
task: 8804fc71b8c0 task.stack: c90002328000
RIP: 0010:refcount_sub_and_test+0x45/0x50
RSP: 0018:c9000232ba58 EFLAGS: 00010282
RAX: 0026 RBX: 88001db1d1c0 RCX: 
RDX:  RSI: 88050a3ccca8 RDI: 88050a3ccca8
RBP: c9000232ba58 R08:  R09: 0001
R10: c9000232ba88 R11:  R12: 88000d3f9b40
R13: 880456948008 R14: 880456948870 R15: c9000232bd10
FS:  7f79b1032700() GS:88050a20() knlGS:
CS:  0010 DS:  ES:  CR0: 80050033
CR2: 008436726348 CR3: 00022cc87000 CR4: 001406e0
DR0: 7f731068f000 DR1: 7f2d83eb9000 DR2: 7f302340e000
DR3:  DR6: 0ff0 DR7: 0600
Call Trace:
 sctp_wfree+0x5d/0x190 [sctp]
 skb_release_head_state+0x64/0xc0
 skb_release_all+0x12/0x30
 consume_skb+0x50/0x170
 sctp_chunk_put+0x59/0x80 [sctp]
 sctp_chunk_free+0x26/0x30 [sctp]
 __sctp_outq_teardown+0x1d8/0x270 [sctp]
 sctp_outq_free+0xe/0x10 [sctp]
 sctp_association_free+0x92/0x220 [sctp]
 sctp_do_sm+0x12a6/0x1920 [sctp]
 ? __get_user_4+0x18/0x20
 ? no_context+0x3f/0x360
 ? lock_acquire+0xe7/0x1e0
 ? skb_dequeue+0x1d/0x70
 sctp_primitive_SHUTDOWN+0x33/0x40 [sctp]
 sctp_close+0x26e/0x2a0 [sctp]
 inet_release+0x3c/0x60
 sock_release+0x1f/0x80
 sock_close+0x12/0x20
 __fput+0xf8/0x200
 fput+0xe/0x10
 task_work_run+0x85/0xc0
 exit_to_usermode_loop+0xa8/0xb0
 do_syscall_64+0x151/0x190
 entry_SYSCALL64_slow_path+0x25/0x25
RIP: 0033:0x7f79b095b1e9
RSP: 002b:7ffc5eca3088 EFLAGS: 0246
 ORIG_RAX: 0120
RAX: fff2 RBX: 0120 RCX: 7f79b095b1e9
RDX: 006e RSI: 008436738120 RDI: 0130
RBP: 7ffc5eca3130 R08:  R09: 0ff0
R10: 00080800 R11: 0246 R12: 0002
R13: 7f79b0ee9058 R14: 7f79b1032698 R15: 7f79b0ee9000
Code: 75 e6 85 d2 0f 94 c0 c3 31 c0 c3 80 3d ce 95 bc 00 00 75 f4 55 48 c7 c7 
00 d9 ee 81 48 89 e5 c6 05 ba 95 bc 00 01 e8 fc 2c c0 ff <0f> ff 31 c0 5d c3 0f 
1f 44 00 00 55 48 89 fe bf 01 00 00 00 48 
---[ end trace 19b7bd878c0f56fd ]---
[ cut here ]
WARNING: CPU: 2 PID: 14455 at net/ipv4/af_inet.c:154 
inet_sock_destruct+0x1b8/0x1f0
CPU: 2 PID: 14455 Comm: trinity-c46 Tainted: G  D W   4.12.0-think+ #11 
task: 8804fc71b8c0 task.stack: c90002328000
RIP: 0010:inet_sock_destruct+0x1b8/0x1f0
RSP: 0018:c9000232bcf8 EFLAGS: 00010286
RAX:  RBX: 88000d3f9b40 RCX: 
RDX: fd00 RSI: 0300 RDI: 88000d3f9ca8
RBP: c9000232bd08 R08:  R09: 
R10:  R11:  R12: 88000d3f9ca8
R13: 88000d3f9b40 R14: 88000d3f9bc8 R15: 8801836e21d0
FS:  7f79b1032700() GS:88050a20() knlGS:
CS:  0010 DS:  ES:  CR0: 80050033
CR2: 3b9ab732 CR3: 00022cc87000 CR4: 001406e0
DR0: 7f731068f000 DR1: 7f2d83eb9000 DR2: 7f302340e000
DR3:  DR6: 0ff0 DR7: 0600
Call Trace:
 sctp_destruct_sock+0x25/0x30 [sctp]
 __sk_destruct+0x28/0x230
 sk_destruct+0x20/0x30
 __sk_free+0x43/0xa0
 sk_free+0x25/0x30
 sctp_close+0x218/0x2a0 [sctp]
 inet_release+0x3c/0x60
 sock_release+0x1f/0x80
 sock_close+0x12/0x20
 __fput+0xf8/0x200
 fput+0xe/0x10
 task_work_run+0x85/0xc0
 exit_to_usermode_loop+0xa8/0xb0
 do_syscall_64+0x151/0x190
 entry_SYSCALL64_slow_path+0x25/0x25
RIP: 0033:0x7f79b095b1e9
RSP: 002b:7ffc5eca3088 EFLAGS: 0246
 ORIG_RAX: 0120
RAX: fff2 RBX: 0120 RCX: 7f79b095b1e9
RDX: 006e RSI: 008436738120 RDI: 0130
RBP: 7ffc5eca3130 R08:  R09: 0ff0
R10: 00080800 R11: 0246 R12: 0002
R13: 7f79b0ee9058 R14: 7f79b1032698 R15: 7f79b0ee9000
Code: df e8 bd 5f f4 ff e9 07 ff ff ff 0f ff 8b 83 8c 02 00 00 85 c0 0f 84 2d 
ff ff ff 0f ff 8b 93 88 02 00 00 85 d2 0f 84 2b ff ff ff <0f> ff 8b 83 40 02 00 
00 85 c0 0f 84 29 ff ff ff 0f ff e9 22 ff 
---[ end trace 19b7bd878c0f56fe ]---
[ cut here ]
WARNING: CPU: 2 PID: 14455 at net/ipv4/af_inet.c:155 
inet_sock_destruct+0x1c8/0x1f0
CPU: 2 PID: 14455 Comm: trinity-c46 Tainted: G  D W   4.12.0-think+ #11 
task: 8804fc71b8c0 task.stack: c90002328000
RIP: 0010:inet_sock_destruct+0x1c8/0x1f0
RSP: 0018:c9000232bcf8 EFLAGS: 00010206
RAX: 0300 RBX: 88000d3f9b40 RCX: 
RDX: fd00 RSI: 0300 RDI: 

netconsole refcount warning

[Dave Jones]

The new refcount debugging code spews this twice during boot on my router..


refcount_t: increment on 0; use-after-free.
[ cut here ]
WARNING: CPU: 1 PID: 17 at lib/refcount.c:152 refcount_inc+0x2b/0x30
CPU: 1 PID: 17 Comm: ksoftirqd/1 Not tainted 4.12.0-firewall+ #8 
task: 8801d4441ac0 task.stack: 8801d445
RIP: 0010:refcount_inc+0x2b/0x30
RSP: 0018:8801d4456da8 EFLAGS: 00010046
RAX: 002c RBX: 8801d4c3cf40 RCX: 
RDX: 002c RSI: 0003 RDI: ed003a88adab
RBP: 8801d4456da8 R08: 0003 R09: fbfff4afcb57
R10:  R11: fbfff4afcb58 R12: 8801d4c3c540
R13: 0082 R14: 8801ce9c7ff8 R15: 8801ce9c8aa0
FS:  () GS:8801d6a0() knlGS:
CS:  0010 DS:  ES:  CR0: 80050033
CR2: 7fa2b803156e CR3: 0001c405d000 CR4: 000406e0
Call Trace:
 zap_completion_queue+0xad/0x1a0
 netpoll_poll_dev+0x16f/0x3f0
 netpoll_send_skb_on_dev+0x25a/0x360
 netpoll_send_udp+0x526/0x850
 write_ext_msg+0x212/0x230
 ? _raw_spin_unlock_irqrestore+0x43/0x70
 ? write_msg+0x11f/0x130
 console_unlock+0x3ea/0x6e0
 vprintk_emit+0x298/0x3a0
 vprintk_default+0x1f/0x30
 vprintk_func+0x34/0xb0
 printk+0x95/0xb2
 ? show_regs_print_info+0x45/0x45
 ? nf_log_buf_open+0x2c/0x70
 ? nf_log_buf_close+0x26/0x70
 nf_log_buf_close+0x3c/0x70
 nf_log_ip_packet+0x111/0x250
 nf_log_packet+0x19e/0x330
 ? nf_logger_find_get+0x1c0/0x1c0
 ? debug_show_all_locks+0x1e0/0x1e0
 ? __local_bh_enable_ip+0x64/0xb0
 ? debug_smp_processor_id+0x17/0x20
 log_tg+0x13d/0x170
 ? log_tg_check+0x70/0x70
 ? trace_hardirqs_on+0xe/0x10
 ? __local_bh_enable_ip+0x64/0xb0
 ? _raw_spin_unlock_bh+0x35/0x40
 ipt_do_table+0x770/0xbb0
 ? mark_lock+0xb7/0x7d0
 ? sched_clock_cpu+0x1c/0x130
 ? ipt_alloc_initial_table+0x2d0/0x2d0
 ? debug_smp_processor_id+0x17/0x20
 ? __lock_is_held+0x55/0x110
 ? ipt_unregister_table+0x50/0x50
 iptable_filter_hook+0x53/0xd0
 nf_hook_slow+0x4a/0x120
 ip_local_deliver+0x1ba/0x2c0
 ? ip_local_deliver+0x100/0x2c0
 ? ip_call_ra_chain+0x270/0x270
 ? inet_del_offload+0x40/0x40
 ip_rcv_finish+0x2b9/0x880
 ip_rcv+0x51f/0x8a0
 ? ip_rcv+0x5ae/0x8a0
 ? ip_local_deliver+0x2c0/0x2c0
 ? ip_local_deliver_finish+0x4d0/0x4d0
 ? ip_local_deliver+0x2c0/0x2c0
 __netif_receive_skb_core+0xd4b/0x1210
 ? enqueue_to_backlog+0x620/0x620
 ? ktime_get_with_offset+0x11d/0x290
 __netif_receive_skb+0x27/0xc0
 ? debug_smp_processor_id+0x17/0x20
 netif_receive_skb_internal+0x3e3/0xc90
 ? netif_receive_skb_internal+0x90/0xc90
 ? __build_skb+0x2f/0x140
 ? __dev_queue_xmit+0xd30/0xd30
 ? debug_dma_sync_single_for_device+0xb7/0xc0
 ? debug_dma_sync_single_for_cpu+0xc0/0xc0
 ? dev_gro_receive+0x90/0x9b0
 ? __lock_is_held+0x30/0x110
 ? __asan_loadN+0x10/0x20
 ? skb_gro_reset_offset+0x93/0x140
 napi_gro_receive+0x1d1/0x270
 rtl8169_poll+0x49b/0xb30
 net_rx_action+0x4c4/0x7d0
 ? napi_complete_done+0x1b0/0x1b0
 ? __lock_is_held+0x30/0x110
 __do_softirq+0x113/0x611
 run_ksoftirqd+0x22/0x90
 smpboot_thread_fn+0x348/0x4f0
 ? __local_bh_enable_ip+0xb0/0xb0
 ? sort_range+0x30/0x30
 ? schedule+0x6c/0xe0
 ? __kthread_parkme+0xf2/0x110
 kthread+0x1ab/0x200
 ? sort_range+0x30/0x30
 ? __kthread_create_on_node+0x340/0x340
 ret_from_fork+0x27/0x40
Code: 55 48 89 e5 e8 97 ff ff ff 84 c0 74 02 5d c3 80 3d 5d 3e 06 01 00 75 f5 
48 c7 c7 20 69 f1 a4 c6 05 4d 3e 06 01 01 e8 ca 41 bc ff <0f> ff 5d c3 90 55 48 
89 e5 41 54 44 8d 27 48 8d 3e 53 48 8d 1e 
---[ end trace a9116b75ea217b54 ]---

Re: af_packet: use after free in prb_retire_rx_blk_timer_expired

[Dave Jones]

On Mon, Apr 10, 2017 at 07:03:30PM +, alexander.le...@verizon.com wrote:
 > Hi all,
 > 
 > I seem to be hitting this use-after-free on a -next kernel using trinity:
 >
 > [  531.036054] BUG: KASAN: use-after-free in prb_retire_rx_blk_timer_expired 
 > (net/packet/af_packet.c:688) 
 > [  531.036961] Read of size 8 at addr 88038c1fb0e8 by task 
 > swapper/1/0  
 >   [  531.037727] 
 >  
 >   [  531.037928] CPU: 1 PID: 0 Comm: swapper/1 Not 
 > tainted 4.11.0-rc5-next-20170407-dirty #24

Funny, I was just going over my old pending bugs, and found this one
from January that looks like what happens with the same bug, but without kasan..

context: PID: 0  TASK: 881ff2fa5100  CPU: 5   COMMAND: "swapper/5"
panic: general protection fault:  [#1]
netversion: 2.2-1 (Feb 2014)
Backtrace:
 #0 [881fffaa3c00] machine_kexec at 81044af8
 #1 [881fffaa3c60] __crash_kexec at 810ec755
 #2 [881fffaa3d28] crash_kexec at 810ec81f
 #3 [881fffaa3d40] oops_end at 8101e348
 #4 [881fffaa3d68] die at 8101e76b
 #5 [881fffaa3d98] do_general_protection at 8101be76
 #6 [881fffaa3dc0] general_protection at 817fe5a2
[exception RIP: prb_retire_rx_blk_timer_expired+65]
RIP: 817e6e41  RSP: 881fffaa3e78  RFLAGS: 00010246
RAX:   RBX: 881fd7075800  RCX: 
RDX: 883ff0a16bb0  RSI: 0074636361757063  RDI: 881fd70758bc
RBP: 881fffaa3e88   R8: 0001   R9: 0005
R10:   R11:   R12: 881fd7075b78
R13: 0100  R14: 817e6e00  R15: 881fd7075800
ORIG_RAX:   CS: 0010  SS: 0018
 #7 [881fffaa3e90] call_timer_fn at 810cec35
 #8 [881fffaa3ec8] run_timer_softirq at 810cf01c
 #9 [881fffaa3f28] __softirqentry_text_start at 817ff05c
#10 [881fffaa3f88] irq_exit at 8107d5fc
#11 [881fffaa3f98] smp_apic_timer_interrupt at 817feea2
#12 [881fffaa3fb0] apic_timer_interrupt at 817fd56f
---  ---
#13 [881ff2fbfdd0] apic_timer_interrupt at 817fd56f
RIP: 0018  RSP:   RFLAGS: 81ebbb60
RAX: e8e0002a0400  RBX: 0067b502e95f  RCX: 0006
RDX: 002e  RSI: 0034  RDI: 0001
RBP: 81150540   R8: 881ff2fbfee0   R9: 0001
R10: 0005  R11: 81ebbb60  R12: 881ff2fbfe48
R13: 881ff2fa5110  R14:   R15: 881ff2fa5100
ORIG_RAX: 881fffab5340  CS: 20c49ba5e353f7cf  SS: ff10
WARNING: possibly bogus exception frame
Dmesg:
Code: 00 00 48 8b 93 10 03 00 00 80 bb 21 03 00 00 00 44 0f b6 83 20 03 00 00 
0f b7 c8 48 8b 34 ca 75 57 <44> 8b 5e 0c 45 85 db 74 1d 8b 93 68 03 00 00 85 d2 
74 13 f3 90 

RIP 
 [] prb_retire_rx_blk_timer_expired+0x41/0x120
 RSP 
[ cut here ]

Re: run_timer_softirq gpf. [smc]

[Dave Jones]

On Tue, Mar 21, 2017 at 08:25:39PM +0100, Thomas Gleixner wrote:
 
 > > I just hit this while fuzzing..
 > > 
 > > general protection fault:  [#1] PREEMPT SMP DEBUG_PAGEALLOC
 > > CPU: 2 PID: 0 Comm: swapper/2 Not tainted 4.11.0-rc2-think+ #1 
 > > task: 88017f0ed440 task.stack: c9094000
 > > RIP: 0010:run_timer_softirq+0x15f/0x700
 > > RSP: 0018:880507c03ec8 EFLAGS: 00010086
 > > RAX: dead0200 RBX: 880507dd0d00 RCX: 0002
 > > RDX: 880507c03ed0 RSI:  RDI: 8204b3a0
 > > RBP: 880507c03f48 R08: 880507dd12d0 R09: 880507c03ed8
 > > R10: 880507dd0db0 R11:  R12: 8215cc38
 > > R13: 880507c03ed0 R14: 82005188 R15: 8804b55491a8
 > > FS:  () GS:880507c0() 
 > > knlGS:
 > > CS:  0010 DS:  ES:  CR0: 80050033
 > > CR2: 0004 CR3: 05011000 CR4: 001406e0
 > > Call Trace:
 > >  
 > >  ? clockevents_program_event+0x47/0x120
 > >  __do_softirq+0xbf/0x5b1
 > >  irq_exit+0xb5/0xc0
 > >  smp_apic_timer_interrupt+0x3d/0x50
 > >  apic_timer_interrupt+0x97/0xa0
 > > RIP: 0010:cpuidle_enter_state+0x12e/0x400
 > > RSP: 0018:c9097e40 EFLAGS: 0202
 > > [CONT START]  ORIG_RAX: ff10
 > > RAX: 88017f0ed440 RBX: e8a03cc8 RCX: 0001
 > > RDX: 20c49ba5e353f7cf RSI: 0001 RDI: 88017f0ed440
 > > RBP: c9097e80 R08:  R09: 0008
 > > R10:  R11:  R12: 0005
 > > R13: 820b9338 R14: 0005 R15: 820b9320
 > >  
 > >  cpuidle_enter+0x17/0x20
 > >  call_cpuidle+0x23/0x40
 > >  do_idle+0xfb/0x200
 > >  cpu_startup_entry+0x71/0x80
 > >  start_secondary+0x16a/0x210
 > >  start_cpu+0x14/0x14
 > > Code: 8b 05 ce 1b ef 7e 83 f8 03 0f 87 4e 01 00 00 89 c0 49 0f a3 04 24 0f 
 > > 82 0a 01 00 00 49 8b 07 49 8b 57 08 48 85 c0 48 89 02 74 04 <48> 89 50 08 
 > > 41 f6 47 2a 20 49 c7 47 08 00 00 00 00 48 89 df 48 
 > 
 > The timer which expires has timer->entry.next == POISON2 !
 > 
 > it's a classic list corruption.  The
 > bad news is that there is no trace of the culprit because that happens when
 > some other timer expires after some random amount of time.
 > 
 > If that is reproducible, then please enable debugobjects. That should
 > pinpoint the culprit.

It's net/smc.  This recently had a similar bug with workqueues. 
(https://marc.info/?l=linux-kernel=148821582909541) fixed by 
637fdbae60d6cb9f6e963c1079d7e0445c86ff7d
so it's probably unsurprising that there are similar issues.


WARNING: CPU: 0 PID: 2430 at lib/debugobjects.c:289 debug_print_object+0x87/0xb0
ODEBUG: free active (active state 0) object type: timer_list hint: 
delayed_work_timer_fn+0x0/0x20
CPU: 0 PID: 2430 Comm: trinity-c4 Not tainted 4.11.0-rc3-think+ #3 
Call Trace:
 dump_stack+0x68/0x93
 __warn+0xcb/0xf0
 warn_slowpath_fmt+0x5f/0x80
 ? debug_check_no_obj_freed+0xd9/0x260
 debug_print_object+0x87/0xb0
 ? work_on_cpu+0xd0/0xd0
 debug_check_no_obj_freed+0x219/0x260
 ? __sk_destruct+0x10d/0x1c0
 kmem_cache_free+0x9f/0x370
 __sk_destruct+0x10d/0x1c0
 sk_destruct+0x20/0x30
 __sk_free+0x43/0xa0
 sk_free+0x18/0x20
 smc_release+0x100/0x1a0 [smc]
 sock_release+0x1f/0x80
 sock_close+0x12/0x20
 __fput+0xf3/0x200
 fput+0xe/0x10
 task_work_run+0x85/0xb0
 do_exit+0x331/0xd70
 __secure_computing+0x9c/0xa0
 syscall_trace_enter+0xd1/0x3d0
 do_syscall_64+0x15f/0x1d0
 entry_SYSCALL64_slow_path+0x25/0x25
RIP: 0033:0x7f535f4b19e7
RSP: 002b:7fff1a0f40e8 EFLAGS: 0246
 ORIG_RAX: 0008
RAX: ffda RBX: 0004 RCX: 7f535f4b19e7
RDX:  RSI:  RDI: 0004
RBP:  R08: 7f535fb8b000 R09: 00c17c2740a303e4
R10:  R11: 0246 R12: 7fff1a0f40f5
R13: 7f535fb60048 R14: 7f535fb83ad8 R15: 7f535fb6
---[ end trace ee67155de15508db ]---

==
[ INFO: possible circular locking dependency detected ]
4.11.0-rc3-think+ #3 Not tainted
---
trinity-c4/2430 is trying to acquire lock:
 (
(console_sem).lock
){-.-...}
, at: [] down_trylock+0x14/0x40

but task is already holding lock:
 (
_hash[i].lock
){-.-.-.}
, at: [] debug_check_no_obj_freed+0xd9/0x260

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3
 (
_hash[i].lock
){-.-.-.}
:
   lock_acquire+0x102/0x260
   _raw_spin_lock_irqsave+0x4c/0x90
   __debug_object_init+0x79/0x460
   debug_object_init+0x16/0x20
   hrtimer_init+0x25/0x1d0
   init_dl_task_timer+0x20/0x30
   __sched_fork.isra.91+0x9c/0x140
   init_idle+0x51/0x240
   sched_init+0x4cd/0x547
   start_kernel+0x246/0x45d
   x86_64_start_reservations+0x2a/0x2c
   x86_64_start_kernel+0x178/0x18b
   

Re: [4.10+] sctp lockdep trace

[Dave Jones]

On Tue, Mar 14, 2017 at 11:35:33AM +0800, Xin Long wrote:
 > >> > [  245.416594]  (
 > >> > [  245.424928] sk_lock-AF_INET
 > >> > [  245.433279] ){+.+.+.}
 > >> > [  245.441889] , at: [] sctp_sendmsg+0x330/0xfe0 
 > >> > [sctp]
 > >> > [  245.450167]
 > >> >stack backtrace:
 > >> > [  245.466352] CPU: 3 PID: 1781 Comm: trinity-c30 Not tainted 
 > >> > 4.10.0-think+ #7
 > >> > [  245.482894] Call Trace:
 > >> > [  245.491096]  dump_stack+0x68/0x93
 > >> > [  245.499314]  lockdep_rcu_suspicious+0xce/0xf0
 > >> > [  245.507610]  sctp_hash_transport+0x6c0/0x7e0 [sctp]
 > >> > [  245.515972]  ? sctp_endpoint_bh_rcv+0x171/0x290 [sctp]
 > >> > [  245.524366]  sctp_assoc_add_peer+0x290/0x3c0 [sctp]
 > >> > [  245.532736]  sctp_sendmsg+0x8f7/0xfe0 [sctp]
 > >> > [  245.541040]  ? rw_copy_check_uvector+0x8e/0x190
 > >> > [  245.549402]  ? import_iovec+0x3a/0xe0
 > >> > [  245.557679]  inet_sendmsg+0x49/0x1e0
 > >> > [  245.565887]  ___sys_sendmsg+0x2d4/0x300
 > >> > [  245.574092]  ? debug_smp_processor_id+0x17/0x20
 > >> > [  245.582342]  ? debug_smp_processor_id+0x17/0x20
 > >> > [  245.590508]  ? get_lock_stats+0x19/0x50
 > >> > [  245.598641]  __sys_sendmsg+0x54/0x90
 > >> > [  245.606745]  SyS_sendmsg+0x12/0x20
 > >> > [  245.614784]  do_syscall_64+0x66/0x1d0
 > >> > [  245.622828]  entry_SYSCALL64_slow_path+0x25/0x25
 > >> > [  245.630894] RIP: 0033:0x7fe095fcb0f9
 > >> > [  245.638962] RSP: 002b:7ffc5601b1d8 EFLAGS: 0246
 > >> > [  245.647071]  ORIG_RAX: 002e
 > >> > [  245.655186] RAX: ffda RBX: 002e RCX: 
 > >> > 7fe095fcb0f9
 > >> > [  245.663435] RDX: 0080 RSI: 5592de12ddc0 RDI: 
 > >> > 012d
 > >> > [  245.671776] RBP: 7fe0965c8000 R08: c000 R09: 
 > >> > 00dc
 > >> > [  245.680111] R10: 000302120088 R11: 0246 R12: 
 > >> > 0002
 > >> > [  245.688460] R13: 7fe0965c8048 R14: 7fe0966a1ad8 R15: 
 > >> > 7fe0965c8000
 > >> >
 > >>
 > >> Cc'ing Xin and linux-sctp@ mailing list.
 > >
 > > Seems the same as Andrey Konovalov had reported?
 > >
 > I would think so, this patch has fixed it:
 > 
 > commit 5179b26694c92373275e4933f5d0ff32d585c675
 > Author: Xin Long 
 > Date:   Tue Feb 28 12:41:29 2017 +0800
 > 
 > sctp: call rcu_read_lock before checking for duplicate transport nodes
 > 
 > not sure which commit your tests are based on, Dave, can you
 > check if this fix has been in your test kernel?

Haven't seen this in a while. Let's call it fixed.

Dave

[4.10+] sctp lockdep trace

[Dave Jones]

[  244.251557] ===
[  244.263321] [ ERR: suspicious RCU usage.  ]
[  244.274982] 4.10.0-think+ #7 Not tainted
[  244.286511] ---
[  244.298008] ./include/linux/rhashtable.h:602 suspicious 
rcu_dereference_check() usage!
[  244.309665] 
   other info that might help us debug this:

[  244.344629] 
   rcu_scheduler_active = 2, debug_locks = 1
[  244.367839] 1 lock held by trinity-c30/1781:
[  244.379481]  #0: 
[  244.390848]  (
[  244.402372] sk_lock-AF_INET
[  244.413825] ){+.+.+.}
[  244.425231] , at: [] sctp_sendmsg+0x330/0xfe0 [sctp]
[  244.436774] 
   stack backtrace:
[  244.459620] CPU: 3 PID: 1781 Comm: trinity-c30 Not tainted 4.10.0-think+ #7 
[  244.482790] Call Trace:
[  244.494201]  dump_stack+0x68/0x93
[  244.505598]  lockdep_rcu_suspicious+0xce/0xf0
[  244.516924]  sctp_hash_transport+0x406/0x7e0 [sctp]
[  244.528137]  ? sctp_endpoint_bh_rcv+0x171/0x290 [sctp]
[  244.539243]  sctp_assoc_add_peer+0x290/0x3c0 [sctp]
[  244.550291]  sctp_sendmsg+0x8f7/0xfe0 [sctp]
[  244.561258]  ? rw_copy_check_uvector+0x8e/0x190
[  244.572308]  ? import_iovec+0x3a/0xe0
[  244.583232]  inet_sendmsg+0x49/0x1e0
[  244.594150]  ___sys_sendmsg+0x2d4/0x300
[  244.605002]  ? debug_smp_processor_id+0x17/0x20
[  244.615844]  ? debug_smp_processor_id+0x17/0x20
[  244.626533]  ? get_lock_stats+0x19/0x50
[  244.637141]  __sys_sendmsg+0x54/0x90
[  244.647817]  SyS_sendmsg+0x12/0x20
[  244.658400]  do_syscall_64+0x66/0x1d0
[  244.668990]  entry_SYSCALL64_slow_path+0x25/0x25
[  244.679582] RIP: 0033:0x7fe095fcb0f9
[  244.690079] RSP: 002b:7ffc5601b1d8 EFLAGS: 0246
[  244.700704]  ORIG_RAX: 002e
[  244.711248] RAX: ffda RBX: 002e RCX: 7fe095fcb0f9
[  244.721818] RDX: 0080 RSI: 5592de12ddc0 RDI: 012d
[  244.732282] RBP: 7fe0965c8000 R08: c000 R09: 00dc
[  244.742576] R10: 000302120088 R11: 0246 R12: 0002
[  244.752804] R13: 7fe0965c8048 R14: 7fe0966a1ad8 R15: 7fe0965c8000

[  244.775549] ===
[  244.785875] [ ERR: suspicious RCU usage.  ]
[  244.796951] 4.10.0-think+ #7 Not tainted
[  244.807185] ---
[  244.819213] ./include/linux/rhashtable.h:605 suspicious 
rcu_dereference_check() usage!
[  244.829420] 
   other info that might help us debug this:

[  244.859963] 
   rcu_scheduler_active = 2, debug_locks = 1
[  244.879766] 1 lock held by trinity-c30/1781:
[  244.889953]  #0: 
[  244.90]  (
[  244.909854] sk_lock-AF_INET
[  244.919645] ){+.+.+.}
[  244.929238] , at: [] sctp_sendmsg+0x330/0xfe0 [sctp]
[  244.939167] 
   stack backtrace:
[  244.958506] CPU: 3 PID: 1781 Comm: trinity-c30 Not tainted 4.10.0-think+ #7 
[  244.978102] Call Trace:
[  244.987735]  dump_stack+0x68/0x93
[  244.997112]  lockdep_rcu_suspicious+0xce/0xf0
[  245.006588]  sctp_hash_transport+0x4ca/0x7e0 [sctp]
[  245.016264]  ? sctp_endpoint_bh_rcv+0x171/0x290 [sctp]
[  245.025797]  sctp_assoc_add_peer+0x290/0x3c0 [sctp]
[  245.035380]  sctp_sendmsg+0x8f7/0xfe0 [sctp]
[  245.044883]  ? rw_copy_check_uvector+0x8e/0x190
[  245.054464]  ? import_iovec+0x3a/0xe0
[  245.064016]  inet_sendmsg+0x49/0x1e0
[  245.073516]  ___sys_sendmsg+0x2d4/0x300
[  245.082967]  ? debug_smp_processor_id+0x17/0x20
[  245.092448]  ? debug_smp_processor_id+0x17/0x20
[  245.101850]  ? get_lock_stats+0x19/0x50
[  245.70]  __sys_sendmsg+0x54/0x90
[  245.120451]  SyS_sendmsg+0x12/0x20
[  245.129649]  do_syscall_64+0x66/0x1d0
[  245.138783]  entry_SYSCALL64_slow_path+0x25/0x25
[  245.147678] RIP: 0033:0x7fe095fcb0f9
[  245.156588] RSP: 002b:7ffc5601b1d8 EFLAGS: 0246
[  245.165503]  ORIG_RAX: 002e
[  245.174601] RAX: ffda RBX: 002e RCX: 7fe095fcb0f9
[  245.183861] RDX: 0080 RSI: 5592de12ddc0 RDI: 012d
[  245.193038] RBP: 7fe0965c8000 R08: c000 R09: 00dc
[  245.202214] R10: 000302120088 R11: 0246 R12: 0002
[  245.211261] R13: 7fe0965c8048 R14: 7fe0966a1ad8 R15: 7fe0965c8000

[  245.308216] ===
[  245.317295] [ ERR: suspicious RCU usage.  ]
[  245.327876] 4.10.0-think+ #7 Not tainted
[  245.337065] ---
[  245.345840] ./include/linux/rhashtable.h:616 suspicious 
rcu_dereference_check() usage!
[  245.356501] 
   other info that might help us debug this:

[  245.382185] 
   rcu_scheduler_active = 2, debug_locks = 1
[  245.399415] 1 lock held by trinity-c30/1781:
[  245.408138]  #0: 
[  245.416594]  (
[  245.424928] sk_lock-AF_INET
[  245.433279] ){+.+.+.}
[  245.441889] , at: [] sctp_sendmsg+0x330/0xfe0 [sctp]
[  245.450167] 
   stack backtrace:
[  245.466352] CPU: 3 PID: 1781 Comm: trinity-c30 Not tainted 4.10.0-think+ #7 
[  

prb_retire_rx_blk_timer_expired use-after-free

[Dave Jones]

RSI looks kinda like slab poison here, so re-using a free'd ptr ?

general protection fault:  [#1] PREEMPT SMP DEBUG_PAGEALLOC
CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.10.0-rc4-think+ #2 
task: 81e16500 task.stack: 81e0
RIP: 0010:prb_retire_rx_blk_timer_expired+0x42/0x130
RSP: 0018:880507803e30 EFLAGS: 00010246
RAX: 81e16500 RBX: 8804bc751158 RCX: 
RDX: 8804fb6e8008 RSI: a56b6b6b6b6b6b6b RDI: 0001
RBP: 880507803e48 R08:  R09: 0001
R10: 61f74469 R11: 0054 R12: 8804bc751338
R13: 8804bc7516d8 R14: 818ab6a0 R15: 8804bc751158
FS:  () GS:88050780() knlGS:
CS:  0010 DS:  ES:  CR0: 80050033
CR2: 5578f64a0130 CR3: 03e11000 CR4: 001406f0
DR0: 7f539ba38000 DR1:  DR2: 
DR3:  DR6: 0ff0 DR7: 0600
Call Trace:
 
 call_timer_fn+0xd2/0x340
 ? call_timer_fn+0x5/0x340
 ? prb_retire_current_block+0x100/0x100
 run_timer_softirq+0x284/0x650
 ? 0xa035c077
 ? run_timer_softirq+0x5/0x650
 ? lapic_next_deadline+0x5/0x40
 __do_softirq+0x143/0x431
 irq_exit+0xa5/0xb0
 smp_apic_timer_interrupt+0x3d/0x50
 apic_timer_interrupt+0x8d/0xa0
RIP: 0010:cpuidle_enter_state+0x129/0x360
RSP: 0018:81e03db8 EFLAGS: 0246
  ORIG_RAX: ff10
RAX:  RBX: e8603cc8 RCX: 001f
RDX: 20c49ba5e353f7cf RSI: 81c5e743 RDI: 81c48102
RBP: 81e03df8 R08: cccd R09: 0018
R10: 022e R11: 0a2c R12: 0005
R13: 81eaf918 R14: 0005 R15: 81eaf900
 
 ? cpuidle_enter_state+0x113/0x360
 cpuidle_enter+0x17/0x20
 call_cpuidle+0x23/0x40
 do_idle+0xf6/0x1f0
 cpu_startup_entry+0x71/0x80
 rest_init+0xb8/0xc0
 start_kernel+0x432/0x453
 x86_64_start_reservations+0x2a/0x2c
 x86_64_start_kernel+0x178/0x18b
 start_cpu+0x14/0x14
 ? start_cpu+0x14/0x14
Code: fb 4c 89 e7 e8 b0 f1 01 00 0f b7 8b 2a 05 00 00 48 8b 93 18 05 00 00 80 
bb 29 05 00 00 00 0f b6 bb 28 05 00 00 48 8b 34 ca 75 58 <8b> 56 0c 48 89 c8 85 
d2 74 1d 8b 93 70 05 00 00 85 d2 74 13 f3 

All code

   0:   fb  sti
   1:   4c 89 e7mov%r12,%rdi
   4:   e8 b0 f1 01 00  callq  0x1f1b9
   9:   0f b7 8b 2a 05 00 00movzwl 0x52a(%rbx),%ecx
  10:   48 8b 93 18 05 00 00mov0x518(%rbx),%rdx
  17:   80 bb 29 05 00 00 00cmpb   $0x0,0x529(%rbx)
  1e:   0f b6 bb 28 05 00 00movzbl 0x528(%rbx),%edi
  25:   48 8b 34 ca mov(%rdx,%rcx,8),%rsi
  29:   75 58   jne0x83
  2b:*  8b 56 0cmov0xc(%rsi),%edx <-- trapping 
instruction
  2e:   48 89 c8mov%rcx,%rax
  31:   85 d2   test   %edx,%edx
  33:   74 1d   je 0x52
  35:   8b 93 70 05 00 00   mov0x570(%rbx),%edx
  3b:   85 d2   test   %edx,%edx
  3d:   74 13   je 0x52
  3f:   f3  repz

Code starting with the faulting instruction
===
   0:   8b 56 0cmov0xc(%rsi),%edx
   3:   48 89 c8mov%rcx,%rax
   6:   85 d2   test   %edx,%edx
   8:   74 1d   je 0x27
   a:   8b 93 70 05 00 00   mov0x570(%rbx),%edx
  10:   85 d2   test   %edx,%edx
  12:   74 13   je 0x27
  14:   f3  repz

That code is the BLOCK_NUM_PKTS line here..

 677 spin_lock(>sk.sk_receive_queue.lock);
 678 
 679 frozen = prb_queue_frozen(pkc);
 680 pbd = GET_CURR_PBLOCK_DESC_FROM_CORE(pkc);
 681 
 682 if (unlikely(pkc->delete_blk_timer))
 683 goto out;
 684 
 685 /* We only need to plug the race when the block is partially 
filled.
 686  * tpacket_rcv:
 687  *  lock(); increment BLOCK_NUM_PKTS; unlock()
 688  *  copy_bits() is in progress ...
 689  *  timer fires on other cpu:
 690  *  we can't retire the current block because copy_bits
 691  *  is in progress.
 692  *
 693  */
 694 if (BLOCK_NUM_PKTS(pbd)) {

ipv6: remove unnecessary inet6_sk check

[Dave Jones]

np is already assigned in the variable declaration of ping_v6_sendmsg.
At this point, we have already dereferenced np several times, so the
NULL check is also redundant.

Suggested-by: Eric Dumazet <eric.duma...@gmail.com>
Signed-off-by: Dave Jones <da...@codemonkey.org.uk>

diff --git a/net/ipv6/ping.c b/net/ipv6/ping.c
index e1f8b34d7a2e..9b522fa90e6d 100644
--- a/net/ipv6/ping.c
+++ b/net/ipv6/ping.c
@@ -126,12 +126,6 @@ static int ping_v6_sendmsg(struct sock *sk, struct msghdr 
*msg, size_t len)
return PTR_ERR(dst);
rt = (struct rt6_info *) dst;
 
-   np = inet6_sk(sk);
-   if (!np) {
-   err = -EBADF;
-   goto dst_err_out;
-   }
-
if (!fl6.flowi6_oif && ipv6_addr_is_multicast())
fl6.flowi6_oif = np->mcast_oif;
else if (!fl6.flowi6_oif)
@@ -166,7 +160,6 @@ static int ping_v6_sendmsg(struct sock *sk, struct msghdr 
*msg, size_t len)
}
release_sock(sk);
 
-dst_err_out:
dst_release(dst);
 
if (err)

sunrpc: Illegal context switch in RCU read-side critical section!

[Dave Jones]

Just noticed this on 4.9. Will try and repro on 4.10rc1 later, but hitting
unrelated boot problems on that machine right now.

===
[ INFO: suspicious RCU usage. ]
4.9.0-backup-debug+ #1 Not tainted
---
./include/linux/rcupdate.h:557 Illegal context switch in RCU read-side critical 
section!

other info that might help us debug this:

rcu_scheduler_active = 1, debug_locks = 1
5 locks held by kworker/4:1/66:
 #0:  ("%s"("ipv6_addrconf")){.+.+..}, at: [] 
process_one_work+0x184/0x790
 #1:  ((addr_chk_work).work){+.+...}, at: [] 
process_one_work+0x184/0x790
 #2:  (rtnl_mutex){+.+.+.}, at: [] rtnl_lock+0x17/0x20
 #3:  (rcu_read_lock_bh){..}, at: [] 
addrconf_verify_rtnl+0x23/0x500
 #4:  (rcu_read_lock){..}, at: [] 
atomic_notifier_call_chain+0x5/0x110

stack backtrace:
CPU: 4 PID: 66 Comm: kworker/4:1 Not tainted 4.9.0-backup-debug+ #1
Workqueue: ipv6_addrconf addrconf_verify_work
 c9273a28 8e5b4ca5 88042ae19780 0001
 c9273a58 8e0d530e  8efcc659
 09a7 8804180b8580 c9273a80 8e0ad2b7
Call Trace:
 [] dump_stack+0x68/0x93
 [] lockdep_rcu_suspicious+0xce/0xf0
 [] ___might_sleep.part.103+0xa7/0x230
 [] __might_sleep+0x4b/0x90
 [] lock_sock_nested+0x32/0xb0
 [] sock_setsockopt+0x8b/0xa50
 [] ? __local_bh_enable_ip+0x65/0xb0
 [] kernel_setsockopt+0x49/0x50
 [] svc_tcp_kill_temp_xprt+0x4a/0x60
 [] svc_age_temp_xprts_now+0x12f/0x1b0
 [] nfsd_inet6addr_event+0x192/0x1f0
 [] ? nfsd_inet6addr_event+0x5/0x1f0
 [] notifier_call_chain+0x39/0xa0
 [] atomic_notifier_call_chain+0x6e/0x110
 [] ? atomic_notifier_call_chain+0x5/0x110
 [] inet6addr_notifier_call_chain+0x1b/0x20
 [] ipv6_del_addr+0x12c/0x200
 [] addrconf_verify_rtnl+0x417/0x500
 [] ? addrconf_verify_rtnl+0x23/0x500
 [] addrconf_verify_work+0x13/0x20
 [] process_one_work+0x20b/0x790
 [] ? process_one_work+0x184/0x790
 [] worker_thread+0x4e/0x490
 [] ? process_one_work+0x790/0x790
 [] ? process_one_work+0x790/0x790
 [] kthread+0xff/0x120
 [] ? kthread_worker_fn+0x140/0x140
 [] ret_from_fork+0x27/0x40

ipv6: handle -EFAULT from skb_copy_bits

[Dave Jones]

By setting certain socket options on ipv6 raw sockets, we can confuse the
length calculation in rawv6_push_pending_frames triggering a BUG_ON.

RIP: 0010:[] [] rawv6_sendmsg+0xc30/0xc40
RSP: 0018:881f6c4a7c18  EFLAGS: 00010282
RAX: fff2 RBX: 881f6c681680 RCX: 0002
RDX: 881f6c4a7cf8 RSI: 0030 RDI: 881fed0f6a00
RBP: 881f6c4a7da8 R08:  R09: 0009
R10: 881fed0f6a00 R11: 0009 R12: 0030
R13: 881fed0f6a00 R14: 881fee39ba00 R15: 881fefa93a80

Call Trace:
 [] ? unmap_page_range+0x693/0x830
 [] inet_sendmsg+0x67/0xa0
 [] sock_sendmsg+0x38/0x50
 [] SYSC_sendto+0xef/0x170
 [] SyS_sendto+0xe/0x10
 [] do_syscall_64+0x50/0xa0
 [] entry_SYSCALL64_slow_path+0x25/0x25

Handle by jumping to the failure path if skb_copy_bits gets an EFAULT.

Reproducer:

#include 
#include 
#include 
#include 
#include 
#include 
#include 

#define LEN 504

int main(int argc, char* argv[])
{
int fd;
int zero = 0;
char buf[LEN];

memset(buf, 0, LEN);

fd = socket(AF_INET6, SOCK_RAW, 7);

setsockopt(fd, SOL_IPV6, IPV6_CHECKSUM, , 4);
setsockopt(fd, SOL_IPV6, IPV6_DSTOPTS, , LEN);

sendto(fd, buf, 1, 0, (struct sockaddr *) buf, 110);
}

Signed-off-by: Dave Jones <da...@codemonkey.org.uk>

diff --git a/net/ipv6/raw.c b/net/ipv6/raw.c
index 291ebc260e70..ea89073c8247 100644
--- a/net/ipv6/raw.c
+++ b/net/ipv6/raw.c
@@ -591,7 +591,11 @@ static int rawv6_push_pending_frames(struct sock *sk, 
struct flowi6 *fl6,
}
 
offset += skb_transport_offset(skb);
-   BUG_ON(skb_copy_bits(skb, offset, , 2));
+   err = skb_copy_bits(skb, offset, , 2);
+   if (err < 0) {
+   ip6_flush_pending_frames(sk);
+   goto out;
+   }
 
/* in case cksum was not initialized */
if (unlikely(csum))

Re: ipv6: handle -EFAULT from skb_copy_bits

[Dave Jones]

On Wed, Dec 21, 2016 at 10:33:20PM +0100, Hannes Frederic Sowa wrote:

 > > Given all of this, I think the best thing to do is validate the offset
 > > after the queue walks, which is pretty much what Dave Jones's original
 > > patch was doing.
 > 
 > I think both approaches protect against the bug reasonably well, but
 > Dave's patch has a bug: we must either call ip6_flush_pending_frames to
 > clear the socket write queue with the buggy send request.

I can fix that up and resubmit, or we can go with your approach.
DaveM ?

Dave

Re: ipv6: handle -EFAULT from skb_copy_bits

[Dave Jones]

On Tue, Dec 20, 2016 at 11:31:38AM -0800, Cong Wang wrote:
 > On Tue, Dec 20, 2016 at 10:17 AM, Dave Jones <da...@codemonkey.org.uk> wrote:
 > > On Mon, Dec 19, 2016 at 08:36:23PM -0500, David Miller wrote:
 > >  > From: Dave Jones <da...@codemonkey.org.uk>
 > >  > Date: Mon, 19 Dec 2016 19:40:13 -0500
 > >  >
 > >  > > On Mon, Dec 19, 2016 at 07:31:44PM -0500, Dave Jones wrote:
 > >  > >
 > >  > >  > Unfortunately, this made no difference.  I spent some time today 
 > > trying
 > >  > >  > to make a better reproducer, but failed. I'll revisit again 
 > > tomorrow.
 > >  > >  >
 > >  > >  > Maybe I need >1 process/thread to trigger this.  That would 
 > > explain why
 > >  > >  > I can trigger it with Trinity.
 > >  > >
 > >  > > scratch that last part, I finally just repro'd it with a single 
 > > process.
 > >  >
 > >  > Thanks for the info, I'll try to think about this some more.
 > >
 > > I threw in some debug printks right before that BUG_ON.
 > > it's always this:
 > >
 > > skb->len=31 skb->data_len=0 offset:30 total_len:9
 > 
 > Clearly we fail because 30 > 31 - 2, seems 'offset' is not correct here,
 > off-by-one?

Ok, I finally made a messy, albeit good enough reproducer.

#include 
#include 
#include 
#include 

#include 
#include 
#include 

#define LEN 504

int main(int argc, char* argv[])
{
int fd;
int zero = 0;
char buf[LEN];

memset(buf, 0, LEN);

fd = socket(AF_INET6, SOCK_RAW, 7);

setsockopt(fd, SOL_IPV6, IPV6_CHECKSUM, , 4);
setsockopt(fd, SOL_IPV6, IPV6_DSTOPTS, , LEN);

sendto(fd, buf, 1, 0, (struct sockaddr *) buf, 110);
}

Re: ipv6: handle -EFAULT from skb_copy_bits

[Dave Jones]

On Tue, Dec 20, 2016 at 01:28:13PM -0500, David Miller wrote:
 
 > This has to do with the SKB buffer layout and geometry, not whether
 > the packet is "fragmented" in the protocol sense.
 > 
 > So no, this isn't a criteria for packets being filtered out by this
 > point.
 > 
 > Can you try to capture what sk->sk_socket->type and
 > inet_sk(sk)->hdrincl are set to at the time of the crash?
 > 

type:3 hdrincl:0

Dave

Re: ipv6: handle -EFAULT from skb_copy_bits

[Dave Jones]

On Mon, Dec 19, 2016 at 08:36:23PM -0500, David Miller wrote:
 > From: Dave Jones <da...@codemonkey.org.uk>
 > Date: Mon, 19 Dec 2016 19:40:13 -0500
 > 
 > > On Mon, Dec 19, 2016 at 07:31:44PM -0500, Dave Jones wrote:
 > > 
 > >  > Unfortunately, this made no difference.  I spent some time today trying
 > >  > to make a better reproducer, but failed. I'll revisit again tomorrow.
 > >  > 
 > >  > Maybe I need >1 process/thread to trigger this.  That would explain why
 > >  > I can trigger it with Trinity.
 > > 
 > > scratch that last part, I finally just repro'd it with a single process.
 > 
 > Thanks for the info, I'll try to think about this some more.

I threw in some debug printks right before that BUG_ON.
it's always this:

skb->len=31 skb->data_len=0 offset:30 total_len:9

Shouldn't we have kicked out data_len=0 skb's somewhere before we got this far ?

Dave

Re: ipv6: handle -EFAULT from skb_copy_bits

[Dave Jones]

On Mon, Dec 19, 2016 at 07:31:44PM -0500, Dave Jones wrote:

 > Unfortunately, this made no difference.  I spent some time today trying
 > to make a better reproducer, but failed. I'll revisit again tomorrow.
 > 
 > Maybe I need >1 process/thread to trigger this.  That would explain why
 > I can trigger it with Trinity.

scratch that last part, I finally just repro'd it with a single process.

Dave

Re: ipv6: handle -EFAULT from skb_copy_bits

[Dave Jones]

On Mon, Dec 19, 2016 at 02:48:48PM -0500, David Miller wrote:

 > One thing that's interesting is that if the user picks "IPPROTO_RAW"
 > as the value of 'protocol' we set inet->hdrincl to 1.
 > 
 > The user can also set inet->hdrincl to 1 or 0 via setsockopt().
 > 
 > I think this is part of the problem.  The test above means to check
 > for "RAW socket with hdrincl set" and is trying to do this more simply.
 > But because setsockopt() can set this arbitrarily, testing sk_protocol
 > alone isn't enough.
 > 
 > So changing:
 > 
 >  sk->sk_protocol == IPPROTO_RAW
 > 
 > into something like:
 > 
 >  (sk->sk_socket->type == SOCK_RAW && inet_sk(sk)->hdrincl)
 > 
 > should correct the test.
 >  ..
 > 
 > You can test if the change I suggest above works.

Unfortunately, this made no difference.  I spent some time today trying
to make a better reproducer, but failed. I'll revisit again tomorrow.

Maybe I need >1 process/thread to trigger this.  That would explain why
I can trigger it with Trinity.

Dave

Re: ipv6: handle -EFAULT from skb_copy_bits

[Dave Jones]

On Sat, Dec 17, 2016 at 10:41:20AM -0500, David Miller wrote:

 > > It seems to be possible to craft a packet for sendmsg that triggers
 > > the -EFAULT path in skb_copy_bits resulting in a BUG_ON that looks like:
 > > 
 > > RIP: 0010:[] [] 
 > > rawv6_sendmsg+0xc30/0xc40
 > > RSP: 0018:881f6c4a7c18  EFLAGS: 00010282
 > > RAX: fff2 RBX: 881f6c681680 RCX: 0002
 > > RDX: 881f6c4a7cf8 RSI: 0030 RDI: 881fed0f6a00
 > > RBP: 881f6c4a7da8 R08:  R09: 0009
 > > R10: 881fed0f6a00 R11: 0009 R12: 0030
 > > R13: 881fed0f6a00 R14: 881fee39ba00 R15: 881fefa93a80
 > > 
 > > Call Trace:
 > >  [] ? unmap_page_range+0x693/0x830
 > >  [] inet_sendmsg+0x67/0xa0
 > >  [] sock_sendmsg+0x38/0x50
 > >  [] SYSC_sendto+0xef/0x170
 > >  [] SyS_sendto+0xe/0x10
 > >  [] do_syscall_64+0x50/0xa0
 > >  [] entry_SYSCALL64_slow_path+0x25/0x25
 > > 
 > > Handle this in rawv6_push_pending_frames and jump to the failure path.
 > > 
 > > Signed-off-by: Dave Jones <da...@codemonkey.org.uk>
 > 
 > Hmmm, that's interesting.  Becaue the code in __ip6_append_data(), which
 > sets up the ->cork.base.length value, seems to be defensively trying to
 > avoid this possibility.
 > 
 > For example, it checks things like:
 > 
 >  if (cork->length + length > mtu - headersize && ipc6->dontfrag &&
 >  (sk->sk_protocol == IPPROTO_UDP ||
 >   sk->sk_protocol == IPPROTO_RAW)) {
 > 
 > This is why the transport offset plus the length should never exceed
 > the total length for that skb_copy_bits() call.
 > 
 > Perhaps this protocol check in the code above is incomplete?  Do you
 > know what the sk->sk_protocol value was when that BUG triggered?  That
 > might shine some light on what is really happening here.

Hm.
  sk_protocol = 7, 






struct sock {
  __sk_common = {
{
  skc_addrpair = 0, 
  {
skc_daddr = 0, 
skc_rcv_saddr = 0
  }
}, 
{
  skc_hash = 0, 
  skc_u16hashes = {0, 0}
}, 
{
  skc_portpair = 458752, 
  {
skc_dport = 0, 
skc_num = 7
  }
}, 
skc_family = 10, 
skc_state = 7 '\a', 
skc_reuse = 1 '\001', 
skc_reuseport = 0 '\000', 
skc_ipv6only = 0 '\000', 
skc_net_refcnt = 1 '\001', 
skc_bound_dev_if = 0, 
{
  skc_bind_node = {
next = 0x0, 
pprev = 0x0
  }, 
  skc_portaddr_node = {
next = 0x0, 
pprev = 0x0
  }
}, 
skc_prot = 0x81cf3bc0 , 
skc_net = {
  net = 0x81ce78c0 
}, 
skc_v6_daddr = {
  in6_u = {
u6_addr8 = 
"\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000", 
u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, 
u6_addr32 = {0, 0, 0, 0}
  }
}, 
}, 
skc_v6_rcv_saddr = {
  in6_u = {
u6_addr8 = 
"\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000", 
u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, 
u6_addr32 = {0, 0, 0, 0}
  }
}, 
skc_cookie = {
  counter = 0
}, 
{
  skc_flags = 256, 
  skc_listener = 0x100, 
  skc_tw_dr = 0x100
}, 
skc_dontcopy_begin = 0x881fd1ce9b68, 
{
  skc_node = {
next = 0x0, 
pprev = 0x0
  }, 
  skc_nulls_node = {
next = 0x0, 
pprev = 0x0
  }
}, 
skc_tx_queue_mapping = -1, 
{
  skc_incoming_cpu = -1, 
  skc_rcv_wnd = 4294967295, 
  skc_tw_rcv_nxt = 4294967295
}, 
skc_refcnt = {
  counter = 1
}, 
skc_dontcopy_end = 0x881fd1ce9b84, 
{
  skc_rxhash = 0, 
  skc_window_clamp = 0, 
  skc_tw_snd_nxt = 0
}
  }, 
  sk_lock = {
slock = {
  {
rlock = {
  raw_lock = {
val = {
  counter = 0
}
  }
}
  }
}, 
owned = 1, 
wq = {
  lock = {
{
  rlock = {
raw_lock = {
  val = {
counter = 0
  }
}
  }
}
  }, 
  task_list = {
next = 0x881fd1ce9b98, 
prev = 0x881fd1ce9b98
  }
}
  }, 
  sk_receive_queue = {
next = 0x881fd1ce9ba8, 
prev = 0x881fd1ce9ba8, 
qlen = 0, 
lock = {
  {
rlock = {
  raw_lock = {
val = {
  counter = 0
}
  }
}
  }
}
  }, 
  sk_backlog = {
rmem_alloc = {
  counter = 0
}, 
len = 0, 
head = 0x0, 
tail = 0x0
  }, 
  sk_forward_alloc = 0, 
  sk_txhash = 0, 
  sk_napi_id = 0, 
  sk_ll_usec = 0, 
  sk_drops = {
counter = 0
  }, 
  sk_rcvbuf = 1

Re: ipv6: handle -EFAULT from skb_copy_bits

[Dave Jones]

On Sat, Dec 17, 2016 at 10:41:20AM -0500, David Miller wrote:
 > From: Dave Jones <da...@codemonkey.org.uk>
 > Date: Wed, 14 Dec 2016 10:47:29 -0500
 > 
 > > It seems to be possible to craft a packet for sendmsg that triggers
 > > the -EFAULT path in skb_copy_bits resulting in a BUG_ON that looks like:
 > > 
 > > RIP: 0010:[] [] 
 > > rawv6_sendmsg+0xc30/0xc40
 > > RSP: 0018:881f6c4a7c18  EFLAGS: 00010282
 > > RAX: fff2 RBX: 881f6c681680 RCX: 0002
 > > RDX: 881f6c4a7cf8 RSI: 0030 RDI: 881fed0f6a00
 > > RBP: 881f6c4a7da8 R08:  R09: 0009
 > > R10: 881fed0f6a00 R11: 0009 R12: 0030
 > > R13: 881fed0f6a00 R14: 881fee39ba00 R15: 881fefa93a80
 > > 
 > > Call Trace:
 > >  [] ? unmap_page_range+0x693/0x830
 > >  [] inet_sendmsg+0x67/0xa0
 > >  [] sock_sendmsg+0x38/0x50
 > >  [] SYSC_sendto+0xef/0x170
 > >  [] SyS_sendto+0xe/0x10
 > >  [] do_syscall_64+0x50/0xa0
 > >  [] entry_SYSCALL64_slow_path+0x25/0x25
 > > 
 > > Handle this in rawv6_push_pending_frames and jump to the failure path.
 > > 
 > > Signed-off-by: Dave Jones <da...@codemonkey.org.uk>
 > 
 > Hmmm, that's interesting.  Becaue the code in __ip6_append_data(), which
 > sets up the ->cork.base.length value, seems to be defensively trying to
 > avoid this possibility.
 > 
 > For example, it checks things like:
 > 
 >  if (cork->length + length > mtu - headersize && ipc6->dontfrag &&
 >  (sk->sk_protocol == IPPROTO_UDP ||
 >   sk->sk_protocol == IPPROTO_RAW)) {
 > 
 > This is why the transport offset plus the length should never exceed
 > the total length for that skb_copy_bits() call.
 > 
 > Perhaps this protocol check in the code above is incomplete?  Do you
 > know what the sk->sk_protocol value was when that BUG triggered?  That
 > might shine some light on what is really happening here.

I'll see if I can craft up a reproducer next week.
For some reason I've not hit this on my test setup at home, but it
reproduces daily in our test setup at facebook.  The only thing
I can think of is that those fb boxes are ipv6 only, so I might be
exercising v4 more at home.

Dave

ipv6: handle -EFAULT from skb_copy_bits

[Dave Jones]

It seems to be possible to craft a packet for sendmsg that triggers
the -EFAULT path in skb_copy_bits resulting in a BUG_ON that looks like:

RIP: 0010:[] [] rawv6_sendmsg+0xc30/0xc40
RSP: 0018:881f6c4a7c18  EFLAGS: 00010282
RAX: fff2 RBX: 881f6c681680 RCX: 0002
RDX: 881f6c4a7cf8 RSI: 0030 RDI: 881fed0f6a00
RBP: 881f6c4a7da8 R08:  R09: 0009
R10: 881fed0f6a00 R11: 0009 R12: 0030
R13: 881fed0f6a00 R14: 881fee39ba00 R15: 881fefa93a80

Call Trace:
 [] ? unmap_page_range+0x693/0x830
 [] inet_sendmsg+0x67/0xa0
 [] sock_sendmsg+0x38/0x50
 [] SYSC_sendto+0xef/0x170
 [] SyS_sendto+0xe/0x10
 [] do_syscall_64+0x50/0xa0
 [] entry_SYSCALL64_slow_path+0x25/0x25

Handle this in rawv6_push_pending_frames and jump to the failure path.

Signed-off-by: Dave Jones <da...@codemonkey.org.uk>

diff --git a/net/ipv6/raw.c b/net/ipv6/raw.c
index 291ebc260e70..35aa82faa052 100644
--- a/net/ipv6/raw.c
+++ b/net/ipv6/raw.c
@@ -591,7 +591,9 @@ static int rawv6_push_pending_frames(struct sock *sk, 
struct flowi6 *fl6,
}
 
offset += skb_transport_offset(skb);
-   BUG_ON(skb_copy_bits(skb, offset, , 2));
+   err = skb_copy_bits(skb, offset, , 2);
+   if (err < 0)
+   goto out;
 
/* in case cksum was not initialized */
if (unlikely(csum))

netconsole: sleeping function called from invalid context

[Dave Jones]

I think this has been around for a while, but for some reason I'm running into
it a lot today.


BUG: sleeping function called from invalid context at kernel/irq/manage.c:110
in_atomic(): 1, irqs_disabled(): 1, pid: 1839, name: modprobe
no locks held by modprobe/1839.
Preemption disabled at:
[] write_ext_msg+0x73/0x2d0
CPU: 0 PID: 1839 Comm: modprobe Not tainted 4.9.0-rc8-think+ #5 
 880442287300
 81651e19
 8001
 
 88044221d380
 006e
 880442287338
 87c3
 88044221d388
 8207b940
 006e
 
Call Trace:
 [] dump_stack+0x6c/0x93
 [] ___might_sleep+0x193/0x210
 [] __might_sleep+0x71/0xe0
 [] ? __synchronize_hardirq+0x94/0xa0
 [] synchronize_irq+0xa8/0x170
 [] ? set_irq_wake_real+0x90/0x90
 [] ? synchronize_irq+0x5/0x170
 [] ? disable_irq+0x5/0x30
 [] disable_irq+0x28/0x30
 [] e1000_netpoll+0x1c4/0x200
 [] ? e1000_intr_msix_tx+0x190/0x190
 [] netpoll_poll_dev+0xa0/0x3b0
 [] ? preempt_count_sub+0x18/0xd0
 [] netpoll_send_skb_on_dev+0x20d/0x3d0
 [] netpoll_send_udp+0x535/0x8c0
 [] write_ext_msg+0x286/0x2d0
 [] ? check_preemption_disabled+0x3b/0x160
 [] call_console_drivers.isra.20.constprop.26+0x165/0x310
 [] console_unlock+0x3b6/0x840
 [] vprintk_emit+0x4b5/0x6e0
 [] vprintk_default+0x48/0x80
 [] printk+0xbc/0xe7
 [] ? printk_lock.constprop.1+0x102/0x102
 [] ? printk+0x5/0xe7
 [] ? bt_init+0x1/0xfa [bluetooth]
 [] bt_info+0xdd/0x110 [bluetooth]
 [] ? bt_to_errno+0x50/0x50 [bluetooth]
 [] ? bt_info+0x5/0x110 [bluetooth]
 [] sco_init+0xb0/0xc40 [bluetooth]
 [] ? 0xa099
 [] bt_init+0x9d/0xfa [bluetooth]
 [] do_one_initcall+0x199/0x220
 [] ? initcall_blacklisted+0x170/0x170
 [] ? do_init_module+0xe3/0x2fd
 [] ? 0xa099
 [] ? do_one_initcall+0x5/0x220
 [] ? __asan_register_globals+0x7c/0xa0
 [] do_init_module+0xf4/0x2fd
 [] load_module+0x3a79/0x4670
 [] ? disable_ro_nx+0x80/0x80
 [] ? module_frob_arch_sections+0x20/0x20
 [] ? __buffer_unlock_commit+0x4a/0x90
 [] ? trace_function+0x9c/0xc0
 [] ? function_trace_call+0xea/0x290
 [] ? SYSC_finit_module+0x181/0x1c0
 [] ? module_frob_arch_sections+0x20/0x20
 [] ? get_user_arg_ptr.isra.26+0xa0/0xa0
 [] ? load_module+0x5/0x4670
 [] SYSC_finit_module+0x181/0x1c0
 [] ? SYSC_init_module+0x220/0x220
 [] ? function_trace_call+0xea/0x290
 [] ? SyS_init_module+0x10/0x10
 [] ? SyS_init_module+0x10/0x10
 [] ? SyS_finit_module+0x5/0x10
 [] ? __this_cpu_preempt_check+0x1c/0x20
 [] ? SyS_init_module+0x10/0x10
 [] SyS_finit_module+0xe/0x10
 [] do_syscall_64+0x100/0x2b0
 [] entry_SYSCALL64_slow_path+0x25/0x25

Re: ipv6: release dst in ping_v6_sendmsg

[Dave Jones]

On Tue, Sep 06, 2016 at 10:52:43AM -0700, Eric Dumazet wrote:
 
 > > > @@ -126,8 +126,10 @@ static int ping_v6_sendmsg(struct sock *sk, struct 
 > > > msghdr *msg, size_t len)
 > > >  rt = (struct rt6_info *) dst;
 > > >
 > > >  np = inet6_sk(sk);
 > > > -if (!np)
 > > > -return -EBADF;
 > > > +if (!np) {
 > > > +err = -EBADF;
 > > > +goto dst_err_out;
 > > > +}
 > > >
 > > >  if (!fl6.flowi6_oif && ipv6_addr_is_multicast())
 > > >  fl6.flowi6_oif = np->mcast_oif;
 > > > @@ -163,6 +165,9 @@ static int ping_v6_sendmsg(struct sock *sk, struct 
 > > > msghdr *msg, size_t len)
 > > >  }
 > > >  release_sock(sk);
 > > >
 > > > +dst_err_out:
 > > > +dst_release(dst);
 > > > +
 > > >  if (err)
 > > >  return err;
 > > >
 > > 
 > > Acked-by: Martin KaFai Lau 
 > 
 > This really does not make sense to me.
 > 
 > If np was NULL, we should have a crash before.

In the case where I was seeing the traces, we were taking the 'success'
path through the function, so sk was non-null.

 > So we should remove this test, since it is absolutely useless.

Looking closer, it seems the assignment of np is duplicated also,
so that can also go.   This is orthogonal to the dst leak though.
I'll submit a follow-up cleaning that up.

Dave

ipv6: release dst in ping_v6_sendmsg

[Dave Jones]

Neither the failure or success paths of ping_v6_sendmsg release
the dst it acquires.  This leads to a flood of warnings from
"net/core/dst.c:288 dst_release" on older kernels that
don't have 8bf4ada2e21378816b28205427ee6b0e1ca4c5f1 backported.

That patch optimistically hoped this had been fixed post 3.10, but
it seems at least one case wasn't, where I've seen this triggered
a lot from machines doing unprivileged icmp sockets.

Cc: Martin Lau <ka...@fb.com>
Signed-off-by: Dave Jones <da...@codemonkey.org.uk>

diff --git a/net/ipv6/ping.c b/net/ipv6/ping.c
index 0900352c924c..0e983b694ee8 100644
--- a/net/ipv6/ping.c
+++ b/net/ipv6/ping.c
@@ -126,8 +126,10 @@ static int ping_v6_sendmsg(struct sock *sk, struct msghdr 
*msg, size_t len)
rt = (struct rt6_info *) dst;
 
np = inet6_sk(sk);
-   if (!np)
-   return -EBADF;
+   if (!np) {
+   err = -EBADF;
+   goto dst_err_out;
+   }
 
if (!fl6.flowi6_oif && ipv6_addr_is_multicast())
fl6.flowi6_oif = np->mcast_oif;
@@ -163,6 +165,9 @@ static int ping_v6_sendmsg(struct sock *sk, struct msghdr 
*msg, size_t len)
}
release_sock(sk);
 
+dst_err_out:
+   dst_release(dst);
+
if (err)
return err;
 

e1000: __pskb_pull_tail failed

[Dave Jones]

MY NFS server running 4.8-rc1 is getting flooded with this message:

e1000e :00:19.0 eth0: __pskb_pull_tail failed.

Never saw it happen with 4.7 or earlier.


That device is this onboard NIC: 

00:19.0 Ethernet controller: Intel Corporation Ethernet Connection (2) I218-V

Dave

[4.6] kernel BUG at net/ipv6/raw.c:592

[Dave Jones]

Found this logs after a Trinity run.

kernel BUG at net/ipv6/raw.c:592!
[ cut here ]
invalid opcode:  [#1] SMP 

Modules linked in: udp_diag dccp_ipv6 dccp_ipv4 dccp sctp af_key tcp_diag 
inet_diag ip6table_filter xt_NFLOG nfnetlink_log xt_comment xt_statistic 
iptable_filter nfsv3 nfs_acl nfs fscache lockd grace autofs4 i2c_piix4 
rpcsec_gss_krb5 auth_rpcgss oid_registry sunrpc loop dummy ipmi_devintf 
iTCO_wdt iTCO_vendor_support acpi_cpufreq efivars ipmi_si ipmi_msghandler 
i2c_i801 i2c_core sg lpc_ich mfd_core button

CPU: 2 PID: 28854 Comm: trinity-c23 Not tainted 4.6.0 #1
Hardware name: Quanta Leopard-DDR3/Leopard-DDR3, BIOS F06_3A14.DDR3 05/13/2015
task: 880459cab600 ti: 880747bc4000 task.ti: 880747bc4000
RIP: 0010:[] [] rawv6_sendmsg+0xc30/0xc40
RSP: 0018:880747bc7bf8  EFLAGS: 00010282
RAX: fff2 RBX: 88080c6f2d00 RCX: 0002
RDX: 880747bc7cd8 RSI: 0030 RDI: 8803de801500
RBP: 880747bc7d90 R08: 002d R09: 0009
R10: 8803de801500 R11: 0009 R12: 0030
R13: 8803de801500 R14: 88086d67e000 R15: 88046bdac480
FS:  7fe29c566700() GS:88046fa4() knlGS:
CS:  0010 DS:  ES:  CR0: 80050033
CR2: 01f0f2c0 CR3: 00080b99d000 CR4: 001406e0
Stack:
  88086d67e000 880747bc7d18 88046bdac480
 8804  880747bc7c68 88086d67e000
 8808002d 88080009  0001
 
Call Trace:
 [] ? page_fault+0x22/0x30
 [] ? bad_to_user+0x6a/0x6fa
 [] inet_sendmsg+0x67/0xa0
 [] sock_sendmsg+0x38/0x50
 [] sock_write_iter+0x78/0xd0
 [] __vfs_write+0xaa/0xe0
 [] vfs_write+0xa2/0x1a0
 [] SyS_write+0x46/0xa0 
 [] entry_SYSCALL_64_fastpath+0x13/0x8f
Code: 23 f7 ff ff f7 d0 41 01 c0 41 83 d0 00 e9 ac fd ff ff 48 8b 44 24 48 48 
8b 80 c0 01 00 00 65 48 ff 40 28 8b 51 78 d0 41 01 c0 41 83 d0 00 e9 ac fd ff 
ff 48 8b 44 24 48 48 8b 80 c0 01 00 00 65 48 ff 40 28 8b 51 78 e9 64 fe ff ff 
<0f> 0b 66 66 66 66 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 

RIP [] rawv6_sendmsg+0xc30/0xc40
 RSP 

 590 
 591 offset += skb_transport_offset(skb);
 592 BUG_ON(skb_copy_bits(skb, offset, , 2));
 593 

af_packet: tone down the Tx-ring unsupported spew.

[Dave Jones]

Trinity and other fuzzers can hit this WARN on far too easily,
resulting in a tainted kernel that hinders automated fuzzing.

Replace it with a rate-limited printk.

Signed-off-by: Dave Jones <da...@codemonkey.org.uk>

diff --git a/net/packet/af_packet.c b/net/packet/af_packet.c
index 1ecfa710ca98..f12c17f355d9 100644
--- a/net/packet/af_packet.c
+++ b/net/packet/af_packet.c
@@ -4151,7 +4151,7 @@ static int packet_set_ring(struct sock *sk, union 
tpacket_req_u *req_u,
 
/* Opening a Tx-ring is NOT supported in TPACKET_V3 */
if (!closing && tx_ring && (po->tp_version > TPACKET_V2)) {
-   WARN(1, "Tx-ring is not supported.\n");
+   net_warn_ratelimited("Tx-ring is not supported.\n");
goto out;
}
 

Make DST_CACHE a silent config option

[Dave Jones]

commit 911362c70d ("net: add dst_cache support") added a new
kconfig option that gets selected by other networking options.
It seems the intent wasn't to offer this as a user-selectable
option given the lack of help text, so this patch converts it
to a silent option.

Signed-off-by: Dave Jones <da...@codemonkey.org.uk>

diff --git a/net/Kconfig b/net/Kconfig
index e13449870d06..a8934d8c8fda 100644
--- a/net/Kconfig
+++ b/net/Kconfig
@@ -397,7 +397,7 @@ config LWTUNNEL
  with light weight tunnel state associated with fib routes.
 
 config DST_CACHE
-   bool "dst cache"
+   bool
default n
 
 config NET_DEVLINK

Re: gro: Make GRO aware of lightweight tunnels.

[Dave Jones]

On Tue, Feb 02, 2016 at 02:28:58AM +, Linux Kernel wrote:
 > Web:
 > https://git.kernel.org/torvalds/c/ce87fc6ce3f9f4488546187e3757cf666d9d4a2a
 > Commit: ce87fc6ce3f9f4488546187e3757cf666d9d4a2a
 > Parent: 5f2f3cad8b878b23f17a11dd5af4f4a2cc41c797
 > Refname:refs/heads/master
 > Author: Jesse Gross 
 > AuthorDate: Wed Jan 20 17:59:49 2016 -0800
 > Committer:  David S. Miller 
 > CommitDate: Wed Jan 20 18:48:38 2016 -0800
 > 
 > gro: Make GRO aware of lightweight tunnels.

Coverity just started complaining about this commit.

 > diff --git a/include/net/dst_metadata.h b/include/net/dst_metadata.h
 > index 6816f0f..30a56ab 100644
 > --- a/include/net/dst_metadata.h
 > +++ b/include/net/dst_metadata.h
 > @@ -44,6 +44,24 @@ static inline bool skb_valid_dst(const struct sk_buff 
 > *skb)
 >  return dst && !(dst->flags & DST_METADATA);
 >  }
 >  
 > +static inline int skb_metadata_dst_cmp(const struct sk_buff *skb_a,
 > +   const struct sk_buff *skb_b)
 > +{
 > +const struct metadata_dst *a, *b;
 > +
 > +if (!(skb_a->_skb_refdst | skb_b->_skb_refdst))
 > +return 0;
 > +
 > +a = (const struct metadata_dst *) skb_dst(skb_a);
 > +b = (const struct metadata_dst *) skb_dst(skb_b);
 > +
 > +if (!a != !b || a->u.tun_info.options_len != b->u.tun_info.options_len)

It complains that we could dereference a null 'a' here.

It's possible the checker got confused, but the first part of that
expression looks odd, is that doing what's intended ?

Dave

net/ipv6/ip6_flowlabel.c:543 suspicious rcu_dereference_check() usage!

[Dave Jones]

===
[ INFO: suspicious RCU usage. ]
4.5.0-rc2-think+ #2 Tainted: GW  
---
net/ipv6/ip6_flowlabel.c:543 suspicious rcu_dereference_check() usage!

other info that might help us debug this:


rcu_scheduler_active = 1, debug_locks = 1
2 locks held by trinity-c0/21982:
 #0:  (sk_lock-AF_INET6){+.+.+.}, at: [] 
do_ipv6_setsockopt.isra.5+0x1bc/0x1c20
 #1:  (ip6_sk_fl_lock){+.}, at: [] 
ipv6_flowlabel_opt+0x584/0x1b00

stack backtrace:
CPU: 1 PID: 21982 Comm: trinity-c0 Tainted: GW   4.5.0-rc2-think+ #2
 b1821f20 e98d3751 88032ccaf798 b076bd50
 41b58ab3 b19d0db1 b076bca5 0001
 8803011308e8 e98d3751 88032ccaf770 0003
Call Trace:
 [] dump_stack+0xab/0x11b
 [] ? _atomic_dec_and_lock+0x95/0x95
 [] lockdep_rcu_suspicious+0xe6/0x100
 [] ipv6_flowlabel_opt+0x62b/0x1b00
 [] ? ipv6_flowlabel_opt_get+0x6b0/0x6b0
 [] ? preempt_count_sub+0x1a/0x140
 [] ? mark_held_locks+0xc8/0x140
 [] ? __local_bh_enable_ip+0x64/0xc0
 [] ? lock_sock_nested+0x5a/0xe0
 [] ? trace_hardirqs_on+0xd/0x10
 [] ? __local_bh_enable_ip+0x64/0xc0
 [] ? lock_sock_nested+0xa9/0xe0
 [] do_ipv6_setsockopt.isra.5+0xbc4/0x1c20
 [] ? debug_lockdep_rcu_enabled.part.34+0x1f/0x40
 [] ? ip6_ra_control+0x1d0/0x1d0
 [] ? mark_lock+0xf4/0xc90
 [] ? print_usage_bug+0x520/0x520
 [] ? print_usage_bug+0x520/0x520
 [] ? native_sched_clock+0x69/0x160
 [] ? __lock_acquire+0x7ee/0x2ec0
 [] ? mark_lock+0xf4/0xc90
 [] ? print_usage_bug+0x520/0x520
 [] ? debug_check_no_locks_freed+0x200/0x200
 [] ? __lock_acquire+0x7ee/0x2ec0
 [] ? preempt_count_sub+0xc9/0x140
 [] ? debug_smp_processor_id+0x17/0x20
 [] ? get_lock_stats+0x4e/0xf0
 [] ? preempt_count_sub+0xc9/0x140
 [] ? trace_hardirqs_off_caller+0x73/0x150
 [] ? trace_hardirqs_off+0xd/0x10
 [] ? __acct_update_integrals+0x108/0x260
 [] ? taskstats_exit+0x5f0/0x5f0
 [] ? debug_smp_processor_id+0x17/0x20
 [] ? get_lock_stats+0x4e/0xf0
 [] ? preempt_count_sub+0xc9/0x140
 [] ? account_user_time+0x141/0x200
 [] ipv6_setsockopt+0x31/0xe0
 [] tcp_setsockopt+0x71/0xd0
 [] sock_common_setsockopt+0x6c/0xb0
 [] SyS_setsockopt+0x116/0x200
 [] ? SyS_recv+0x20/0x20
 [] ? int_ret_from_sys_call+0x52/0x9f
 [] ? trace_hardirqs_on_thunk+0x17/0x19
 [] entry_SYSCALL_64_fastpath+0x12/0x6b

Re: out of bounds in pptp_connect.

[Dave Jones]

On Sun, Jan 17, 2016 at 12:06:58PM -0500, Dave Jones wrote:
 > I've managed to trigger this a few times the last few days, on Linus' tree.
 > 
 > ==
 > BUG: KASAN: slab-out-of-bounds in pptp_connect+0xb7b/0xc70 [pptp] at addr 
 > 8800242da0d0
 > Read of size 2 by task trinity-c14/13664
 > =
 > BUG kmalloc-8192 (Not tainted): kasan: bad access detected
 > -
 > 
 > Disabling lock debugging due to kernel taint
 > INFO: Allocated in copy_thread_tls+0x6b3/0x8d0 age=5483091 cpu=1 pid=18329
 >  ___slab_alloc.constprop.66+0x4de/0x580
 >  __slab_alloc.isra.63.constprop.65+0x48/0x80
 >  __kmalloc_track_caller+0x2a2/0x2f0
 >  kmemdup+0x20/0x50
 >  copy_thread_tls+0x6b3/0x8d0
 >  copy_process.part.40+0x3679/0x57b0
 >  _do_fork+0x16c/0xba0
 >  SyS_clone+0x19/0x20
 >  tracesys_phase2+0x84/0x89
 > INFO: Freed in x86_pmu_event_init+0x477/0x550 age=5483145 cpu=1 pid=18329
 >  __slab_free+0x18b/0x2b0
 >  kfree+0x272/0x290
 >  x86_pmu_event_init+0x477/0x550
 >  perf_try_init_event+0x164/0x1c0
 >  perf_event_alloc+0x1235/0x18c0
 >  inherit_event.isra.88+0xd4/0x6c0
 >  inherit_task_group.isra.90.part.91+0x68/0x200
 >  perf_event_init_task+0x41f/0x830
 >  copy_process.part.40+0x15d6/0x57b0
 >  _do_fork+0x16c/0xba0
 >  SyS_clone+0x19/0x20
 >  tracesys_phase2+0x84/0x89

I'm now seeing different bug type, with similar traces.
Instead of an out of bounds, it's now a use-after-free, but
it's interesting that it's complaining about memory that used
to belong to perf again.  Could the bug be in perf ?

Dave


BUG: KASAN: use-after-free in pptp_connect+0x19f/0x5e0 [pptp] at addr 
8804632ba0d0
Read of size 2 by task trinity-c4/18013
=
BUG kmalloc-2048 (Tainted: GW  ): kasan: bad access detected
-

INFO: Allocated in perf_event_alloc+0x72/0xd60 age=5653 cpu=0 pid=17555
___slab_alloc.constprop.71+0x523/0x5c0
__slab_alloc.isra.67.constprop.70+0x48/0x80
kmem_cache_alloc_trace+0x24c/0x2e0
perf_event_alloc+0x72/0xd60
inherit_event.isra.90+0x82/0x3a0
inherit_task_group.isra.92.part.93+0x55/0x120
perf_event_init_task+0x35a/0x530
copy_process.part.40+0xb3d/0x2db0
_do_fork+0x164/0x880
SyS_clone+0x19/0x20
tracesys_phase2+0x84/0x89
INFO: Freed in free_event_rcu+0x38/0x40 age=5635 cpu=0 pid=17555
__slab_free+0x19e/0x2d0
kfree+0x25c/0x280
free_event_rcu+0x38/0x40
rcu_process_callbacks+0xbac/0x1200
__do_softirq+0x1a4/0x590
irq_exit+0xf5/0x100
smp_apic_timer_interrupt+0x5c/0x70
apic_timer_interrupt+0x90/0xa0
context_tracking_exit+0x1d/0x20
enter_from_user_mode+0x1f/0x50
syscall_trace_enter_phase1+0x1cb/0x260
tracesys+0xd/0x44
INFO: Slab 0xea00118cae00 objects=13 used=9 fp=0x8804632bae68 
flags=0x80004080
INFO: Object 0x8804632b9bd8 @offset=7128 fp=0x8804632be618

suspicious rcu_dereference in tcp_v6_send_synack

[Dave Jones]

===
[ INFO: suspicious RCU usage. ]
4.4.0-rc8-firewall+ #1 Not tainted
---
net/ipv6/tcp_ipv6.c:465 suspicious rcu_dereference_check() usage!

other info that might help us debug this:


rcu_scheduler_active = 1, debug_locks = 1
1 lock held by swapper/1/0:
 #0:  (((>rsk_timer))){+.-...}, at: [] 
call_timer_fn+0x5/0x3f0

stack backtrace:
CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.4.0-rc8-firewall+ #1
  8801d7a07b28 9948b3b5 8801d6046500
 8801d7a07b58 990e9b7a 8801cd356240 
 8801d23b1698 8801d23b0c40 8801d7a07ba8 99b635d2
Call Trace:
   [] dump_stack+0x4e/0x79
 [] lockdep_rcu_suspicious+0xea/0x110
 [] tcp_v6_send_synack+0x2c2/0x350
 [] tcp_rtx_synack+0xdd/0x180
 [] ? tcp_send_probe0+0x1a0/0x1a0
 [] reqsk_timer_handler+0x4c4/0x530
 [] ? inet_csk_reqsk_queue_drop+0x3a0/0x3a0
 [] ? __lock_is_held+0x9b/0xd0
 [] call_timer_fn+0x132/0x3f0
 [] ? call_timer_fn+0x5/0x3f0
 [] ? inet_csk_reqsk_queue_drop+0x3a0/0x3a0
 [] ? process_timeout+0x10/0x10
 [] ? trace_hardirqs_on_caller+0x192/0x2a0
 [] ? preempt_count_sub+0x1a/0x130
 [] run_timer_softirq+0x47b/0x590
 [] ? inet_csk_reqsk_queue_drop+0x3a0/0x3a0
 [] ? internal_add_timer+0x110/0x110
 [] ? __lock_is_held+0x28/0xd0
 [] __do_softirq+0x1b2/0x5c0
 [] irq_exit+0xfc/0x110
 [] smp_apic_timer_interrupt+0x5f/0x70
 [] apic_timer_interrupt+0x8b/0x90
   [] ? cpuidle_enter_state+0x1c7/0x460
 [] ? cpuidle_enter_state+0x1c2/0x460
 [] ? rcu_eqs_enter_common+0x139/0x280
 [] cpuidle_enter+0x17/0x20
 [] cpu_startup_entry+0x4d2/0x5b0
 [] ? default_idle_call+0x60/0x60
 [] ? clockevents_config_and_register+0x64/0x70
 [] ? setup_APIC_timer+0x115/0x120
 [] start_secondary+0x23a/0x2a0
 [] ? set_cpu_sibling_map+0x9c0/0x9c0

--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: 4.4-rc7 failure report

[Dave Jones]

On Wed, Dec 30, 2015 at 10:38:56AM +0100, Daniel Borkmann wrote:

 > Given that this drop doesn't strictly need to be caused by filter code,
 > it would be nice if you could pin the location down where the packet gets
 > dropped exactly. Perhaps dropwatch or perf with '-e skb:kfree_skb -a -g
 > dhclient ', etc could help to get a first overview to dig into
 > details then.

Wild stab in the dark, but..
Could this bug be another symptom fixed by 
http://article.gmane.org/gmane.linux.network/392885 ?

Dave

--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: suspicious RCU usage (netlink/rhashtable)

[Dave Jones]

On Tue, Dec 22, 2015 at 04:50:20PM -0500, David Miller wrote:
 
 > >  > > Simple fix is below.  Though, I don't understand the history of the
 > >  > > multiple locks in this structure to be sure it's correct.  I'll send
 > >  > > it as a formal patch.  Please reject if it's not the right approach.
 > >  > > 
 > >  > > diff --git a/lib/rhashtable.c b/lib/rhashtable.c
 > >  > > index 1c149e9..cc80870 100644
 > >  > > --- a/lib/rhashtable.c
 > >  > > +++ b/lib/rhashtable.c
 > >  > > @@ -516,7 +516,8 @@ int rhashtable_walk_init(struct rhashtable *ht,
 > >  > > struct rhashtable_iter *iter)
 > >  > > return -ENOMEM;
 > >  > > 
 > >  > > spin_lock(>lock);
 > >  > > -   iter->walker->tbl = rht_dereference(ht->tbl, ht);
 > >  > > +   iter->walker->tbl =
 > >  > > +   rcu_dereference_protected(ht->tbl, 
 > > lockdep_is_held(>lock));
 > >  > > list_add(>walker->list, >walker->tbl->walkers);
 > >  > > spin_unlock(>lock);
 > >  > 
 > >  > How can this be the "fix"?  That's exactly what's in the tree.
 > > 
 > > I should have made clear, this is Linus' tree I'm hitting this on,
 > > which matches what Craig posted.
 > 
 > Ok, so this should be fixed in my 'net' tree and I'll send that to Linus
 > soon.

Great, thanks Dave.  Sorry for the fire-alarm :)

Dave
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: suspicious RCU usage (netlink/rhashtable)

[Dave Jones]

On Tue, Dec 22, 2015 at 04:42:25PM -0500, David Miller wrote:
 > From: Craig Gallek 
 > Date: Tue, 22 Dec 2015 16:38:32 -0500
 > 
 > > On Tue, Dec 22, 2015 at 4:28 PM, David Miller  wrote:
 > >> From: Craig Gallek 
 > >> Date: Tue, 22 Dec 2015 15:51:19 -0500
 > >>
 > >>> I was actually just looking at this as well (though a slightly
 > >>> different stack).  The issue is with: c6ff5268293e rhashtable: Fix
 > >>> walker list corruption
 > >>>
 > >>> It changed the lock acquired in rhashtable_walk_init to use the new
 > >>> spinlock, but the rht_dereference macro expects the mutex.  I was
 > >>> still trying to track down which repository this change came in
 > >>> through, though...
 > >>
 > >> Both cam via my networking tree.
 > > Simple fix is below.  Though, I don't understand the history of the
 > > multiple locks in this structure to be sure it's correct.  I'll send
 > > it as a formal patch.  Please reject if it's not the right approach.
 > > 
 > > diff --git a/lib/rhashtable.c b/lib/rhashtable.c
 > > index 1c149e9..cc80870 100644
 > > --- a/lib/rhashtable.c
 > > +++ b/lib/rhashtable.c
 > > @@ -516,7 +516,8 @@ int rhashtable_walk_init(struct rhashtable *ht,
 > > struct rhashtable_iter *iter)
 > > return -ENOMEM;
 > > 
 > > spin_lock(>lock);
 > > -   iter->walker->tbl = rht_dereference(ht->tbl, ht);
 > > +   iter->walker->tbl =
 > > +   rcu_dereference_protected(ht->tbl, 
 > > lockdep_is_held(>lock));
 > > list_add(>walker->list, >walker->tbl->walkers);
 > > spin_unlock(>lock);
 > 
 > How can this be the "fix"?  That's exactly what's in the tree.

I should have made clear, this is Linus' tree I'm hitting this on,
which matches what Craig posted.

Dave
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

suspicious RCU usage (netlink/rhashtable)

[Dave Jones]

===
[ INFO: suspicious RCU usage. ]
4.4.0-rc6-think+ #1 Not tainted
---
lib/rhashtable.c:522 suspicious rcu_dereference_protected() usage!

other info that might help us debug this:


rcu_scheduler_active = 1, debug_locks = 0
2 locks held by trinity-c1/3652:
 #0:  (>lock){+.+.+.}, at: [] seq_read+0xd7/0x900
 #1:  (&(>lock)->rlock){+.+...}, at: [] 
rhashtable_walk_init+0x9d/0x170

stack backtrace:
CPU: 0 PID: 3652 Comm: trinity-c1 Not tainted 4.4.0-rc6-think+ #1
 9af6ac60 3fc014d4 8800cff779e0 9a548da1
 880459b8b700 8800cff77a10 9a131068 8800cdd32c48
 880464af8000 8800cdd32c58 880464af8160 8800cff77a48
Call Trace:
 [] dump_stack+0x4e/0x7d
 [] lockdep_rcu_suspicious+0xf8/0x110
 [] rhashtable_walk_init+0x163/0x170
 [] netlink_walk_start+0x49/0x90
 [] netlink_seq_start+0x40/0x90
 [] seq_read+0x1bf/0x900
 [] ? seq_lseek+0x1b0/0x1b0
 [] ? __might_fault+0xe0/0xf0
 [] ? __might_fault+0x87/0xf0
 [] ? rw_copy_check_uvector+0x139/0x170
 [] proc_reg_read+0x7f/0xc0
 [] do_loop_readv_writev+0xe0/0x110
 [] ? proc_reg_write+0xc0/0xc0
 [] do_readv_writev+0x38b/0x3c0
 [] ? proc_reg_write+0xc0/0xc0
 [] ? vfs_write+0x260/0x260
 [] ? __lock_is_held+0x25/0xd0
 [] ? mark_held_locks+0x23/0xc0
 [] ? context_tracking_exit.part.5+0x2a/0x50
 [] ? trace_hardirqs_on_caller+0x186/0x280
 [] ? trace_hardirqs_on+0xd/0x10
 [] vfs_readv+0x56/0x70
 [] SyS_preadv+0x15d/0x180
 [] ? SyS_writev+0x1a0/0x1a0
 [] ? trace_hardirqs_on_thunk+0x17/0x19
 [] entry_SYSCALL_64_fastpath+0x12/0x6b

--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

suspicious rcu_dereference_check in sctp_v6_get_dst

[Dave Jones]

===
[ INFO: suspicious RCU usage. ]
4.4.0-rc3-think+ #8 Tainted: GW  
---
net/sctp/ipv6.c:331 suspicious rcu_dereference_check() usage!

other info that might help us debug this:


rcu_scheduler_active = 1, debug_locks = 0
1 lock held by trinity-c2/15441:
 #0:  (sk_lock-AF_INET6){+.+.+.}, at: [] 
sctp_sendmsg+0x501/0x16a0 [sctp]

stack backtrace:
CPU: 2 PID: 15441 Comm: trinity-c2 Tainted: GW   4.4.0-rc3-think+ #8
 ff9b 880458d677c8 ab530f11 88045f1db700
 880458d677f8 ab12d248 880452b13f80 880452b13f60
  88045ad45280 880458d67970 c0673a7c
Call Trace:
 [] dump_stack+0x4e/0x7d
 [] lockdep_rcu_suspicious+0xf8/0x110
 [] sctp_v6_get_dst+0xacc/0xb30 [sctp]
 [] ? sctp_v6_get_dst+0x6b6/0xb30 [sctp]
 [] ? sctp_inet6_send_verify+0x180/0x180 [sctp]
 [] ? get_random_bytes+0x69/0x150
 [] ? extract_buf+0x370/0x370
 [] ? __lock_is_held+0x92/0xd0
 [] ? sctp_transport_new+0x2f0/0x320 [sctp]
 [] sctp_transport_route+0x66/0x1c0 [sctp]
 [] sctp_assoc_add_peer+0x242/0x680 [sctp]
 [] sctp_sendmsg+0xcd1/0x16a0 [sctp]
 [] ? mark_lock+0x6f/0x8a0
 [] ? sctp_id2assoc+0x140/0x140 [sctp]
 [] ? debug_check_no_locks_freed+0x1b0/0x1b0
 [] ? mark_lock+0x6f/0x8a0
 [] ? native_sched_clock+0x69/0x160
 [] ? debug_smp_processor_id+0x17/0x20
 [] ? preempt_count_sub+0xc1/0x120
 [] inet_sendmsg+0x18e/0x270
 [] ? inet_sendmsg+0x5/0x270
 [] SYSC_sendto+0x1d8/0x2c0
 [] ? sock_create_kern+0x20/0x20
 [] ? __lock_is_held+0x25/0xd0
 [] ? trace_hardirqs_on_caller+0x186/0x280
 [] ? trace_hardirqs_on+0xd/0x10
 [] ? context_tracking_exit+0x1d/0x20
 [] ? enter_from_user_mode+0x1f/0x50
 [] ? syscall_trace_enter_phase1+0x1a2/0x240
 [] ? enter_from_user_mode+0x50/0x50
 [] ? int_ret_from_sys_call+0x52/0x9f
 [] ? trace_hardirqs_on_caller+0x186/0x280
 [] ? trace_hardirqs_on_thunk+0x17/0x19
 [] SyS_sendto+0xe/0x10
 [] entry_SYSCALL_64_fastpath+0x12/0x6b

This maybe ?

diff --git a/net/sctp/ipv6.c b/net/sctp/ipv6.c
index acb45b8c2a9d..7081183f4d9f 100644
--- a/net/sctp/ipv6.c
+++ b/net/sctp/ipv6.c
@@ -328,7 +328,9 @@ static void sctp_v6_get_dst(struct sctp_transport *t, union 
sctp_addr *saddr,
if (baddr) {
fl6->saddr = baddr->v6.sin6_addr;
fl6->fl6_sport = baddr->v6.sin6_port;
+   rcu_read_lock();
final_p = fl6_update_dst(fl6, rcu_dereference(np->opt), );
+   rcu_read_unlock();
dst = ip6_dst_lookup_flow(sk, fl6, final_p);
}
 
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: suspicious rcu_dereference_check in sctp_v6_get_dst

[Dave Jones]

On Sat, Dec 05, 2015 at 05:13:06PM -0800, Eric Dumazet wrote:
 
 > > diff --git a/net/sctp/ipv6.c b/net/sctp/ipv6.c
 > > index acb45b8c2a9d..7081183f4d9f 100644
 > > --- a/net/sctp/ipv6.c
 > > +++ b/net/sctp/ipv6.c
 > > @@ -328,7 +328,9 @@ static void sctp_v6_get_dst(struct sctp_transport *t, 
 > > union sctp_addr *saddr,
 > >if (baddr) {
 > >fl6->saddr = baddr->v6.sin6_addr;
 > >fl6->fl6_sport = baddr->v6.sin6_port;
 > > +  rcu_read_lock();
 > >final_p = fl6_update_dst(fl6, rcu_dereference(np->opt), );
 > > +  rcu_read_unlock();
 > >dst = ip6_dst_lookup_flow(sk, fl6, final_p);
 > >}
 > >  
 > 
 > Hmm, better use :
 > 
 > diff --git a/net/sctp/ipv6.c b/net/sctp/ipv6.c
 > index acb45b8c2a9d..d28c0b4c9128 100644
 > --- a/net/sctp/ipv6.c
 > +++ b/net/sctp/ipv6.c
 > @@ -323,14 +323,13 @@ static void sctp_v6_get_dst(struct sctp_transport *t, 
 > union sctp_addr *saddr,
 >  }
 >  }
 >  }
 > -rcu_read_unlock();
 > -
 >  if (baddr) {
 >  fl6->saddr = baddr->v6.sin6_addr;
 >  fl6->fl6_sport = baddr->v6.sin6_port;
 >  final_p = fl6_update_dst(fl6, rcu_dereference(np->opt), );
 >  dst = ip6_dst_lookup_flow(sk, fl6, final_p);
 >  }
 > +rcu_read_unlock();
 >  
 >  out:
 >  if (!IS_ERR_OR_NULL(dst)) {

I looked at that option first, but decided to mirror the other use of 
fl6_update_dst.

It looks like your solution would work too, so I'm not against it, but..
For my own understanding, why is this better? Just to cut down on the
number of repeated lock/unlocks in the same function?  Or is there some
semantic I'm missing in the earlier lock/unlock section that's somehow
related to the np->opt ?

thanks,

Dave

--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

4.4-rc2 xfrm_lookup kasan trace

[Dave Jones]

My router fell off the internet. When I got home, I found a few hundred
of these traces in the logs, and it refusing to route packets.

Oddly, it only prints a stack trace, and no clue as to why it printed that 
trace.

There was also nothing in the log prior to this that indicates how it got that 
B taint flag.

Dave


[603360.306331] CPU: 1 PID: 0 Comm: swapper/1 Tainted: GB   
4.4.0-rc2-firewall+ #1 
[603360.337025]  8801cd6ce000 8801d7a06cf8 9048b2f5 
8801d5e7e480
[603360.368282]  8801d7a06d28 90229b0e 8801d5e7e480 
ea000735b380
[603360.399125]  8801cd6ce000 8801d5ff0fc0 8801d7a06d50 
9022d3f6
[603360.429176] Call Trace:
[603360.458052][] dump_stack+0x4e/0x79
[603360.487675]  [] print_trailer+0xfe/0x160
[603360.517636]  [] object_err+0x36/0x40
[603360.546088]  [] kasan_report_error+0x220/0x550
[603360.574215]  [] ? __lock_acquire+0x896/0x2640
[603360.601980]  [] kasan_report+0x3b/0x40
[603360.629324]  [] ? debug_show_all_locks+0x180/0x1e0
[603360.656451]  [] ? xfrm_lookup+0xf0/0x660
[603360.683140]  [] __asan_load8+0x5f/0x70
[603360.709419]  [] xfrm_lookup+0xf0/0x660
[603360.735602]  [] ? __xfrm_sk_clone_policy+0xc0/0xc0
[603360.761639]  [] ? debug_smp_processor_id+0x17/0x20
[603360.787360]  [] ? preempt_count_sub+0x1a/0x130
[603360.812995]  [] ? __lock_is_held+0x46/0xd0
[603360.838501]  [] ? memset+0x29/0x30
[603360.863983]  [] nf_xfrm_me_harder+0x114/0x2d0
[603360.889656]  [] ? __nf_nat_l4proto_find+0x80/0x80
[603360.915558]  [] ? nf_nat_ipv4_fn+0x290/0x2e0
[603360.941462]  [] ? iptable_nat_ipv4_fn+0x20/0x20
[603360.967401]  [] nf_nat_ipv4_out+0x184/0x220
[603360.993433]  [] ? iptable_nat_ipv4_local_fn+0x20/0x20
[603361.019595]  [] iptable_nat_ipv4_out+0x15/0x20
[603361.045888]  [] nf_iterate+0xd2/0xf0
[603361.072191]  [] nf_hook_slow+0x13a/0x240
[603361.098581]  [] ? nf_hook_slow+0x5/0x240
[603361.124834]  [] ? nf_iterate+0xf0/0xf0
[603361.151104]  [] ? memset+0x29/0x30
[603361.177243]  [] ? __alloc_skb+0x212/0x300
[603361.203134]  [] ip_output+0x1ad/0x210
[603361.228679]  [] ? ip_mc_output+0x460/0x460
[603361.254310]  [] ? ip_fragment.constprop.55+0x100/0x100
[603361.280199]  [] ip_local_out+0x63/0xb0
[603361.306122]  [] ip_build_and_send_pkt+0x28b/0x3a0
[603361.332270]  [] tcp_v4_send_synack+0x112/0x190
[603361.358528]  [] ? tcp_v4_send_check+0x50/0x50
[603361.384745]  [] ? inet_ehash_insert+0x1dd/0x280
[603361.410437]  [] tcp_conn_request+0x113a/0x12b0
[603361.435741]  [] ? netlink_has_listeners+0x150/0x220
[603361.460943]  [] ? netlink_has_listeners+0x37/0x220
[603361.485599]  [] ? inet_reqsk_alloc+0x150/0x150
[603361.510179]  [] ? mark_lock+0x78/0x8e0
[603361.534585]  [] ? mark_lock+0x78/0x8e0
[603361.558608]  [] ? percpu_down_read_trylock+0x60/0xb0
[603361.582983]  [] ? __lock_acquire+0x896/0x2640
[603361.607459]  [] ? __lock_is_held+0x46/0xd0
[603361.631958]  [] tcp_v4_conn_request+0xa2/0x100
[603361.656480]  [] tcp_v6_conn_request+0x114/0x120
[603361.680930]  [] tcp_rcv_state_process+0x390/0x1a80
[603361.705533]  [] ? tcp_finish_connect+0x200/0x200
[603361.730243]  [] ? sk_filter+0x189/0x370
[603361.754986]  [] ? sk_filter+0x8d/0x370
[603361.779605]  [] ? bpf_skb_store_bytes+0x480/0x480
[603361.804405]  [] ? __inet_lookup_listener+0x5/0x420
[603361.829127]  [] tcp_v4_do_rcv+0x162/0x3b0
[603361.853660]  [] tcp_v4_rcv+0x1117/0x1380
[603361.877999]  [] ip_local_deliver_finish+0x157/0x500
[603361.902445]  [] ? ip_local_deliver_finish+0x7d/0x500
[603361.926905]  [] ip_local_deliver+0xd2/0x170
[603361.951315]  [] ? ip_call_ra_chain+0x270/0x270
[603361.975613]  [] ? inet_del_offload+0x40/0x40
[603361.999726]  [] ip_rcv_finish+0x129/0x750
[603362.023793]  [] ip_rcv+0x4e6/0x720
[603362.047137]  [] ? ip_local_deliver+0x170/0x170
[603362.069940]  [] ? packet_rcv_spkt+0x19f/0x1e0
[603362.092671]  [] ? ip_local_deliver_finish+0x500/0x500
[603362.115505]  [] ? packet_rcv_spkt+0x19f/0x1e0
[603362.138080]  [] ? ip_local_deliver+0x170/0x170
[603362.160542]  [] __netif_receive_skb_core+0x81f/0x1000
[603362.183021]  [] ? packet_setsockopt+0x1260/0x1260
[603362.205603]  [] ? __netdev_printk+0x2d0/0x2d0
[603362.228193]  [] ? mark_held_locks+0x24/0xd0
[603362.250707]  [] ? ktime_get_with_offset+0x119/0x280
[603362.273297]  [] __netif_receive_skb+0x27/0xb0
[603362.295803]  [] ? debug_smp_processor_id+0x17/0x20
[603362.318343]  [] netif_receive_skb_internal+0xd1/0x2a0
[603362.341056]  [] ? netif_receive_skb_internal+0x85/0x2a0
[603362.363888]  [] ? netif_rx_internal+0x3e0/0x3e0
[603362.386617]  [] ? dev_gro_receive+0xbb/0x7f0
[603362.409379]  [] ? dev_gro_receive+0x2b9/0x7f0
[603362.431953]  [] ? rcu_read_lock_sched_held+0x8c/0xa0
[603362.454630]  [] ? __lock_is_held+0x28/0xd0
[603362.477325]  [] napi_gro_receive+0x15c/0x220
[603362.44]  [] rtl8169_poll+0x49d/0xb70
[603362.522636]  [] ? debug_show_all_locks+0x1e0/0x1e0
[603362.545398]  [] net_rx_action+0x41b/0x6a0
[603362.568169]  [] ? napi_complete_done+0x100/0x100

dccp->bind_conflict jump to null.

[Dave Jones]

I've been trying to figure this one out for a while. It smells like a race,
but I can't figure out any more than the clues below, and I've not really
got the time to dig into it.

After running Trinity for a while, I saw the machine just suddenly reboot.
I managed to capture a partial trace over serial console, which pointed
me at dccp.

Oops: 0010 [#1] PREEMPT SMP DEBUG_PAGEALLOC 
CPU: 1 PID: 20093 Comm: trinity-c201 Tainted: GW   4.4.0-rc1
task: 8800d08b8000 ti: 8801e1464000 task.ti: 8801e1464000
RIP: 0010:[<>]  [<  (null)>]   (null)
RSP: 0018:8801e1467e68  EFLAGS: 00010246
RAX: c02aa1c0 RBX: 8804563ee9c0 RCX: 8804563ee9c0
RDX: 0001 RSI: 88046af1fb00 RDI: 8804563ee9c0
RBP: 8801e1467ed8 R08: 88046af1fb00 R09: 0001
R10: 8800d08b88d0 R11: a42b R12: 8804563ee9c0
R13: c02a0900 R14: 8800ce16be80 R15: 97ed3040
FS:  7f5f8e3f8700() GS:880507a0() knlGS:
CS:  0010 DS:  ES:  CR0: 80050033
CR2:  CR3: 000101aa2000 CR4: 001406e0
Stack:
 97740a04 03e80005 97d0a9d8 8804563ee9c0
 88046af1fb00 0032 a42b 
 8804563eef70 8804563ee9c0 0008 0008
Call Trace:
 [] ? inet_csk_get_port+0x3e4/0x4f0
 [] inet_csk_listen_start+0x65/0xc0
 [] inet_dccp_listen+0x87/0xb0 [dccp]
 [] SyS_listen+0x4e/0x80
 [] entry_SYSCALL_64_fastpath+0x12/0x6b
Code:  Bad RIP value.
RIP  [<  (null)>]   (null)
 RSP 
CR2: 


I added some simple null checks before inet_csk_get_port called into
->bind_conflict, with some debug info, and noticed that I managed
to trigger both calls...

[282097.685755] 1st bind_conflict == NULL   ops=c05601c0 state=7 
err:110 protocol:33 type:6
[350754.355455] 2nd bind_conflict == NULL   ops=c05601c0 state=10 
err:0 protocol:33 type:6

the ops struct is dccp_ipv6_mapped.

I was wondering if maybe the whole ops struct was getting zero'd.
But that doesn't look like the case..

(from a different run: different addresses)

[87853.676775] 2nd bind_conflict == NULLops=c054d1c0 state=10 
err:0 protocol:33 type:6
[87853.683740] queue_xmit:a473a510
[87853.690634] send_check:c04c8010
[87853.697574] rebuild_header:a47766a0
[87853.704509] sk_rx_dst_set:  (null)
[87853.711467] conn_request:c054c590
[87853.718427] syn_recv_sock:c054b880
[87853.725296] setsockopt:a47d5410
[87853.732055] getsockopt:a47d3ea0
[87853.738789] compat_setsockopt:a47d54b0
[87853.745554] compat_getsockopt:a47d3fb0
[87853.752244] addr2sockaddr:a47f29a0
[87853.758936] bind_conflict:  (null)
[87853.765643] mtu_reduced:  (null)


The reason I think this looks like a race, is that even with my NULL checks
before doing the dereference, sometimes I still get that sudden reboot,
with the same partial trace. It happens a lot less with my check, but it's
obviously not perfect, and just a few instructions is wide enough to lose
the race sometimes.

Debug patches I came up with below.

Anyone have any idea what's up here ? I don't use dccp, and neither does
$dayjob, so I'm about ready to just disable it and move on, but in case
anyone is interested in debugging this further...

Dave


diff --git a/net/ipv4/inet_connection_sock.c b/net/ipv4/inet_connection_sock.c
index 46b9c887bede..071cbe556a97 100644
--- a/net/ipv4/inet_connection_sock.c
+++ b/net/ipv4/inet_connection_sock.c
@@ -87,6 +87,25 @@ int inet_csk_bind_conflict(const struct sock *sk,
 }
 EXPORT_SYMBOL_GPL(inet_csk_bind_conflict);
 
+static void printops(const struct inet_connection_sock_af_ops *o)
+{
+   printk("queue_xmit:%p\n", o->queue_xmit);
+   printk("send_check:%p\n", o->send_check);
+   printk("rebuild_header:%p\n", o->rebuild_header);
+   printk("sk_rx_dst_set:%p\n", o->sk_rx_dst_set);
+   printk("conn_request:%p\n", o->conn_request);
+   printk("syn_recv_sock:%p\n", o->syn_recv_sock);
+   printk("setsockopt:%p\n", o->setsockopt);
+   printk("getsockopt:%p\n", o->getsockopt);
+#ifdef CONFIG_COMPAT
+   printk("compat_setsockopt:%p\n", o->compat_setsockopt);
+   printk("compat_getsockopt:%p\n", o->compat_getsockopt);
+#endif
+   printk("addr2sockaddr:%p\n", o->addr2sockaddr);
+   printk("bind_conflict:%p\n", o->bind_conflict);
+   printk("mtu_reduced:%p\n", o->mtu_reduced);
+}
+
 /* Obtain a reference to a local port for the given sock,
  * if snum is zero it means select any available local port.
  */
@@ -137,6 +156,15 @@ again:
smallest_size = tb->num_owners;
smallest_rover = rover;
}
+
+  

Re: 4.3.0+ breaks software VPN

[Dave Jones]

On Fri, Nov 13, 2015 at 02:37:00PM -0700, Jens Axboe wrote:
 > Hi,
 > 
 > Tried to connect to sw vpn today, and it isn't working. Running git 
 > as-of yesterday. In dmesg:
 > 
 > [23703.921542] vpn0: set_features() failed (-1); wanted 
 > 0x008048c1, left 0x0080001b48c9
 > 
 > Reverting:
 > 
 > fd867d51f889
 > 5ba3f7d61a3a
 > e7868a85e1b2
 > 
 > in reverse order makes it work again. How do we get this fixed so that 
 > 4.4-rc1 doesn't break basic VPN support?

Possibly related:
I see those set_features warnings have started spewing in my 2-nic bonding
setup too.

[   51.595169] Ethernet Channel Bonding Driver: v3.7.1 (April 27, 2011)
[   51.595647] bond0: set_features() failed (-1); wanted 0x0fc0f388, 
left 0x0fd9fbe9
[   51.597168] bond0: Setting MII monitoring interval to 100
[   51.600782] bond0: Adding slave eth0
[   51.831790] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   51.832078] bond0: set_features() failed (-1); wanted 0x0fd9fba9, 
left 0x0fd9fbe9
[   51.832190] bond0: Enslaving eth0 as an active interface with a down link
[   51.836657] bond0: Adding slave eth1
[   52.039515] IPv6: ADDRCONF(NETDEV_UP): eth1: link is not ready
[   52.039655] bond0: set_features() failed (-1); wanted 0x0fd9fba9, 
left 0x0fd9fbe9
[   52.039735] bond0: Enslaving eth1 as an active interface with a down link


Dave
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: kasan r8169 use-after-free trace.

[Dave Jones]

On Wed, Nov 11, 2015 at 10:19:28AM +0100, Francois Romieu wrote:
 > Dave Jones <da...@codemonkey.org.uk> :
 > > This happens during boot, (and then there's a flood of traces that happen 
 > > so fast
 > > afterwards it completely overwhelms serial console; not sure if they're the
 > > same/related or not).
 > > 
 > > ==
 > > BUG: KASAN: use-after-free in rtl8169_poll+0x4b6/0xb70 at addr 
 > > 8801d43b3288
 > > Read of size 1 by task kworker/0:3/188
 > > =
 > > BUG kmalloc-256 (Not tainted): kasan: bad access detected
 > > -
 > > 
 > > Disabling lock debugging due to kernel taint
 > > INFO: Slab 0xea000750ecc0 objects=16 used=16 fp=0x  (null) 
 > > flags=0x8080
 > > INFO: Object 0x8801d43b3200 @offset=512 fp=0x8801d43b3800
 > > 
 > > Bytes b4 8801d43b31f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
 > >  
 > > Object 8801d43b3200: 00 38 3b d4 01 88 ff ff 00 00 00 00 00 00 00 00  
 > > .8;.
 > 
 > Does the patch below cure it ?

It did, thanks for the quick turnaround!  It also turns out this was responsible
for the flood of spew afterwards. It's completely silent when I apply your diff.

Dave
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

kasan r8169 use-after-free trace.

[Dave Jones]

This happens during boot, (and then there's a flood of traces that happen so 
fast
afterwards it completely overwhelms serial console; not sure if they're the
same/related or not).


==
BUG: KASAN: use-after-free in rtl8169_poll+0x4b6/0xb70 at addr 8801d43b3288
Read of size 1 by task kworker/0:3/188
=
BUG kmalloc-256 (Not tainted): kasan: bad access detected
-

Disabling lock debugging due to kernel taint
INFO: Slab 0xea000750ecc0 objects=16 used=16 fp=0x  (null) 
flags=0x8080
INFO: Object 0x8801d43b3200 @offset=512 fp=0x8801d43b3800

Bytes b4 8801d43b31f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  

Object 8801d43b3200: 00 38 3b d4 01 88 ff ff 00 00 00 00 00 00 00 00  
.8;.
Object 8801d43b3210: 0d 17 8e 3c 8b 87 15 14 00 00 00 00 00 00 00 00  
...<
Object 8801d43b3220: 00 80 bb 37 00 88 ff ff 00 00 00 00 00 00 00 00  
...7
Object 8801d43b3230: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  

Object 8801d43b3240: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  

Object 8801d43b3250: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  

Object 8801d43b3260: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  

Object 8801d43b3270: 00 00 00 00 00 00 00 00 2e 00 00 00 00 00 00 00  

Object 8801d43b3280: 0e 00 00 00 00 00 21 00 01 00 00 00 00 00 00 00  
..!.
Object 8801d43b3290: 00 00 00 00 00 00 00 00 02 00 00 00 00 00 00 00  

Object 8801d43b32a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  

Object 8801d43b32b0: 00 00 00 00 08 06 4e 00 4e 00 40 00 7c 00 00 00  
..N.N.@.|...
Object 8801d43b32c0: 80 00 00 00 00 00 00 00 40 7e 60 d5 01 88 ff ff  
@~`.
Object 8801d43b32d0: 8e 7e 60 d5 01 88 ff ff c0 02 00 00 01 00 00 00  
.~`.
Object 8801d43b32e0: 40 82 c5 d3 01 88 ff ff 00 00 00 00 00 00 00 00  
@...
Object 8801d43b32f0: a8 1c 2d d5 00 88 ff ff 00 00 00 00 00 00 00 00  
..-.
CPU: 0 PID: 188 Comm: kworker/0:3 Tainted: GB   4.3.0-firewall+ #15
Workqueue: events linkwatch_event
 880037bb89d8 8801d7a07bc8 93489155 8801d6801900
 8801d7a07bf8 932295de 8801d6801900 ea000750ecc0
 8801d43b3200 8800d442a000 8801d7a07c20 9322ce06
Call Trace:
   [] dump_stack+0x4e/0x79
 [] print_trailer+0xfe/0x160
 [] object_err+0x36/0x40
 [] kasan_report_error+0x220/0x550
 [] ? dev_gro_receive+0xbb/0x7f0
 [] ? dev_gro_receive+0x2b9/0x7f0
 [] kasan_report+0x3b/0x40
 [] ? rtl8169_poll+0x4b6/0xb70
 [] __asan_load1+0x48/0x50
 [] rtl8169_poll+0x4b6/0xb70
 [] ? _raw_spin_unlock_irqrestore+0x43/0x70
 [] net_rx_action+0x41b/0x6a0
 [] ? napi_complete_done+0x100/0x100
 [] __do_softirq+0x1b2/0x5c0
 [] irq_exit+0xfc/0x110
 [] do_IRQ+0x82/0x160
 [] common_interrupt+0x86/0x86
   [] ? console_unlock+0x3bd/0x620
 [] vprintk_emit+0x3ce/0x6d0
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH] sh_eth: merge sh_eth_free_dma_buffer() into sh_eth_ring_free()

[Dave Jones]

On Thu, Nov 05, 2015 at 01:29:15PM -0500, David Miller wrote:
 > From: Sergei Shtylyov 
 > Date: Thu, 5 Nov 2015 20:19:17 +0300
 > 
 > >Hmm, I hadn't seen your announcement, else I would have refrained from
 > >sending. Will look for it now...
 > 
 > I really don't know how to better get people's attention than this:
 > 
 >  http://marc.info/?l=linux-netdev=144652382428132=2
 > 
 > Do I have to use all CAPS?  Flashing LEDs in the Subject?
 > 
 > Just tell me, I'll do it...

web page on www.isnetnextopen.com, with a giant word saying YES or NO :)

Dave

--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

I218 e1000e hangs.

[Dave Jones]

I've got a machine with an onboard NIC that reproduces a hardware
hang every time I do an rsync to it.

[  488.752630] e1000e :00:19.0 eth0: Detected Hardware Unit Hang:
  TDH  27
  TDT  34
  next_to_use  34
  next_to_clean23
buffer_info[next_to_clean]:
  time_stamp   148b2
  next_to_watch27
  jiffies  149d8
  next_to_watch.status 0
MAC Status 80083
PHY Status 796d
PHY 1000BASE-T Status  7c00
PHY Extended Status3000
PCI Status 10
[  490.751948] e1000e :00:19.0 eth0: Detected Hardware Unit Hang:
  TDH  27
  TDT  34
  next_to_use  34
  next_to_clean23
buffer_info[next_to_clean]:
  time_stamp   148b2
  next_to_watch27
  jiffies  14aa0
  next_to_watch.status 0
MAC Status 80083
PHY Status 796d
PHY 1000BASE-T Status  7c00
PHY Extended Status3000
PCI Status 10
[  492.750447] e1000e :00:19.0 eth0: Detected Hardware Unit Hang:
  TDH  27
  TDT  34
  next_to_use  34
  next_to_clean23
buffer_info[next_to_clean]:
  time_stamp   148b2
  next_to_watch27
  jiffies  14b68
  next_to_watch.status 0
MAC Status 80083
PHY Status 796d
PHY 1000BASE-T Status  7c00
PHY Extended Status3000
PCI Status 10
[  494.749507] e1000e :00:19.0 eth0: Detected Hardware Unit Hang:
  TDH  27
  TDT  34
  next_to_use  34
  next_to_clean23
buffer_info[next_to_clean]:
  time_stamp   148b2
  next_to_watch27
  jiffies  14c30
  next_to_watch.status 0
MAC Status 80083
PHY Status 796d
PHY 1000BASE-T Status  7c00
PHY Extended Status3000
PCI Status 10
[  494.758881] [ cut here ]
[  494.759109] WARNING: CPU: 0 PID: 0 at net/sched/sch_generic.c:303 
dev_watchdog+0x23a/0x250()
[  494.759347] NETDEV WATCHDOG: eth0 (e1000e): transmit queue 0 timed out
[  494.759585] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 
4.2.0-rc6-backup-debug+ #1
[  494.759841]  b0ddd622 0431bce15e8d04e9 88043d803d08 
b097e15b
[  494.760111]  0007 88043d803d60 88043d803d48 
b0076de5
[  494.760392]     
880427bb7d30
[  494.760648] Call Trace:
[  494.760896]  IRQ  [b097e15b] dump_stack+0x4c/0x65
[  494.761160]  [b0076de5] warn_slowpath_common+0x85/0xc0
[  494.761423]  [b0076ea5] warn_slowpath_fmt+0x55/0x70
[  494.761686]  [b087b02a] dev_watchdog+0x23a/0x250
[  494.761949]  [b087adf0] ? qdisc_rcu_free+0x40/0x40
[  494.762215]  [b00e9703] call_timer_fn+0xb3/0x420
[  494.762483]  [b00e9655] ? call_timer_fn+0x5/0x420
[  494.762753]  [b00e9c02] run_timer_softirq+0x192/0x3d0
[  494.763025]  [b007b6b5] ? __do_softirq+0xb5/0x5d0
[  494.763300]  [b087adf0] ? qdisc_rcu_free+0x40/0x40
[  494.763570]  [b007b6df] __do_softirq+0xdf/0x5d0
[  494.763838]  [b007bd58] ? irq_exit+0x78/0xc0
[  494.764108]  [b007bd98] irq_exit+0xb8/0xc0
[  494.764381]  [b098bee6] smp_apic_timer_interrupt+0x46/0x60
[  494.764662]  [b098a8ad] apic_timer_interrupt+0x6d/0x80
[  494.764943]  EOI  [b0815916] ? cpuidle_enter_state+0x106/0x3a0
[  494.765232]  [b0815951] ? cpuidle_enter_state+0x141/0x3a0
[  494.765525]  [b0815946] ? cpuidle_enter_state+0x136/0x3a0
[  494.765815]  [b0815be7] cpuidle_enter+0x17/0x20
[  494.766105]  [b00bca5c] cpu_startup_entry+0x38c/0x500
[  494.766396]  [b0977988] rest_init+0x138/0x140
[  494.766692]  [b0f91f23] start_kernel+0x466/0x487
[  494.766990]  [b0f91495] x86_64_start_reservations+0x2a/0x2c
[  494.767292]  [b0f91583] x86_64_start_kernel+0xec/0xf0

Here's another instance after rebooting, with some different register states..

[ 2379.674285] e1000e :00:19.0 eth0: Detected Hardware Unit Hang:
  TDH  50
  TDT  5d
  next_to_use  5d
  next_to_clean4d
buffer_info[next_to_clean]:
  time_stamp   100032c2d
  next_to_watch50
  jiffies  100032ce8
  next_to_watch.status 0
MAC Status 80083
PHY Status 796d
PHY 1000BASE-T Status  3c00
PHY Extended Status3000
PCI Status 10
[ 2381.672792] e1000e :00:19.0 eth0: Detected Hardware Unit Hang:
  TDH  50
  TDT  5d
  next_to_use  5d
  next_to_clean4d
buffer_info[next_to_clean]:
  time_stamp   100032c2d
  next_to_watch50
  jiffies  100032db0
  next_to_watch.status 0
MAC Status 80083
PHY Status 796d
PHY 1000BASE-T Status  3c00
PHY Extended 

Re: dccp related oops in inet_csk_get_port

[Dave Jones]

On Wed, Jul 15, 2015 at 06:07:10PM -0400, Dave Jones wrote:
  While experimenting with some dccp fuzzing, I hit this..
  
  Oops: 0010 [#1] PREEMPT SMP DEBUG_PAGEALLOC 
  CPU: 3 PID: 19269 Comm: trinity-c22 Not tainted 4.2.0-rc2-think+ #2
  task: 88006f3954c0 ti: 8802b89b task.ti: 8802b89b
  RIP: 0010:[]  [  (null)]   (null)
  RSP: 0018:8802b89b3e30  EFLAGS: 00010246
  RAX: c063b200 RBX: 908c RCX: 908c
  RDX: 0001 RSI: 8800cb94ef00 RDI: 880501ad8c40
  RBP: 8802b89b3eb8 R08: 8800cb94ef00 R09: 
  R10: 0001 R11: 0005 R12: 908c
  R13: c0631940 R14: afeefd40 R15: 8800cc97e850
  FS:  7fc948b0b740() GS:880507e0() knlGS:
  CS:  0010 DS:  ES:  CR0: 80050033
  CR2:  CR3: 00024f2d2000 CR4: 001407e0
  DR0: 7fe46baf DR1:  DR2: 
  DR3:  DR6: 0ff0 DR7: 0600
  Stack:
   af725ae5 8802b89b3e48 03e80005 8802b89b3e68
   880501ad8c40 8800cb94ef00 880033cc8000 b89b3e88
    880501ad9200 880501ad9200 8802b89b3eb8
  Call Trace:
   [af725ae5] ? inet_csk_get_port+0x3a5/0x4f0
   [af7260a9] inet_csk_listen_start+0x79/0xe0
   [c06260bb] inet_dccp_listen+0x8b/0xc0 [dccp]
   [af6b509e] SyS_listen+0x4e/0x80
   [af80063c] tracesys_phase2+0x84/0x89

I managed to reproduce this a lot faster. I can now hit it several times a day.

I threw in this debug patch:

diff --git a/net/ipv4/inet_connection_sock.c b/net/ipv4/inet_connection_sock.c
index 60021d0d9326..89b9cba73b3d 100644
--- a/net/ipv4/inet_connection_sock.c
+++ b/net/ipv4/inet_connection_sock.c
@@ -198,6 +198,14 @@ tb_found:
goto success;
} else {
ret = 1;
+
+   if (inet_csk(sk)-icsk_af_ops-bind_conflict == NULL) {
+   printk(KERN_INFO bind_conflict == NULL\tops=%p 
state=%d err:%d\n,
+   inet_csk(sk)-icsk_af_ops,
+   sk-sk_state, sk-sk_err);
+   goto fail_unlock;
+   }
+
if (inet_csk(sk)-icsk_af_ops-bind_conflict(sk, tb, 
true)) {
if (((sk-sk_reuse  sk-sk_state != 
TCP_LISTEN) ||
 (tb-fastreuseport  0 



And now I regularly get 

[ 7544.518516] bind_conflict == NULLops=c04a1200 state=10 err:0

$ grep c04a1200  /proc/kallsyms 
c04a1200 r dccp_ipv6_mapped [dccp_ipv6]

It's always the v6 struct this happens with (at least so far).

What I'm missing, is how that pointer can be zero.
It's in rodata. Any write to it should cause a page fault.

Also, I don't see anywhere where we actually write to that table directly.
Do we do an indirect clearing of icsk_af_ops anywhere ?
I'm not seeing anything obvious.

Dave

--
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

dccp related oops in inet_csk_listen_start

[Dave Jones]

While experimenting with some dccp fuzzing, I hit this..

Oops: 0010 [#1] PREEMPT SMP DEBUG_PAGEALLOC 
CPU: 3 PID: 19269 Comm: trinity-c22 Not tainted 4.2.0-rc2-think+ #2
task: 88006f3954c0 ti: 8802b89b task.ti: 8802b89b
RIP: 0010:[]  [  (null)]   (null)
RSP: 0018:8802b89b3e30  EFLAGS: 00010246
RAX: c063b200 RBX: 908c RCX: 908c
RDX: 0001 RSI: 8800cb94ef00 RDI: 880501ad8c40
RBP: 8802b89b3eb8 R08: 8800cb94ef00 R09: 
R10: 0001 R11: 0005 R12: 908c
R13: c0631940 R14: afeefd40 R15: 8800cc97e850
FS:  7fc948b0b740() GS:880507e0() knlGS:
CS:  0010 DS:  ES:  CR0: 80050033
CR2:  CR3: 00024f2d2000 CR4: 001407e0
DR0: 7fe46baf DR1:  DR2: 
DR3:  DR6: 0ff0 DR7: 0600
Stack:
 af725ae5 8802b89b3e48 03e80005 8802b89b3e68
 880501ad8c40 8800cb94ef00 880033cc8000 b89b3e88
  880501ad9200 880501ad9200 8802b89b3eb8
Call Trace:
 [af725ae5] ? inet_csk_get_port+0x3a5/0x4f0
 [af7260a9] inet_csk_listen_start+0x79/0xe0
 [c06260bb] inet_dccp_listen+0x8b/0xc0 [dccp]
 [af6b509e] SyS_listen+0x4e/0x80
 [af80063c] tracesys_phase2+0x84/0x89


inet_csk_listen_start has an insightful comment about a potential race.
I added this for debugging..

diff --git a/net/ipv4/inet_connection_sock.c b/net/ipv4/inet_connection_sock.c
index 60021d0d9326..d53cba9c1dfd 100644
--- a/net/ipv4/inet_connection_sock.c
+++ b/net/ipv4/inet_connection_sock.c
@@ -814,11 +814,15 @@ int inet_csk_listen_start(struct sock *sk, const int 
nr_table_entries)
inet-inet_sport = htons(inet-inet_num);
 
sk_dst_reset(sk);
+   if (sk-sk_prot-hash == NULL) {
+   printk(sk-sk_prot-hash WAS NULL!\n);
+   goto out;
+   }
sk-sk_prot-hash(sk);
 
return 0;
}
-
+out:
sk-sk_state = TCP_CLOSE;
__reqsk_queue_destroy(icsk-icsk_accept_queue);
return -EADDRINUSE;

But haven't been able to provoke it into happening again.

Is a null check sufficient here, or should this be solved
elsewhere ?

Dave

--
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [RFC net-next] net: Build IPv6 into kernel by default

[Dave Jones]

On Thu, Jul 09, 2015 at 01:42:29PM -0700, Tom Herbert wrote:
 
 For general information about IPv6, see
 https://en.wikipedia.org/wiki/IPv6.
  -  For Linux IPv6 development information, see 
  http://www.linux-ipv6.org.
  -  For specific information about IPv6 under Linux, read the HOWTO at
  -  http://www.bieringer.de/linux/IPv6/.
  +  For specific information about IPv6 under Linux, see
  +  Documentation/networking/ipv6.txt and read the HOWTO at
  +  http://http://www.tldp.org/HOWTO/Linux+IPv6-HOWTO/
   ^^^
Dupe.

Dave

--
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

4.1+ use after free in netlink_broadcast_filtered

[Dave Jones]

I taught Trinity about NETLINK_LISTEN_ALL_NSID and NETLINK_LIST_MEMBERSHIPS
yesterday, and this evening, this fell out..

general protection fault:  [#1] PREEMPT SMP DEBUG_PAGEALLOC 
CPU: 1 PID: 9130 Comm: kworker/1:1 Not tainted 4.1.0-gelk-debug+ #1
Workqueue: sock_diag_events sock_diag_broadcast_destroy_work
task: 8800b94e4c40 ti: 8800352ec000 task.ti: 8800352ec000
RIP: 0010:[845c82e4]  [845c82e4] 
netlink_broadcast_filtered+0x24/0x3b0
RSP: :8800352efd08  EFLAGS: 00010292
RAX: 8800ab903d80 RBX: 0003 RCX: 0003
RDX:  RSI: 00d0 RDI: 8800b9c586c0
RBP: 8800352efd78 R08: 00d0 R09: 
R10:  R11: 0220 R12: 
R13: 6b6b6b6b6b6b6b6b R14: 0003 R15: 
FS:  () GS:8800bf70() knlGS:
CS:  0010 DS:  ES:  CR0: 8005003b
CR2: 02121ff8 CR3: 30169000 CR4: 07e0
DR0: 7fe1f0454000 DR1:  DR2: 
DR3:  DR6: 0ff0 DR7: 0600
Stack:
 8800b9c586c0 8800b9c586c0 8800ac4692c0 8800936d4a90
 8800352efd38 8469a93e 8800352efd98 c09b9b90
 8800352efd78 8800ac4692c0 8800b9c586c0 8800831b6ab8
Call Trace:
 [8469a93e] ? mutex_unlock+0xe/0x10
 [c09b9b90] ? inet_diag_handler_get_info+0x110/0x1fb [inet_diag]
 [845c868d] netlink_broadcast+0x1d/0x20
 [8469a93e] ? mutex_unlock+0xe/0x10
 [845b2bf5] sock_diag_broadcast_destroy_work+0xd5/0x160
 [8408ea97] process_one_work+0x147/0x420
 [8408f0f9] worker_thread+0x69/0x470
 [8409fda3] ? preempt_count_sub+0xa3/0xf0
 [8408f090] ? rescuer_thread+0x320/0x320
 [84093cd7] kthread+0x107/0x120
 [84093bd0] ? kthread_create_on_node+0x1b0/0x1b0
 [8469d31f] ret_from_fork+0x3f/0x70
 [84093bd0] ? kthread_create_on_node+0x1b0/0x1b0
Code: 1f 84 00 00 00 00 00 66 66 66 66 90 55 48 89 e5 41 57 41 56 41 55 49 89 
fd 48 89 f7 44 89 c6 41 54 41 89 d4 53 89 cb 48 83 ec 48 49 8b 45 30 44 89 45 
a4 4c 89 4d 98 48 89 45 c0 e8 07 f6 ff ff 
RIP  [845c82e4] netlink_broadcast_filtered+0x24/0x3b0
 RSP 8800352efd08
---[ end trace e2d8a07893775a9e ]---
 

r13 looks like slab poison, and the decoded instruction shows..


int netlink_broadcast_filtered(struct sock *ssk, struct sk_buff *skb, u32 
portid,
u32 group, gfp_t allocation,
int (*filter)(struct sock *dsk, struct sk_buff *skb, void *data),
void *filter_data)
{
1b70:   e8 00 00 00 00  callq  1b75 
netlink_broadcast_filtered+0x5
1b75:   55  push   %rbp
1b76:   48 89 e5mov%rsp,%rbp
1b79:   41 57   push   %r15
1b7b:   41 56   push   %r14
1b7d:   41 55   push   %r13
1b7f:   49 89 fdmov%rdi,%r13
1b82:   48 89 f7mov%rsi,%rdi
1b85:   44 89 c6mov%r8d,%esi
1b88:   41 54   push   %r12
1b8a:   41 89 d4mov%edx,%r12d
1b8d:   53  push   %rbx
1b8e:   89 cb   mov%ecx,%ebx
1b90:   48 83 ec 48 sub$0x48,%rsp
1b94:   49 8b 45 30 mov0x30(%r13),%rax--  trapping 
instruction
1b98:   44 89 45 a4 mov%r8d,-0x5c(%rbp)
1b9c:   4c 89 4d 98 mov%r9,-0x68(%rbp)
1ba0:   48 89 45 c0 mov%rax,-0x40(%rbp)
struct net *net = sock_net(ssk);


So it looks like the ssk we passed in was already freed.
I'll dig into this some more next week, and try to find a better
reproducer.

Dave

--
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

ssh connections hanging on 4.1rc7

[Dave Jones]

Just hit this weird problem where I can ssh into a machine once,
then after logging out, subsequent ssh connections hang.

The client side looks like..

13:39:06.307781 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [S], seq 319726787, win 29200, options [mss 1460,sackOK,TS val 77408596 
ecr 0,nop,wscale 7], length 0
13:39:06.308580 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 319726788:319726820, ack 1404309216, win 229, options 
[nop,nop,TS val 77408597 ecr 19368680], length 32
13:39:06.332551 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 32:2000, ack 33, win 229, options [nop,nop,TS val 77408621 ecr 
19368703], length 1968
13:39:06.370042 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 2048:2064, ack 1265, win 258, options [nop,nop,TS val 77408658 
ecr 19368734], length 16
13:39:06.449511 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [.], ack 1309, win 258, options [nop,nop,TS val 77408738 ecr 19368782], 
length 0

until I ctrl-c which then sends the FIN

13:40:06.914614 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [F.], seq 2108, ack 1309, win 258, options [nop,nop,TS val 77469203 ecr 
19368782], length 0


On the sshd side..


13:39:06.311005 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [S], seq 319726787, win 29200, options [mss 1460,sackOK,TS val 77408596 
ecr 0,nop,wscale 7], length 0
13:39:06.311254 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [.], ack 1404309216, win 229, options [nop,nop,TS val 77408596 ecr 
19368680], length 0
13:39:06.311778 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 0:32, ack 1, win 229, options [nop,nop,TS val 77408597 ecr 
19368680], length 32
13:39:06.334546 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [.], ack 33, win 229, options [nop,nop,TS val 77408619 ecr 19368703], 
length 0
13:39:06.335779 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 32:2000, ack 33, win 229, options [nop,nop,TS val 77408621 ecr 
19368703], length 1968
13:39:06.347867 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 2000:2048, ack 985, win 243, options [nop,nop,TS val 77408633 
ecr 19368711], length 48
13:39:06.373232 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 2048:2064, ack 1265, win 258, options [nop,nop,TS val 77408658 
ecr 19368734], length 16
13:39:06.413173 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 2064:2108, ack 1265, win 258, options [nop,nop,TS val 77408698 
ecr 19368782], length 44
13:39:06.452714 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [.], ack 1309, win 258, options [nop,nop,TS val 77408738 ecr 19368782], 
length 0

until the ctrl-c...

13:40:06.917807 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [F.], seq 2108, ack 1309, win 258, options [nop,nop,TS val 77469203 ecr 
19368782], length 0
13:40:06.921241 IP wopr.kernelslacker.org.43982  gelk.kernelslacker.org.ssh: 
Flags [.], ack 1310, win 258, options [nop,nop,TS val 77469206 ecr 19429290], 
length 0


Is there anything out of the ordinary here that I'm missing, or is this perhaps
an sshd bug ?

The odd thing is that it seems repeatable with every host I try to ssh to.

4.1rc7 on both sides, haven't tried reproducing with different kernels yet.

Dave

--
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: ssh connections hanging on 4.1rc7

[Dave Jones]

On Thu, Jun 11, 2015 at 01:46:18PM -0400, Dave Jones wrote:
  Just hit this weird problem where I can ssh into a machine once,
  then after logging out, subsequent ssh connections hang.
  
  The client side looks like..
 
derp, missed half the tcpdump capture on both sides, and now
I can't reproduce it.  I'll resend if it happens again.

Dave
--
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: ssh connections hanging on 4.1rc7

[Dave Jones]

On Thu, Jun 11, 2015 at 11:24:21AM -0700, Eric Dumazet wrote:
 
   Just hit this weird problem where I can ssh into a machine once,
   then after logging out, subsequent ssh connections hang.
   
  Your tcpdumps look one way only.

ok hit it again, so let's try again...

client side:

15:34:10.184012 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [.], ack 1505519347, win 229, options [nop,nop,TS val 84312472 ecr 
26272557], length 0
15:34:10.210704 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [.], ack 33, win 229, options [nop,nop,TS val 84312499 ecr 26272584], 
length 0
15:34:10.218178 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 2000:2048, ack 985, win 243, options [nop,nop,TS val 84312506 
ecr 26272587], length 48
15:34:10.248332 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 2048:2064, ack 1265, win 258, options [nop,nop,TS val 84312536 
ecr 26272614], length 16
15:34:10.288172 IP gelk.kernelslacker.org.ssh  wopr.kernelslacker.org.44268: 
Flags [.], ack 2064, win 257, options [nop,nop,TS val 26272662 ecr 84312536], 
length 0
15:34:10.328516 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [.], ack 1309, win 258, options [nop,nop,TS val 84312617 ecr 26272662], 
length 0
ctrl-c
15:34:27.693304 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [.], ack 1310, win 258, options [nop,nop,TS val 84329981 ecr 26290067], 
length 0

server side:

15:34:10.188611 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [S], seq 2139969123, win 29200, options [mss 1460,sackOK,TS val 84312472 
ecr 0,nop,wscale 7], length 0
15:34:10.188777 IP gelk.kernelslacker.org.ssh  wopr.kernelslacker.org.44268: 
Flags [S.], seq 1505519346, ack 2139969124, win 28960, options [mss 
1460,sackOK,TS val 26272557 ecr 84312472,nop,wscale 7], length 0
15:34:10.189033 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [.], ack 1, win 229, options [nop,nop,TS val 84312472 ecr 26272557], 
length 0
15:34:10.189534 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 1:33, ack 1, win 229, options [nop,nop,TS val 84312473 ecr 
26272557], length 32
15:34:10.189636 IP gelk.kernelslacker.org.ssh  wopr.kernelslacker.org.44268: 
Flags [.], ack 33, win 227, options [nop,nop,TS val 26272558 ecr 84312473], 
length 0
15:34:10.215507 IP gelk.kernelslacker.org.ssh  wopr.kernelslacker.org.44268: 
Flags [P.], seq 1:33, ack 33, win 227, options [nop,nop,TS val 26272584 ecr 
84312473], length 32
15:34:10.215700 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [.], ack 33, win 229, options [nop,nop,TS val 84312499 ecr 26272584], 
length 0
15:34:10.216834 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 33:2001, ack 33, win 229, options [nop,nop,TS val 84312500 ecr 
26272584], length 1968
15:34:10.216938 IP gelk.kernelslacker.org.ssh  wopr.kernelslacker.org.44268: 
Flags [.], ack 2001, win 257, options [nop,nop,TS val 26272585 ecr 84312500], 
length 0
15:34:10.218280 IP gelk.kernelslacker.org.ssh  wopr.kernelslacker.org.44268: 
Flags [P.], seq 33:985, ack 2001, win 257, options [nop,nop,TS val 26272587 ecr 
84312500], length 952
15:34:10.223192 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 2001:2049, ack 985, win 243, options [nop,nop,TS val 84312506 
ecr 26272587], length 48
15:34:10.245469 IP gelk.kernelslacker.org.ssh  wopr.kernelslacker.org.44268: 
Flags [P.], seq 985:1265, ack 2049, win 257, options [nop,nop,TS val 26272614 
ecr 84312506], length 280
15:34:10.253331 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 2049:2065, ack 1265, win 258, options [nop,nop,TS val 84312536 
ecr 26272614], length 16
15:34:10.293038 IP gelk.kernelslacker.org.ssh  wopr.kernelslacker.org.44268: 
Flags [.], ack 2065, win 257, options [nop,nop,TS val 26272662 ecr 84312536], 
length 0
15:34:10.293210 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [P.], seq 2065:2109, ack 1265, win 258, options [nop,nop,TS val 84312576 
ecr 26272662], length 44
15:34:10.293313 IP gelk.kernelslacker.org.ssh  wopr.kernelslacker.org.44268: 
Flags [.], ack 2109, win 257, options [nop,nop,TS val 26272662 ecr 84312576], 
length 0
15:34:10.293487 IP gelk.kernelslacker.org.ssh  wopr.kernelslacker.org.44268: 
Flags [P.], seq 1265:1309, ack 2109, win 257, options [nop,nop,TS val 26272662 
ecr 84312576], length 44
15:34:10.333528 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [.], ack 1309, win 258, options [nop,nop,TS val 84312617 ecr 26272662], 
length 0
ctrl-c
15:34:27.693322 IP wopr.kernelslacker.org.44268  gelk.kernelslacker.org.ssh: 
Flags [F.], seq 2109, ack 1309, win 258, options [nop,nop,TS val 84329976 ecr 
26272662], length 0
15:34:27.698094 IP gelk.kernelslacker.org.ssh  wopr.kernelslacker.org.44268: 
Flags [F.], seq 1309, ack 2110, win 257, 

lockdep trace from rc2.

[Dave Jones]

https://bugzilla.redhat.com/show_bug.cgi?id=431038 has some more info,
but the trace is below...
I'll get an rc3 kernel built and ask the user to retest, but in case this
isn't a known problem, I'm forwarding this here.

Dave
 
Feb 24 17:53:21 cirithungol kernel: 
===
Feb 24 17:53:21 cirithungol kernel: [ INFO: possible circular locking 
dependency detected ]
Feb 24 17:53:21 cirithungol kernel: 2.6.25-0.54.rc2.fc9 #1
Feb 24 17:53:21 cirithungol kernel: 
---
Feb 24 17:53:21 cirithungol kernel: ip/10650 is trying to acquire lock:
Feb 24 17:53:21 cirithungol kernel:  (events){--..}, at: [c0436f9a] 
flush_workqueue+0x0/0x85
Feb 24 17:53:21 cirithungol kernel: 
Feb 24 17:53:21 cirithungol kernel: but task is already holding lock:
Feb 24 17:53:21 cirithungol kernel:  (rtnl_mutex){--..}, at: [c05cea31] 
rtnetlink_rcv+0x12/0x26
Feb 24 17:53:21 cirithungol kernel: 
Feb 24 17:53:21 cirithungol kernel: which lock already depends on the new lock.
Feb 24 17:53:21 cirithungol kernel: 
Feb 24 17:53:21 cirithungol kernel: 
Feb 24 17:53:21 cirithungol kernel: the existing dependency chain (in reverse 
order) is:
Feb 24 17:53:21 cirithungol kernel: 
Feb 24 17:53:21 cirithungol kernel: - #2 (rtnl_mutex){--..}:
Feb 24 17:53:21 cirithungol kernel:[c04458f7] 
__lock_acquire+0xa7c/0xbf4
Feb 24 17:53:21 cirithungol kernel:[c05cea1d] rtnl_lock+0xf/0x11
Feb 24 17:53:21 cirithungol kernel:[c04415dc] 
tick_program_event+0x31/0x55
Feb 24 17:53:21 cirithungol kernel:[c0445ad9] lock_acquire+0x6a/0x90
Feb 24 17:53:21 cirithungol kernel:[c05cea1d] rtnl_lock+0xf/0x11
Feb 24 17:53:21 cirithungol kernel:[c0638d21] 
mutex_lock_nested+0xdb/0x271
Feb 24 17:53:21 cirithungol kernel:[c05cea1d] rtnl_lock+0xf/0x11
Feb 24 17:53:21 cirithungol kernel:last message repeated 2 times
Feb 24 17:53:21 cirithungol kernel:[c05cf755] linkwatch_event+0x8/0x22
Feb 24 17:53:21 cirithungol kernel:[c043675c] run_workqueue+0xd3/0x1a1
Feb 24 17:53:21 cirithungol kernel:[c043671a] run_workqueue+0x91/0x1a1
Feb 24 17:53:21 cirithungol kernel:[c05cf74d] linkwatch_event+0x0/0x22
Feb 24 17:53:21 cirithungol kernel:[c04368e0] worker_thread+0xb6/0xc2
Feb 24 17:53:21 cirithungol kernel:[c0439733] 
autoremove_wake_function+0x0/0x33
Feb 24 17:53:21 cirithungol kernel:[c043682a] worker_thread+0x0/0xc2
Feb 24 17:53:21 cirithungol kernel:[c04394e2] kthread+0x3b/0x61
Feb 24 17:53:21 cirithungol kernel:[c04394a7] kthread+0x0/0x61
Feb 24 17:53:21 cirithungol kernel:[c0406a1b] 
kernel_thread_helper+0x7/0x10
Feb 24 17:53:21 cirithungol kernel:[] 0x
Feb 24 17:53:21 cirithungol kernel: 
Feb 24 17:53:21 cirithungol kernel: - #1 ((linkwatch_work).work){--..}:
Feb 24 17:53:21 cirithungol kernel:[c04458f7] 
__lock_acquire+0xa7c/0xbf4
Feb 24 17:53:21 cirithungol kernel:[c043671a] run_workqueue+0x91/0x1a1
Feb 24 17:53:21 cirithungol kernel:[c0445ad9] lock_acquire+0x6a/0x90
Feb 24 17:53:21 cirithungol kernel:[c043671a] run_workqueue+0x91/0x1a1
Feb 24 17:53:21 cirithungol kernel:[c0436756] run_workqueue+0xcd/0x1a1
Feb 24 17:53:21 cirithungol kernel:[c043671a] run_workqueue+0x91/0x1a1
Feb 24 17:53:21 cirithungol kernel:[c05cf74d] linkwatch_event+0x0/0x22
Feb 24 17:53:21 cirithungol kernel:[c04368e0] worker_thread+0xb6/0xc2
Feb 24 17:53:21 cirithungol kernel:[c0439733] 
autoremove_wake_function+0x0/0x33
Feb 24 17:53:21 cirithungol kernel:[c043682a] worker_thread+0x0/0xc2
Feb 24 17:53:21 cirithungol kernel:[c04394e2] kthread+0x3b/0x61
Feb 24 17:53:21 cirithungol kernel:[c04394a7] kthread+0x0/0x61
Feb 24 17:53:21 cirithungol kernel:[c0406a1b] 
kernel_thread_helper+0x7/0x10
Feb 24 17:53:21 cirithungol kernel:[] 0x
Feb 24 17:53:21 cirithungol kernel: 
Feb 24 17:53:21 cirithungol kernel: - #0 (events){--..}:
Feb 24 17:53:21 cirithungol kernel:[c0444ad8] 
print_circular_bug_entry+0x39/0x43
Feb 24 17:53:21 cirithungol kernel:[c0445816] 
__lock_acquire+0x99b/0xbf4
Feb 24 17:53:21 cirithungol kernel:[c040a354] 
native_sched_clock+0xb5/0xd1
Feb 24 17:53:21 cirithungol kernel:[c0445ad9] lock_acquire+0x6a/0x90
Feb 24 17:53:21 cirithungol kernel:[c0436f9a] flush_workqueue+0x0/0x85
Feb 24 17:53:21 cirithungol kernel:[c0436fde] 
flush_workqueue+0x44/0x85
Feb 24 17:53:21 cirithungol kernel:[c0436f9a] flush_workqueue+0x0/0x85
Feb 24 17:53:21 cirithungol kernel:[c043702c] 
flush_scheduled_work+0xd/0xf
Feb 24 17:53:21 cirithungol kernel:[f8f4380a] tulip_down+0x20/0x1a3 
[tulip]
Feb 24 17:53:21 cirithungol kernel:[c044495b] 
trace_hardirqs_on+0xe9/0x10a
Feb 24 17:53:21 cirithungol kernel:[c05d5103] dev_deactivate+0xb1/0xde
Feb 24 

Re: [RFC] ehea: kdump support using new shutdown hook

[Dave Jones]

On Wed, Dec 12, 2007 at 05:53:43PM +0100, Thomas Klein wrote:

  +static void ehea_update_adapter_handles(struct ehea_adapter *adapter)
  +{
  +int i, k;
  +int j = 0;
  +
  +memset(adapter-res_handles, sizeof(adapter-res_handles), 0);

arguments wrong way around.
 
Dave
 
-- 
http://www.codemonkey.org.uk
--
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

delay via-rhine irq initialisation.

[Dave Jones]

With CONFIG_DEBUG_SHIRQ set, via-rhine complains during init.
(See https://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=377721 for a report).

Does this diff look right?
(I don't have a via-rhine handy to test with)

We may be able to get away with moving the request_irq to just after the
alloc_tbufs(), but I feel if a real interrupt occured, this diff would
stand more chance of doing the right thing.

Comments?

Dave

Delay irq registration until after we've allocated ring buffers,
otherwise DEBUG_SHIRQ will complain.

Signed-off-by: Dave Jones [EMAIL PROTECTED]

diff --git a/drivers/net/via-rhine.c b/drivers/net/via-rhine.c
index 07263cd..37b3efb 100644
--- a/drivers/net/via-rhine.c
+++ b/drivers/net/via-rhine.c
@@ -1151,24 +1151,28 @@ static int rhine_open(struct net_device *dev)
void __iomem *ioaddr = rp-base;
int rc;
 
-   rc = request_irq(rp-pdev-irq, rhine_interrupt, IRQF_SHARED, 
dev-name,
-   dev);
-   if (rc)
-   return rc;
-
if (debug  1)
printk(KERN_DEBUG %s: rhine_open() irq %d.\n,
   dev-name, rp-pdev-irq);
 
rc = alloc_ring(dev);
-   if (rc) {
-   free_irq(rp-pdev-irq, dev);
+   if (rc)
return rc;
-   }
+
alloc_rbufs(dev);
alloc_tbufs(dev);
rhine_chip_reset(dev);
init_registers(dev);
+
+   rc = request_irq(rp-pdev-irq, rhine_interrupt, IRQF_SHARED, 
dev-name,
+   dev);
+   if (rc) {
+   free_rbufs(dev);
+   free_tbufs(dev);
+   free_ring(dev);
+   return rc;
+   }
+
if (debug  2)
printk(KERN_DEBUG %s: Done rhine_open(), status %4.4x 
   MII status: %4.4x.\n,
-- 
http://www.codemonkey.org.uk
--
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH RFC] [1/9] Core module symbol namespaces code and intro.

[Dave Jones]

On Mon, Nov 26, 2007 at 10:25:33AM -0800, Stephen Hemminger wrote:
 
  1) Why is everyone so concerned that export symbol space is large?
   - does it cost cpu or running memory?
   - does it cause bugs?
   - or are you just worried about evil modules?

To clarify something here, by evil, don't necessarily think binary only. 

Out of tree modules are frequently using symbols that they shouldn't be.
Because they get no peer-review here, they 'get away with it' for the most part.
Until distro vendors push rebased kernel updates that removed exports that
should never have been exported, and suddenly people like me get bombed
with Fedora broke my xyz driver mails.

Reducing the opportunity for people to screw things up is a good thing.
If a symbol is exported, most out-of-tree driver authors seem to
think its fair game to use it.

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH RFC] [1/9] Core module symbol namespaces code and intro.

[Dave Jones]

On Tue, Nov 27, 2007 at 10:09:42PM +0100, Adrian Bunk wrote:
  On Tue, Nov 27, 2007 at 02:00:37PM -0500, Dave Jones wrote:
   On Mon, Nov 26, 2007 at 10:25:33AM -0800, Stephen Hemminger wrote:

 1) Why is everyone so concerned that export symbol space is large?
 - does it cost cpu or running memory?
 - does it cause bugs?
 - or are you just worried about evil modules?
   
   To clarify something here, by evil, don't necessarily think binary 
   only. 
   
   Out of tree modules are frequently using symbols that they shouldn't be.
   Because they get no peer-review here, they 'get away with it' for the most 
   part.
   Until distro vendors push rebased kernel updates that removed exports that
   should never have been exported, and suddenly people like me get bombed
   with Fedora broke my xyz driver mails.
  ...
  
  The real problem is that these drivers are not in the upstream kernel.

You're preaching to the choir.

  Are there common reasons why these drivers are not upstream?

It varies case by case.

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH RFC] [1/9] Core module symbol namespaces code and intro.

[Dave Jones]

On Thu, Nov 22, 2007 at 03:43:06AM +0100, Andi Kleen wrote:

  There seems to be rough consensus that the kernel currently has too many 
  exported symbols. A lot of these exports are generally usable utility 
  functions or important driver interfaces; but another large part are 
  functions
  intended by only one or two very specific modules for a very specific 
  purpose.
  One example is the TCP code. It has most of its internals exported, but 
  only for use by tcp_ipv6.c (and now a few more by the TCP/IP congestion 
  modules) 
  But it doesn't make sense to include these exported for a specific module
  functions into a broader kernel interface.   External modules assume
  they can use these functions, but they were never intended for that.
  
  This patch allows to export symbols only for specific modules by 
  introducing symbol name spaces. A module name space has a white
  list of modules that are allowed to import symbols for it; all others
  can't use the symbols.

I really like this patchset.   Definitely a step in the right direction imo.
Looks like some nits there that checkpatch will probably pick up on,
but otherwise, looks very straightforward too.

Kudos.

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH] Add eeprom_bad_csum_allow module option to e1000.

[Dave Jones]

On Tue, Oct 23, 2007 at 04:40:01PM -0400, Jeff Garzik wrote:

   In any case, this patch should not be merged. We often send it around to 
   users to
   debug their issue in case it involves eeproms, but merging it will just 
   conceal
   the real issue and all of a sudden a flood of people stop reporting *real* 
   issues
   to us.
  
  Sorry, I disagree.  Just as with e100, if there is a clear way the user 
  can recover their setup -- and Adam says his was effective -- I don't 
  see why we should be denying users the ability to use their own hardware.
 
Indeed. This is a common enough problem that not including it causes more pain
than its worth.  I have two affected boxes myself that I actually thought
the hardware was dead before I tried ajax's patch.

People aren't going to report this as a bug. They aren't going to try out 
patches,
they're going to do what I did and stick another network card in the box and
go on with life.

Our users deserve better than this.

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH] Add eeprom_bad_csum_allow module option to e1000.

[Dave Jones]

On Tue, Oct 23, 2007 at 04:03:38PM -0700, Kok, Auke wrote:
  Dave Jones wrote:
   On Tue, Oct 23, 2007 at 04:40:01PM -0400, Jeff Garzik wrote:
   
  In any case, this patch should not be merged. We often send it around 
   to users to
  debug their issue in case it involves eeproms, but merging it will 
   just conceal
  the real issue and all of a sudden a flood of people stop reporting 
   *real* issues
  to us.
 
 Sorry, I disagree.  Just as with e100, if there is a clear way the user 
 can recover their setup -- and Adam says his was effective -- I don't 
 see why we should be denying users the ability to use their own 
   hardware.

   Indeed. This is a common enough problem that not including it causes more 
   pain
   than its worth.  I have two affected boxes myself that I actually thought
   the hardware was dead before I tried ajax's patch.
  
  
  look: You should have reported this to us and you didn't. Now you are using 
  the
  fact that you did not report it as an argument which is out of place.

you're missing the point.  It looks like a hardware failure. Why would I report 
this? 

  why do you say it is common? how often have you seen this and not reported 
  it back
  to our support? are you willingly trying to frustrate this issue?

Not at all. The only frustration here is that I used to have a kernel that
worked, upgraded, and thought that my hardware was broken.
How many other users thought the same ?

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: e100 problems in .23rc8 ?

[Dave Jones]

On Thu, Oct 18, 2007 at 10:59:59AM -0700, Kok, Auke wrote:
  David Mack wrote:
   It appears that the needed e100 fix made it into the Fedora
   2.6.23.1-23.fc8 kernel. Boots reliably now.
   
   Huge thanks and great work, guys.
  
  DaveJ, I didn't push anything upstream. Can you verify this now works?

There was no e100 changes in the kernel above, so David just
got lucky. (The race doesn't always occur, so it sometimes appears
something got fixed.).

I included the patch below in the latest build, but I've not had
chance to try it on an e100 box yet..

Dave

--- linux-2.6.23.noarch/drivers/net/e100.c~ 2007-10-18 16:10:40.0 
-0400
+++ linux-2.6.23.noarch/drivers/net/e100.c  2007-10-18 16:16:02.0 
-0400
@@ -2682,6 +2682,8 @@ static int __devinit e100_probe(struct p
if (err)
DPRINTK(PROBE, ERR, Error clearing wake event\n);
 
+   netif_poll_disable(netdev);
+
strcpy(netdev-name, eth%d);
if((err = register_netdev(netdev))) {
DPRINTK(PROBE, ERR, Cannot register net device, aborting.\n);

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: e100 problems in .23rc8 ?

[Dave Jones]

On Thu, Oct 11, 2007 at 09:10:34AM -0700, Kok, Auke wrote:
  Herbert Xu wrote:
   On Wed, Oct 10, 2007 at 08:36:38PM -0400, Dave Jones wrote:
   The e1000 changes you reference above, is this the changeset you mean?
  
   commit 416b5d10afdc797c21c457ade3714e8f2f75edd9
   Author: Auke Kok [EMAIL PROTECTED]
   Date:   Fri Jun 1 10:22:39 2007 -0700
  
   e1000: disable polling before registering netdevice
   
   Yep.
  
  this patch actually called napi_disable() in the probe routine which was 
  wrong,
  but e100 does not do that. Nonetheless e100 doesn't call netif_carrier_off() 
  and
  netif_stop_queue(), so to make e100 the same as e1000 we should probably do 
  this,
  see below.
  
  Dave, can you see if this resolves the issue for you? If so then we might 
  want to
  push this to -stable.
 
Will do, thanks Auke.

Eric/David, the Fedora 8 RPM version 2.6.23-6.fc8 will have this if you
want to give it a shot too.  It'll be at
http://people.redhat.com/davej/kernels/Fedora/f7.92/ when it's done
building in an hour or so.

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: e100 problems in .23rc8 ?

[Dave Jones]

On Thu, Sep 27, 2007 at 02:58:27PM +0800, Herbert Xu wrote:
  Kok, Auke [EMAIL PROTECTED] wrote:
   Dave Jones wrote:
   Last night, I hit this bug during boot up..
   http://www.codemonkey.org.uk/junk/e100-2.jpg
   
   This morning, I got a mail from a Fedora user of the same
   .23-rc8 based kernel that has seen a different trace
   also implicating e100..
   
   http://www.codemonkey.org.uk/junk/e100.jpg
   
   It may be that the two problems are unrelated, and it's
   just coincidence that both reports happen to be on an e100,
   but the timing is odd.  Have there been other reports
   of similar problems recently ?
   
   there hasn't been a change to e100 in two months now - perhaps something 
   slipped
   into the stack that broke it? If this reproduces, could you bisect?

So I looked into this some more, after it reared its head again.
The problem with bisecting it is that it doesn't happen on every
boot, so it's difficult to determine the good/bad state.
I've never managed to reproduce it on 2.6.22 however.

  Well this looks exactly like the e1000 race that we fixed around
  the time of the last kernel release.  That fix never made it into
  e100 so it's no surprise that we get a similar crash here.

We're starting to see more reports of this from Fedora users
now that 2.6.23 is final.  Once we push that as an update
for Fedora 7 users, it's likely we'll see even more.
(likewise for the soon-to-be released F8, based on 2.6.23)

The e1000 changes you reference above, is this the changeset you mean?

commit 416b5d10afdc797c21c457ade3714e8f2f75edd9
Author: Auke Kok [EMAIL PROTECTED]
Date:   Fri Jun 1 10:22:39 2007 -0700

e1000: disable polling before registering netdevice


  The problem is that if a spurious interrupt comes in between
  request_irq and netif_poll_enable then you'll get a crash at
  the next netif_rx_complete.
  
  It'd be good if this were reproducible as it would allow us
  to identify the source of the spurious interrupt, which may
  well be caused by an unrelated bug somewhere else.
  
  In any case, e100 should be prepared to deal with spurious
  interrupts as e1000 has been fixed to do.

Adding some of the other reporters of this bug to Cc,
in case they've found this more reproducable than myself
(maybe they'll have more luck bisecting).

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

lockdep report from bonding.

[Dave Jones]

Reported by a Fedora user this morning.

Ethernet Channel Bonding Driver: v3.1.3 (June 13, 2007)
bonding: MII link monitoring set to 100 ms
ADDRCONF(NETDEV_UP): bond0: link is not ready
bonding: bond0: Adding slave eth0.
e100: eth0: e100_watchdog: link up, 100Mbps, full-duplex
bonding: bond0: making interface eth0 the new active one.
bonding: bond0: enslaving eth0 as an active interface with an up link.

=
[ INFO: inconsistent lock state ]
2.6.23-0.214.rc8.git2.fc8 #1
-
inconsistent {softirq-on-W} - {in-softirq-W} usage.
events/1/10 [HC0[0]:SC1[1]:HE1:SE0] takes:
 ((bond_info-tx_hashtbl_lock)){-+..}, at: [f8ad154c] 
tlb_clear_slave+0x1d/0x9a [bonding]
{softirq-on-W} state was registered at:
  [c0449fb0] __lock_acquire+0x4ff/0xc67
  [c044ab92] lock_acquire+0x7b/0x9e
  [c0633050] _spin_lock+0x2e/0x58
  [f8ad293a] bond_alb_initialize+0x64/0x18e [bonding]
  [f8acf25f] bond_open+0x33/0x178 [bonding]
  [c05ceb36] dev_open+0x31/0x6c
  [c05ccc8d] dev_change_flags+0xa3/0x156
  [c060d579] devinet_ioctl+0x207/0x50e
  [c060dc27] inet_ioctl+0x86/0xa4
  [c05c2e62] sock_ioctl+0x1ac/0x1c9
  [c04942a2] do_ioctl+0x22/0x68
  [c0494531] vfs_ioctl+0x249/0x25c
  [c049458d] sys_ioctl+0x49/0x64
  [c040522e] syscall_call+0x7/0xb
  [] 0x
irq event stamp: 40878
hardirqs last  enabled at (40878): [c0633474] _spin_unlock_irq+0x22/0x2f
hardirqs last disabled at (40877): [c063339d] _spin_lock_irq+0x19/0x67
softirqs last  enabled at (40872): [c05e6fcf] rt_run_flush+0x6e/0x97
softirqs last disabled at (40873): [c04075d4] do_softirq+0x74/0xf7

other info that might help us debug this:
3 locks held by events/1/10:
 #0:  (rtnl_mutex){--..}, at: [c0631c31] mutex_lock+0x21/0x24
 #1:  (bond-lock){-.-+}, at: [f8ad25ed] bond_alb_monitor+0x16/0x26e 
[bonding]
 #2:  (bond-curr_slave_lock){..-+}, at: [f8ad2680] 
bond_alb_monitor+0xa9/0x26e [bonding]

stack backtrace:
 [c0406463] show_trace_log_lvl+0x1a/0x2f
 [c0406e4d] show_trace+0x12/0x14
 [c0406e65] dump_stack+0x16/0x18
 [c0448856] print_usage_bug+0x141/0x14b
 [c04490dc] mark_lock+0x12f/0x472
 [c0449f38] __lock_acquire+0x487/0xc67
 [c044ab92] lock_acquire+0x7b/0x9e
 [c0633050] _spin_lock+0x2e/0x58
 [f8ad154c] tlb_clear_slave+0x1d/0x9a [bonding]
 [f8ad269a] bond_alb_monitor+0xc3/0x26e [bonding]
 [c043541b] run_timer_softirq+0x127/0x18f
 [c0432a21] __do_softirq+0x78/0xff
 [c04075d4] do_softirq+0x74/0xf7
 ===
ADDRCONF(NETDEV_CHANGE): bond0: link becomes ready
bonding: bond0: Adding slave eth1.

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

e100 problems in .23rc8 ?

[Dave Jones]

Last night, I hit this bug during boot up..
http://www.codemonkey.org.uk/junk/e100-2.jpg

This morning, I got a mail from a Fedora user of the same
.23-rc8 based kernel that has seen a different trace
also implicating e100..

http://www.codemonkey.org.uk/junk/e100.jpg

It may be that the two problems are unrelated, and it's
just coincidence that both reports happen to be on an e100,
but the timing is odd.  Have there been other reports
of similar problems recently ?

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: e100 problems in .23rc8 ?

[Dave Jones]

On Wed, Sep 26, 2007 at 11:10:11AM -0700, Kok, Auke wrote:
  Dave Jones wrote:
   Last night, I hit this bug during boot up..
   http://www.codemonkey.org.uk/junk/e100-2.jpg
   
   This morning, I got a mail from a Fedora user of the same
   .23-rc8 based kernel that has seen a different trace
   also implicating e100..
   
   http://www.codemonkey.org.uk/junk/e100.jpg
   
   It may be that the two problems are unrelated, and it's
   just coincidence that both reports happen to be on an e100,
   but the timing is odd.  Have there been other reports
   of similar problems recently ?
  
  there hasn't been a change to e100 in two months now - perhaps something 
  slipped
  into the stack that broke it? If this reproduces, could you bisect?

Yeah, I notice only 3 changes to e100 since .22
I'll see if I can reproduce the first one and bisect.

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

lockdep report in the bonding code.

[Dave Jones]

A Fedora users reported this against our 2.6.23-rc3 build

Dave

NET: Registered protocol family 10
lo: Disabled Privacy Extensions
Ethernet Channel Bonding Driver: v3.1.3 (June 13, 2007)
bonding: MII link monitoring set to 100 ms
ADDRCONF(NETDEV_UP): bond0: link is not ready
bonding: bond0: Adding slave eth0.
e100: eth0: e100_watchdog: link up, 100Mbps, half-duplex
bonding: bond0: making interface eth0 the new active one.
bonding: bond0: enslaving eth0 as an active interface with an up link.
ADDRCONF(NETDEV_CHANGE): bond0: link becomes ready

=
[ INFO: inconsistent lock state ]
2.6.23-0.104.rc3.fc8 #1
-
inconsistent {softirq-on-W} - {in-softirq-W} usage.
events/0/9 [HC0[0]:SC1[2]:HE1:SE0] takes:
 ((bond_info-tx_hashtbl_lock)){-+..}, at: [f8ae4cc2] 
bond_alb_xmit+0x26a/0x42c [bonding]
{softirq-on-W} state was registered at:
  [c044a6e4] __lock_acquire+0x4ff/0xc67
  [c044b2c6] lock_acquire+0x7b/0x9e
  [c062ecc8] _spin_lock+0x2e/0x58
  [f8ae492e] bond_alb_initialize+0x64/0x18e [bonding]
  [f8ae1256] bond_open+0x33/0x175 [bonding]
  [c05ca8aa] dev_open+0x31/0x6c
  [c05c8a01] dev_change_flags+0xa3/0x156
  [c0609231] devinet_ioctl+0x207/0x50e
  [c06098df] inet_ioctl+0x86/0xa4
  [c05bec32] sock_ioctl+0x1ac/0x1c9
  [c0490b76] do_ioctl+0x22/0x68
  [c0490e05] vfs_ioctl+0x249/0x25c
  [c0490e61] sys_ioctl+0x49/0x64
  [c040519e] syscall_call+0x7/0xb
  [] 0x
irq event stamp: 266326
hardirqs last  enabled at (266326): [c043258f] local_bh_enable_ip+0xf3/0x106
hardirqs last disabled at (266325): [c0432516] local_bh_enable_ip+0x7a/0x106
softirqs last  enabled at (266306): [c05e2d20] rt_run_flush+0x6e/0x97
softirqs last disabled at (266309): [c0407548] do_softirq+0x74/0xf7

other info that might help us debug this:
3 locks held by events/0/9:
 #0:  (rtnl_mutex){--..}, at: [c062d8a9] mutex_lock+0x21/0x24
 #1:  (bond-lock){-.-+}, at: [f8ae4a90] bond_alb_xmit+0x38/0x42c [bonding]
 #2:  (bond-curr_slave_lock){..-+}, at: [f8ae4a98] bond_alb_xmit+0x40/0x42c 
[bonding]

stack backtrace:
 [c04063d8] show_trace_log_lvl+0x1a/0x2f
 [c0406e71] show_trace+0x12/0x14
 [c0406e89] dump_stack+0x16/0x18
 [c0448f8a] print_usage_bug+0x141/0x14b
 [c0449810] mark_lock+0x12f/0x472
 [c044a66c] __lock_acquire+0x487/0xc67
 [c044b2c6] lock_acquire+0x7b/0x9e
 [c062ecc8] _spin_lock+0x2e/0x58
 [f8ae4cc2] bond_alb_xmit+0x26a/0x42c [bonding]
 [c05c9467] dev_hard_start_xmit+0x21c/0x27a
 [c05cb489] dev_queue_xmit+0x1f7/0x2aa
 [f8b274e0] mld_sendpack+0x210/0x35a [ipv6]
 [f8b28535] mld_ifc_timer_expire+0x1e9/0x211 [ipv6]
 [c0435a5f] run_timer_softirq+0x127/0x18f
 [c0432708] __do_softirq+0x78/0xff
 [c0407548] do_softirq+0x74/0xf7
 [c04325e6] irq_exit+0x44/0x46
 [c041d3a3] smp_apic_timer_interrupt+0x74/0x81
 [c0405cb7] apic_timer_interrupt+0x33/0x38
 [c062eba6] _spin_unlock_bh+0x25/0x28
 [c05e2d20] rt_run_flush+0x6e/0x97
 [c05e471c] rt_cache_flush+0x7c/0xaf
 [c060e86f] fib_netdev_event+0x62/0x68
 [c0630e6c] notifier_call_chain+0x2b/0x4a
 [c04391c8] __raw_notifier_call_chain+0x19/0x1e
 [c04391e7] raw_notifier_call_chain+0x1a/0x1c
 [c05c84f3] netdev_state_change+0x20/0x31
 [c05d251a] __linkwatch_run_queue+0x159/0x183
 [c05d2564] linkwatch_event+0x20/0x27
 [c043bd9b] run_workqueue+0x7d/0x129
 [c043c75b] worker_thread+0xbb/0xc8
 [c043ef6f] kthread+0x3b/0x64
 [c0405e5b] kernel_thread_helper+0x7/0x10
 ===
bonding: bond0: Adding slave eth1.
e100: eth1: e100_watchdog: link up, 100Mbps, half-duplex
bonding: bond0: enslaving eth1 as an active interface with an up link.
audit(1187170179.728:3): audit_pid=1885 old=0 by auid=4294967295
bond0: no IPv6 routers present

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH] [IPv6]: Invalid semicolon after if statement

[Dave Jones]

On Wed, Aug 15, 2007 at 03:08:14PM -0700, David Miller wrote:
  From: Ilpo_Järvinen [EMAIL PROTECTED]
  Date: Thu, 16 Aug 2007 00:57:00 +0300 (EEST)
  
   A similar fix to netfilter from Eric Dumazet inspired me to
   look around a bit by using some grep/sed stuff as looking for
   this kind of bugs seemed easy to automate. This is one of them
   I found where it looks like this semicolon is not valid.
   
   Signed-off-by: Ilpo Järvinen [EMAIL PROTECTED]
  
  Yikes!  Makes you want to audit the entire tree for these
  things :-)))
 
Indeed.  Here's another one.


Signed-off-by: Dave Jones [EMAIL PROTECTED]

diff --git a/net/netfilter/xt_u32.c b/net/netfilter/xt_u32.c
index 74f9b14..bec4279 100644
--- a/net/netfilter/xt_u32.c
+++ b/net/netfilter/xt_u32.c
@@ -36,7 +36,7 @@ static bool u32_match_it(const struct xt_u32 *data,
at  = 0;
pos = ct-location[0].number;
 
-   if (skb-len  4 || pos  skb-len - 4);
+   if (skb-len  4 || pos  skb-len - 4)
return false;
 
ret   = skb_copy_bits(skb, pos, n, sizeof(n));


-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Remove incorrect comment from hamradio/scc.

[Dave Jones]

scc_rxint doesn't call this function at all.
http://bugzilla.kernel.org/show_bug.cgi?id=8146

Signed-off-by: Dave Jones [EMAIL PROTECTED]

diff --git a/drivers/net/hamradio/scc.c b/drivers/net/hamradio/scc.c
index 6fdaad5..30bed2a 100644
--- a/drivers/net/hamradio/scc.c
+++ b/drivers/net/hamradio/scc.c
@@ -1610,7 +1610,7 @@ static int scc_net_close(struct net_device *dev)
return 0;
 }
 
-/*  receive frame, called from scc_rxint()  */
+/*  receive frame  */
 
 static void scc_net_rx(struct scc_channel *scc, struct sk_buff *skb)
 {

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

typo in via-velocity.c

[Dave Jones]

http://bugzilla.kernel.org/show_bug.cgi?id=8160

Signed-off-by: Dave Jones [EMAIL PROTECTED]

diff --git a/drivers/net/via-velocity.c b/drivers/net/via-velocity.c
index 25b75b6..b670b97 100644
--- a/drivers/net/via-velocity.c
+++ b/drivers/net/via-velocity.c
@@ -1562,7 +1562,7 @@ static void velocity_print_link_status(struct 
velocity_info *vptr)
if (vptr-mii_status  VELOCITY_LINK_FAIL) {
VELOCITY_PRT(MSG_LEVEL_INFO, KERN_NOTICE %s: failed to detect 
cable link\n, vptr-dev-name);
} else if (vptr-options.spd_dpx == SPD_DPX_AUTO) {
-   VELOCITY_PRT(MSG_LEVEL_INFO, KERN_NOTICE %s: Link 
autonegation, vptr-dev-name);
+   VELOCITY_PRT(MSG_LEVEL_INFO, KERN_NOTICE %s: Link 
auto-negotiation, vptr-dev-name);
 
if (vptr-mii_status  VELOCITY_SPEED_1000)
VELOCITY_PRT(MSG_LEVEL_INFO,  speed 1000M bps);

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: warnings in git-wireless

[Dave Jones]

On Wed, Jun 06, 2007 at 06:04:21PM -0700, Andrew Morton wrote:

  There _should_ be some #ifdeffable thing which is being passed to cpp when
  we run sparse (but I'm not sure what it is).

#ifdef __CHECKER__

(See include/linux/compiler.h, this is how we implement __user  friends)

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH] e1000: Don't enable polling in open() (was: e1000: assertion hit in e1000_clean(), kernel 2.6.21.1)

[Dave Jones]

On Mon, May 21, 2007 at 02:51:35PM -0700, Auke Kok wrote:
  Herbert Xu wrote:
  netif_poll_enable can only be called if you've previously called
  netif_poll_disable.  Otherwise a poll might already be in action
  and you may get a crash like this.
  
  Removing the call to netif_poll_enable in e1000_open should fix this issue,
  the only other call to netif_poll_enable is in e1000_up() which is only
  reached after a device reset or resume.
  
  Bugzilla: http://bugzilla.kernel.org/show_bug.cgi?id=8455
  https://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=240339

This probably doesn't solve the latter bug.
The code you reference isn't there in the kernel tested in that bug
(2.6.21)   In 2.6.21, netif_poll_enable is only called from
e1000_up(), not e1000_open()

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH] e1000: Don't enable polling in open() (was: e1000: assertion hit in e1000_clean(), kernel 2.6.21.1)

[Dave Jones]

On Mon, May 21, 2007 at 05:58:27PM -0700, Kok, Auke wrote:
   This probably doesn't solve the latter bug.
   The code you reference isn't there in the kernel tested in that bug
   (2.6.21)   In 2.6.21, netif_poll_enable is only called from
   e1000_up(), not e1000_open()
   
   Yes we need a different fix for 2.6.21.  There e1000_open calls
   e1000_up which is why we still get the netif_poll_enable.
  
  yes, basically they need the patch that introduced(exposed) the problem as 
  well, 
  but that is a rather significant change and kind of moves the whole 
  netstack-init code in e1000 around. The size was the reason why that patch 
  didn't go into 2.6.21 in the first place, but perhaps they can pull both 
  patches 
  into the FC tree.
  
  For reference, this is the commit:
  
  commit e0aac5a289b1dacbc94bd9ae8c449bcdf9ab508c
  Author: Auke Kok [EMAIL PROTECTED]
  Date:   Tue Mar 6 08:57:21 2007 -0800
  
   e1000: FIX: be ready for incoming irq at pci_request_irq
  
   DEBUG_SHIRQ code exposed that e1000 was not ready for incoming 
  interrupts
   after having called pci_request_irq. This obviously requires us to 
  finish
   our software setup which assigns the irq handler before we request the
   irq.
  
   Signed-off-by: Auke Kok [EMAIL PROTECTED]
   Signed-off-by: Jeff Garzik [EMAIL PROTECTED]
  
  Dave, would that be an option for you?

Sounds like a plan.  I'll do a test-build with this and the other
patch, and throw it at the people seeing the problem tomorrow.

Thanks,

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Correct rp_filter help text.

[Dave Jones]

As mentioned in http://bugzilla.kernel.org/show_bug.cgi?id=5015
The helptext implies that this is on by default.
This may be true on some distros (Fedora/RHEL have it enabled
in /etc/sysctl.conf), but the kernel defaults to it off.

Signed-off-by: Dave Jones [EMAIL PROTECTED]

diff --git a/net/ipv4/Kconfig b/net/ipv4/Kconfig
index c68196c..420d7a4 100644
--- a/net/ipv4/Kconfig
+++ b/net/ipv4/Kconfig
@@ -43,11 +43,11 @@ config IP_ADVANCED_ROUTER
  asymmetric routing (packets from you to a host take a different path
  than packets from that host to you) or if you operate a non-routing
  host which has several IP addresses on different interfaces. To turn
- rp_filter off use:
+ rp_filter on use:
 
- echo 0  /proc/sys/net/ipv4/conf/device/rp_filter
+ echo 1  /proc/sys/net/ipv4/conf/device/rp_filter
  or
- echo 0  /proc/sys/net/ipv4/conf/all/rp_filter
+ echo 1  /proc/sys/net/ipv4/conf/all/rp_filter
 
  If unsure, say N here.
 

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: PROBLEM: SIS900 Driver change in Linux Kernel 2.6.21 causes kernel panic.

[Dave Jones]

On Wed, May 16, 2007 at 02:33:18PM -0700, - wrote:
  Kernel version 2.6.20.4 works.  What I'm experiencing is a kernel panic as
  soon as the first received packet comes in via the sis900 ethernet
  interface.  The machine is locked up and part of the kernel panic message
  is lost as it has scrolled off the screen and the virtual terminal has
  crashed as well (the kernel appears to have done a permanent halt - the
  keyboard LEDs are flashing).  The only way I could get the machine to boot
  without this problem was to unplug the ethernet cable - but it would
  appear as soon as the the first packet was received after plugging the
  cable back in.  That's not good since the machine in question is a server
  in a co-location facility (I can't print the screen either).  The kernel
  panic was repeatable without fail.  As this usually happens before init
  is called, the only program running is the kernel itself.  I don't have
  any syslog/dmesg message recorded to disk for the event.  I've rolled back
  to version 2.6.20.4 in the meantime.

You need this..

http://git.kernel.org/?p=linux%2Fkernel%2Fgit%2Ftorvalds%2Flinux-2.6.git;a=commitdiff_plain;h=dc5a144991ba803bc8afded105c9db1dea0e57ab

Which is queued for -stable afaik, but no sign of 2.6.21.2 yet. Greg/Chris?

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [1/2] 2.6.21-rc7: known regressions

[Dave Jones]

On Mon, Apr 16, 2007 at 05:14:40PM -0700, Brandeburg, Jesse wrote:
  Adrian Bunk wrote:
   Subject: laptops with e1000: lockups
   References :
   https://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=229603 
   Submitter  : Dave Jones [EMAIL PROTECTED]
   Handled-By : Jesse Brandeburg [EMAIL PROTECTED]
   Status : problem is being debugged
  
  this is being actively debugged, here is what we have so far:
  o v2.6.20: crashes during boot, unless noacpi and nousb bootparams used
  o v2.6.21-rc6: some userspace issue, crashes just after root mount
  without init=/bin/bash
  o v2.6.2X: serial console in docking station spews goo at all speeds
  with console=ttyS0,n8 . work continues on this, as we don't know if
  there are kernel panic messages during the hard lock.
  o fedora 7 test kernel 2948: boots okay, have been using this as only
  truly working kernel on this machine.
  
  one reproduction of the problem was had with scp -l 5000 file remote
  when linked at 100Mb/Full.  Tried probably 20 other times same test with
  no repro, ugh.
  
  Otherwise, slogging through continues.  We are actively working on this
  in case it *is* an e1000 issue.  Right now the repro is so unlikely we
  could hardly tell if we fixed it.

FWIW, I can reproduce this pretty much ondemand, on 100M through
the ethernet port on a netgear wireless AP.
A number of our Fedora7 testers are also able to easily reproduce this.
To isolate e1000, for tomorrows test build I've reverted e1000 to
the same code that was in 2.6.20.  If that works out without causing
hangs, I'll try and narrow down further which of the dozen csets
is responsible.

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

2.6.21rc7 e1000 media-detect oddness.

[Dave Jones]

I booted up 2.6.21rc7 without an ethernet cable plugged in,
and noticed this..

e1000: :02:00.0: e1000_probe: The EEPROM Checksum Is Not Valid
e1000: probe of :02:00.0 failed with error -5

I plugged a cable in, did rmmod e1000;modprobe e1000, and got this..

e1000: :02:00.0: e1000_probe: (PCI Express:2.5Gb/s:Width x1) 
00:16:d3:3a:62:d3
e1000: eth0: e1000_probe: Intel(R) PRO/1000 Network Connection
e1000: eth0: e1000_watchdog: NIC Link is Up 100 Mbps Full Duplex, Flow Control: 
RX
e1000: eth0: e1000_watchdog: 10/100 speed: disabling TSO

and it works fine..
Why would no cable make it think the EEPROM is invalid ?

I repeated this a few times, just to be sure it wasn't a fluke, and it
seems to happen 100% reproducably.

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [RFT] proxy arp deadlock possible

[Dave Jones]

On Wed, Apr 04, 2007 at 06:10:42PM -0700, Arjan van de Ven wrote:
  On Thu, 2007-04-05 at 10:44 +1000, Herbert Xu wrote:
   Stephen Hemminger [EMAIL PROTECTED] wrote:
Thanks Dave, there is a classic AB BA deadlock here.
We should break the dependency like this.

Could someone who uses proxy ARP test this?
   
   Sorry Stephen, this isn't necessary.  The lockdep thing is
   simply confused here.  It's treating tbl-proxy_queue as the
   same thing as neigh-arp_queue when they're clearly different.
   
   I'm disappointed that after all this time lockdep is still
   producing bogus reports like this.  I'm sure we've been
   through this particular issue many times already.
  
  
  what's the exact lockdep output here?

http://www.mail-archive.com/netdev@vger.kernel.org/msg35266.html

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

lockdep report from 2.6.20.5-rc1

[Dave Jones]

===
[ INFO: possible circular locking dependency detected ]
2.6.20-1.2933.fc6debug #1
---
swapper/0 is trying to acquire lock:
 (tbl-lock){-+-+}, at: [c05d5664] neigh_lookup+0x43/0xa2

but task is already holding lock:
 (list-lock#4){-+..}, at: [c05d65c8] neigh_proxy_process+0x20/0xc2

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

- #2 (list-lock#4){-+..}:
   [c043f4f2] __lock_acquire+0x913/0xa43
   [c043f933] lock_acquire+0x56/0x6f
   [c06325df] _spin_lock_irqsave+0x34/0x44
   [c05cbb87] skb_dequeue+0x12/0x43
   [c05cc9d4] skb_queue_purge+0x14/0x1b
   [c05d5b70] neigh_update+0x349/0x3a5
   [c060cd37] arp_process+0x4d1/0x50a
   [c060ce53] arp_rcv+0xe3/0x100
   [c05d0e43] netif_receive_skb+0x2db/0x35a
   [c05d2806] process_backlog+0x95/0xf6
   [c05d29ed] net_rx_action+0xa1/0x1a8
   [c042c1f6] __do_softirq+0x6f/0xe2
   [c04063c6] do_softirq+0x61/0xd0
   [] 0x

- #1 (n-lock){-+-+}:
   [c043f4f2] __lock_acquire+0x913/0xa43
   [c043f933] lock_acquire+0x56/0x6f
   [c063231e] _write_lock+0x2b/0x38
   [c05d74b7] neigh_periodic_timer+0x99/0x138
   [c042f053] run_timer_softirq+0x104/0x168
   [c042c1f6] __do_softirq+0x6f/0xe2
   [c04063c6] do_softirq+0x61/0xd0
   [] 0x

- #0 (tbl-lock){-+-+}:
   [c043f3f3] __lock_acquire+0x814/0xa43
   [c043f933] lock_acquire+0x56/0x6f
   [c06323d6] _read_lock_bh+0x30/0x3d
   [c05d5664] neigh_lookup+0x43/0xa2
   [c05d6317] neigh_event_ns+0x2c/0x7a
   [c060cbec] arp_process+0x386/0x50a
   [c060ce78] parp_redo+0x8/0xa
   [c05d660e] neigh_proxy_process+0x66/0xc2
   [c042f053] run_timer_softirq+0x104/0x168
   [c042c1f6] __do_softirq+0x6f/0xe2
   [c04063c6] do_softirq+0x61/0xd0
   [] 0x

other info that might help us debug this:

1 lock held by swapper/0:
 #0:  (list-lock#4){-+..}, at: [c05d65c8] neigh_proxy_process+0x20/0xc2

stack backtrace:
 [c04051dd] show_trace_log_lvl+0x1a/0x2f
 [c0405782] show_trace+0x12/0x14
 [c0405806] dump_stack+0x16/0x18
 [c043dcf5] print_circular_bug_tail+0x5f/0x68
 [c043f3f3] __lock_acquire+0x814/0xa43
 [c043f933] lock_acquire+0x56/0x6f
 [c06323d6] _read_lock_bh+0x30/0x3d
 [c05d5664] neigh_lookup+0x43/0xa2
 [c05d6317] neigh_event_ns+0x2c/0x7a
 [c060cbec] arp_process+0x386/0x50a
 [c060ce78] parp_redo+0x8/0xa
 [c05d660e] neigh_proxy_process+0x66/0xc2
 [c042f053] run_timer_softirq+0x104/0x168
 [c042c1f6] __do_softirq+0x6f/0xe2
 [c04063c6] do_softirq+0x61/0xd0
 ===


-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

fix up misplaced inlines.

[Dave Jones]

Turning up the warnings on gcc makes it emit warnings
about the placement of 'inline' in function declarations.
Here's everything that was under net/

Signed-off-by: Dave Jones [EMAIL PROTECTED]

diff --git a/net/bluetooth/hidp/core.c b/net/bluetooth/hidp/core.c
index 4c914df..ecfe8da 100644
--- a/net/bluetooth/hidp/core.c
+++ b/net/bluetooth/hidp/core.c
@@ -319,7 +319,7 @@ static int __hidp_send_ctrl_message(struct hidp_session 
*session,
return 0;
 }
 
-static int inline hidp_send_ctrl_message(struct hidp_session *session,
+static inline int hidp_send_ctrl_message(struct hidp_session *session,
unsigned char hdr, unsigned char *data, int size)
 {
int err;
diff --git a/net/bridge/br_netfilter.c b/net/bridge/br_netfilter.c
index 7712d76..5439a3c 100644
--- a/net/bridge/br_netfilter.c
+++ b/net/bridge/br_netfilter.c
@@ -61,7 +61,7 @@ static int brnf_filter_vlan_tagged __read_mostly = 1;
 #define brnf_filter_vlan_tagged 1
 #endif
 
-static __be16 inline vlan_proto(const struct sk_buff *skb)
+static inline __be16 vlan_proto(const struct sk_buff *skb)
 {
return vlan_eth_hdr(skb)-h_vlan_encapsulated_proto;
 }
diff --git a/net/core/sock.c b/net/core/sock.c
index 8d65d64..27c4f62 100644
--- a/net/core/sock.c
+++ b/net/core/sock.c
@@ -808,7 +808,7 @@ lenout:
  *
  * (We also register the sk_lock with the lock validator.)
  */
-static void inline sock_lock_init(struct sock *sk)
+static inline void sock_lock_init(struct sock *sk)
 {
sock_lock_init_class_and_name(sk,
af_family_slock_key_strings[sk-sk_family],
diff --git a/net/ipv6/addrconf.c b/net/ipv6/addrconf.c
index a7fee6b..1b61699 100644
--- a/net/ipv6/addrconf.c
+++ b/net/ipv6/addrconf.c
@@ -804,7 +804,7 @@ struct ipv6_saddr_score {
 #define IPV6_SADDR_SCORE_LABEL 0x0020
 #define IPV6_SADDR_SCORE_PRIVACY   0x0040
 
-static int inline ipv6_saddr_preferred(int type)
+static inline int ipv6_saddr_preferred(int type)
 {
if (type  (IPV6_ADDR_MAPPED|IPV6_ADDR_COMPATv4|
IPV6_ADDR_LOOPBACK|IPV6_ADDR_RESERVED))
@@ -813,7 +813,7 @@ static int inline ipv6_saddr_preferred(int type)
 }
 
 /* static matching label */
-static int inline ipv6_saddr_label(const struct in6_addr *addr, int type)
+static inline int ipv6_saddr_label(const struct in6_addr *addr, int type)
 {
  /*
   *prefix (longest match)  label
@@ -3318,7 +3318,7 @@ errout:
rtnl_set_sk_err(RTNLGRP_IPV6_IFADDR, err);
 }
 
-static void inline ipv6_store_devconf(struct ipv6_devconf *cnf,
+static inline void ipv6_store_devconf(struct ipv6_devconf *cnf,
__s32 *array, int bytes)
 {
BUG_ON(bytes  (DEVCONF_MAX * 4));
diff --git a/net/ipv6/route.c b/net/ipv6/route.c
index 0e1f4b2..a6b3117 100644
--- a/net/ipv6/route.c
+++ b/net/ipv6/route.c
@@ -308,7 +308,7 @@ static inline void rt6_probe(struct rt6_info *rt)
 /*
  * Default Router Selection (RFC 2461 6.3.6)
  */
-static int inline rt6_check_dev(struct rt6_info *rt, int oif)
+static inline int rt6_check_dev(struct rt6_info *rt, int oif)
 {
struct net_device *dev = rt-rt6i_dev;
int ret = 0;
@@ -328,7 +328,7 @@ static int inline rt6_check_dev(struct rt6_info *rt, int 
oif)
return ret;
 }
 
-static int inline rt6_check_neigh(struct rt6_info *rt)
+static inline int rt6_check_neigh(struct rt6_info *rt)
 {
struct neighbour *neigh = rt-rt6i_nexthop;
int m = 0;
diff --git a/net/ipv6/xfrm6_tunnel.c b/net/ipv6/xfrm6_tunnel.c
index ee4b84a..93c4223 100644
--- a/net/ipv6/xfrm6_tunnel.c
+++ b/net/ipv6/xfrm6_tunnel.c
@@ -58,7 +58,7 @@ static struct kmem_cache *xfrm6_tunnel_spi_kmem __read_mostly;
 static struct hlist_head 
xfrm6_tunnel_spi_byaddr[XFRM6_TUNNEL_SPI_BYADDR_HSIZE];
 static struct hlist_head xfrm6_tunnel_spi_byspi[XFRM6_TUNNEL_SPI_BYSPI_HSIZE];
 
-static unsigned inline xfrm6_tunnel_spi_hash_byaddr(xfrm_address_t *addr)
+static inline unsigned xfrm6_tunnel_spi_hash_byaddr(xfrm_address_t *addr)
 {
unsigned h;
 
@@ -70,7 +70,7 @@ static unsigned inline 
xfrm6_tunnel_spi_hash_byaddr(xfrm_address_t *addr)
return h;
 }
 
-static unsigned inline xfrm6_tunnel_spi_hash_byspi(u32 spi)
+static inline unsigned xfrm6_tunnel_spi_hash_byspi(u32 spi)
 {
return spi % XFRM6_TUNNEL_SPI_BYSPI_HSIZE;
 }
diff --git a/net/sched/cls_route.c b/net/sched/cls_route.c
index e85df07..abc47cc 100644
--- a/net/sched/cls_route.c
+++ b/net/sched/cls_route.c
@@ -93,7 +93,7 @@ void route4_reset_fastmap(struct net_device *dev, struct 
route4_head *head, u32
spin_unlock_bh(dev-queue_lock);
 }
 
-static void __inline__
+static inline void
 route4_set_fastmap(struct route4_head *head, u32 id, int iif,
   struct route4_filter *f)
 {
diff --git a/net/xfrm/xfrm_user.c b/net/xfrm/xfrm_user.c
index 9678995..e81e2fb 100644
--- a/net/xfrm/xfrm_user.c
+++ b/net/xfrm/xfrm_user.c
@@ -2025,7 +2025,7 @@ nlmsg_failure:
return -1;
 }
 
-static int inline

Re: FC5 iptables-restore failure

[Dave Jones]

On Thu, Feb 15, 2007 at 02:45:07AM -0800, Andrew Morton wrote:
  
  I've recently been noticing nasty messages come out of FC5:
  
  sony:/home/akpm# service iptables stop
  Flushing firewall rules:   [  OK  ]
  Setting chains to policy ACCEPT: filter[  OK  ]
  Unloading iptables modules:[  OK  ]
  sony:/home/akpm# service iptables start
  Applying iptables firewall rules: iptables-restore: line 20 failed
 [FAILED]
  
  Dunno when it started happening, but it's in mainline now.
  
  It's a pretty stupid error message.  line 20 of what?

2.6.18 - 2.6.19 changes a bunch of netfilter config option names.
Sure you weren't bitten by that ?

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH] bcm43xx: Readd dropped assignment

[Dave Jones]

On Wed, Oct 18, 2006 at 04:40:00PM +0200, Michael Buesch wrote:
  On Wednesday 18 October 2006 01:12, Daniel Drake wrote:
   Larry Finger pointed out a problem with my ieee80211 IV/ICV stripping 
   patch,
   which I forgot about. Sorry about that.
   
   The patch readds the frame_ctl assignment which was accidently dropped.
   
   Signed-off-by: Daniel Drake [EMAIL PROTECTED]
  
  Whoops. Please merge this as fast as possible, John.
  That's a real bug which prevents RX from working.

Is that one for -stable too? That file looks similar enough
between .18.1 and .19rc that it should be the case ?

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH 2/3] netpoll: rework skb transmit queue

[Dave Jones]

On Fri, Oct 20, 2006 at 01:25:32PM -0700, Stephen Hemminger wrote:
  On Fri, 20 Oct 2006 12:52:26 -0700 (PDT)
  David Miller [EMAIL PROTECTED] wrote:
  
   From: Stephen Hemminger [EMAIL PROTECTED]
   Date: Fri, 20 Oct 2006 12:25:27 -0700
   
Sorry, but why should we treat out-of-tree vendor code any
differently than out-of-tree other code.
   
   I think what netdump was trying to do, provide a way to
   requeue instead of fully drop the SKB, is quite reasonable.
   Don't you think?
  
  
  Netdump doesn't even exist in the current Fedora source rpm.
  I think Dave dropped it.

Indeed. Practically no-one cared about it, so it bit-rotted
really fast after we shipped RHEL4.  That, along with the focus
shifting to making kdump work seemed to kill it off over the last
12 months.

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Remove useless comment from sb1250

[Dave Jones]

Signed-off-by: Dave Jones [EMAIL PROTECTED]

diff --git a/drivers/net/sb1250-mac.c b/drivers/net/sb1250-mac.c
index db23249..1eae16b 100644
--- a/drivers/net/sb1250-mac.c
+++ b/drivers/net/sb1250-mac.c
@@ -2903,7 +2903,7 @@ #endif
 
dev = alloc_etherdev(sizeof(struct sbmac_softc));
if (!dev)
-   return -ENOMEM; /* return ENOMEM */
+   return -ENOMEM;
 
printk(KERN_DEBUG sbmac: configuring MAC at %lx\n, port);
 

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html

sfuzz hanging on 2.6.18

[Dave Jones]

sfuzz.c (google for it if you don't have it already) used to
run forver (or until I got bored and ctrl-c'd it) as long
as it didn't trigger an oops or the like in 2.6.17

Running it against 2.6.18, I notice that it runs for a while,
and then gets totally wedged.  It doesn't respond to any signals,
can't be ptraced, and even strace subsequently gets wedged.
The machine responds, and is still interactive, but that process
is hosed.

sysrq-t shows it stuck here..

sfuzz D 724EF62A  2828 28717  28691 (NOTLB)
   cd69fe98 0082 012d 724ef62a 0001971a 0010 0007 df6d22b0 
   dfd81080 725bbc5e 0001971a 000cc634 0001 df6d23bc c140e260 0202 
   de1d5ba0 cd69fea0 de1d5ba0   de1d5b60 de1d5b8c de1d5ba0 
Call Trace:
 [c05b1708] lock_sock+0x75/0xa6
 [e0b0b604] dn_getname+0x18/0x5f [decnet]
 [c05b083b] sys_getsockname+0x5c/0xb0
 [c05b0b46] sys_socketcall+0xef/0x261
 [c0403f97] syscall_call+0x7/0xb
DWARF2 unwinder stuck at syscall_call+0x7/0xb

I wonder if the plethora of lockdep related changes inadvertantly broke 
something?

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe netdev in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html