| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <4684eef5-ea50-2965-86a0-492b8b1e4f52@I-love.SAKURA.ne.jp>
Date: Mon, 15 Apr 2019 22:36:13 +0900
From: Tetsuo Handa <penguin-kernel@...ove.SAKURA.ne.jp>
To: Julian Anastasov <ja@....bg>, Cong Wang <xiyou.wangcong@...il.com>
Cc: syzbot <syzbot+30209ea299c09d8785c9@...kaller.appspotmail.com>,
ddstreet@...e.org, dvyukov@...gle.com,
linux-kernel@...r.kernel.org, netdev@...r.kernel.org,
syzkaller-bugs@...glegroups.com
Subject: Re: unregister_netdevice: waiting for DEV to become free (2)
On 2018/08/20 21:55, Julian Anastasov wrote:
> Well, only IPVS and tun in the game? But IPVS does not
> take any dev references for sync threads. Can it be a problem
> in tun? For example, a side effects from dst_cache_reset?
> May be dst_release is called too late? Here is what should happen
> on unregistration:
>
> - NETDEV_UNREGISTER event: rt_flush_dev changes dst->dev with lo
> but dst is not released
>
> - ndo_uninit/ip_tunnel_uninit: dst_cache_reset is called which
> does nothing!?! May be dst_release call is needed here.
>
> - no more references are expected here ...
>
> - netdev_run_todo -> netdev_wait_allrefs: loop here due to refcnt!=0
>
> - dev->priv_destructor (ip_tunnel_dev_free) calls dst_cache_destroy
> where dst_release is used but it is not reached because we loop in
> netdev_wait_allrefs above
>
> - dst_cache_destroy: really call dst_release
>
> In fact, after calling rt_flush_dev and replacing the
> dst->dev we should reach dev->priv_destructor (ip_tunnel_dev_free)
> for tun device where dst_release for lo should be called. But may be
> something prevents it, exit batching?
I traced using debug printk() patch shown below.
----------------------------------------
diff --git a/include/linux/netdevice.h b/include/linux/netdevice.h
index 26f69cf763f4..25f7acacf457 100644
--- a/include/linux/netdevice.h
+++ b/include/linux/netdevice.h
@@ -3726,6 +3726,11 @@ void netdev_run_todo(void);
*/
static inline void dev_put(struct net_device *dev)
{
+ if (!strcmp(dev->name, "lo")) {
+ int count = netdev_refcnt_read(dev);
+ printk("dev_put(%p): %u->%u\n", dev, count, count - 1);
+ dump_stack();
+ }
this_cpu_dec(*dev->pcpu_refcnt);
}
@@ -3737,6 +3742,11 @@ static inline void dev_put(struct net_device *dev)
*/
static inline void dev_hold(struct net_device *dev)
{
+ if (!strcmp(dev->name, "lo")) {
+ int count = netdev_refcnt_read(dev);
+ printk("dev_hold(%p): %u->%u\n", dev, count, count + 1);
+ dump_stack();
+ }
this_cpu_inc(*dev->pcpu_refcnt);
}
diff --git a/net/core/dev.c b/net/core/dev.c
index fdcff29df915..53ff4385c8f7 100644
--- a/net/core/dev.c
+++ b/net/core/dev.c
@@ -8897,9 +8897,9 @@ static void netdev_wait_allrefs(struct net_device *dev)
refcnt = netdev_refcnt_read(dev);
- if (time_after(jiffies, warning_time + 10 * HZ)) {
- pr_emerg("unregister_netdevice: waiting for %s to become free. Usage count = %d\n",
- dev->name, refcnt);
+ if (time_after(jiffies, warning_time + HZ)) {
+ pr_emerg("unregister_netdevice: waiting for %s to become free. Usage count = %d%s (%p)\n",
+ dev->name, refcnt, netdev_reg_state(dev), dev);
warning_time = jiffies;
}
}
diff --git a/net/ipv4/route.c b/net/ipv4/route.c
index a5da63e5faa2..4c5baca105ed 100644
--- a/net/ipv4/route.c
+++ b/net/ipv4/route.c
@@ -1503,6 +1503,7 @@ void rt_flush_dev(struct net_device *dev)
list_for_each_entry(rt, &ul->head, rt_uncached) {
if (rt->dst.dev != dev)
continue;
+ printk("rt_flush_dev(%p)->(%p)\n", dev, net->loopback_dev);
rt->dst.dev = net->loopback_dev;
dev_hold(rt->dst.dev);
dev_put(dev);
@@ -2560,6 +2561,7 @@ struct dst_entry *ipv4_blackhole_route(struct net *net, struct dst_entry *dst_or
new->input = dst_discard;
new->output = dst_discard_out;
+ printk("ipv4_blackhole_route(%p)->(%p)\n", new->dev, net->loopback_dev);
new->dev = net->loopback_dev;
if (new->dev)
dev_hold(new->dev);
----------------------------------------
When a new loopback device in a new network namespace is created using unshare(),
nothing is wrong.
[ 60.873014][ T7306] dev_hold(00000000d9f4ea20): 0->1
[ 60.873019][ T7306] CPU: 4 PID: 7306 Comm: a.out Not tainted 5.1.0-rc5+ #177
[ 60.873021][ T7306] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 04/13/2018
[ 60.873022][ T7306] Call Trace:
[ 60.873031][ T7306] dump_stack+0xaa/0xd8
[ 60.873037][ T7306] net_rx_queue_update_kobjects+0x1f5/0x200
[ 60.873042][ T7306] netdev_register_kobject+0xf8/0x1a0
[ 60.873047][ T7306] register_netdevice+0x4cc/0x650
[ 60.873052][ T7306] register_netdev+0x23/0x40
[ 60.873056][ T7306] loopback_net_init+0x50/0xc0
[ 60.873059][ T7306] ? loopback_dev_init+0xa0/0xa0
[ 60.873064][ T7306] ops_init+0x4f/0x140
[ 60.873068][ T7306] setup_net+0xe7/0x250
[ 60.873072][ T7306] copy_net_ns+0xee/0x1e0
[ 60.873077][ T7306] create_new_namespaces+0x141/0x2a0
[ 60.873081][ T7306] unshare_nsproxy_namespaces+0x7e/0xf0
[ 60.873086][ T7306] ksys_unshare+0x268/0x4b0
[ 60.873090][ T7306] __x64_sys_unshare+0x16/0x20
[ 60.873095][ T7306] do_syscall_64+0x7c/0x180
[ 60.873099][ T7306] entry_SYSCALL_64_after_hwframe+0x44/0xa9
But when some device in a network namespace calls rt_flush_dev(),
it gets a usage count on loopback device in that network namespace.
[ 71.388104][ T7620] rt_flush_dev(00000000cd35e96a)->(00000000d9f4ea20)
[ 71.391757][ T7620] dev_hold(00000000d9f4ea20): 7->8
[ 71.394725][ T7620] CPU: 4 PID: 7620 Comm: a.out Not tainted 5.1.0-rc5+ #177
[ 71.398094][ T7620] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 04/13/2018
[ 71.403711][ T7620] Call Trace:
[ 71.405912][ T7620] dump_stack+0xaa/0xd8
[ 71.408252][ T7620] rt_flush_dev+0x177/0x1b0
[ 71.410802][ T7620] fib_netdev_event+0x150/0x1b0
[ 71.413270][ T7620] notifier_call_chain+0x47/0xd0
[ 71.415849][ T7620] raw_notifier_call_chain+0x2d/0x40
[ 71.418491][ T7620] ? tun_show_group+0x90/0x90
[ 71.421108][ T7620] call_netdevice_notifiers_info+0x32/0x70
[ 71.423854][ T7620] rollback_registered_many+0x421/0x680
[ 71.426583][ T7620] rollback_registered+0x68/0xb0
[ 71.429244][ T7620] unregister_netdevice_queue+0xa5/0x100
[ 71.432191][ T7620] __tun_detach+0x576/0x590
[ 71.435533][ T7620] tun_chr_close+0x41/0x80
[ 71.437957][ T7620] ? __tun_detach+0x590/0x590
[ 71.440500][ T7620] __fput+0xeb/0x2d0
[ 71.442816][ T7620] ____fput+0x15/0x20
[ 71.445090][ T7620] task_work_run+0xa9/0xd0
[ 71.447467][ T7620] do_exit+0x37a/0xf40
[ 71.449623][ T7620] do_group_exit+0x57/0xe0
[ 71.451826][ T7620] get_signal+0x114/0x950
[ 71.453989][ T7620] do_signal+0x2f/0x700
[ 71.456126][ T7620] ? handle_mm_fault+0x1a8/0x360
[ 71.458323][ T7620] ? __x64_sys_futex+0x179/0x210
[ 71.460620][ T7620] exit_to_usermode_loop+0x159/0x180
[ 71.462956][ T7620] do_syscall_64+0x15d/0x180
[ 71.465110][ T7620] entry_SYSCALL_64_after_hwframe+0x44/0xa9
The usage count printed by "unregister_netdevice: waiting for lo to become free."
seems to match number of rt_flush_dev() traces shown above. (Complete log is at
http://I-love.SAKURA.ne.jp/tmp/serial-20190415.txt.xz .)
Although netdev_wait_allrefs() is periodically calling
call_netdevice_notifiers(NETDEV_UNREGISTER, dev) in order to try to drop
the usgae count,
list_for_each_entry(rt, &ul->head, rt_uncached) {
if (rt->dst.dev != dev)
continue;
rt->dst.dev = net->loopback_dev;
dev_hold(rt->dst.dev);
dev_put(dev);
}
in rt_flush_dev() becomes a no-op because dev == net->loopback_dev and
therefore cannot drop the usage count forever. That is, netdev_wait_allrefs()
on a loopback device cannot make forward progress.
[ 95.502947][ T4478] unregister_netdevice: waiting for lo to become free. Usage count = 28 (unregistered) (00000000d9f4ea20)
[ 95.509108][ T4478] rt_flush_dev(00000000d9f4ea20)->(00000000d9f4ea20)
[ 95.512598][ T4478] dev_hold(00000000d9f4ea20): 28->29
[ 95.517241][ T4478] CPU: 5 PID: 4478 Comm: kworker/u128:28 Not tainted 5.1.0-rc5+ #177
[ 95.522984][ T4478] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 04/13/2018
[ 95.532898][ T4478] Workqueue: netns cleanup_net
[ 95.537134][ T4478] Call Trace:
[ 95.539751][ T4478] dump_stack+0xaa/0xd8
[ 95.543642][ T4478] rt_flush_dev+0x177/0x1b0
[ 95.546835][ T4478] fib_netdev_event+0x150/0x1b0
[ 95.550609][ T4478] notifier_call_chain+0x47/0xd0
[ 95.557990][ T4478] raw_notifier_call_chain+0x2d/0x40
[ 95.563900][ T4478] call_netdevice_notifiers_info+0x32/0x70
[ 95.568655][ T4478] netdev_run_todo+0x197/0x410
[ 95.572554][ T4478] rtnl_unlock+0xe/0x10
[ 95.576836][ T4478] default_device_exit_batch+0x1ab/0x1d0
[ 95.579650][ T4478] ? do_wait_intr_irq+0xb0/0xb0
[ 95.582236][ T4478] ? unregister_netdevice_many+0x30/0x30
[ 95.584766][ T4478] ? dev_change_net_namespace+0x4e0/0x4e0
[ 95.587397][ T4478] ops_exit_list.isra.6+0x75/0x90
[ 95.590063][ T4478] cleanup_net+0x20d/0x380
[ 95.592373][ T4478] process_one_work+0x202/0x4f0
[ 95.595017][ T4478] worker_thread+0x3c/0x4b0
[ 95.597520][ T4478] kthread+0x139/0x160
[ 95.599822][ T4478] ? process_one_work+0x4f0/0x4f0
[ 95.602351][ T4478] ? kthread_destroy_worker+0x70/0x70
[ 95.604901][ T4478] ret_from_fork+0x35/0x40
[ 95.607249][ T4478] dev_put(00000000d9f4ea20): 29->28
[ 95.609935][ T4478] CPU: 5 PID: 4478 Comm: kworker/u128:28 Not tainted 5.1.0-rc5+ #177
[ 95.613282][ T4478] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 04/13/2018
[ 95.618699][ T4478] Workqueue: netns cleanup_net
[ 95.621345][ T4478] Call Trace:
[ 95.623381][ T4478] dump_stack+0xaa/0xd8
[ 95.625787][ T4478] rt_flush_dev+0x19f/0x1b0
[ 95.628284][ T4478] fib_netdev_event+0x150/0x1b0
[ 95.630827][ T4478] notifier_call_chain+0x47/0xd0
[ 95.633153][ T4478] raw_notifier_call_chain+0x2d/0x40
[ 95.635702][ T4478] call_netdevice_notifiers_info+0x32/0x70
[ 95.638372][ T4478] netdev_run_todo+0x197/0x410
[ 95.640641][ T4478] rtnl_unlock+0xe/0x10
[ 95.642828][ T4478] default_device_exit_batch+0x1ab/0x1d0
[ 95.645230][ T4478] ? do_wait_intr_irq+0xb0/0xb0
[ 95.647613][ T4478] ? unregister_netdevice_many+0x30/0x30
[ 95.650148][ T4478] ? dev_change_net_namespace+0x4e0/0x4e0
[ 95.652594][ T4478] ops_exit_list.isra.6+0x75/0x90
[ 95.654975][ T4478] cleanup_net+0x20d/0x380
[ 95.657140][ T4478] process_one_work+0x202/0x4f0
[ 95.659829][ T4478] worker_thread+0x3c/0x4b0
[ 95.662098][ T4478] kthread+0x139/0x160
[ 95.664119][ T4478] ? process_one_work+0x4f0/0x4f0
[ 95.666467][ T4478] ? kthread_destroy_worker+0x70/0x70
[ 95.668916][ T4478] ret_from_fork+0x35/0x40
If we do something like
list_for_each_entry(rt, &ul->head, rt_uncached) {
if (rt->dst.dev != dev)
continue;
- rt->dst.dev = net->loopback_dev;
+ if (dev == net->loopback_dev)
+ rt->dst.dev = init_net.loopback_dev;
+ else
+ rt->dst.dev = net->loopback_dev;
dev_hold(rt->dst.dev);
dev_put(dev);
}
at rt_flush_dev(), I guess that this problem will go away. I don't
know which device should be used instead of init_net.loopback_dev .
But I guess that we need to somehow avoid getting usage count on
a loopback device (by e.g. using a dummy device which is not under
unregistration procedure) when we want to unregister that loopback
device.
Powered by blists - more mailing lists