[PATCH] ASoC: lower "no backend DAIs enabled for ... Port" log severity
If SNDRV_PCM_IOCTL_PREPARE is called when the mixer settings linking frontend and backend have not been setup yet this results in e.g. the following errors getting logged:
[ 43.244549] Baytrail Audio Port: ASoC: no backend DAIs enabled for Baytrail Audio Port [ 43.244744] Baytrail Audio Port: ASoC: error at dpcm_fe_dai_prepare on Baytrail Audio Port: -22
pipewire triggers this leading to 96 repeats of this in the log after the user has logged into a GNOME session.
IMHO userspace should not be able to get the kernel to spam dmesg like this. Lower the severity of the "no backend DAIs enabled" log message for dai-s with the dynamic flag set to avoid this.
And also changes _soc_pcm_ret() to not log for -EINVAL errors, to fix the other error. Userspace passing wrong parameters should not lead to dmesg messages.
Link: https://gitlab.freedesktop.org/pipewire/pipewire/-/issues/3407 Signed-off-by: Hans de Goede hdegoede@redhat.com --- sound/soc/soc-pcm.c | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-)
diff --git a/sound/soc/soc-pcm.c b/sound/soc/soc-pcm.c index 8896227e4fb7..fdc1a1c654d6 100644 --- a/sound/soc/soc-pcm.c +++ b/sound/soc/soc-pcm.c @@ -38,6 +38,7 @@ static inline int _soc_pcm_ret(struct snd_soc_pcm_runtime *rtd, switch (ret) { case -EPROBE_DEFER: case -ENOTSUPP: + case -EINVAL: break; default: dev_err(rtd->dev, @@ -2466,7 +2467,11 @@ static int dpcm_fe_dai_prepare(struct snd_pcm_substream *substream)
/* there is no point preparing this FE if there are no BEs */ if (list_empty(&fe->dpcm[stream].be_clients)) { - dev_err(fe->dev, "ASoC: no backend DAIs enabled for %s\n", + if (fe->dai_link->dynamic) + dev_dbg(fe->dev, "ASoC: no backend DAIs enabled for %s\n", + fe->dai_link->name); + else + dev_err(fe->dev, "ASoC: no backend DAIs enabled for %s\n", fe->dai_link->name); ret = -EINVAL; goto out;
On 8/4/23 08:26, Hans de Goede wrote:
If SNDRV_PCM_IOCTL_PREPARE is called when the mixer settings linking frontend and backend have not been setup yet this results in e.g. the following errors getting logged:
[ 43.244549] Baytrail Audio Port: ASoC: no backend DAIs enabled for Baytrail Audio Port [ 43.244744] Baytrail Audio Port: ASoC: error at dpcm_fe_dai_prepare on Baytrail Audio Port: -22
pipewire triggers this leading to 96 repeats of this in the log after the user has logged into a GNOME session.
IMHO userspace should not be able to get the kernel to spam dmesg like this. Lower the severity of the "no backend DAIs enabled" log message for dai-s with the dynamic flag set to avoid this.
And also changes _soc_pcm_ret() to not log for -EINVAL errors, to fix the other error. Userspace passing wrong parameters should not lead to dmesg messages.
Maybe, but it's a questionable flow if pipewire tries to open stuff without the mixer values set-up. Is there something done about this?
The reason why I am pushing back is that we had a similar issue with HDaudio where HDMI/DP PCM devices were opened without checking if the jack was connected.
It really makes no sense for userspace to try and open devices that are known to be problematic. We can push kernel error logs below the rug, it doesn't make the programming flows better.
On Fri, 04 Aug 2023 16:06:45 +0200, Pierre-Louis Bossart wrote:
On 8/4/23 08:26, Hans de Goede wrote:
If SNDRV_PCM_IOCTL_PREPARE is called when the mixer settings linking frontend and backend have not been setup yet this results in e.g. the following errors getting logged:
[ 43.244549] Baytrail Audio Port: ASoC: no backend DAIs enabled for Baytrail Audio Port [ 43.244744] Baytrail Audio Port: ASoC: error at dpcm_fe_dai_prepare on Baytrail Audio Port: -22
pipewire triggers this leading to 96 repeats of this in the log after the user has logged into a GNOME session.
IMHO userspace should not be able to get the kernel to spam dmesg like this. Lower the severity of the "no backend DAIs enabled" log message for dai-s with the dynamic flag set to avoid this.
And also changes _soc_pcm_ret() to not log for -EINVAL errors, to fix the other error. Userspace passing wrong parameters should not lead to dmesg messages.
Maybe, but it's a questionable flow if pipewire tries to open stuff without the mixer values set-up. Is there something done about this?
I think it's an oft-seen problem when user runs the system without installing a proper UCM profile.
The reason why I am pushing back is that we had a similar issue with HDaudio where HDMI/DP PCM devices were opened without checking if the jack was connected.
It really makes no sense for userspace to try and open devices that are known to be problematic. We can push kernel error logs below the rug, it doesn't make the programming flows better.
Downgrading the message also hides to show what's wrong there. Although the message doesn't indicate how to fix the problem, no message would make debug harder.
So in general I agree that it's annoying and it should be fixed, but hiding all as default can be bad, too. Maybe we can introduce a counter and shut out after three strikes?
Takashi
Hi,
On 8/4/23 16:42, Takashi Iwai wrote:
On Fri, 04 Aug 2023 16:06:45 +0200, Pierre-Louis Bossart wrote:
On 8/4/23 08:26, Hans de Goede wrote:
If SNDRV_PCM_IOCTL_PREPARE is called when the mixer settings linking frontend and backend have not been setup yet this results in e.g. the following errors getting logged:
[ 43.244549] Baytrail Audio Port: ASoC: no backend DAIs enabled for Baytrail Audio Port [ 43.244744] Baytrail Audio Port: ASoC: error at dpcm_fe_dai_prepare on Baytrail Audio Port: -22
pipewire triggers this leading to 96 repeats of this in the log after the user has logged into a GNOME session.
IMHO userspace should not be able to get the kernel to spam dmesg like this. Lower the severity of the "no backend DAIs enabled" log message for dai-s with the dynamic flag set to avoid this.
And also changes _soc_pcm_ret() to not log for -EINVAL errors, to fix the other error. Userspace passing wrong parameters should not lead to dmesg messages.
Maybe, but it's a questionable flow if pipewire tries to open stuff without the mixer values set-up. Is there something done about this?
I'm working with the pipewire folks to see if we can fix this on pipewire's side too:
Link: https://gitlab.freedesktop.org/pipewire/pipewire/-/issues/3407
I think it's an oft-seen problem when user runs the system without installing a proper UCM profile.
The reason why I am pushing back is that we had a similar issue with HDaudio where HDMI/DP PCM devices were opened without checking if the jack was connected.
It really makes no sense for userspace to try and open devices that are known to be problematic. We can push kernel error logs below the rug, it doesn't make the programming flows better.
Downgrading the message also hides to show what's wrong there. Although the message doesn't indicate how to fix the problem, no message would make debug harder.
So in general I agree that it's annoying and it should be fixed, but hiding all as default can be bad, too. Maybe we can introduce a counter and shut out after three strikes?
Right, this also happens with unsupported codecs (either unsupported in the kernel or no UCM profile available yet). So making this less "chatty" would be good.
I would prefer to just go for only log this once rather then three strikes though, then we can simply use 'dev_err_once()' for this.
Regards,
Hans
Maybe, but it's a questionable flow if pipewire tries to open stuff without the mixer values set-up. Is there something done about this?
I'm working with the pipewire folks to see if we can fix this on pipewire's side too:
Link: https://gitlab.freedesktop.org/pipewire/pipewire/-/issues/3407
I think it's an oft-seen problem when user runs the system without installing a proper UCM profile.
The reason why I am pushing back is that we had a similar issue with HDaudio where HDMI/DP PCM devices were opened without checking if the jack was connected.
It really makes no sense for userspace to try and open devices that are known to be problematic. We can push kernel error logs below the rug, it doesn't make the programming flows better.
Downgrading the message also hides to show what's wrong there. Although the message doesn't indicate how to fix the problem, no message would make debug harder.
So in general I agree that it's annoying and it should be fixed, but hiding all as default can be bad, too. Maybe we can introduce a counter and shut out after three strikes?
Right, this also happens with unsupported codecs (either unsupported in the kernel or no UCM profile available yet). So making this less "chatty" would be good.
I would prefer to just go for only log this once rather then three strikes though, then we can simply use 'dev_err_once()' for this.
I'd be fine with dev_err_once(). In general when you have this error it's a telltale sign that a configuration is missing. Repeating the message does not makes things better.
Maybe also add some information for the user, e.g. "ASoC: no backend DAIs enabled for Baytrail Audio Port, possibly missing ALSA mixer-based routing or UCM profile"
On Fri, Aug 04, 2023 at 04:42:34PM +0200, Takashi Iwai wrote:
Pierre-Louis Bossart wrote:
And also changes _soc_pcm_ret() to not log for -EINVAL errors, to fix the other error. Userspace passing wrong parameters should not lead to dmesg messages.
Maybe, but it's a questionable flow if pipewire tries to open stuff without the mixer values set-up. Is there something done about this?
I think it's an oft-seen problem when user runs the system without installing a proper UCM profile.
Yeah, it's really easy to do.
It really makes no sense for userspace to try and open devices that are known to be problematic. We can push kernel error logs below the rug, it doesn't make the programming flows better.
Downgrading the message also hides to show what's wrong there. Although the message doesn't indicate how to fix the problem, no message would make debug harder.
So in general I agree that it's annoying and it should be fixed, but hiding all as default can be bad, too. Maybe we can introduce a counter and shut out after three strikes?
Hrm, do systems typically filter out debug logs? Most of the systems I work on do still log debug logs, they just only include them in dmesg by default. There are ratelimited printk APIs which we could use, though they're not quite ratelimited enough for this I think.
On Fri, 04 Aug 2023 17:15:14 +0200, Mark Brown wrote:
On Fri, Aug 04, 2023 at 04:42:34PM +0200, Takashi Iwai wrote:
Pierre-Louis Bossart wrote:
And also changes _soc_pcm_ret() to not log for -EINVAL errors, to fix the other error. Userspace passing wrong parameters should not lead to dmesg messages.
Maybe, but it's a questionable flow if pipewire tries to open stuff without the mixer values set-up. Is there something done about this?
I think it's an oft-seen problem when user runs the system without installing a proper UCM profile.
Yeah, it's really easy to do.
It really makes no sense for userspace to try and open devices that are known to be problematic. We can push kernel error logs below the rug, it doesn't make the programming flows better.
Downgrading the message also hides to show what's wrong there. Although the message doesn't indicate how to fix the problem, no message would make debug harder.
So in general I agree that it's annoying and it should be fixed, but hiding all as default can be bad, too. Maybe we can introduce a counter and shut out after three strikes?
Hrm, do systems typically filter out debug logs? Most of the systems I work on do still log debug logs, they just only include them in dmesg by default.
I thought flipping the dynamic debug flag needed for showing them up with dev_dbg() and co.
There are ratelimited printk APIs which we could use, though they're not quite ratelimited enough for this I think.
Yes, this is printed not too frequently but just repeatedly.
IMHO, dev_err_once() would be a good compromise.
thanks,
Takashi
On Fri, Aug 04, 2023 at 05:40:20PM +0200, Takashi Iwai wrote:
Mark Brown wrote:
Hrm, do systems typically filter out debug logs? Most of the systems I work on do still log debug logs, they just only include them in dmesg by default.
I thought flipping the dynamic debug flag needed for showing them up with dev_dbg() and co.
That's an optional feature, I guess perhaps distro kernels will tend to turn it on but not the defconfigs I'm generally using so I've not been seeing it.
There are ratelimited printk APIs which we could use, though they're not quite ratelimited enough for this I think.
Yes, this is printed not too frequently but just repeatedly.
IMHO, dev_err_once() would be a good compromise.
I can imagine that being *super* frustrating when trying to actually develop configurations since you only get told once per boot that there's something missing. dev_dbg() did seem like a sensible choice here, even with dynamic debug you can at least turn it on. Perhaps both a dev_err_once() and a dev_dbg() so you get a hint that there's something wrong in the logs and can still get ongoing information when developing your configuration.
On Fri, 04 Aug 2023 17:50:02 +0200, Mark Brown wrote:
On Fri, Aug 04, 2023 at 05:40:20PM +0200, Takashi Iwai wrote:
Mark Brown wrote:
Hrm, do systems typically filter out debug logs? Most of the systems I work on do still log debug logs, they just only include them in dmesg by default.
I thought flipping the dynamic debug flag needed for showing them up with dev_dbg() and co.
That's an optional feature, I guess perhaps distro kernels will tend to turn it on but not the defconfigs I'm generally using so I've not been seeing it.
Ah yes, most distros set CONFIG_DYNAMIC_DEBUG, but defconfig is a different set.
There are ratelimited printk APIs which we could use, though they're not quite ratelimited enough for this I think.
Yes, this is printed not too frequently but just repeatedly.
IMHO, dev_err_once() would be a good compromise.
I can imagine that being *super* frustrating when trying to actually develop configurations since you only get told once per boot that there's something missing. dev_dbg() did seem like a sensible choice here, even with dynamic debug you can at least turn it on. Perhaps both a dev_err_once() and a dev_dbg() so you get a hint that there's something wrong in the logs and can still get ongoing information when developing your configuration.
+1, this sounds like a solution.
thanks,
Takashi
On Fri, 04 Aug 2023 15:26:28 +0200, Hans de Goede wrote:
If SNDRV_PCM_IOCTL_PREPARE is called when the mixer settings linking frontend and backend have not been setup yet this results in e.g. the following errors getting logged:
[ 43.244549] Baytrail Audio Port: ASoC: no backend DAIs enabled for Baytrail Audio Port [ 43.244744] Baytrail Audio Port: ASoC: error at dpcm_fe_dai_prepare on Baytrail Audio Port: -22
[...]
Applied to
https://git.kernel.org/pub/scm/linux/kernel/git/broonie/sound.git for-next
Thanks!
[1/1] ASoC: lower "no backend DAIs enabled for ... Port" log severity commit: 1f566435141047ca7db26aa4b0b6647a25badaee
All being well this means that it will be integrated into the linux-next tree (usually sometime in the next 24 hours) and sent to Linus during the next merge window (or sooner if it is a bug fix), however if problems are discovered then the patch may be dropped or reverted.
You may get further e-mails resulting from automated or manual testing and review of the tree, please engage with people reporting problems and send followup patches addressing any issues that are reported if needed.
If any updates are required or you are submitting further changes they should be sent as incremental updates against current git, existing patches will not be replaced.
Please add any relevant lists and maintainers to the CCs when replying to this mail.
Thanks, Mark
participants (4)
-
Hans de Goede -
Mark Brown -
Pierre-Louis Bossart -
Takashi Iwai