[<prev] [next>] [day] [month] [year] [list]
Message-ID: <20170629024739.GA22535@inn.lkp.intel.com>
Date: Thu, 29 Jun 2017 10:47:39 +0800
From: kernel test robot <xiaolong.ye@...el.com>
To: Alan Stern <stern@...land.harvard.edu>
Cc: Greg Kroah-Hartman <gregkh@...uxfoundation.org>,
Andrey Konovalov <andreyknvl@...gle.com>,
Felipe Balbi <felipe.balbi@...ux.intel.com>,
LKML <linux-kernel@...r.kernel.org>,
Linus Torvalds <torvalds@...ux-foundation.org>, lkp@...org
Subject: [USB] f16443a034: EIP:arch_local_irq_restore
FYI, we noticed the following commit:
commit: f16443a034c7aa359ddf6f0f9bc40d01ca31faea ("USB: gadgetfs, dummy-hcd, net2280: fix locking for callbacks")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
in testcase: trinity
with following parameters:
runtime: 300s
test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/
on test machine: qemu-system-x86_64 -enable-kvm -m 420M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-----------------------------------------+------------+------------+
| | d2f48f05cd | f16443a034 |
+-----------------------------------------+------------+------------+
| boot_successes | 53 | 0 |
| boot_failures | 1 | 58 |
| INFO:task_blocked_for_more_than#seconds | 1 | |
| calltrace:rtnl_lock | 1 | |
| calltrace:debug_show_all_locks | 1 | |
| BUG:kernel_hang_in_test_stage | 1 | |
| EIP:arch_local_irq_restore | 0 | 34 |
| EIP:ftrace_likely_update | 0 | 5 |
| EIP:__rb_reserve_next | 0 | 3 |
| EIP:native_safe_halt | 0 | 5 |
| EIP:arch_local_irq_enable | 0 | 1 |
| EIP:ring_buffer_unlock_commit | 0 | 1 |
| EIP:ring_buffer_lock_reserve | 0 | 3 |
| EIP:rb_calculate_event_length | 0 | 2 |
| EIP:rb_commit | 0 | 2 |
| EIP:paravirt_sched_clock | 0 | 1 |
| EIP:ring_buffer_producer | 0 | 1 |
+-----------------------------------------+------------+------------+
[ 2.748828] kernel_init+0x8/0x150
[ 2.748828] kernel_init+0x8/0x150
[ 2.748830] ret_from_fork+0x19/0x24
[ 2.748830] ret_from_fork+0x19/0x24
[ 2.748830]
[ 2.748830] other info that might help us debug this:
[ 2.748830]
[ 2.748830]
[ 2.748830] other info that might help us debug this:
[ 2.748830]
[ 2.748837] Possible unsafe locking scenario:
[ 2.748837]
[ 2.748837] Possible unsafe locking scenario:
[ 2.748837]
[ 2.748839] CPU0 CPU1
[ 2.748839] CPU0 CPU1
[ 2.748840] ---- ----
[ 2.748840] ---- ----
[ 2.748840] lock(&(&cdev->lock)->rlock);
[ 2.748840] lock(&(&cdev->lock)->rlock);
[ 2.748843] lock(&(&dum_hcd->dum->lock)->rlock);
[ 2.748843] lock(&(&dum_hcd->dum->lock)->rlock);
[ 2.748845] lock(&(&cdev->lock)->rlock);
[ 2.748845] lock(&(&cdev->lock)->rlock);
[ 2.748848] lock(&(&dum_hcd->dum->lock)->rlock);
[ 2.748848] lock(&(&dum_hcd->dum->lock)->rlock);
[ 2.748850]
[ 2.748850] *** DEADLOCK ***
[ 2.748850]
[ 2.748850]
[ 2.748850] *** DEADLOCK ***
[ 2.748850]
[ 2.748852] 3 locks held by swapper/1:
[ 2.748852] 3 locks held by swapper/1:
[ 2.748853] #0: (console_lock){+.+...}, at: [<790d2ca8>] vprintk_emit+0x363/0x38e
[ 2.748853] #0: (console_lock){+.+...}, at: [<790d2ca8>] vprintk_emit+0x363/0x38e
[ 2.748859] #1: ((&dum_hcd->timer)){+.-...}, at: [<790ec25b>] call_timer_fn+0x0/0x38c
[ 2.748859] #1: ((&dum_hcd->timer)){+.-...}, at: [<790ec25b>] call_timer_fn+0x0/0x38c
[ 2.748865] #2: (&(&cdev->lock)->rlock){..-...}, at: [<799eab67>] composite_setup+0xaa9/0x1a55
[ 2.748865] #2: (&(&cdev->lock)->rlock){..-...}, at: [<799eab67>] composite_setup+0xaa9/0x1a55
[ 2.748871]
[ 2.748871] stack backtrace:
[ 2.748871]
[ 2.748871] stack backtrace:
[ 2.748874] CPU: 0 PID: 1 Comm: swapper Not tainted 4.12.0-rc5-00006-gf16443a #1
[ 2.748874] CPU: 0 PID: 1 Comm: swapper Not tainted 4.12.0-rc5-00006-gf16443a #1
[ 2.748876] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[ 2.748876] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[ 2.748878] Call Trace:
[ 2.748878] Call Trace:
[ 2.748879] <SOFTIRQ>
[ 2.748879] <SOFTIRQ>
[ 2.748882] ? show_stack+0x56/0x5e
[ 2.748882] ? show_stack+0x56/0x5e
[ 2.748886] dump_stack+0x16/0x18
[ 2.748886] dump_stack+0x16/0x18
[ 2.748889] print_circular_bug+0x18b/0x198
[ 2.748889] print_circular_bug+0x18b/0x198
[ 2.748892] validate_chain+0x668/0x829
[ 2.748892] validate_chain+0x668/0x829
[ 2.748895] ? ret_from_fork+0x19/0x24
[ 2.748895] ? ret_from_fork+0x19/0x24
[ 2.748897] ? mark_lock+0x1e/0x1cc
[ 2.748897] ? mark_lock+0x1e/0x1cc
[ 2.748900] __lock_acquire+0x543/0x5eb
[ 2.748900] __lock_acquire+0x543/0x5eb
[ 2.748902] lock_acquire+0xe1/0x157
[ 2.748902] lock_acquire+0xe1/0x157
[ 2.748905] ? dummy_queue+0xd6/0x1fb
[ 2.748905] ? dummy_queue+0xd6/0x1fb
[ 2.748907] _raw_spin_lock_irqsave+0x37/0x47
[ 2.748907] _raw_spin_lock_irqsave+0x37/0x47
[ 2.748910] ? dummy_queue+0xd6/0x1fb
[ 2.748910] ? dummy_queue+0xd6/0x1fb
[ 2.748911] dummy_queue+0xd6/0x1fb
[ 2.748911] dummy_queue+0xd6/0x1fb
[ 2.748913] usb_ep_queue+0x80/0x1b5
[ 2.748913] usb_ep_queue+0x80/0x1b5
[ 2.748915] ncm_do_notify+0x155/0x187
[ 2.748915] ncm_do_notify+0x155/0x187
[ 2.748917] ncm_set_alt+0x267/0x276
[ 2.748917] ncm_set_alt+0x267/0x276
[ 2.748919] composite_setup+0xc75/0x1a55
[ 2.748919] composite_setup+0xc75/0x1a55
[ 2.748920] ? check_chain_key+0x8c/0xe1
[ 2.748920] ? check_chain_key+0x8c/0xe1
[ 2.748923] ? do_raw_spin_unlock+0xea/0x126
[ 2.748923] ? do_raw_spin_unlock+0xea/0x126
[ 2.748925] dummy_timer+0x8ba/0x1083
[ 2.748925] dummy_timer+0x8ba/0x1083
[ 2.748926] ? dummy_timer+0x8ba/0x1083
[ 2.748926] ? dummy_timer+0x8ba/0x1083
[ 2.748928] ? __lock_is_held+0x35/0x65
[ 2.748928] ? __lock_is_held+0x35/0x65
[ 2.748930] ? dummy_udc_probe+0x1b5/0x1b5
[ 2.748930] ? dummy_udc_probe+0x1b5/0x1b5
[ 2.748932] call_timer_fn+0x179/0x38c
[ 2.748932] call_timer_fn+0x179/0x38c
[ 2.748933] ? dummy_udc_probe+0x1b5/0x1b5
[ 2.748933] ? dummy_udc_probe+0x1b5/0x1b5
[ 2.748935] ? dummy_udc_probe+0x1b5/0x1b5
[ 2.748935] ? dummy_udc_probe+0x1b5/0x1b5
[ 2.748936] run_timer_softirq+0x1a1/0x1c9
[ 2.748936] run_timer_softirq+0x1a1/0x1c9
[ 2.748939] ? rcu_read_unlock_sched_notrace+0x21/0x41
[ 2.748939] ? rcu_read_unlock_sched_notrace+0x21/0x41
[ 2.748941] __do_softirq+0x1f6/0x4c7
[ 2.748941] __do_softirq+0x1f6/0x4c7
[ 2.748946] ? univ8250_console_setup+0x7a/0x7a
[ 2.748946] ? univ8250_console_setup+0x7a/0x7a
[ 2.748948] ? _local_bh_enable+0x5f/0x5f
[ 2.748948] ? _local_bh_enable+0x5f/0x5f
[ 2.748950] do_softirq_own_stack+0x1e/0x24
[ 2.748950] do_softirq_own_stack+0x1e/0x24
[ 2.748951] </SOFTIRQ>
[ 2.748951] </SOFTIRQ>
[ 2.748953] irq_exit+0x92/0xab
[ 2.748953] irq_exit+0x92/0xab
[ 2.748954] smp_apic_timer_interrupt+0x23/0x2c
[ 2.748954] smp_apic_timer_interrupt+0x23/0x2c
[ 2.748956] apic_timer_interrupt+0x34/0x3c
[ 2.748956] apic_timer_interrupt+0x34/0x3c
[ 2.748958] EIP: arch_local_irq_restore+0x5/0xb
[ 2.748958] EIP: arch_local_irq_restore+0x5/0xb
[ 2.748959] EFLAGS: 00200202 CPU: 0
[ 2.748959] EFLAGS: 00200202 CPU: 0
[ 2.748960] EAX: 00200202 EBX: 00000000 ECX: 00000006 EDX: 00000007
[ 2.748960] EAX: 00200202 EBX: 00000000 ECX: 00000006 EDX: 00000007
[ 2.748961] ESI: 796eb13b EDI: 00000000 EBP: 919efe00 ESP: 919efe00
[ 2.748961] ESI: 796eb13b EDI: 00000000 EBP: 919efe00 ESP: 919efe00
[ 2.748962] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[ 2.748962] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[ 2.748964] ? univ8250_console_setup+0x7a/0x7a
[ 2.748964] ? univ8250_console_setup+0x7a/0x7a
[ 2.748966] ? trace_raw_output_console+0x2d/0x59
[ 2.748966] ? trace_raw_output_console+0x2d/0x59
[ 2.748968] console_unlock+0x514/0x667
[ 2.748968] console_unlock+0x514/0x667
[ 2.748970] vprintk_emit+0x384/0x38e
[ 2.748970] vprintk_emit+0x384/0x38e
[ 2.748971] vprintk_default+0x12/0x14
[ 2.748971] vprintk_default+0x12/0x14
[ 2.748973] vprintk_func+0x63/0x67
[ 2.748973] vprintk_func+0x63/0x67
[ 2.748975] printk+0xe/0x10
[ 2.748975] printk+0xe/0x10
[ 2.748977] test+0x2c7/0x314
[ 2.748977] test+0x2c7/0x314
[ 2.748979] ? disk_type+0x4e/0x4e
[ 2.748979] ? disk_type+0x4e/0x4e
[ 2.748981] raid6_test+0xb8/0x116
[ 2.748981] raid6_test+0xb8/0x116
[ 2.748983] ? test+0x314/0x314
[ 2.748983] ? test+0x314/0x314
[ 2.748984] do_one_initcall+0x8f/0x18f
[ 2.748984] do_one_initcall+0x8f/0x18f
[ 2.748986] ? parse_args+0x19f/0x24d
[ 2.748986] ? parse_args+0x19f/0x24d
[ 2.748988] ? kernel_init_freeable+0xdb/0x1bc
[ 2.748988] ? kernel_init_freeable+0xdb/0x1bc
[ 2.748989] kernel_init_freeable+0xfe/0x1bc
[ 2.748989] kernel_init_freeable+0xfe/0x1bc
[ 2.748991] ? rest_init+0x12a/0x12a
[ 2.748991] ? rest_init+0x12a/0x12a
[ 2.748992] kernel_init+0x8/0x150
[ 2.748992] kernel_init+0x8/0x150
[ 2.748994] ret_from_fork+0x19/0x24
[ 2.748994] ret_from_fork+0x19/0x24
[ 2.821984] cdc_ncm 1-1:1.0: MAC-Address: 4e:8c:d2:7b:df:4e
[ 2.821984] cdc_ncm 1-1:1.0: MAC-Address: 4e:8c:d2:7b:df:4e
[ 2.822334] cdc_ncm 1-1:1.0 usb1: register 'cdc_ncm' at usb-dummy_hcd.0-1, CDC NCM, 4e:8c:d2:7b:df:4e
[ 2.822334] cdc_ncm 1-1:1.0 usb1: register 'cdc_ncm' at usb-dummy_hcd.0-1, CDC NCM, 4e:8c:d2:7b:df:4e
[ 2.827981] raid6test: test_disks(12, 15): faila= 12(D) failb= 15(D) OK
To reproduce:
git clone https://github.com/01org/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Kernel Test Robot
View attachment "config-4.12.0-rc5-00006-gf16443a" of type "text/plain" (111482 bytes)
View attachment "job-script" of type "text/plain" (3653 bytes)
Download attachment "dmesg.xz" of type "application/octet-stream" (28836 bytes)
Powered by blists - more mailing lists