| Message ID | 1476897666-13974-3-git-send-email-javier@osg.samsung.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
On Wed, Oct 19, 2016 at 02:21:06PM -0300, Javier Martinez Canillas wrote: > If the snd_soc_register_card() fails due a missing resource and the probe > has to be deferred, the driver prints an error message. > > But since many probe retries can happen before a resource is available, > the printed messages can spam the kernel log buffer and slow the boot. > > The information is useful to know that a dependency was not meet and a > defer happened, but isn't necessary to print it on each probe deferral. > > Signed-off-by: Javier Martinez Canillas <javier@osg.samsung.com> > > --- > > sound/soc/samsung/snow.c | 8 +++++++- > 1 file changed, 7 insertions(+), 1 deletion(-) > > diff --git a/sound/soc/samsung/snow.c b/sound/soc/samsung/snow.c > index d8ac907bbb0d..068bfb78a668 100644 > --- a/sound/soc/samsung/snow.c > +++ b/sound/soc/samsung/snow.c > @@ -103,7 +103,13 @@ static int snow_probe(struct platform_device *pdev) > > ret = devm_snd_soc_register_card(&pdev->dev, card); > if (ret) { > - dev_err(&pdev->dev, "snd_soc_register_card failed (%d)\n", ret); > + if (ret == -EPROBE_DEFER) > + dev_err_once(&pdev->dev, > + "snd_soc_register_card deferred (%d)\n", > + ret); dev_warn_once? I understand you didn't want to change the logic behind this but this is not really an error condition. Probe deferral happens and one should not be worried seeing it once in 'dmesg -l err'. Another point is now we would miss different error condition - infinite (or very long) probe deferral. I am not sure how useful it might be but theoretically seeing many deferrals is a sign of something to fix. Best regards, Krzysztof
Hello Krzysztof, Thanks a lot for your feedback. On 10/19/2016 03:12 PM, Krzysztof Kozlowski wrote: > On Wed, Oct 19, 2016 at 02:21:06PM -0300, Javier Martinez Canillas wrote: >> If the snd_soc_register_card() fails due a missing resource and the probe >> has to be deferred, the driver prints an error message. >> >> But since many probe retries can happen before a resource is available, >> the printed messages can spam the kernel log buffer and slow the boot. >> >> The information is useful to know that a dependency was not meet and a >> defer happened, but isn't necessary to print it on each probe deferral. >> >> Signed-off-by: Javier Martinez Canillas <javier@osg.samsung.com> >> >> --- >> >> sound/soc/samsung/snow.c | 8 +++++++- >> 1 file changed, 7 insertions(+), 1 deletion(-) >> >> diff --git a/sound/soc/samsung/snow.c b/sound/soc/samsung/snow.c >> index d8ac907bbb0d..068bfb78a668 100644 >> --- a/sound/soc/samsung/snow.c >> +++ b/sound/soc/samsung/snow.c >> @@ -103,7 +103,13 @@ static int snow_probe(struct platform_device *pdev) >> >> ret = devm_snd_soc_register_card(&pdev->dev, card); >> if (ret) { >> - dev_err(&pdev->dev, "snd_soc_register_card failed (%d)\n", ret); >> + if (ret == -EPROBE_DEFER) >> + dev_err_once(&pdev->dev, >> + "snd_soc_register_card deferred (%d)\n", >> + ret); > > dev_warn_once? I understand you didn't want to change the logic behind > this but this is not really an error condition. Probe deferral happens > and one should not be worried seeing it once in 'dmesg -l err'. > Exactly, I even thought about doing that change (or even dev_dbg_once) but I didn't want to change the current logic. > Another point is now we would miss different error condition - infinite > (or very long) probe deferral. I am not sure how useful it might be but > theoretically seeing many deferrals is a sign of something to fix. > Yes, not sure how we can have both though. Maybe dev_{err,warn}_ratelimit is a good trade off? > Best regards, > Krzysztof > Best regards,
On 10/19/2016 07:21 PM, Javier Martinez Canillas wrote: > If the snd_soc_register_card() fails due a missing resource and the probe > has to be deferred, the driver prints an error message. > > But since many probe retries can happen before a resource is available, > the printed messages can spam the kernel log buffer and slow the boot. Do you know why CPU DAI is not registered by the time snow machine driver gets probed? Did you try to debug the I2S driver? Does perhaps deferring happen due to some I2S clocks missing? DMA seems to be already initialized. The deferral loop looks suspicious, do you perhaps know what commits in v4.8 cause such changes in probing order? Did you start to use some drivers as loadable module? As far as the error log is concerned, I would just not print anything in snow_probe() when register_card() returns EPROBE_DEFER.
Hello Sylwester, Thanks a lot for your feedback. On 10/20/2016 06:12 AM, Sylwester Nawrocki wrote: > On 10/19/2016 07:21 PM, Javier Martinez Canillas wrote: >> If the snd_soc_register_card() fails due a missing resource and the probe >> has to be deferred, the driver prints an error message. >> >> But since many probe retries can happen before a resource is available, >> the printed messages can spam the kernel log buffer and slow the boot. > > Do you know why CPU DAI is not registered by the time snow machine > driver gets probed? Did you try to debug the I2S driver? Does perhaps > deferring happen due to some I2S clocks missing? DMA seems to be > already initialized. > The deferral loop looks suspicious, do you perhaps know what commits It's suspicious indeed and I've been trying to figure out what changed the behavior in v4.8 but I haven't found it yet. > in v4.8 cause such changes in probing order? Did you start to use I did a git bisect to find the first v4.8 commit that caused this but finished in a merge commit c9b95e5961c0 ("Merge tag 'sound-4.8-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/tiwai/sound"). That branch alone works the same than v4.7 so it seems that is not a single commit but a combination from different branches that caused this on integration. > some drivers as loadable module? > I see no relevant changes in exynos_defconfig between v4.7..v4.8 and also no changes in drivers/Makefile that could cause things to be initialized on a different order. But I thought the patches had merits on its own since probe deferral can make a driver probe many times and the error logs were noisy. I wasn't sure though and that's why are marked as RFC. > As far as the error log is concerned, I would just not print anything > in snow_probe() when register_card() returns EPROBE_DEFER. > I believe it may be useful to know that a driver's probe is deferring due a missing dependency but have no strong opinion and can remove the message. Best regards,
On 10/20/2016 12:41 PM, Javier Martinez Canillas wrote: > I see no relevant changes in exynos_defconfig between v4.7..v4.8 and > also no changes in drivers/Makefile that could cause things to be > initialized on a different order. I remember this commit 6eb1c9496b81680f2cd2e0eda06c531317e2e28d clk: probe common clock drivers earlier going in recently, but it's rather dubious it could cause such trouble. Anyway, I'd try to add some debug prints to samsung_i2s_probe() to see what's the issue with the CPU DAI registration. > But I thought the patches had merits on its own since probe deferral > can make a driver probe many times and the error logs were noisy. I > wasn't sure though and that's why are marked as RFC. In general I wouldn't be disabling those err logs unless proper EPROBE_DEFER handling is added on related error paths and we can differentiate between probe deferral and real unrecoverable errors and can disable logging only for EPROBE_DEFER cases. >> As far as the error log is concerned, I would just not print anything >> in snow_probe() when register_card() returns EPROBE_DEFER. >> > > I believe it may be useful to know that a driver's probe is deferring > due a missing dependency but have no strong opinion and can remove the > message. I'd rather rely on core code to inform about missing resources when registering components. Otherwise booting unnecessarily takes more time when there is more probe deferring logs printed on the console. -- Thanks, Sylwester
Hello Sylwester, On 10/20/2016 08:27 AM, Sylwester Nawrocki wrote: > On 10/20/2016 12:41 PM, Javier Martinez Canillas wrote: >> I see no relevant changes in exynos_defconfig between v4.7..v4.8 and >> also no changes in drivers/Makefile that could cause things to be >> initialized on a different order. > > I remember this > > commit 6eb1c9496b81680f2cd2e0eda06c531317e2e28d > clk: probe common clock drivers earlier > > going in recently, but it's rather dubious it could cause such trouble. > Yes, I'm aware of this change (and in fact it broke MMC in the Peach Pi Chromebook) but that commit landed in v4.9-rc1, not v4.8. > Anyway, I'd try to add some debug prints to samsung_i2s_probe() to see > what's the issue with the CPU DAI registration. > Sure, I'm busy with other stuff now but I'll dig again this next week. >> But I thought the patches had merits on its own since probe deferral >> can make a driver probe many times and the error logs were noisy. I >> wasn't sure though and that's why are marked as RFC. > > In general I wouldn't be disabling those err logs unless proper > EPROBE_DEFER handling is added on related error paths and we can > differentiate between probe deferral and real unrecoverable errors > and can disable logging only for EPROBE_DEFER cases. > Yes, the sound core change (patch 1/2) is only for the EPROBE_DEFER path. >>> As far as the error log is concerned, I would just not print anything >>> in snow_probe() when register_card() returns EPROBE_DEFER. >>> >> >> I believe it may be useful to know that a driver's probe is deferring >> due a missing dependency but have no strong opinion and can remove the >> message. > > I'd rather rely on core code to inform about missing resources when > registering components. Otherwise booting unnecessarily takes more > time when there is more probe deferring logs printed on the console. > Fair enough. > > -- > Thanks, > Sylwester > Best regards,
+Marek, Hello, On 10/20/2016 08:27 AM, Sylwester Nawrocki wrote: > On 10/20/2016 12:41 PM, Javier Martinez Canillas wrote: >> I see no relevant changes in exynos_defconfig between v4.7..v4.8 and >> also no changes in drivers/Makefile that could cause things to be >> initialized on a different order. > > I remember this > > commit 6eb1c9496b81680f2cd2e0eda06c531317e2e28d > clk: probe common clock drivers earlier > > going in recently, but it's rather dubious it could cause such trouble. > > Anyway, I'd try to add some debug prints to samsung_i2s_probe() to see > what's the issue with the CPU DAI registration. > fyi, Marek already fixed this issue on patch "ASoC: samsung: get access to DMA engine early to defer probe properly": https://patchwork.kernel.org/patch/9399613/ Best regards,
On 10/27/2016 05:38 PM, Javier Martinez Canillas wrote: > +Marek, > > Hello, > > On 10/20/2016 08:27 AM, Sylwester Nawrocki wrote: >> On 10/20/2016 12:41 PM, Javier Martinez Canillas wrote: >>> I see no relevant changes in exynos_defconfig between v4.7..v4.8 and >>> also no changes in drivers/Makefile that could cause things to be >>> initialized on a different order. >> >> I remember this >> >> commit 6eb1c9496b81680f2cd2e0eda06c531317e2e28d >> clk: probe common clock drivers earlier >> >> going in recently, but it's rather dubious it could cause such trouble. >> >> Anyway, I'd try to add some debug prints to samsung_i2s_probe() to see >> what's the issue with the CPU DAI registration. >> > > fyi, Marek already fixed this issue on patch "ASoC: samsung: get access to > DMA engine early to defer probe properly": Yeah, we have spent some time together today investigating this issue.
Hello Sylwester, On 10/27/2016 12:48 PM, Sylwester Nawrocki wrote: > On 10/27/2016 05:38 PM, Javier Martinez Canillas wrote: >> +Marek, >> >> Hello, >> >> On 10/20/2016 08:27 AM, Sylwester Nawrocki wrote: >>> On 10/20/2016 12:41 PM, Javier Martinez Canillas wrote: >>>> I see no relevant changes in exynos_defconfig between v4.7..v4.8 and >>>> also no changes in drivers/Makefile that could cause things to be >>>> initialized on a different order. >>> >>> I remember this >>> >>> commit 6eb1c9496b81680f2cd2e0eda06c531317e2e28d >>> clk: probe common clock drivers earlier >>> >>> going in recently, but it's rather dubious it could cause such trouble. >>> >>> Anyway, I'd try to add some debug prints to samsung_i2s_probe() to see >>> what's the issue with the CPU DAI registration. >>> >> >> fyi, Marek already fixed this issue on patch "ASoC: samsung: get access to >> DMA engine early to defer probe properly": > > Yeah, we have spent some time together today investigating this issue. > Thanks a lot. I thought you would be aware but wanted to mention it on this thread for completeness. Best regards,
diff --git a/sound/soc/samsung/snow.c b/sound/soc/samsung/snow.c index d8ac907bbb0d..068bfb78a668 100644 --- a/sound/soc/samsung/snow.c +++ b/sound/soc/samsung/snow.c @@ -103,7 +103,13 @@ static int snow_probe(struct platform_device *pdev) ret = devm_snd_soc_register_card(&pdev->dev, card); if (ret) { - dev_err(&pdev->dev, "snd_soc_register_card failed (%d)\n", ret); + if (ret == -EPROBE_DEFER) + dev_err_once(&pdev->dev, + "snd_soc_register_card deferred (%d)\n", + ret); + else + dev_err(&pdev->dev, + "snd_soc_register_card failed (%d)\n", ret); return ret; }
If the snd_soc_register_card() fails due a missing resource and the probe has to be deferred, the driver prints an error message. But since many probe retries can happen before a resource is available, the printed messages can spam the kernel log buffer and slow the boot. The information is useful to know that a dependency was not meet and a defer happened, but isn't necessary to print it on each probe deferral. Signed-off-by: Javier Martinez Canillas <javier@osg.samsung.com> --- sound/soc/samsung/snow.c | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-)