Fengguang Wu
2013-Oct-23 23:20 UTC
[virtio-net] BUG: sleeping function called from invalid context at kernel/mutex.c:616
Hi Jason, On Tue, Oct 22, 2013 at 04:35:32PM +0800, Jason Wang wrote:> On 10/20/2013 10:34 AM, Fengguang Wu wrote: > > Greetings, > > > > I got the below dmesg and the first bad commit is > > > > commit 3ab098df35f8b98b6553edc2e40234af512ba877 > > Author: Jason Wang <jasowang at redhat.com> > > Date: Tue Oct 15 11:18:58 2013 +0800 > > > > virtio-net: don't respond to cpu hotplug notifier if we're not ready > > > > We're trying to re-configure the affinity unconditionally in cpu hotplug > > callback. This may lead the issue during resuming from s3/s4 since > > > > - virt queues haven't been allocated at that time. > > - it's unnecessary since thaw method will re-configure the affinity. > > > > Fix this issue by checking the config_enable and do nothing is we're not ready. > > > > The bug were introduced by commit 8de4b2f3ae90c8fc0f17eeaab87d5a951b66ee17 > > (virtio-net: reset virtqueue affinity when doing cpu hotplug). > > > > Cc: Rusty Russell <rusty at rustcorp.com.au> > > Cc: Michael S. Tsirkin <mst at redhat.com> > > Cc: Wanlong Gao <gaowanlong at cn.fujitsu.com> > > Acked-by: Michael S. Tsirkin <mst at redhat.com> > > Reviewed-by: Wanlong Gao <gaowanlong at cn.fujitsu.com> > > Signed-off-by: Jason Wang <jasowang at redhat.com> > > Signed-off-by: David S. Miller <davem at davemloft.net> > > > > [ 622.944441] CPU0 attaching NULL sched-domain. > > [ 622.944446] CPU1 attaching NULL sched-domain. > > [ 622.944485] CPU0 attaching NULL sched-domain. > > [ 622.950795] BUG: sleeping function called from invalid context at kernel/mutex.c:616 > > [ 622.950796] in_atomic(): 1, irqs_disabled(): 1, pid: 10, name: migration/1 > > [ 622.950796] no locks held by migration/1/10. > > [ 622.950798] CPU: 1 PID: 10 Comm: migration/1 Not tainted 3.12.0-rc5-wl-01249-gb91e82d #317 > > [ 622.950799] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 > > [ 622.950802] 0000000000000000 ffff88001d42dba0 ffffffff81a32f22 ffff88001bfb9c70 > > [ 622.950803] ffff88001d42dbb0 ffffffff810edb02 ffff88001d42dc38 ffffffff81a396ed > > [ 622.950805] 0000000000000046 ffff88001d42dbe8 ffffffff810e861d 0000000000000000 > > [ 622.950805] Call Trace: > > [ 622.950810] [<ffffffff81a32f22>] dump_stack+0x54/0x74 > > [ 622.950815] [<ffffffff810edb02>] __might_sleep+0x112/0x114 > > [ 622.950817] [<ffffffff81a396ed>] mutex_lock_nested+0x3c/0x3c6 > > [ 622.950818] [<ffffffff810e861d>] ? up+0x39/0x3e > > [ 622.950821] [<ffffffff8153ea7c>] ? acpi_os_signal_semaphore+0x21/0x2d > > [ 622.950824] [<ffffffff81565ed1>] ? acpi_ut_release_mutex+0x5e/0x62 > > [ 622.950828] [<ffffffff816d04ec>] virtnet_cpu_callback+0x33/0x87 > > [ 622.950830] [<ffffffff81a42576>] notifier_call_chain+0x3c/0x5e > > [ 622.950832] [<ffffffff810e86a8>] __raw_notifier_call_chain+0xe/0x10 > > [ 622.950835] [<ffffffff810c5556>] __cpu_notify+0x20/0x37 > > [ 622.950836] [<ffffffff810c5580>] cpu_notify+0x13/0x15 > > [ 622.950838] [<ffffffff81a237cd>] take_cpu_down+0x27/0x3a > > [ 622.950841] [<ffffffff81136289>] stop_machine_cpu_stop+0x93/0xf1 > > [ 622.950842] [<ffffffff81136167>] cpu_stopper_thread+0xa0/0x12f > > [ 622.950844] [<ffffffff811361f6>] ? cpu_stopper_thread+0x12f/0x12f > > [ 622.950847] [<ffffffff81119710>] ? lock_release_holdtime.part.7+0xa3/0xa8 > > [ 622.950848] [<ffffffff81135e4b>] ? cpu_stop_should_run+0x3f/0x47 > > [ 622.950850] [<ffffffff810ea9b0>] smpboot_thread_fn+0x1c5/0x1e3 > > [ 622.950852] [<ffffffff810ea7eb>] ? lg_global_unlock+0x67/0x67 > > [ 622.950854] [<ffffffff810e36b7>] kthread+0xd8/0xe0 > > [ 622.950857] [<ffffffff81a3bfad>] ? wait_for_common+0x12f/0x164 > > [ 622.950859] [<ffffffff810e35df>] ? kthread_create_on_node+0x124/0x124 > > [ 622.950861] [<ffffffff81a45ffc>] ret_from_fork+0x7c/0xb0 > > [ 622.950862] [<ffffffff810e35df>] ? kthread_create_on_node+0x124/0x124 > > [ 622.950876] smpboot: CPU 1 is now offline > > [ 623.194556] SMP alternatives: lockdep: fixing up alternatives > > [ 623.194559] smpboot: Booting Node 0 Processor 1 APIC 0x1 > > Thanks for the testing Fengguang, could you please try the attached > patch to see if it works?Yes it reduces the sleeping function bug: /kernel/x86_64-lkp-CONFIG_SCSI_DEBUG/7c4ed2767afb813493b0a8fb18d666cd44550963 +------------------------------------------------------------------------------------+-----------+--------------+--------------+ | | v3.12-rc3 | 3ab098df35f8 | 7c4ed2767afb | +------------------------------------------------------------------------------------+-----------+--------------+--------------+ | good_boots | 30 | 0 | 93 | | has_kernel_error_warning | 0 | 20 | 7 | | BUG:sleeping_function_called_from_invalid_context_at_kernel/mutex.c | 0 | 20 | | | INFO:rcu_sched_self-detected_stall_on_CPU(t=jiffies_g=c=q=) | 0 | 0 | 1 | | INFO:task_blocked_for_more_than_seconds | 0 | 0 | 2 | | INFO:NMI_handler(arch_trigger_all_cpu_backtrace_handler)took_too_long_to_run:msecs | 0 | 0 | 1 | | Kernel_panic-not_syncing:hung_task:blocked_tasks | 0 | 0 | 1 | | BUG:kernel_test_crashed | 0 | 0 | 3 | | BUG:kernel_test_hang | 0 | 0 | 1 | +------------------------------------------------------------------------------------+-----------+--------------+--------------+ However I'll need to increase tests on v3.12-rc3 to make sure it's not the patch that added the other error messages. Thanks, Fengguang> >From 01e6c3f71c202aa02e4feda169e7cc9fb24193f5 Mon Sep 17 00:00:00 2001 > From: Jason Wang <jasowang at redhat.com> > Date: Mon, 21 Oct 2013 20:39:09 +0800 > Subject: [PATCH] virtio-net: fix > > --- > drivers/net/virtio_net.c | 13 ++++++------- > 1 file changed, 6 insertions(+), 7 deletions(-) > > diff --git a/drivers/net/virtio_net.c b/drivers/net/virtio_net.c > index 9fbdfcd..bbc9cb8 100644 > --- a/drivers/net/virtio_net.c > +++ b/drivers/net/virtio_net.c > @@ -1118,11 +1118,6 @@ static int virtnet_cpu_callback(struct notifier_block *nfb, > { > struct virtnet_info *vi = container_of(nfb, struct virtnet_info, nb); > > - mutex_lock(&vi->config_lock); > - > - if (!vi->config_enable) > - goto done; > - > switch(action & ~CPU_TASKS_FROZEN) { > case CPU_ONLINE: > case CPU_DOWN_FAILED: > @@ -1136,8 +1131,6 @@ static int virtnet_cpu_callback(struct notifier_block *nfb, > break; > } > > -done: > - mutex_unlock(&vi->config_lock); > return NOTIFY_OK; > } > > @@ -1699,6 +1692,8 @@ static int virtnet_freeze(struct virtio_device *vdev) > struct virtnet_info *vi = vdev->priv; > int i; > > + unregister_hotcpu_notifier(&vi->nb); > + > /* Prevent config work handler from accessing the device */ > mutex_lock(&vi->config_lock); > vi->config_enable = false; > @@ -1747,6 +1742,10 @@ static int virtnet_restore(struct virtio_device *vdev) > virtnet_set_queues(vi, vi->curr_queue_pairs); > rtnl_unlock(); > > + err = register_hotcpu_notifier(&vi->nb); > + if (err) > + return err; > + > return 0; > } > #endif > -- > 1.8.1.2 >
Jason Wang
2013-Oct-28 05:44 UTC
[virtio-net] BUG: sleeping function called from invalid context at kernel/mutex.c:616
On 10/24/2013 07:20 AM, Fengguang Wu wrote:> Yes it reduces the sleeping function bug: > > /kernel/x86_64-lkp-CONFIG_SCSI_DEBUG/7c4ed2767afb813493b0a8fb18d666cd44550963 > > +------------------------------------------------------------------------------------+-----------+--------------+--------------+ > | | v3.12-rc3 | 3ab098df35f8 | 7c4ed2767afb | > +------------------------------------------------------------------------------------+-----------+--------------+--------------+ > | good_boots | 30 | 0 | 93 | > | has_kernel_error_warning | 0 | 20 | 7 | > | BUG:sleeping_function_called_from_invalid_context_at_kernel/mutex.c | 0 | 20 | | > | INFO:rcu_sched_self-detected_stall_on_CPU(t=jiffies_g=c=q=) | 0 | 0 | 1 | > | INFO:task_blocked_for_more_than_seconds | 0 | 0 | 2 | > | INFO:NMI_handler(arch_trigger_all_cpu_backtrace_handler)took_too_long_to_run:msecs | 0 | 0 | 1 | > | Kernel_panic-not_syncing:hung_task:blocked_tasks | 0 | 0 | 1 | > | BUG:kernel_test_crashed | 0 | 0 | 3 | > | BUG:kernel_test_hang | 0 | 0 | 1 | > +------------------------------------------------------------------------------------+-----------+--------------+--------------+ > > However I'll need to increase tests on v3.12-rc3 to make sure it's not > the patch that added the other error messages. > > Thanks, > FengguangThanks, any more update on the result of v3.12-rc3 for this?
Fengguang Wu
2013-Oct-28 12:49 UTC
[virtio-net] BUG: sleeping function called from invalid context at kernel/mutex.c:616
On Mon, Oct 28, 2013 at 01:44:04PM +0800, Jason Wang wrote:> On 10/24/2013 07:20 AM, Fengguang Wu wrote: > > Yes it reduces the sleeping function bug: > > > > /kernel/x86_64-lkp-CONFIG_SCSI_DEBUG/7c4ed2767afb813493b0a8fb18d666cd44550963 > > > > +------------------------------------------------------------------------------------+-----------+--------------+--------------+ > > | | v3.12-rc3 | 3ab098df35f8 | 7c4ed2767afb | > > +------------------------------------------------------------------------------------+-----------+--------------+--------------+ > > | good_boots | 30 | 0 | 93 | > > | has_kernel_error_warning | 0 | 20 | 7 | > > | BUG:sleeping_function_called_from_invalid_context_at_kernel/mutex.c | 0 | 20 | | > > | INFO:rcu_sched_self-detected_stall_on_CPU(t=jiffies_g=c=q=) | 0 | 0 | 1 | > > | INFO:task_blocked_for_more_than_seconds | 0 | 0 | 2 | > > | INFO:NMI_handler(arch_trigger_all_cpu_backtrace_handler)took_too_long_to_run:msecs | 0 | 0 | 1 | > > | Kernel_panic-not_syncing:hung_task:blocked_tasks | 0 | 0 | 1 | > > | BUG:kernel_test_crashed | 0 | 0 | 3 | > > | BUG:kernel_test_hang | 0 | 0 | 1 | > > +------------------------------------------------------------------------------------+-----------+--------------+--------------+ > > > > However I'll need to increase tests on v3.12-rc3 to make sure it's not > > the patch that added the other error messages. > > > > Thanks, > > Fengguang > > Thanks, any more update on the result of v3.12-rc3 for this?Yes, it's confirmed that there are no new error types in 7c4ed2767afb comparing to v3.12-rc3, so your fix is fine. /kernel/x86_64-lkp-CONFIG_SCSI_DEBUG/7c4ed2767afb813493b0a8fb18d666cd44550963 +------------------------------------------------------------------------------------+-----------+--------------+--------------+ | | v3.12-rc3 | 3ab098df35f8 | 7c4ed2767afb | +------------------------------------------------------------------------------------+-----------+--------------+--------------+ | good_boots | 877 | 0 | 93 | | has_kernel_error_warning | 154 | 20 | 7 | | BUG:kernel_test_hang | 112 | 0 | 1 | | INFO:rcu_sched_self-detected_stall_on_CPU(t=jiffies_g=c=q=) | 1 | 0 | 1 | | INFO:task_blocked_for_more_than_seconds | 18 | 0 | 2 | | INFO:NMI_handler(arch_trigger_all_cpu_backtrace_handler)took_too_long_to_run:msecs | 11 | 0 | 1 | | Kernel_panic-not_syncing:hung_task:blocked_tasks | 11 | 0 | 1 | | BUG:kernel_test_crashed | 13 | 0 | 3 | | Out_of_memory:Kill_process | 9 | | | | BUG:kernel_early_hang_without_any_printk_output | 1 | | | | page_allocation_failure:order:,mode | 1 | | | | Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 2 | | | | BUG:sleeping_function_called_from_invalid_context_at_kernel/mutex.c | 0 | 20 | | +------------------------------------------------------------------------------------+-----------+--------------+--------------+ Thanks, Fengguang
Possibly Parallel Threads
- [virtio-net] BUG: sleeping function called from invalid context at kernel/mutex.c:616
- [virtio-net] BUG: sleeping function called from invalid context at kernel/mutex.c:616
- [virtio_blk] WARNING: CPU: 0 PID: 1 at fs/sysfs/dir.c:526 sysfs_add_one()
- [virtio_blk] WARNING: CPU: 0 PID: 1 at fs/sysfs/dir.c:526 sysfs_add_one()
- [virtio-net] BUG: sleeping function called from invalid context at kernel/mutex.c:616