Greetings,
0day kernel testing robot got the below dmesg and the first bad commit is
https://github.com/0day-ci/linux
Vladimir-Zapolskiy/driver-core-flush-async-calls-before-testing-driver-removal/20161210-194555
commit 3bf447ce13427ab9ac6a69cc87db60f2489bbdeb
Author: Vladimir Zapolskiy <vz(a)mleia.com>
AuthorDate: Sat Dec 10 02:15:19 2016 +0200
Commit: 0day robot <fengguang.wu(a)intel.com>
CommitDate: Sat Dec 10 19:45:57 2016 +0800
driver core: flush async calls before testing driver removal
If CONFIG_DEBUG_TEST_DRIVER_REMOVE option is enabled a number of false
positives are reported for ATA controller drivers, because ATA port
probes are done asynchronously, and the same problem may also touch
other asynchronously probed drivers.
To reduce the rate of false reports on boot call async_synchronize_full()
before attempting to remove a driver, the same is done in delete_module()
syscall for all possible drivers and in __device_release_driver() function
for asynchronously probed drivers.
Fixes: bea5b158ff0d ("driver core: add test of driver remove calls during
probe")
Suggested-by: Tejun Heo <tj(a)kernel.org>
Signed-off-by: Vladimir Zapolskiy <vz(a)mleia.com>
+-----------------------------------------------------------+----------+------------+------------+
| | v4.9-rc8 | 3bf447ce13 |
6754c50dca |
+-----------------------------------------------------------+----------+------------+------------+
| boot_successes | 60 | 0 | 0
|
| boot_failures | 48 | 22 | 17
|
| Kernel_panic-not_syncing:Attempted_to_kill_init!exitcode= | 48 | |
|
| INFO:task_blocked_for_more_than#seconds | 0 | 22 | 17
|
| calltrace:i8042_init | 0 | 22 | 17
|
| calltrace:device_lock | 0 | 22 | 17
|
| calltrace:watchdog | 0 | 22 | 13
|
| Kernel_panic-not_syncing:hung_task:blocked_tasks | 0 | 22 | 13
|
| calltrace:rcu_torture_fakewriter | 0 | 0 | 1
|
| calltrace:async_run_entry_fn | 0 | 0 | 4
|
+-----------------------------------------------------------+----------+------------+------------+
[ 188.047100] rcu_preempt: wait state: 1 ->state: 0x1
[ 188.048112] rcu_sched: wait state: 1 ->state: 0x1
[ 188.049090] rcu_bh: wait state: 1 ->state: 0x1
[ 244.354988] INFO: task swapper/0:1 blocked for more than 120 seconds.
[ 244.356960] Not tainted 4.9.0-rc8-00001-g3bf447c #1
[ 244.358696] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
this message.
[ 244.361980] swapper/0 D13280 1 0 0x00000000
[ 244.364012] 0000000000005011 ffffffff81a6c620 ffff88001dbb4000 ffff88001fa15840
[ 244.367480] ffff88001e966000 ffff88001e937cd8 ffffffff8152d420 0000000000000286
[ 244.370795] 0000000000000000 ffff88001fa15858 ffff88001e966000 0000000000000000
[ 244.374089] Call Trace:
[ 244.375515] [<ffffffff8152d420>] ? __schedule+0x3b8/0x47e
[ 244.377255] [<ffffffff8152d56a>] schedule+0x84/0x95
[ 244.378900] [<ffffffff8108a439>] async_synchronize_cookie_domain+0x89/0x119
[ 244.381255] [<ffffffff8109d227>] ? add_wait_queue_exclusive+0x3f/0x3f
[ 244.383313] [<ffffffff8108a4d9>] async_synchronize_full_domain+0x10/0x12
[ 244.385521] [<ffffffff8108a4e6>] async_synchronize_full+0xb/0xd
[ 244.387350] [<ffffffff813dd3d2>] driver_probe_device+0x19b/0x41b
[ 244.389190] [<ffffffff813dd652>] ? driver_probe_device+0x41b/0x41b
[ 244.390947] [<ffffffff813dd6c0>] __driver_attach+0x6e/0xc8
[ 244.392137] [<ffffffff813db702>] bus_for_each_dev+0x5a/0x82
[ 244.393228] [<ffffffff813dcd5e>] driver_attach+0x19/0x1b
[ 244.394371] [<ffffffff813dc992>] bus_add_driver+0xf6/0x232
[ 244.395535] [<ffffffff81b3870d>] ? do_early_param+0x8f/0x8f
[ 244.396631] [<ffffffff813ddcb7>] driver_register+0x83/0xba
[ 244.397711] [<ffffffff8136d673>] pnp_register_driver+0x1b/0x1d
[ 244.398842] [<ffffffff81b786d2>] i8042_init+0x83/0x412
[ 244.400059] [<ffffffff81b7864f>] ? i8042_free_aux_ports+0x2b/0x2b
[ 244.401278] [<ffffffff8100043f>] do_one_initcall+0x8b/0x115
[ 244.402365] [<ffffffff81b3870d>] ? do_early_param+0x8f/0x8f
[ 244.403532] [<ffffffff81b39023>] kernel_init_freeable+0x112/0x1ab
[ 244.404767] [<ffffffff81527917>] ? rest_init+0xbe/0xbe
[ 244.406419] [<ffffffff81527920>] kernel_init+0x9/0xf0
[ 244.408046] [<ffffffff815315a5>] ret_from_fork+0x25/0x30
[ 244.409805]
[ 244.409805] Showing all locks held in the system:
[ 244.411620] 2 locks held by swapper/0/1:
[ 244.412596] #0:
[ 244.412863] (
&dev->mutex
[ 244.413815] ){......}
, at:
[ 244.414754] [<ffffffff813dcb8b>] device_lock+0xf/0x11
[ 244.415990] #1:
[ 244.416255] (
&dev->mutex
[ 244.417136] ){......}
, at:
[ 244.418366] [<ffffffff813dcb8b>] device_lock+0xf/0x11
[ 244.419833] 3 locks held by kworker/u2:0/6:
[ 244.421135] #0:
[ 244.421521] (
"events_unbound"
[ 244.422946] ){......}
, at:
[ 244.424324] [<ffffffff810829b2>] process_one_work+0x14e/0x2f4
[ 244.425626] #1:
[ 244.425893] (
(&entry->work)
[ 244.426806] ){......}
, at:
[ 244.427769] [<ffffffff810829b2>] process_one_work+0x14e/0x2f4
[ 244.429244] #2:
[ 244.429575] (
&dev->mutex
[ 244.430457] ){......}
, at:
[ 244.431842] [<ffffffff813dcb8b>] device_lock+0xf/0x11
[ 244.433797] 2 locks held by khungtaskd/16:
[ 244.435512] #0:
[ 244.435987] (
rcu_read_lock
[ 244.437582] ){......}
, at:
[ 244.438915] [<ffffffff810dd4e8>] rcu_read_lock+0x0/0x2c
[ 244.440502] #1:
[ 244.440832] (
tasklist_lock
[ 244.441742] ){......}
, at:
[ 244.442652] [<ffffffff810a0519>] debug_show_all_locks+0x48/0x15f
[ 244.443975]
[ 244.444714] =============================================
[ 244.444714]
[ 244.447040] NMI backtrace for cpu 0
[ 244.447973] CPU: 0 PID: 16 Comm: khungtaskd Not tainted 4.9.0-rc8-00001-g3bf447c #1
[ 244.450479] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.9.3-20161025_171302-gandalf 04/01/2014
[ 244.453493] ffff88001ea8bdb8 ffffffff812ac6d7 0000000000000000 0000000000000000
[ 244.455863] ffff88001ea8bde0 ffffffff812b036a ffffffff8102aee0 ffff88001e9662c0
[ 244.457797] 0000000000000000 ffff88001ea8be08 ffffffff812b03d6 ffff88001e966000
[ 244.460288] Call Trace:
[ 244.461185] [<ffffffff812ac6d7>] dump_stack+0x61/0x7d
[ 244.462212] [<ffffffff812b036a>] nmi_cpu_backtrace+0x7c/0x8e
[ 244.463401] [<ffffffff8102aee0>] ? irq_force_complete_move+0xcf/0xcf
[ 244.482190] [<ffffffff812b03d6>] nmi_trigger_cpumask_backtrace+0x5a/0xcc
[ 244.484305] [<ffffffff8102af37>] arch_trigger_cpumask_backtrace+0x14/0x16
[ 244.486514] [<ffffffff810dd77f>] watchdog+0x26b/0x2df
[ 244.488388] [<ffffffff810dd514>] ? rcu_read_lock+0x2c/0x2c
[ 244.490299] [<ffffffff81087c87>] kthread+0xc1/0xc9
[ 244.492138] [<ffffffff81087bc6>] ? __kthread_unpark+0x55/0x55
[ 244.494143] [<ffffffff815315a5>] ret_from_fork+0x25/0x30
[ 244.496039] Kernel panic - not syncing: hung_task: blocked tasks
[ 244.498130] CPU: 0 PID: 16 Comm: khungtaskd Not tainted 4.9.0-rc8-00001-g3bf447c #1
[ 244.501197] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.9.3-20161025_171302-gandalf 04/01/2014
[ 244.504828] ffff88001ea8bd98 ffffffff812ac6d7 ffff88001e966000 ffffffff8185cd1c
[ 244.508275] ffff88001ea8be18 ffffffff810eebdb ffff880000000008 ffff88001ea8be28
[ 244.511739] ffff88001ea8bdc0 ffffffff810a877a 0000000000000000 0000000000000040
[ 244.515229] Call Trace:
[ 244.516566] [<ffffffff812ac6d7>] dump_stack+0x61/0x7d
[ 244.518475] [<ffffffff810eebdb>] panic+0xd3/0x21c
[ 244.520193] [<ffffffff810a877a>] ? printk_nmi_flush+0x51/0x65
[ 244.522139] [<ffffffff810dd78b>] watchdog+0x277/0x2df
[ 244.523986] [<ffffffff810dd514>] ? rcu_read_lock+0x2c/0x2c
[ 244.525931] [<ffffffff81087c87>] kthread+0xc1/0xc9
[ 244.527705] [<ffffffff81087bc6>] ? __kthread_unpark+0x55/0x55
[ 244.529682] [<ffffffff815315a5>] ret_from_fork+0x25/0x30
[ 244.531637] Kernel Offset: disabled
Elapsed time: 250
git bisect start 6754c50dca1401230f7400775e0691f8bec4b522
3e5de27e940d00d8d504dfb96625fb654f641509 --
git bisect bad abdbbc8e4432fed566b17909f0a8d0b562934829 # 02:52 0- 7 Merge
'andersson-remoteproc/rproc-next' into devel-spot-201612102335
git bisect bad 04b822473f10ac892b0106fc7a008f5d78631de1 # 03:03 0- 1 Merge
'linux-review/Robert-LeBlanc/Add-800M-crashkernel-explaination/20161210-172144'
into devel-spot-201612102335
git bisect good ec79d77aadb3bd4cb86ec3325201e821831f6bd3 # 03:17 22+ 13 Merge
'linux-review/Marek-Vasut/Bluetooth-hci_ldisc-Possible-race-condition/20161210-212333'
into devel-spot-201612102335
git bisect bad c6ed644d7e597268462171ae6159b8b2bd26b8f4 # 03:32 0- 14 Merge
'linux-review/Florian-Fainelli/ARM-Add-support-for-CONFIG_DEBUG_VIRTUAL/20161210-185829'
into devel-spot-201612102335
git bisect bad 585e3cb084ff3958d9294ae2b3c3701bbe402fd0 # 04:05 0- 16 Merge
'linux-review/Vladimir-Zapolskiy/driver-core-flush-async-calls-before-testing-driver-removal/20161210-194555'
into devel-spot-201612102335
git bisect good bb40c409928fffc6a0a09d7854de3f81e9fa9f4c # 04:28 22+ 13 Merge
'linux-review/Marcos-Paulo-de-Souza/Input-i8042-x86ia64io-h-Comment-else-endif-of-CONFIG_PNP/20161210-200008'
into devel-spot-201612102335
git bisect bad 3bf447ce13427ab9ac6a69cc87db60f2489bbdeb # 04:43 0- 12 driver
core: flush async calls before testing driver removal
# first bad commit: [3bf447ce13427ab9ac6a69cc87db60f2489bbdeb] driver core: flush async
calls before testing driver removal
git bisect good 3e5de27e940d00d8d504dfb96625fb654f641509 # 04:46 64+ 48 Linux
4.9-rc8
# extra tests with CONFIG_DEBUG_INFO_REDUCED
git bisect bad 3bf447ce13427ab9ac6a69cc87db60f2489bbdeb # 04:59 0- 23 driver
core: flush async calls before testing driver removal
# extra tests on HEAD of linux-devel/devel-spot-201612102335
git bisect bad 6754c50dca1401230f7400775e0691f8bec4b522 # 04:59 0- 17 0day
head guard for 'devel-spot-201612102335'
# extra tests on tree/branch
linux-review/Vladimir-Zapolskiy/driver-core-flush-async-calls-before-testing-driver-removal/20161210-194555
git bisect bad 3bf447ce13427ab9ac6a69cc87db60f2489bbdeb # 05:01 0- 22 driver
core: flush async calls before testing driver removal
# extra tests with first bad commit reverted
git bisect good a450737cf851a92cdc0ac3e788dc1e1ca1b71cd3 # 05:17 66+ 24 Revert
"driver core: flush async calls before testing driver removal"
# extra tests on tree/branch linus/master
git bisect good 045169816b31b10faed984b01c390db1b32ee4c1 # 05:31 61+ 54 Merge
branch 'linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/herbert/crypto-2.6
# extra tests on tree/branch linux-next/master
git bisect good 4a71e4389b1f8bbf02f43522c234143fd571dcb8 # 05:44 64+ 39 Add
linux-next specific files for 20161209
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation