2020-05-22 00:00:40

by kernel test robot

[permalink] [raw]
Subject: 6fe12cdbcf ("i2c: core: support bus regulator controlling in .."): BUG: sleeping function called from invalid context at kernel/locking/mutex.c:935

Greetings,

0day kernel testing robot got the below dmesg and the first bad commit is

https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git master

commit 6fe12cdbcfe35ad4726a619a9546822d34fc934c
Author: Bibby Hsieh <[email protected]>
AuthorDate: Tue May 19 15:27:29 2020 +0800
Commit: Wolfram Sang <[email protected]>
CommitDate: Wed May 20 15:25:55 2020 +0200

i2c: core: support bus regulator controlling in adapter

Although in the most platforms, the bus power of i2c
are alway on, some platforms disable the i2c bus power
in order to meet low power request.

We get and enable bulk regulator in i2c adapter device.

Signed-off-by: Bibby Hsieh <[email protected]>
Reviewed-by: Tomasz Figa <[email protected]>
Signed-off-by: Wolfram Sang <[email protected]>

6aab46bc52 dt-binding: i2c: add bus-supply property
6fe12cdbcf i2c: core: support bus regulator controlling in adapter
+-----------------------------------------------------------------------------+------------+------------+
| | 6aab46bc52 | 6fe12cdbcf |
+-----------------------------------------------------------------------------+------------+------------+
| boot_successes | 33 | 0 |
| boot_failures | 2 | 16 |
| WARNING:at_lib/kobject_uevent.c:#add_uevent_var | 1 | |
| EIP:add_uevent_var | 1 | |
| BUG:kernel_hang_in_boot_stage | 1 | |
| BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/mutex.c | 0 | 16 |
+-----------------------------------------------------------------------------+------------+------------+

If you fix the issue, kindly add following tag
Reported-by: kernel test robot <[email protected]>

[ 105.730065] ### dt-test ### EXPECT / : OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data/overlay-node/test-bus/i2c-test-bus/test-unittest13/status
[ 105.730071] ### dt-test ### EXPECT \ : i2c i2c-1: Added multiplexed i2c bus 3
[ 105.747587] i2c i2c-3: supply bus not found, using dummy regulator
[ 105.754529] i2c i2c-1: Added multiplexed i2c bus 3
[ 105.756092] ### dt-test ### EXPECT / : i2c i2c-1: Added multiplexed i2c bus 3
[ 105.773831] BUG: sleeping function called from invalid context at kernel/locking/mutex.c:935
[ 105.777468] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 189, name: kworker/0:2
[ 105.778995] 2 locks held by kworker/0:2/189:
[ 105.779775] #0: f48249a4 ((wq_completion)rcu_gp){+.+.}-{0:0}, at: process_one_work+0x3ac/0x1050
[ 105.781743] #1: f4145f34 ((work_completion)(&sdp->work)){+.+.}-{0:0}, at: process_one_work+0x3ac/0x1050
[ 105.783485] Preemption disabled at:
[ 105.783509] [<cdbb653d>] srcu_invoke_callbacks+0x14d/0x280
[ 105.785397] CPU: 0 PID: 189 Comm: kworker/0:2 Not tainted 5.7.0-rc1-00058-g6fe12cdbcfe35 #1
[ 105.786961] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 105.788608] Workqueue: rcu_gp srcu_invoke_callbacks
[ 105.789777] Call Trace:
[ 105.790308] dump_stack+0x32/0x4a
[ 105.790914] ___might_sleep+0x3dc/0x4b0
[ 105.791659] ? srcu_invoke_callbacks+0x14d/0x280
[ 105.792574] ? srcu_invoke_callbacks+0x14d/0x280
[ 105.793677] ? srcu_invoke_callbacks+0x14d/0x280
[ 105.794480] __might_sleep+0x10e/0x210
[ 105.795186] __mutex_lock+0x34/0x12f0
[ 105.795838] ? mark_held_locks+0xb3/0x100
[ 105.796561] ? _raw_spin_unlock_irqrestore+0x13b/0x190
[ 105.797694] ? _raw_spin_unlock_irqrestore+0x13b/0x190
[ 105.798653] ? lockdep_hardirqs_on+0x1bb/0x420
[ 105.799462] mutex_lock_nested+0x41/0x60
[ 105.800155] ? regulator_put+0x25/0x70
[ 105.800839] regulator_put+0x25/0x70
[ 105.801641] devm_regulator_release+0x1d/0x30
[ 105.802415] release_nodes+0x326/0x500
[ 105.803126] devres_release_all+0xb9/0x130
[ 105.803873] device_release+0x25/0x1b0
[ 105.804548] ? srcu_invoke_callbacks+0xfa/0x280
[ 105.805591] kobject_put+0x33e/0x800
[ 105.806244] ? refcount_dec_not_one+0x107/0x2f0
[ 105.807050] ? srcu_invoke_callbacks+0x14d/0x280
[ 105.807918] __device_link_free_srcu+0x79/0xe0
[ 105.808685] srcu_invoke_callbacks+0x160/0x280
[ 105.809729] process_one_work+0x594/0x1050
[ 105.810535] ? process_one_work+0x3ac/0x1050
[ 105.811314] ? _raw_spin_lock_irq+0x56/0xe0
[ 105.812113] worker_thread+0x4a3/0xc00
[ 105.812823] kthread+0x31f/0x3b0
[ 105.813537] ? rescuer_thread+0x720/0x720
[ 105.814227] ? kthread_bind+0x30/0x30
[ 105.814920] ret_from_fork+0x19/0x24
[ 105.866663] ### dt-test ### EXPECT \ : GPIO line <<int>> (line-B-input) hogged as input
[ 105.868134] ### dt-test ### EXPECT \ : GPIO line <<int>> (line-A-input) hogged as input
[ 105.870372] GPIO line 509 (line-B-input) hogged as input
[ 105.872524] GPIO line 503 (line-A-input) hogged as input
[ 105.874446] ### dt-test ### EXPECT / : GPIO line <<int>> (line-A-input) hogged as input

# HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start d0edf98c01ebe0790295cf888a2976d2d04377b1 b9bbe6ed63b2b9f2c9ee5cbd0f2c946a2723f4ce --
git bisect bad 4fde3f7c56e653e1d62102a4a77534f4bfec9689 # 07:04 B 0 17 33 0 Merge 'linux-review/Anson-Huang/ARM-dts-imx-Make-tempmon-node-as-child-of-anatop-node/20200520-230948' into devel-hourly-2020052107
git bisect bad e8344c6f4e6b7a7318fa46dd6fd5418f3e36d010 # 07:04 B 0 17 33 0 Merge 'linux-review/Gabriel-Krisman-Bertazi/iscsi-Fix-deadlock-on-recovery-path-during-GFP_IO-reclaim/20200520-220836' into devel-hourly-2020052107
git bisect good 6332b5a106b02909b3ac673832d1e36a901d81fa # 07:04 G 11 0 0 0 Merge 'stericsson/ux500-dts' into devel-hourly-2020052107
git bisect bad 05c599fa08c02ea883075d05cc544f5e133dad15 # 07:04 B 0 11 27 0 Merge 'ras/edac-misc' into devel-hourly-2020052107
git bisect good 25ef63dabd6b9567bd3d7870c5e8595b6b87c678 # 07:05 G 11 0 0 0 Merge 'linux-review/Maulik-Shah/arm64-dts-qcom-sc7180-Correct-the-pdc-interrupt-ranges/20200518-202257' into devel-hourly-2020052107
git bisect good 0db2ae8dfea89b3541eb5ffb6e0aed13d921b277 # 07:05 G 11 0 0 0 Merge 'linux-review/Geert-Uytterhoeven/ARM-dts-r9a06g032-Correct-GIC-compatible-value-order/20200519-204708' into devel-hourly-2020052107
git bisect good aeee233deb1c06fcf7630402c1f15208aa3d723a # 07:05 G 11 0 0 0 Merge 'linux-review/Lubomir-Rintel/media-marvell-ccic-Add-support-for-runtime-PM/20200521-053250' into devel-hourly-2020052107
git bisect bad 6872daa8abed0e8bd8447d56cfca80c4d29d6243 # 07:05 B 0 10 27 1 Merge 'linux-review/Dinghao-Liu/i2c-imx-lpi2c-fix-runtime-pm-imbalance-on-error/20200521-033738' into devel-hourly-2020052107
git bisect good f23da43a58d09dc6ea58837a45374e15de36537e # 07:05 G 10 0 0 1 Merge branch 'i2c/for-current' into i2c/for-next
git bisect good fadb47fca1f132c123395bca26c69007e816988f # 07:05 G 11 0 0 0 Merge branch 'i2c/for-5.8' into i2c/for-next
git bisect bad 4f118a7e4686062bd4df4a37e24c22cd71495b5f # 07:05 B 0 11 27 0 Merge tag 'for-5.8-i2c' of git://git.kernel.org/pub/scm/linux/kernel/git/tegra/linux into i2c/for-5.8
git bisect good c73178b93754edd8449dccd3faf05baafd4d3f0e # 07:05 G 11 0 0 0 i2c: tegra: Add support for the VI I2C on Tegra210
git bisect good 6aab46bc52a8f579879d491c9d8062e03caa5c61 # 07:05 G 30 0 0 3 dt-binding: i2c: add bus-supply property
git bisect bad f89c326dcaa0cb8c3af7764e75eeed4e3f3c879a # 07:05 B 0 15 31 0 Merge branch 'i2c/for-current-fixed' into i2c/for-5.8
git bisect bad 6fe12cdbcfe35ad4726a619a9546822d34fc934c # 07:05 B 0 15 45 0 i2c: core: support bus regulator controlling in adapter
# first bad commit: [6fe12cdbcfe35ad4726a619a9546822d34fc934c] i2c: core: support bus regulator controlling in adapter
git bisect good 6aab46bc52a8f579879d491c9d8062e03caa5c61 # 07:06 G 30 0 0 3 dt-binding: i2c: add bus-supply property
# extra tests with debug options
git bisect bad 6fe12cdbcfe35ad4726a619a9546822d34fc934c # 07:06 B 0 14 30 0 i2c: core: support bus regulator controlling in adapter
# extra tests on revert first bad commit
git bisect good 3788bb973ab542fcf623106a1cef5d8b1e237f7c # 07:56 G 10 0 0 0 Revert "i2c: core: support bus regulator controlling in adapter"
# good: [3788bb973ab542fcf623106a1cef5d8b1e237f7c] Revert "i2c: core: support bus regulator controlling in adapter"

---
0-DAY CI Kernel Test Service, Intel Corporation
https://lists.01.org/hyperkitty/list/[email protected]


Attachments:
(No filename) (8.94 kB)
dmesg-openwrt-vm-openwrt-30:20200522001242:i386-randconfig-a013-20200520:5.7.0-rc1-00058-g6fe12cdbcfe35:1.gz (20.16 kB)
dmesg-openwrt-vm-openwrt-33:20200522002459:i386-randconfig-a013-20200520:5.7.0-rc1-00057-g6aab46bc52a8f:1.gz (24.92 kB)
reproduce-openwrt-vm-openwrt-30:20200522001242:i386-randconfig-a013-20200520:5.7.0-rc1-00058-g6fe12cdbcfe35:1 (991.00 B)
d0edf98c01ebe0790295cf888a2976d2d04377b1:gcc-5:i386-randconfig-a013-20200520:BUG:sleeping_function_called_from_invalid_context_at_kernel_locking_mutex.c.xz (7.81 kB)
config-5.7.0-rc1-00058-g6fe12cdbcfe35 (175.00 kB)
config-5.7.0-rc1-00058-g6fe12cdbcfe35 (175.00 kB)
Download all attachments

2020-05-22 00:12:35

by Tomasz Figa

[permalink] [raw]
Subject: Re: 6fe12cdbcf ("i2c: core: support bus regulator controlling in .."): BUG: sleeping function called from invalid context at kernel/locking/mutex.c:935

On Fri, May 22, 2020 at 1:57 AM kernel test robot <[email protected]> wrote:
>
> Greetings,
>
> 0day kernel testing robot got the below dmesg and the first bad commit is
>
> https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git master
>
> commit 6fe12cdbcfe35ad4726a619a9546822d34fc934c
> Author: Bibby Hsieh <[email protected]>
> AuthorDate: Tue May 19 15:27:29 2020 +0800
> Commit: Wolfram Sang <[email protected]>
> CommitDate: Wed May 20 15:25:55 2020 +0200
>
> i2c: core: support bus regulator controlling in adapter
>
> Although in the most platforms, the bus power of i2c
> are alway on, some platforms disable the i2c bus power
> in order to meet low power request.
>
> We get and enable bulk regulator in i2c adapter device.
>
> Signed-off-by: Bibby Hsieh <[email protected]>
> Reviewed-by: Tomasz Figa <[email protected]>
> Signed-off-by: Wolfram Sang <[email protected]>
>
> 6aab46bc52 dt-binding: i2c: add bus-supply property
> 6fe12cdbcf i2c: core: support bus regulator controlling in adapter
> +-----------------------------------------------------------------------------+------------+------------+
> | | 6aab46bc52 | 6fe12cdbcf |
> +-----------------------------------------------------------------------------+------------+------------+
> | boot_successes | 33 | 0 |
> | boot_failures | 2 | 16 |
> | WARNING:at_lib/kobject_uevent.c:#add_uevent_var | 1 | |
> | EIP:add_uevent_var | 1 | |
> | BUG:kernel_hang_in_boot_stage | 1 | |
> | BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/mutex.c | 0 | 16 |
> +-----------------------------------------------------------------------------+------------+------------+
>
> If you fix the issue, kindly add following tag
> Reported-by: kernel test robot <[email protected]>
>
> [ 105.730065] ### dt-test ### EXPECT / : OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data/overlay-node/test-bus/i2c-test-bus/test-unittest13/status
> [ 105.730071] ### dt-test ### EXPECT \ : i2c i2c-1: Added multiplexed i2c bus 3
> [ 105.747587] i2c i2c-3: supply bus not found, using dummy regulator
> [ 105.754529] i2c i2c-1: Added multiplexed i2c bus 3
> [ 105.756092] ### dt-test ### EXPECT / : i2c i2c-1: Added multiplexed i2c bus 3
> [ 105.773831] BUG: sleeping function called from invalid context at kernel/locking/mutex.c:935
> [ 105.777468] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 189, name: kworker/0:2
> [ 105.778995] 2 locks held by kworker/0:2/189:
> [ 105.779775] #0: f48249a4 ((wq_completion)rcu_gp){+.+.}-{0:0}, at: process_one_work+0x3ac/0x1050
> [ 105.781743] #1: f4145f34 ((work_completion)(&sdp->work)){+.+.}-{0:0}, at: process_one_work+0x3ac/0x1050
> [ 105.783485] Preemption disabled at:
> [ 105.783509] [<cdbb653d>] srcu_invoke_callbacks+0x14d/0x280
> [ 105.785397] CPU: 0 PID: 189 Comm: kworker/0:2 Not tainted 5.7.0-rc1-00058-g6fe12cdbcfe35 #1
> [ 105.786961] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
> [ 105.788608] Workqueue: rcu_gp srcu_invoke_callbacks
> [ 105.789777] Call Trace:
> [ 105.790308] dump_stack+0x32/0x4a
> [ 105.790914] ___might_sleep+0x3dc/0x4b0
> [ 105.791659] ? srcu_invoke_callbacks+0x14d/0x280
> [ 105.792574] ? srcu_invoke_callbacks+0x14d/0x280
> [ 105.793677] ? srcu_invoke_callbacks+0x14d/0x280
> [ 105.794480] __might_sleep+0x10e/0x210
> [ 105.795186] __mutex_lock+0x34/0x12f0
> [ 105.795838] ? mark_held_locks+0xb3/0x100
> [ 105.796561] ? _raw_spin_unlock_irqrestore+0x13b/0x190
> [ 105.797694] ? _raw_spin_unlock_irqrestore+0x13b/0x190
> [ 105.798653] ? lockdep_hardirqs_on+0x1bb/0x420
> [ 105.799462] mutex_lock_nested+0x41/0x60
> [ 105.800155] ? regulator_put+0x25/0x70
> [ 105.800839] regulator_put+0x25/0x70
> [ 105.801641] devm_regulator_release+0x1d/0x30
> [ 105.802415] release_nodes+0x326/0x500
> [ 105.803126] devres_release_all+0xb9/0x130
> [ 105.803873] device_release+0x25/0x1b0

This is entirely my guess for now, but isn't it suspicious that
device_release() has been called with interrupts disabled?

Is it possible that something else introduced a bug that causes
device_release() to be called in an atomic context and it only
triggered with this patch, because the affected struct device now has
a mutex lock in the release path?

> [ 105.804548] ? srcu_invoke_callbacks+0xfa/0x280
> [ 105.805591] kobject_put+0x33e/0x800
> [ 105.806244] ? refcount_dec_not_one+0x107/0x2f0
> [ 105.807050] ? srcu_invoke_callbacks+0x14d/0x280
> [ 105.807918] __device_link_free_srcu+0x79/0xe0
> [ 105.808685] srcu_invoke_callbacks+0x160/0x280
> [ 105.809729] process_one_work+0x594/0x1050
> [ 105.810535] ? process_one_work+0x3ac/0x1050
> [ 105.811314] ? _raw_spin_lock_irq+0x56/0xe0
> [ 105.812113] worker_thread+0x4a3/0xc00
> [ 105.812823] kthread+0x31f/0x3b0
> [ 105.813537] ? rescuer_thread+0x720/0x720
> [ 105.814227] ? kthread_bind+0x30/0x30
> [ 105.814920] ret_from_fork+0x19/0x24
> [ 105.866663] ### dt-test ### EXPECT \ : GPIO line <<int>> (line-B-input) hogged as input
> [ 105.868134] ### dt-test ### EXPECT \ : GPIO line <<int>> (line-A-input) hogged as input
> [ 105.870372] GPIO line 509 (line-B-input) hogged as input
> [ 105.872524] GPIO line 503 (line-A-input) hogged as input
> [ 105.874446] ### dt-test ### EXPECT / : GPIO line <<int>> (line-A-input) hogged as input
>
> # HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
> git bisect start d0edf98c01ebe0790295cf888a2976d2d04377b1 b9bbe6ed63b2b9f2c9ee5cbd0f2c946a2723f4ce --
> git bisect bad 4fde3f7c56e653e1d62102a4a77534f4bfec9689 # 07:04 B 0 17 33 0 Merge 'linux-review/Anson-Huang/ARM-dts-imx-Make-tempmon-node-as-child-of-anatop-node/20200520-230948' into devel-hourly-2020052107
> git bisect bad e8344c6f4e6b7a7318fa46dd6fd5418f3e36d010 # 07:04 B 0 17 33 0 Merge 'linux-review/Gabriel-Krisman-Bertazi/iscsi-Fix-deadlock-on-recovery-path-during-GFP_IO-reclaim/20200520-220836' into devel-hourly-2020052107
> git bisect good 6332b5a106b02909b3ac673832d1e36a901d81fa # 07:04 G 11 0 0 0 Merge 'stericsson/ux500-dts' into devel-hourly-2020052107
> git bisect bad 05c599fa08c02ea883075d05cc544f5e133dad15 # 07:04 B 0 11 27 0 Merge 'ras/edac-misc' into devel-hourly-2020052107
> git bisect good 25ef63dabd6b9567bd3d7870c5e8595b6b87c678 # 07:05 G 11 0 0 0 Merge 'linux-review/Maulik-Shah/arm64-dts-qcom-sc7180-Correct-the-pdc-interrupt-ranges/20200518-202257' into devel-hourly-2020052107
> git bisect good 0db2ae8dfea89b3541eb5ffb6e0aed13d921b277 # 07:05 G 11 0 0 0 Merge 'linux-review/Geert-Uytterhoeven/ARM-dts-r9a06g032-Correct-GIC-compatible-value-order/20200519-204708' into devel-hourly-2020052107
> git bisect good aeee233deb1c06fcf7630402c1f15208aa3d723a # 07:05 G 11 0 0 0 Merge 'linux-review/Lubomir-Rintel/media-marvell-ccic-Add-support-for-runtime-PM/20200521-053250' into devel-hourly-2020052107
> git bisect bad 6872daa8abed0e8bd8447d56cfca80c4d29d6243 # 07:05 B 0 10 27 1 Merge 'linux-review/Dinghao-Liu/i2c-imx-lpi2c-fix-runtime-pm-imbalance-on-error/20200521-033738' into devel-hourly-2020052107
> git bisect good f23da43a58d09dc6ea58837a45374e15de36537e # 07:05 G 10 0 0 1 Merge branch 'i2c/for-current' into i2c/for-next
> git bisect good fadb47fca1f132c123395bca26c69007e816988f # 07:05 G 11 0 0 0 Merge branch 'i2c/for-5.8' into i2c/for-next
> git bisect bad 4f118a7e4686062bd4df4a37e24c22cd71495b5f # 07:05 B 0 11 27 0 Merge tag 'for-5.8-i2c' of git://git.kernel.org/pub/scm/linux/kernel/git/tegra/linux into i2c/for-5.8
> git bisect good c73178b93754edd8449dccd3faf05baafd4d3f0e # 07:05 G 11 0 0 0 i2c: tegra: Add support for the VI I2C on Tegra210
> git bisect good 6aab46bc52a8f579879d491c9d8062e03caa5c61 # 07:05 G 30 0 0 3 dt-binding: i2c: add bus-supply property
> git bisect bad f89c326dcaa0cb8c3af7764e75eeed4e3f3c879a # 07:05 B 0 15 31 0 Merge branch 'i2c/for-current-fixed' into i2c/for-5.8
> git bisect bad 6fe12cdbcfe35ad4726a619a9546822d34fc934c # 07:05 B 0 15 45 0 i2c: core: support bus regulator controlling in adapter
> # first bad commit: [6fe12cdbcfe35ad4726a619a9546822d34fc934c] i2c: core: support bus regulator controlling in adapter
> git bisect good 6aab46bc52a8f579879d491c9d8062e03caa5c61 # 07:06 G 30 0 0 3 dt-binding: i2c: add bus-supply property
> # extra tests with debug options
> git bisect bad 6fe12cdbcfe35ad4726a619a9546822d34fc934c # 07:06 B 0 14 30 0 i2c: core: support bus regulator controlling in adapter
> # extra tests on revert first bad commit
> git bisect good 3788bb973ab542fcf623106a1cef5d8b1e237f7c # 07:56 G 10 0 0 0 Revert "i2c: core: support bus regulator controlling in adapter"
> # good: [3788bb973ab542fcf623106a1cef5d8b1e237f7c] Revert "i2c: core: support bus regulator controlling in adapter"
>
> ---
> 0-DAY CI Kernel Test Service, Intel Corporation
> https://lists.01.org/hyperkitty/list/[email protected]