rsnd: clk-multiplier already disabled warning on Ebisu
Hi Morimoto-san,
While booting Ebisu-4D, I saw the below warnings (once).
rcar_sound ec500000.sound: can't use clk 1
rsnd_adg_clk_control() failed to enable CLKB, but continues.
------------[ cut here ]------------ clk-multiplier already disabled WARNING: CPU: 1 PID: 52 at drivers/clk/clk.c:952 clk_core_disable+0x30/0x9c Modules linked in: CPU: 1 PID: 52 Comm: kworker/1:2 Not tainted 5.10.0-rc7-rcar3-initrd-00582-gadecf297acf4-dirty #183 Hardware name: Renesas Ebisu-4D board based on r8a77990 (DT) Workqueue: events deferred_probe_work_func pstate: 60000085 (nZCv daIf -PAN -UAO -TCO BTYPE=--) pc : clk_core_disable+0x30/0x9c lr : clk_core_disable+0x30/0x9c sp : ffffffc010f939f0 x29: ffffffc010f939f0 x28: 0000000000000000 x27: ffffff800949eb00 x26: ffffff80093c40f8 x25: 0000000000000001 x24: ffffffc010805fea x23: 0000000000000000 x22: ffffff80082b8810 x21: ffffff80093c4080 x20: ffffff8009368b00 x19: ffffff8009368b00 x18: 0000000000000000 x17: 000000004ef774c4 x16: 0000000000000014 x15: ffffffffffffffff x14: ffffffc010b8e8b0 x13: fffffffffff9fd47 x12: 0720072007200720 x11: fffffffffffc0000 x10: ffffffc010b8e8d8 x9 : 0720072007200720 x8 : 2079646165726c61 x7 : 0000000000000004 x6 : 00000000ffffe6ad x5 : ffffffc010f93718 x4 : 0000000000000000 x3 : 0000000000000000 x2 : 00000000ffffffff x1 : 0000000000000000 x0 : 0000000000000000 Call trace: clk_core_disable+0x30/0x9c clk_core_disable_lock+0x24/0x3c clk_disable+0x20/0x30 rsnd_adg_clk_control+0xa0/0xd4 rsnd_adg_remove+0x58/0x6c rsnd_probe+0x134/0x3cc
Something else fails (-EPROBE_DEFER?), and thus rsnd_adg_remove() is called. The latter disables all clocks, including the one that failed to enable before, leading to the warning.
platform_drv_probe+0x54/0xa4 really_probe+0x234/0x340 driver_probe_device+0xa0/0xb0 __device_attach_driver+0x9c/0xa8 bus_for_each_drv+0x9c/0xc4 __device_attach+0xd4/0x140 device_initial_probe+0x14/0x20 bus_probe_device+0x30/0x94 deferred_probe_work_func+0x9c/0xb0 process_one_work+0x180/0x1f0 process_scheduled_works+0x44/0x48 worker_thread+0x1ec/0x270 kthread+0xdc/0xec ret_from_fork+0x10/0x30 ---[ end trace 8d8c2a1b7537ca36 ]--- ------------[ cut here ]------------ clk-multiplier already unprepared WARNING: CPU: 1 PID: 52 at drivers/clk/clk.c:810 clk_core_unprepare+0x30/0xd0 [...] ---[ end trace 8d8c2a1b7537ca37 ]---
Gr{oetje,eeting}s,
Geert
We need to care clock accessibility, because we might can't use clock for some reasons.
It sets clk_rate for each clocks when enabled. This means it doesn't have clk_rate if we can't use. We can avoid to call clk_disable_unprepare() in such case.
Reported-by: Geert Uytterhoeven geert@linux-m68k.org Signed-off-by: Kuninori Morimoto kuninori.morimoto.gx@renesas.com ---
Hi Geert.
Thank you for your reporting. I have never seen this kind of error, but it possible to happen. Unfortunately, I can't reproduce this but I hope this patch can solve it. Could you please check this ? I added [RFC] on this patch Subject.
sound/soc/sh/rcar/adg.c | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-)
diff --git a/sound/soc/sh/rcar/adg.c b/sound/soc/sh/rcar/adg.c index b9aacf3d3b29..b870e834aa0a 100644 --- a/sound/soc/sh/rcar/adg.c +++ b/sound/soc/sh/rcar/adg.c @@ -366,25 +366,25 @@ void rsnd_adg_clk_control(struct rsnd_priv *priv, int enable) struct rsnd_adg *adg = rsnd_priv_to_adg(priv); struct device *dev = rsnd_priv_to_dev(priv); struct clk *clk; - int i, ret; + int i;
for_each_rsnd_clk(clk, adg, i) { - ret = 0; if (enable) { - ret = clk_prepare_enable(clk); + int ret = clk_prepare_enable(clk);
/* * We shouldn't use clk_get_rate() under * atomic context. Let's keep it when * rsnd_adg_clk_enable() was called */ - adg->clk_rate[i] = clk_get_rate(adg->clk[i]); + if (ret < 0) + dev_warn(dev, "can't use clk %d\n", i); + else + adg->clk_rate[i] = clk_get_rate(adg->clk[i]); } else { - clk_disable_unprepare(clk); + if (adg->clk_rate[i]) + clk_disable_unprepare(clk); } - - if (ret < 0) - dev_warn(dev, "can't use clk %d\n", i); } }
On Tue, Dec 15, 2020 at 09:06:05AM +0900, Kuninori Morimoto wrote:
adg->clk_rate[i] = clk_get_rate(adg->clk[i]);
if (ret < 0)dev_warn(dev, "can't use clk %d\n", i);elseadg->clk_rate[i] = clk_get_rate(adg->clk[i]);
We never reset adg->clk_rate[i] so if we use the clock once then get an error attempting to use it again...
} else {
clk_disable_unprepare(clk);
if (adg->clk_rate[i])clk_disable_unprepare(clk);
...we'll try to disable twice. This was already an issue of course, not something introduced in this patch.
Hi Morimoto-san,
On Tue, Dec 15, 2020 at 1:06 AM Kuninori Morimoto kuninori.morimoto.gx@renesas.com wrote:
We need to care clock accessibility, because we might can't use clock for some reasons.
It sets clk_rate for each clocks when enabled. This means it doesn't have clk_rate if we can't use. We can avoid to call clk_disable_unprepare() in such case.
Reported-by: Geert Uytterhoeven geert@linux-m68k.org
Feel free to use geert+renesas@glider.be instead ;-)
Signed-off-by: Kuninori Morimoto kuninori.morimoto.gx@renesas.com
Hi Geert.
Thank you for your reporting. I have never seen this kind of error, but it possible to happen. Unfortunately, I can't reproduce this but I hope this patch can solve it. Could you please check this ? I added [RFC] on this patch Subject.
The patch looks good to me, but I also cannot trigger the issue at will. I went through my old boot logs, and found 2 other occurrences, also on Ebisu. In all cases, it happened while a lot of output was printed to the serial console (either a WARN() splat, or DEBUG_PINCTRL output). My guess is that console output or disabling interrupts too long is triggering a race condition or other issue in the i2c driver (clk 1 is the cs2000 clock generator, controlled through i2c).
--- a/sound/soc/sh/rcar/adg.c +++ b/sound/soc/sh/rcar/adg.c @@ -366,25 +366,25 @@ void rsnd_adg_clk_control(struct rsnd_priv *priv, int enable) struct rsnd_adg *adg = rsnd_priv_to_adg(priv); struct device *dev = rsnd_priv_to_dev(priv); struct clk *clk;
int i, ret;
int i; for_each_rsnd_clk(clk, adg, i) {
ret = 0; if (enable) {ret = clk_prepare_enable(clk);
int ret = clk_prepare_enable(clk); /* * We shouldn't use clk_get_rate() under * atomic context. Let's keep it when * rsnd_adg_clk_enable() was called */
adg->clk_rate[i] = clk_get_rate(adg->clk[i]);
if (ret < 0)dev_warn(dev, "can't use clk %d\n", i);elseadg->clk_rate[i] = clk_get_rate(adg->clk[i]); } else {
clk_disable_unprepare(clk);
if (adg->clk_rate[i])clk_disable_unprepare(clk);
As pointed out by Mark, you may want to clear adg->clk_rate[i] here?
}
if (ret < 0)dev_warn(dev, "can't use clk %d\n", i); }}
With the above sorted out: Reviewed-by: Geert Uytterhoeven geert+renesas@glider.be
Gr{oetje,eeting}s,
Geert
Hi Geert, Mark
Reported-by: Geert Uytterhoeven geert@linux-m68k.org
Feel free to use geert+renesas@glider.be instead ;-)
OK, will do
The patch looks good to me, but I also cannot trigger the issue at will. I went through my old boot logs, and found 2 other occurrences, also on Ebisu. In all cases, it happened while a lot of output was printed to the serial console (either a WARN() splat, or DEBUG_PINCTRL output). My guess is that console output or disabling interrupts too long is triggering a race condition or other issue in the i2c driver (clk 1 is the cs2000 clock generator, controlled through i2c).
OK, Thanks, nice to know. It was rare case issue, difficult to find :)
} else {
clk_disable_unprepare(clk);
if (adg->clk_rate[i])clk_disable_unprepare(clk);As pointed out by Mark, you may want to clear adg->clk_rate[i] here?
I thought we can re-get clock if we could get clock once. But we shouldn't assume it. Will fix it in v2.
Thank you for your help !!
Best regards --- Kuninori Morimoto
Hi Morimoto-san,
On Thu, Dec 17, 2020 at 1:20 AM Kuninori Morimoto kuninori.morimoto.gx@renesas.com wrote:
Reported-by: Geert Uytterhoeven geert@linux-m68k.org
Feel free to use geert+renesas@glider.be instead ;-)
OK, will do
The patch looks good to me, but I also cannot trigger the issue at will. I went through my old boot logs, and found 2 other occurrences, also on Ebisu. In all cases, it happened while a lot of output was printed to the serial console (either a WARN() splat, or DEBUG_PINCTRL output). My guess is that console output or disabling interrupts too long is triggering a race condition or other issue in the i2c driver (clk 1 is the cs2000 clock generator, controlled through i2c).
OK, Thanks, nice to know. It was rare case issue, difficult to find :)
} else {
clk_disable_unprepare(clk);
if (adg->clk_rate[i])clk_disable_unprepare(clk);As pointed out by Mark, you may want to clear adg->clk_rate[i] here?
I thought we can re-get clock if we could get clock once.
Indeed. If a clock worked before, it should keep on working. However, the failing clock was the cs2000 clock, which can fail to enable if something goes wrong with i2c.
Gr{oetje,eeting}s,
Geert
participants (3)
-
Geert Uytterhoeven -
Kuninori Morimoto -
Mark Brown