2021-06-10 07:22:06

by Sean Nyekjaer

[permalink] [raw]
Subject: [PATCH] clk: fix possible circular locking in clk_notifier_register()

Allocating memory with prepare_lock mutex held makes lockdep unhappy
when memory pressure makes the system do fs_reclaim on eg. rawnand using
clk.

Push the allocation outside the lock.

[ 462.466020] ======================================================
[ 462.472211] WARNING: possible circular locking dependency detected
[ 462.478406] 4.19.128-00489-gffc0949c2231 #2 Not tainted
[ 462.483641] ------------------------------------------------------
[ 462.489831] kswapd0/22 is trying to acquire lock:
[ 462.494553] 882c9532 (&c->commit_sem){++++}, at: make_reservation+0x68/0x41c
[ 462.501638]
[ 462.501638] but task is already holding lock:
[ 462.507483] 11f3c233 (fs_reclaim){+.+.}, at: __fs_reclaim_acquire+0x0/0x48
[ 462.514388]
[ 462.514388] which lock already depends on the new lock.
[ 462.514388]
[ 462.522579]
[ 462.522579] the existing dependency chain (in reverse order) is:
[ 462.530073]
[ 462.530073] -> #4 (fs_reclaim){+.+.}:
[ 462.535242] fs_reclaim_acquire+0x78/0x88
[ 462.539792] kmem_cache_alloc_trace+0x34/0x2e8
[ 462.544775] clk_notifier_register+0x84/0xfc
[ 462.549586] i2c_imx_probe+0x23c/0x678
[ 462.553872] platform_drv_probe+0x50/0xa0
[ 462.558419] really_probe+0x2b8/0x3d8
[ 462.562617] driver_probe_device+0x64/0x16c
[ 462.567334] __driver_attach+0x120/0x144
[ 462.571795] bus_for_each_dev+0x7c/0xc4
[ 462.576166] driver_attach+0x20/0x28
[ 462.580276] bus_add_driver+0x174/0x208
[ 462.584646] driver_register+0x90/0x120
[ 462.589016] __platform_driver_register+0x38/0x4c
[ 462.594260] i2c_adap_imx_init+0x18/0x20
[ 462.598721] do_one_initcall+0x8c/0x32c
[ 462.603096] kernel_init_freeable+0x300/0x3e4
[ 462.607993] kernel_init+0x10/0x114
[ 462.612016] ret_from_fork+0x14/0x20
[ 462.616124] (null)
[ 462.618928]
[ 462.618928] -> #3 (prepare_lock){+.+.}:
[ 462.624270] __mutex_lock+0x60/0x8dc
[ 462.628381] mutex_lock_nested+0x24/0x2c
[ 462.632843] clk_prepare_lock+0x44/0xec
[ 462.637216] clk_unprepare+0x24/0x34
[ 462.641327] gpmi_disable_clk+0x2c/0x3c
[ 462.645697] gpmi_select_chip+0x84/0xa4
[ 462.650071] nand_read_oob+0x748/0x7b8
[ 462.654358] part_read_oob+0x40/0x78
[ 462.658466] mtd_read+0x10c/0x13c
[ 462.662318] ubi_io_read+0xc8/0x354
[ 462.666342] ubi_eba_read_leb+0xc8/0x544
[ 462.670798] ubi_eba_read_leb_sg+0x70/0x170
[ 462.675514] ubi_leb_read_sg+0x7c/0xbc
[ 462.679799] ubiblock_do_work+0xcc/0x118
[ 462.684260] process_one_work+0x2a4/0x744
[ 462.688805] worker_thread+0x5c/0x554
[ 462.693004] kthread+0x120/0x160
[ 462.696767] ret_from_fork+0x14/0x20
[ 462.700874] (null)
[ 462.703676]
[ 462.703676] -> #2 (&le->mutex){++++}:
[ 462.708842] down_read+0x3c/0x80
[ 462.712608] ubi_eba_read_leb+0x4c/0x544
[ 462.717065] ubi_leb_read+0x7c/0xbc
[ 462.721089] ubifs_leb_read+0x34/0x80
[ 462.725288] ubifs_read_nnode+0x194/0x208
[ 462.729831] ubifs_lpt_lookup_dirty+0x1e0/0x294
[ 462.734899] ubifs_replay_journal+0x48/0x15a8
[ 462.739789] ubifs_mount+0x104c/0x15f0
[ 462.744074] mount_fs+0x1c/0xb8
[ 462.747753] vfs_kern_mount.part.0+0x58/0x148
[ 462.752648] do_mount+0x6a4/0xec8
[ 462.756499] ksys_mount+0x90/0xbc
[ 462.760349] sys_mount+0x1c/0x24
[ 462.764108] ret_fast_syscall+0x0/0x28
[ 462.768390] 0xbebcbb38
[ 462.771367]
[ 462.771367] -> #1 (&c->lp_mutex){+.+.}:
[ 462.776705] __mutex_lock+0x60/0x8dc
[ 462.780818] mutex_lock_nested+0x24/0x2c
[ 462.785277] ubifs_gc_start_commit+0x28/0x32c
[ 462.790170] do_commit+0x1cc/0x7e4
[ 462.794105] ubifs_run_commit+0x98/0xd0
[ 462.798476] grab_empty_leb+0x60/0x98
[ 462.802674] ubifs_rcvry_gc_commit+0x10c/0x1d8
[ 462.807651] ubifs_mount+0x1308/0x15f0
[ 462.811934] mount_fs+0x1c/0xb8
[ 462.815610] vfs_kern_mount.part.0+0x58/0x148
[ 462.820503] do_mount+0x6a4/0xec8
[ 462.824353] ksys_mount+0x90/0xbc
[ 462.828201] sys_mount+0x1c/0x24
[ 462.831962] ret_fast_syscall+0x0/0x28
[ 462.836243] 0xbebcbb38
[ 462.839220]
[ 462.839220] -> #0 (&c->commit_sem){++++}:
[ 462.844733] lock_acquire+0xd4/0x1f8
[ 462.848845] down_read+0x3c/0x80
[ 462.852608] make_reservation+0x68/0x41c
[ 462.857064] ubifs_jnl_write_data+0x134/0x2b8
[ 462.861955] do_writepage+0x88/0x210
[ 462.866063] ubifs_writepage+0x1b8/0x274
[ 462.870522] shrink_page_list+0x800/0xf68
[ 462.875065] shrink_inactive_list+0x1b4/0x4f0
[ 462.879956] shrink_node+0x44c/0x9c0
[ 462.884063] kswapd+0x3f8/0x928
[ 462.887741] kthread+0x120/0x160
[ 462.891504] ret_from_fork+0x14/0x20
[ 462.895609] (null)
[ 462.898412]
[ 462.898412] other info that might help us debug this:
[ 462.898412]
[ 462.906428] Chain exists of:
[ 462.906428] &c->commit_sem --> prepare_lock --> fs_reclaim
[ 462.906428]
[ 462.916455] Possible unsafe locking scenario:
[ 462.916455]
[ 462.922384] CPU0 CPU1
[ 462.926923] ---- ----
[ 462.931459] lock(fs_reclaim);
[ 462.934613] lock(prepare_lock);
[ 462.940458] lock(fs_reclaim);
[ 462.946127] lock(&c->commit_sem);
[ 462.949628]
[ 462.949628] *** DEADLOCK ***
[ 462.949628]
[ 462.955563] 1 lock held by kswapd0/22:
[ 462.959322] #0: 11f3c233 (fs_reclaim){+.+.}, at: __fs_reclaim_acquire+0x0/0x48

Signed-off-by: Sean Nyekjaer <[email protected]>
---
drivers/clk/clk.c | 17 ++++++++++-------
1 file changed, 10 insertions(+), 7 deletions(-)

diff --git a/drivers/clk/clk.c b/drivers/clk/clk.c
index 65508eb89ec9..c32b71b08ccb 100644
--- a/drivers/clk/clk.c
+++ b/drivers/clk/clk.c
@@ -4340,17 +4340,20 @@ int clk_notifier_register(struct clk *clk, struct notifier_block *nb)
if (!clk || !nb)
return -EINVAL;

+ /* allocate new clk_notifier */
+ cn = kzalloc(sizeof(*cn), GFP_KERNEL);
+ if (!cn)
+ goto out;
+
clk_prepare_lock();

/* search the list of notifiers for this clk */
list_for_each_entry(cn, &clk_notifier_list, node)
- if (cn->clk == clk)
+ if (cn->clk == clk) {
+ /* if clk is in the notifier list, free new clk_notifier */
+ kfree(cn);
goto found;
-
- /* if clk wasn't in the notifier list, allocate new clk_notifier */
- cn = kzalloc(sizeof(*cn), GFP_KERNEL);
- if (!cn)
- goto out;
+ }

cn->clk = clk;
srcu_init_notifier_head(&cn->notifier_head);
@@ -4362,9 +4365,9 @@ int clk_notifier_register(struct clk *clk, struct notifier_block *nb)

clk->core->notifier_count++;

-out:
clk_prepare_unlock();

+out:
return ret;
}
EXPORT_SYMBOL_GPL(clk_notifier_register);
--
2.31.0


2021-06-10 07:28:28

by Sean Nyekjaer

[permalink] [raw]
Subject: Re: [PATCH] clk: fix possible circular locking in clk_notifier_register()

On 10/06/2021 09.17, Sean Nyekjaer wrote:
> Allocating memory with prepare_lock mutex held makes lockdep unhappy
> when memory pressure makes the system do fs_reclaim on eg. rawnand using
> clk.
>
> Push the allocation outside the lock.
>
[...]
>
> Signed-off-by: Sean Nyekjaer <[email protected]>
Fixes: b2476490ef111 ("clk: introduce the common clock framework")

We could possibly add this fixes tag ^^
> ---
> drivers/clk/clk.c | 17 ++++++++++-------
> 1 file changed, 10 insertions(+), 7 deletions(-)
>
> diff --git a/drivers/clk/clk.c b/drivers/clk/clk.c
> index 65508eb89ec9..c32b71b08ccb 100644
> --- a/drivers/clk/clk.c
> +++ b/drivers/clk/clk.c
> @@ -4340,17 +4340,20 @@ int clk_notifier_register(struct clk *clk, struct notifier_block *nb)
> if (!clk || !nb)
> return -EINVAL;
>
> + /* allocate new clk_notifier */
> + cn = kzalloc(sizeof(*cn), GFP_KERNEL);
> + if (!cn)
> + goto out;
> +
> clk_prepare_lock();
>
> /* search the list of notifiers for this clk */
> list_for_each_entry(cn, &clk_notifier_list, node)
> - if (cn->clk == clk)
> + if (cn->clk == clk) {
> + /* if clk is in the notifier list, free new clk_notifier */
> + kfree(cn);
> goto found;
> -
> - /* if clk wasn't in the notifier list, allocate new clk_notifier */
> - cn = kzalloc(sizeof(*cn), GFP_KERNEL);
> - if (!cn)
> - goto out;
> + }
>
> cn->clk = clk;
> srcu_init_notifier_head(&cn->notifier_head);
> @@ -4362,9 +4365,9 @@ int clk_notifier_register(struct clk *clk, struct notifier_block *nb)
>
> clk->core->notifier_count++;
>
> -out:
> clk_prepare_unlock();
>
> +out:
> return ret;
> }
> EXPORT_SYMBOL_GPL(clk_notifier_register);
>

2021-06-10 21:20:21

by Stephen Boyd

[permalink] [raw]
Subject: Re: [PATCH] clk: fix possible circular locking in clk_notifier_register()

Quoting Sean Nyekjaer (2021-06-10 00:17:57)
> Allocating memory with prepare_lock mutex held makes lockdep unhappy
> when memory pressure makes the system do fs_reclaim on eg. rawnand using
> clk.
>
> Push the allocation outside the lock.
>
> [ 462.466020] ======================================================
> [ 462.472211] WARNING: possible circular locking dependency detected
> [ 462.478406] 4.19.128-00489-gffc0949c2231 #2 Not tainted

4.19 is quite old. Is it happening in mainline? I suppose so given that
the allocation is still under the prepare lock?

> [ 462.483641] ------------------------------------------------------
> [ 462.489831] kswapd0/22 is trying to acquire lock:
> [ 462.494553] 882c9532 (&c->commit_sem){++++}, at: make_reservation+0x68/0x41c
> [ 462.501638]
> [ 462.501638] but task is already holding lock:
> [ 462.507483] 11f3c233 (fs_reclaim){+.+.}, at: __fs_reclaim_acquire+0x0/0x48
> [ 462.514388]
> [ 462.514388] which lock already depends on the new lock.
> [ 462.514388]
> [ 462.522579]
> [ 462.522579] the existing dependency chain (in reverse order) is:
> [ 462.530073]
> [ 462.530073] -> #4 (fs_reclaim){+.+.}:
> [ 462.535242] fs_reclaim_acquire+0x78/0x88
> [ 462.539792] kmem_cache_alloc_trace+0x34/0x2e8
> [ 462.544775] clk_notifier_register+0x84/0xfc
> [ 462.549586] i2c_imx_probe+0x23c/0x678
> [ 462.553872] platform_drv_probe+0x50/0xa0
> [ 462.558419] really_probe+0x2b8/0x3d8
> [ 462.562617] driver_probe_device+0x64/0x16c
> [ 462.567334] __driver_attach+0x120/0x144
> [ 462.571795] bus_for_each_dev+0x7c/0xc4
> [ 462.576166] driver_attach+0x20/0x28
> [ 462.580276] bus_add_driver+0x174/0x208
> [ 462.584646] driver_register+0x90/0x120
> [ 462.589016] __platform_driver_register+0x38/0x4c
> [ 462.594260] i2c_adap_imx_init+0x18/0x20
> [ 462.598721] do_one_initcall+0x8c/0x32c
> [ 462.603096] kernel_init_freeable+0x300/0x3e4
> [ 462.607993] kernel_init+0x10/0x114
> [ 462.612016] ret_from_fork+0x14/0x20
> [ 462.616124] (null)
> [ 462.618928]
> [ 462.618928] -> #3 (prepare_lock){+.+.}:
> [ 462.624270] __mutex_lock+0x60/0x8dc
> [ 462.628381] mutex_lock_nested+0x24/0x2c
> [ 462.632843] clk_prepare_lock+0x44/0xec
> [ 462.637216] clk_unprepare+0x24/0x34
> [ 462.641327] gpmi_disable_clk+0x2c/0x3c
> [ 462.645697] gpmi_select_chip+0x84/0xa4
> [ 462.650071] nand_read_oob+0x748/0x7b8
> [ 462.654358] part_read_oob+0x40/0x78
> [ 462.658466] mtd_read+0x10c/0x13c
> [ 462.662318] ubi_io_read+0xc8/0x354
> [ 462.666342] ubi_eba_read_leb+0xc8/0x544
> [ 462.670798] ubi_eba_read_leb_sg+0x70/0x170
> [ 462.675514] ubi_leb_read_sg+0x7c/0xbc
> [ 462.679799] ubiblock_do_work+0xcc/0x118
> [ 462.684260] process_one_work+0x2a4/0x744
> [ 462.688805] worker_thread+0x5c/0x554
> [ 462.693004] kthread+0x120/0x160
> [ 462.696767] ret_from_fork+0x14/0x20
> [ 462.700874] (null)
> [ 462.703676]
> [ 462.703676] -> #2 (&le->mutex){++++}:
> [ 462.708842] down_read+0x3c/0x80
> [ 462.712608] ubi_eba_read_leb+0x4c/0x544
> [ 462.717065] ubi_leb_read+0x7c/0xbc
> [ 462.721089] ubifs_leb_read+0x34/0x80
> [ 462.725288] ubifs_read_nnode+0x194/0x208
> [ 462.729831] ubifs_lpt_lookup_dirty+0x1e0/0x294
> [ 462.734899] ubifs_replay_journal+0x48/0x15a8
> [ 462.739789] ubifs_mount+0x104c/0x15f0
> [ 462.744074] mount_fs+0x1c/0xb8
> [ 462.747753] vfs_kern_mount.part.0+0x58/0x148
> [ 462.752648] do_mount+0x6a4/0xec8
> [ 462.756499] ksys_mount+0x90/0xbc
> [ 462.760349] sys_mount+0x1c/0x24
> [ 462.764108] ret_fast_syscall+0x0/0x28
> [ 462.768390] 0xbebcbb38
> [ 462.771367]
> [ 462.771367] -> #1 (&c->lp_mutex){+.+.}:
> [ 462.776705] __mutex_lock+0x60/0x8dc
> [ 462.780818] mutex_lock_nested+0x24/0x2c
> [ 462.785277] ubifs_gc_start_commit+0x28/0x32c
> [ 462.790170] do_commit+0x1cc/0x7e4
> [ 462.794105] ubifs_run_commit+0x98/0xd0
> [ 462.798476] grab_empty_leb+0x60/0x98
> [ 462.802674] ubifs_rcvry_gc_commit+0x10c/0x1d8
> [ 462.807651] ubifs_mount+0x1308/0x15f0
> [ 462.811934] mount_fs+0x1c/0xb8
> [ 462.815610] vfs_kern_mount.part.0+0x58/0x148
> [ 462.820503] do_mount+0x6a4/0xec8
> [ 462.824353] ksys_mount+0x90/0xbc
> [ 462.828201] sys_mount+0x1c/0x24
> [ 462.831962] ret_fast_syscall+0x0/0x28
> [ 462.836243] 0xbebcbb38
> [ 462.839220]
> [ 462.839220] -> #0 (&c->commit_sem){++++}:
> [ 462.844733] lock_acquire+0xd4/0x1f8
> [ 462.848845] down_read+0x3c/0x80
> [ 462.852608] make_reservation+0x68/0x41c
> [ 462.857064] ubifs_jnl_write_data+0x134/0x2b8
> [ 462.861955] do_writepage+0x88/0x210
> [ 462.866063] ubifs_writepage+0x1b8/0x274
> [ 462.870522] shrink_page_list+0x800/0xf68
> [ 462.875065] shrink_inactive_list+0x1b4/0x4f0
> [ 462.879956] shrink_node+0x44c/0x9c0
> [ 462.884063] kswapd+0x3f8/0x928
> [ 462.887741] kthread+0x120/0x160
> [ 462.891504] ret_from_fork+0x14/0x20
> [ 462.895609] (null)
> [ 462.898412]
> [ 462.898412] other info that might help us debug this:
> [ 462.898412]
> [ 462.906428] Chain exists of:
> [ 462.906428] &c->commit_sem --> prepare_lock --> fs_reclaim
> [ 462.906428]
> [ 462.916455] Possible unsafe locking scenario:
> [ 462.916455]
> [ 462.922384] CPU0 CPU1
> [ 462.926923] ---- ----
> [ 462.931459] lock(fs_reclaim);
> [ 462.934613] lock(prepare_lock);
> [ 462.940458] lock(fs_reclaim);
> [ 462.946127] lock(&c->commit_sem);
> [ 462.949628]
> [ 462.949628] *** DEADLOCK ***
> [ 462.949628]
> [ 462.955563] 1 lock held by kswapd0/22:
> [ 462.959322] #0: 11f3c233 (fs_reclaim){+.+.}, at: __fs_reclaim_acquire+0x0/0x48

Please consider removing the timestamps on the log. Otherwise I will do
it myself next time.

>
> Signed-off-by: Sean Nyekjaer <[email protected]>
> ---
> drivers/clk/clk.c | 17 ++++++++++-------
> 1 file changed, 10 insertions(+), 7 deletions(-)
>
> diff --git a/drivers/clk/clk.c b/drivers/clk/clk.c
> index 65508eb89ec9..c32b71b08ccb 100644
> --- a/drivers/clk/clk.c
> +++ b/drivers/clk/clk.c
> @@ -4340,17 +4340,20 @@ int clk_notifier_register(struct clk *clk, struct notifier_block *nb)
> if (!clk || !nb)
> return -EINVAL;
>
> + /* allocate new clk_notifier */
> + cn = kzalloc(sizeof(*cn), GFP_KERNEL);
> + if (!cn)
> + goto out;
> +
> clk_prepare_lock();
>
> /* search the list of notifiers for this clk */
> list_for_each_entry(cn, &clk_notifier_list, node)

Isn't this going to overwrite 'cn'?

> - if (cn->clk == clk)
> + if (cn->clk == clk) {
> + /* if clk is in the notifier list, free new clk_notifier */
> + kfree(cn);

Ideally we also kfree() outside the lock.

> goto found;
> -
> - /* if clk wasn't in the notifier list, allocate new clk_notifier */
> - cn = kzalloc(sizeof(*cn), GFP_KERNEL);
> - if (!cn)
> - goto out;
> + }
>
> cn->clk = clk;
> srcu_init_notifier_head(&cn->notifier_head);
> @@ -4362,9 +4365,9 @@ int clk_notifier_register(struct clk *clk, struct notifier_block *nb)
>
> clk->core->notifier_count++;
>
> -out:
> clk_prepare_unlock();
>
> +out:
> return ret;
> }
> EXPORT_SYMBOL_GPL(clk_notifier_register);
>

How about this totally untested patch?

----8<----

diff --git a/drivers/clk/clk.c b/drivers/clk/clk.c
index e2ec1b745243..dac53dbedff1 100644
--- a/drivers/clk/clk.c
+++ b/drivers/clk/clk.c
@@ -4334,29 +4334,27 @@ void __clk_put(struct clk *clk)
*/
int clk_notifier_register(struct clk *clk, struct notifier_block *nb)
{
- struct clk_notifier *cn;
- int ret = -ENOMEM;
+ struct clk_notifier *cn, *new_cn;
+ int ret;

if (!clk || !nb)
return -EINVAL;

- clk_prepare_lock();
+ new_cn = kzalloc(sizeof(*new_cn), GFP_KERNEL);
+ if (!new_cn)
+ return -ENOMEM;

+ clk_prepare_lock();
/* search the list of notifiers for this clk */
list_for_each_entry(cn, &clk_notifier_list, node)
if (cn->clk == clk)
goto found;

- /* if clk wasn't in the notifier list, allocate new clk_notifier */
- cn = kzalloc(sizeof(*cn), GFP_KERNEL);
- if (!cn)
- goto out;
-
+ /* if clk wasn't in the notifier list, use new clk_notifier */
+ cn = new_cn;
cn->clk = clk;
srcu_init_notifier_head(&cn->notifier_head);
-
list_add(&cn->node, &clk_notifier_list);
-
found:
ret = srcu_notifier_chain_register(&cn->notifier_head, nb);

@@ -4365,6 +4363,10 @@ int clk_notifier_register(struct clk *clk, struct notifier_block *nb)
out:
clk_prepare_unlock();

+ /* Did we reuse an existing notifier? If so, free the new one */
+ if (cn != new_cn)
+ kfree(new_cn);
+
return ret;
}
EXPORT_SYMBOL_GPL(clk_notifier_register);

2021-06-10 21:20:23

by Stephen Boyd

[permalink] [raw]
Subject: Re: [PATCH] clk: fix possible circular locking in clk_notifier_register()

Quoting Sean Nyekjaer (2021-06-10 00:23:30)
> On 10/06/2021 09.17, Sean Nyekjaer wrote:
> > Allocating memory with prepare_lock mutex held makes lockdep unhappy
> > when memory pressure makes the system do fs_reclaim on eg. rawnand using
> > clk.
> >
> > Push the allocation outside the lock.
> >
> [...]
> >
> > Signed-off-by: Sean Nyekjaer <[email protected]>
> Fixes: b2476490ef111 ("clk: introduce the common clock framework")
>
> We could possibly add this fixes tag ^^

Sure.

2021-06-11 08:05:00

by Sean Nyekjaer

[permalink] [raw]
Subject: Re: [PATCH] clk: fix possible circular locking in clk_notifier_register()

On 10/06/2021 23.17, Stephen Boyd wrote:

> Quoting Sean Nyekjaer (2021-06-10 00:17:57)

>> Allocating memory with prepare_lock mutex held makes lockdep unhappy

>> when memory pressure makes the system do fs_reclaim on eg. rawnand using

>> clk.

>>

>> Push the allocation outside the lock.

>>

>> [ 462.466020] ======================================================

>> [ 462.472211] WARNING: possible circular locking dependency detected

>> [ 462.478406] 4.19.128-00489-gffc0949c2231 #2 Not tainted

>

> 4.19 is quite old. Is it happening in mainline? I suppose so given that

> the allocation is still under the prepare lock?


I'm not able to reproduce on 5.10, as the oom killer is quite a lot smarter and

kills my reproducer application...



>

>> [ 462.483641] ------------------------------------------------------

>> [ 462.489831] kswapd0/22 is trying to acquire lock:

>> [ 462.494553] 882c9532 (&c->commit_sem){++++}, at: make_reservation+0x68/0x41c


[...]


>> [ 462.959322] #0: 11f3c233 (fs_reclaim){+.+.}, at: __fs_reclaim_acquire+0x0/0x48

>

> Please consider removing the timestamps on the log. Otherwise I will do

> it myself next time.


Sure will do, they are quite noisy...


>

>>

>> Signed-off-by: Sean Nyekjaer <[email protected]>

>> ---

>> drivers/clk/clk.c | 17 ++++++++++-------

>> 1 file changed, 10 insertions(+), 7 deletions(-)

>>

>> diff --git a/drivers/clk/clk.c b/drivers/clk/clk.c

>> index 65508eb89ec9..c32b71b08ccb 100644

>> --- a/drivers/clk/clk.c

>> +++ b/drivers/clk/clk.c

>> @@ -4340,17 +4340,20 @@ int clk_notifier_register(struct clk *clk, struct notifier_block *nb)

>> if (!clk || !nb)

>> return -EINVAL;

>>

>> + /* allocate new clk_notifier */

>> + cn = kzalloc(sizeof(*cn), GFP_KERNEL);

>> + if (!cn)

>> + goto out;

>> +

>> clk_prepare_lock();

>>

>> /* search the list of notifiers for this clk */

>> list_for_each_entry(cn, &clk_notifier_list, node)

>

> Isn't this going to overwrite 'cn'?


Yes :(



>

>> - if (cn->clk == clk)

>> + if (cn->clk == clk) {

>> + /* if clk is in the notifier list, free new clk_notifier */

>> + kfree(cn);

>

> Ideally we also kfree() outside the lock.


Ok.



>

>> goto found;

>> -

>> - /* if clk wasn't in the notifier list, allocate new clk_notifier */

>> - cn = kzalloc(sizeof(*cn), GFP_KERNEL);



[...]



>> }

>> EXPORT_SYMBOL_GPL(clk_notifier_register);

>>

>

> How about this totally untested patch?

>

[...]

Yes it's also a fix, but i catches another circular dep :(


======================================================


WARNING: possible circular locking dependency detected


4.19.128-00489-gffc0949c2231-dirty #5 Not tainted


------------------------------------------------------


kswapd0/22 is trying to acquire lock:


cf8513b3 (&c->commit_sem){++++}, at: make_reservation+0x68/0x41c





but task is already holding lock:


0a27c3f4 (fs_reclaim){+.+.}, at: __fs_reclaim_acquire+0x0/0x48





which lock already depends on the new lock.





the existing dependency chain (in reverse order) is:





-> #5 (fs_reclaim){+.+.}:


fs_reclaim_acquire+0x78/0x88


__kmalloc+0x48/0x31c


pcpu_mem_zalloc+0x34/0x8c


pcpu_create_chunk+0x20/0x270


pcpu_balance_workfn+0x5dc/0x74c


process_one_work+0x2a4/0x744


worker_thread+0x5c/0x554


kthread+0x120/0x160


ret_from_fork+0x14/0x20


(null)





-> #4 (pcpu_alloc_mutex){+.+.}:


__mutex_lock+0x60/0x8dc


mutex_lock_killable_nested+0x24/0x30


pcpu_alloc+0x404/0x854


__alloc_percpu+0x18/0x20


init_srcu_struct_fields+0x3e4/0x460


__init_srcu_struct+0x50/0x5c


srcu_init_notifier_head+0x2c/0x54


clk_notifier_register+0xd0/0x130


i2c_imx_probe+0x23c/0x678


platform_drv_probe+0x50/0xa0


really_probe+0x2b8/0x3d8


driver_probe_device+0x64/0x16c


__driver_attach+0x120/0x144


bus_for_each_dev+0x7c/0xc4


driver_attach+0x20/0x28


bus_add_driver+0x174/0x208


driver_register+0x90/0x120


__platform_driver_register+0x38/0x4c


i2c_adap_imx_init+0x18/0x20


do_one_initcall+0x8c/0x32c


kernel_init_freeable+0x300/0x3e4


kernel_init+0x10/0x114


ret_from_fork+0x14/0x20


(null)





-> #3 (prepare_lock){+.+.}:


__mutex_lock+0x60/0x8dc


mutex_lock_nested+0x24/0x2c


clk_prepare_lock+0x44/0xec


clk_prepare+0x20/0x38


__gpmi_enable_clk+0x34/0xb8


gpmi_enable_clk+0x14/0x18


gpmi_select_chip+0x4c/0xa4


nand_read_oob+0xa0/0x7b8


part_read_oob+0x40/0x78


mtd_read+0x10c/0x13c


ubi_io_read+0xc8/0x354


ubi_eba_read_leb+0xc8/0x544


ubi_eba_read_leb_sg+0x70/0x170


ubi_leb_read_sg+0x7c/0xbc


ubiblock_do_work+0xcc/0x118


process_one_work+0x2a4/0x744


worker_thread+0x5c/0x554


kthread+0x120/0x160


ret_from_fork+0x14/0x20


(null)





-> #2 (&le->mutex){++++}:


down_read+0x3c/0x80


ubi_eba_read_leb+0x4c/0x544


ubi_leb_read+0x7c/0xbc


ubifs_leb_read+0x34/0x80


ubifs_read_nnode+0x194/0x208


ubifs_lpt_lookup_dirty+0x1e0/0x294


ubifs_replay_journal+0x48/0x15a8


ubifs_mount+0x104c/0x15f0


mount_fs+0x1c/0xb8


vfs_kern_mount.part.0+0x58/0x148


do_mount+0x6a4/0xec8


ksys_mount+0x90/0xbc


sys_mount+0x1c/0x24


ret_fast_syscall+0x0/0x28


0xbee78b38





-> #1 (&c->lp_mutex){+.+.}:


__mutex_lock+0x60/0x8dc


mutex_lock_nested+0x24/0x2c


ubifs_gc_start_commit+0x28/0x32c


do_commit+0x1cc/0x7e4


ubifs_run_commit+0x98/0xd0


grab_empty_leb+0x60/0x98


ubifs_rcvry_gc_commit+0x10c/0x1d8


ubifs_mount+0x1308/0x15f0


mount_fs+0x1c/0xb8


vfs_kern_mount.part.0+0x58/0x148


do_mount+0x6a4/0xec8


ksys_mount+0x90/0xbc


sys_mount+0x1c/0x24


ret_fast_syscall+0x0/0x28


0xbee78b38





-> #0 (&c->commit_sem){++++}:


lock_acquire+0xd4/0x1f8


down_read+0x3c/0x80


make_reservation+0x68/0x41c


ubifs_jnl_write_data+0x134/0x2b8


do_writepage+0x88/0x210


ubifs_writepage+0x1b8/0x274


shrink_page_list+0x800/0xf68


shrink_inactive_list+0x1b4/0x4f0


shrink_node+0x44c/0x9c0


kswapd+0x3f8/0x928


kthread+0x120/0x160


ret_from_fork+0x14/0x20


(null)





other info that might help us debug this:





Chain exists of:


&c->commit_sem --> pcpu_alloc_mutex --> fs_reclaim





Possible unsafe locking scenario:





CPU0 CPU1


---- ----


lock(fs_reclaim);


lock(pcpu_alloc_mutex);


lock(fs_reclaim);


lock(&c->commit_sem);





*** DEADLOCK ***





1 lock held by kswapd0/22:


#0: 0a27c3f4 (fs_reclaim){+.+.}, at: __fs_reclaim_acquire+0x0/0x48

2021-06-26 14:52:15

by kernel test robot

[permalink] [raw]
Subject: [clk] b3f27bce16: kernel_BUG_at_lib/list_debug.c



Greeting,

FYI, we noticed the following commit (built with gcc-9):

commit: b3f27bce1653cb3e5549e6a4ba293cb148e7336a ("[PATCH] clk: fix possible circular locking in clk_notifier_register()")
url: https://github.com/0day-ci/linux/commits/Sean-Nyekjaer/clk-fix-possible-circular-locking-in-clk_notifier_register/20210616-233417
base: https://git.kernel.org/cgit/linux/kernel/git/clk/linux.git clk-next

in testcase: kernel-selftests
version: kernel-selftests-x86_64-f8879e85-1_20210621
with following parameters:

group: sgx
ucode: 0xde

test-description: The kernel contains a set of "self tests" under the tools/testing/selftests/ directory. These are intended to be small unit tests to exercise individual code paths in the kernel.
test-url: https://www.kernel.org/doc/Documentation/kselftest.txt


on test machine: 16 threads 1 sockets Intel(R) Xeon(R) E-2278G CPU @ 3.40GHz with 32G memory

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):



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


[ 5.484190] kernel BUG at lib/list_debug.c:29!
[ 5.488680] invalid opcode: 0000 [#1] PREEMPT SMP NOPTI
[ 5.489676] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 5.13.0-rc1-00059-gb3f27bce1653 #1
[ 5.489676] Hardware name: Intel Corporation Mehlow UP Server Platform/Moss Beach Server, BIOS CNLSE2R1.R00.X188.B13.1903250419 03/25/2019
[ 5.489676] RIP: 0010:__list_add_valid.cold (lib/list_debug.c:29 (discriminator 3))
[ 5.489676] Code: 9f ec 81 ff 4c 89 c1 48 c7 c7 18 a8 82 82 e8 1d e0 fe ff 0f 0b 48 89 f2 4c 89 c1 48 89 fe 48 c7 c7 c8 a8 82 82 e8 06 e0 fe ff <0f> 0b 48 89 d1 4c 89 c6 4c 89 ca 48 c7 c7 70 a8 82 82 e8 ef df fe
All code
========
0: 9f lahf
1: ec in (%dx),%al
2: 81 ff 4c 89 c1 48 cmp $0x48c1894c,%edi
8: c7 c7 18 a8 82 82 mov $0x8282a818,%edi
e: e8 1d e0 fe ff callq 0xfffffffffffee030
13: 0f 0b ud2
15: 48 89 f2 mov %rsi,%rdx
18: 4c 89 c1 mov %r8,%rcx
1b: 48 89 fe mov %rdi,%rsi
1e: 48 c7 c7 c8 a8 82 82 mov $0xffffffff8282a8c8,%rdi
25: e8 06 e0 fe ff callq 0xfffffffffffee030
2a:* 0f 0b ud2 <-- trapping instruction
2c: 48 89 d1 mov %rdx,%rcx
2f: 4c 89 c6 mov %r8,%rsi
32: 4c 89 ca mov %r9,%rdx
35: 48 c7 c7 70 a8 82 82 mov $0xffffffff8282a870,%rdi
3c: e8 .byte 0xe8
3d: ef out %eax,(%dx)
3e: df fe (bad)

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 48 89 d1 mov %rdx,%rcx
5: 4c 89 c6 mov %r8,%rsi
8: 4c 89 ca mov %r9,%rdx
b: 48 c7 c7 70 a8 82 82 mov $0xffffffff8282a870,%rdi
12: e8 .byte 0xe8
13: ef out %eax,(%dx)
14: df fe (bad)
[ 5.489676] RSP: 0000:ffffc9000004b570 EFLAGS: 00010246
[ 5.489676] RAX: 0000000000000058 RBX: ffffffff835a3db0 RCX: 0000000000000000
[ 5.489676] RDX: 0000000000000000 RSI: ffffffff8122f88f RDI: ffffffff8122f88f
[ 5.489676] RBP: ffff888101e25de0 R08: 0000000000000001 R09: 0000000000000001
[ 5.489676] R10: 0000000000000001 R11: 0000000000000001 R12: ffffffff835a3db8
[ 5.489676] R13: ffff888109b08558 R14: ffffffff835b7720 R15: 0000000000000000
[ 5.489676] FS: 0000000000000000(0000) GS:ffff88887d240000(0000) knlGS:0000000000000000
[ 5.489676] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 5.489676] CR2: 0000000000000000 CR3: 000000087ac26001 CR4: 00000000003706e0
[ 5.489676] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 5.489676] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 5.489676] Call Trace:
[ 5.489676] clk_notifier_register (include/linux/list.h:67 include/linux/list.h:86 drivers/clk/clk.c:4361)
[ 5.489676] dw8250_probe (drivers/tty/serial/8250/8250_dw.c:597)
[ 5.489676] ? dw8250_serial_in (drivers/tty/serial/8250/8250_dw.c:212)
[ 5.489676] ? dw8250_check_lcr (drivers/tty/serial/8250/8250_dw.c:202)
[ 5.489676] ? dw8250_runtime_resume (drivers/tty/serial/8250/8250_dw.c:331)
[ 5.489676] ? dw8250_serial_out (drivers/tty/serial/8250/8250_dw.c:361)
[ 5.489676] ? dw8250_handle_irq (drivers/tty/serial/8250/8250_dw.c:319)
[ 5.489676] platform_probe (drivers/base/platform.c:1447)
[ 5.489676] really_probe (drivers/base/dd.c:576)
[ 5.489676] driver_probe_device (drivers/base/dd.c:763)
[ 5.489676] ? driver_allows_async_probing (drivers/base/dd.c:843)
[ 5.489676] bus_for_each_drv (drivers/base/bus.c:431)
[ 5.489676] __device_attach (drivers/base/dd.c:938)
[ 5.489676] bus_probe_device (drivers/base/bus.c:491)
[ 5.489676] device_add (drivers/base/core.c:3326)
[ 5.489676] ? preempt_count_sub (kernel/sched/core.c:4817 kernel/sched/core.c:4814 kernel/sched/core.c:4836)
[ 5.489676] platform_device_add (drivers/base/platform.c:748)
[ 5.489676] mfd_add_devices (drivers/mfd/mfd-core.c:278 drivers/mfd/mfd-core.c:330)
[ 5.489676] ? up_write (kernel/locking/rwsem.c:1311 kernel/locking/rwsem.c:1459)
[ 5.489676] ? __debugfs_create_file (fs/debugfs/inode.c:421)
[ 5.489676] intel_lpss_probe (drivers/mfd/intel-lpss.c:428)
[ 5.489676] intel_lpss_pci_probe (drivers/mfd/intel-lpss-pci.c:44 drivers/mfd/intel-lpss-pci.c:20)
[ 5.489676] local_pci_probe (drivers/pci/pci-driver.c:309)
[ 5.489676] pci_device_probe (drivers/pci/pci-driver.c:366 drivers/pci/pci-driver.c:391 drivers/pci/pci-driver.c:434)
[ 5.489676] really_probe (drivers/base/dd.c:576)
[ 5.489676] driver_probe_device (drivers/base/dd.c:763)
[ 5.489676] device_driver_attach (drivers/base/dd.c:1039)
[ 5.489676] __driver_attach (drivers/base/dd.c:1119)
[ 5.489676] ? device_driver_attach (drivers/base/dd.c:1071)
[ 5.489676] ? device_driver_attach (drivers/base/dd.c:1071)
[ 5.489676] bus_for_each_dev (drivers/base/bus.c:305)
[ 5.489676] bus_add_driver (drivers/base/bus.c:623)
[ 5.489676] driver_register (drivers/base/driver.c:171)
[ 5.489676] ? intel_lpss_init (drivers/mfd/intel-lpss-pci.c:450)
[ 5.489676] do_one_initcall (init/main.c:1249)
[ 5.489676] ? rcu_read_lock_sched_held (include/linux/lockdep.h:283 kernel/rcu/update.c:125)
[ 5.489676] kernel_init_freeable (init/main.c:1321 init/main.c:1338 init/main.c:1358 init/main.c:1560)
[ 5.489676] ? rest_init (init/main.c:1444)
[ 5.489676] kernel_init (init/main.c:1449)
[ 5.489676] ret_from_fork (arch/x86/entry/entry_64.S:294)
[ 5.489676] Modules linked in:
[ 5.781493] ---[ end trace 3ef99eb0369b1cec ]---
[ 5.786147] RIP: 0010:__list_add_valid.cold (lib/list_debug.c:29 (discriminator 3))
[ 5.791239] Code: 9f ec 81 ff 4c 89 c1 48 c7 c7 18 a8 82 82 e8 1d e0 fe ff 0f 0b 48 89 f2 4c 89 c1 48 89 fe 48 c7 c7 c8 a8 82 82 e8 06 e0 fe ff <0f> 0b 48 89 d1 4c 89 c6 4c 89 ca 48 c7 c7 70 a8 82 82 e8 ef df fe
All code
========
0: 9f lahf
1: ec in (%dx),%al
2: 81 ff 4c 89 c1 48 cmp $0x48c1894c,%edi
8: c7 c7 18 a8 82 82 mov $0x8282a818,%edi
e: e8 1d e0 fe ff callq 0xfffffffffffee030
13: 0f 0b ud2
15: 48 89 f2 mov %rsi,%rdx
18: 4c 89 c1 mov %r8,%rcx
1b: 48 89 fe mov %rdi,%rsi
1e: 48 c7 c7 c8 a8 82 82 mov $0xffffffff8282a8c8,%rdi
25: e8 06 e0 fe ff callq 0xfffffffffffee030
2a:* 0f 0b ud2 <-- trapping instruction
2c: 48 89 d1 mov %rdx,%rcx
2f: 4c 89 c6 mov %r8,%rsi
32: 4c 89 ca mov %r9,%rdx
35: 48 c7 c7 70 a8 82 82 mov $0xffffffff8282a870,%rdi
3c: e8 .byte 0xe8
3d: ef out %eax,(%dx)
3e: df fe (bad)

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 48 89 d1 mov %rdx,%rcx
5: 4c 89 c6 mov %r8,%rsi
8: 4c 89 ca mov %r9,%rdx
b: 48 c7 c7 70 a8 82 82 mov $0xffffffff8282a870,%rdi
12: e8 .byte 0xe8
13: ef out %eax,(%dx)
14: df fe (bad)


To reproduce:

git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
bin/lkp run generated-yaml-file



---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/[email protected] Intel Corporation

Thanks,
Oliver Sang


Attachments:
(No filename) (9.01 kB)
config-5.13.0-rc1-00059-gb3f27bce1653 (178.25 kB)
job-script (6.27 kB)
dmesg.xz (13.27 kB)
job.yaml (5.31 kB)
Download all attachments