On 5/15/2023 3:02 PM, Takashi Iwai wrote:
On Mon, 15 May 2023 13:19:29 +0200,
Amadeusz Sławiński wrote:
On 5/12/2023 2:24 PM, Takashi Iwai wrote:
On Fri, 12 May 2023 14:00:54 +0200,
Amadeusz Sławiński wrote:
On 5/12/2023 1:33 PM, Takashi Iwai wrote:
On Fri, 12 May 2023 13:23:49 +0200,
Takashi Iwai wrote:
On Thu, 11 May 2023 19:20:17 +0200,
Amadeusz Sławiński wrote:
On 5/11/2023 5:58 PM, Takashi Iwai wrote:
On Thu, 11 May 2023 17:31:37 +0200,
Amadeusz Sławiński wrote:
On 5/10/2023 2:21 PM, Takashi Iwai wrote:
On Tue, 09 May 2023 12:10:06 +0200,
Amadeusz Sławiński wrote:
Then capture stream starts and seems to assume that
registers were already set, so it doesn't write them to hw.
... it seems this didn't happen, and that's the inconsistency.
So the further question is:
At the point just before you start recording, is the codec in runtime
suspended? Or it's running?
If it's runtime-suspended, snd_hda_regmap_sync() must be called from
alc269_resume() via runtime-resume, and this must write out the
cached values. Then the bug can be along with that line.
Or if it's running, it means that the previous check of
snd_hdac_keep_power_up() was bogus (or racy).
Well, it is in... let's call it semi powered state. When snd_hda_intel
driver is loaded with power_save=X option it sets timeout to X seconds
and problem only happens when I start the stream before those X
seconds pass and it runs first runtime suspend. After it suspends it
then uses standard pm_runtime_resume and works correctly. That's why
the pm_runtime_force_suspend(&codec->core.dev); mentioned in first
email in thread "fixes" the problem, as it forces it to be instantly
suspended instead of waiting for timeout and then later normal
resume-play/record-suspend flow can be followed.
Hm, then maybe it's a bad idea to rely on the usage count there.
Even if the usage is 0, the device can be still active, and the update
can be missed.
How about the patch like below?
Scratch that, it returns a wrong value.
A simpler version like below works instead?
Yes it was broken, arecord didn't even start capturing ;)
Takashi
--- a/sound/hda/hdac_device.c
+++ b/sound/hda/hdac_device.c
@@ -611,10 +611,9 @@ EXPORT_SYMBOL_GPL(snd_hdac_power_up_pm);
int snd_hdac_keep_power_up(struct hdac_device *codec)
{
if (!atomic_inc_not_zero(&codec->in_pm)) {
- int ret = pm_runtime_get_if_in_use(&codec->dev);
- if (!ret)
+ if (!pm_runtime_active(&codec->dev))
return -1;
- if (ret < 0)
+ if (pm_runtime_get_sync(&codec->dev) < 0)
return 0;
}
return 1;
This one seems to work, as in I'm able to record before first suspend
hits. However device stays in D0 when no stream is running...
# cat /sys/devices/pci0000\:00/0000\:00\:0e.0/power_state
D0
OK, one step forward. The previous change was bad in anyway, as we
shouldn't sync there at all.
So, the problem becomes clearer now: it's in the lazy update mechanism
that misses the case that has to be written.
Scratch the previous one again, and could you try the following one
instead?
Takashi
--- a/sound/hda/hdac_regmap.c
+++ b/sound/hda/hdac_regmap.c
@@ -293,8 +293,17 @@ static int hda_reg_write(void *context, unsigned int reg, unsigned int val)
if (verb != AC_VERB_SET_POWER_STATE) {
pm_lock = codec_pm_lock(codec);
- if (pm_lock < 0)
- return codec->lazy_cache ? 0 : -EAGAIN;
+ if (pm_lock < 0) {
+ /* skip the actual write if it's in lazy-update mode
+ * and only if the device is actually suspended;
+ * the usage count can be zero at transition phase
+ * (either suspending/resuming or auto-suspend sleep)
+ */
+ if (codec->lazy_cache &&
+ pm_runtime_suspended(&codec->dev))
+ return 0;
+ return -EAGAIN;
+ }
}
if (is_stereo_amp_verb(reg)) {
With this one we are back to same behavior as without it. When capture
is started before first suspend it records silence. After waiting for
timeout and suspend it records correctly.
Hm, interesting. Does it mean that the pm_runtime_get_if_in_use() (in
snd_hdac_keep_power_up()) returns a non-zero value?
Or is pm_runtime_suspended() returns really true there?
So I've tested with vanilla kernel, where pm_runtime_get_if_in_use
returns -22 until loaded and then 13 times "0" until arecord.
With above patch it returns 13 times "0" and then one more time "1".
pm_runtime_suspended() returns 0 (needed to modify patch a bit)
Patch:
diff --git a/sound/hda/hdac_device.c b/sound/hda/hdac_device.c
index 035b720bf602..62880952e398 100644
--- a/sound/hda/hdac_device.c
+++ b/sound/hda/hdac_device.c
@@ -612,6 +612,7 @@ int snd_hdac_keep_power_up(struct hdac_device *codec)
{
if (!atomic_inc_not_zero(&codec->in_pm)) {
int ret = pm_runtime_get_if_in_use(&codec->dev);
+ pr_err("DEBUG:%s:%d %s ret=%d\n", __FILE__, __LINE__,
__func__, ret);
if (!ret)
return -1;
if (ret < 0)
diff --git a/sound/hda/hdac_regmap.c b/sound/hda/hdac_regmap.c
index fe3587547cfe..d6cf3fa2d4e7 100644
--- a/sound/hda/hdac_regmap.c
+++ b/sound/hda/hdac_regmap.c
@@ -293,8 +293,19 @@ static int hda_reg_write(void *context, unsigned
int reg, unsigned int val)
if (verb != AC_VERB_SET_POWER_STATE) {
pm_lock = codec_pm_lock(codec);
- if (pm_lock < 0)
- return codec->lazy_cache ? 0 : -EAGAIN;
+ if (pm_lock < 0) {
+ bool x;
+ /* skip the actual write if it's in lazy-update mode
+ * and only if the device is actually suspended;
+ * the usage count can be zero at transition phase
+ * (either suspending/resuming or auto-suspend
sleep)
+ */
+ x = pm_runtime_suspended(&codec->dev);
+ pr_err("DEBUG: %s:%d x = %d\n", __FILE__,
__LINE__, x);
+ if (codec->lazy_cache && x)
+ return 0;
+ return -EAGAIN;
+ }
}
if (is_stereo_amp_verb(reg)) {
Part of vanilla dmesg (contains only first chunk):
[ 85.152514] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=-22
[ 85.153698] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=-22
[ 85.162216] snd_hda_core:snd_hdac_display_power: snd_hda_intel
0000:00:0e.0: display power enable
[ 85.166311] input: HDA Intel PCH Mic as
/devices/pci0000:00/0000:00:0e.0/sound/card0/input4
[ 85.168075] input: HDA Intel PCH Headphone as
/devices/pci0000:00/0000:00:0e.0/sound/card0/input5
[ 85.168867] input: HDA Intel PCH HDMI/DP,pcm=3 as
/devices/pci0000:00/0000:00:0e.0/sound/card0/input6
[ 85.169615] input: HDA Intel PCH HDMI/DP,pcm=7 as
/devices/pci0000:00/0000:00:0e.0/sound/card0/input7
[ 85.170620] input: HDA Intel PCH HDMI/DP,pcm=8 as
/devices/pci0000:00/0000:00:0e.0/sound/card0/input8
[ 85.172761] snd_hda_core:snd_hdac_display_power: snd_hda_intel
0000:00:0e.0: display power disable
[ 85.302102] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 85.302142] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 85.302162] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 85.302181] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 85.302241] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 85.302261] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 85.302282] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 85.302300] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 85.302778] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 85.302800] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 85.302845] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 85.302864] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 85.340127] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 86.724945] PRE ARECORD
[ 86.746549] snd_hda_codec:snd_hda_codec_setup_stream:
snd_hda_codec_realtek hdaudioC0D0: hda_codec_setup_stream: NID=0x9,
stream=0x1, channel=0, format=0x11
[ 90.805536] snd_hda_core:snd_hdac_display_power: snd_hda_intel
0000:00:0e.0: display power disable
Part of fully patched dmesg:
[ 79.418123] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=-22
[ 79.419102] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=-22
[ 79.425939] snd_hda_core:snd_hdac_display_power: snd_hda_intel
0000:00:0e.0: display power enable
[ 79.433261] input: HDA Intel PCH Mic as
/devices/pci0000:00/0000:00:0e.0/sound/card0/input4
[ 79.436524] input: HDA Intel PCH Headphone as
/devices/pci0000:00/0000:00:0e.0/sound/card0/input5
[ 79.437992] input: HDA Intel PCH HDMI/DP,pcm=3 as
/devices/pci0000:00/0000:00:0e.0/sound/card0/input6
[ 79.438742] input: HDA Intel PCH HDMI/DP,pcm=7 as
/devices/pci0000:00/0000:00:0e.0/sound/card0/input7
[ 79.442223] input: HDA Intel PCH HDMI/DP,pcm=8 as
/devices/pci0000:00/0000:00:0e.0/sound/card0/input8
[ 79.443541] snd_hda_core:snd_hdac_display_power: snd_hda_intel
0000:00:0e.0: display power disable
[ 79.556191] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 79.556234] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 79.556256] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 79.556276] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 79.556340] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 79.556362] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 79.556383] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 79.556403] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 79.559139] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 79.559174] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 79.559221] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 79.559243] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 79.587950] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=0
[ 79.588013] DEBUG:sound/hda/hdac_device.c:615 snd_hdac_keep_power_up
ret=1
[ 80.975460] PRE ARECORD
[ 80.998701] snd_hda_codec:snd_hda_codec_setup_stream:
snd_hda_codec_realtek hdaudioC0D0: hda_codec_setup_stream: NID=0x9,
stream=0x1, channel=0, format=0x11
[ 85.674194] snd_hda_core:snd_hdac_display_power: snd_hda_intel
0000:00:0e.0: display power disable
[ 92.229492] snd_hda_codec:__snd_hda_codec_cleanup_stream:
snd_hda_codec_realtek hdaudioC0D0: hda_codec_cleanup_stream: NID=0x9
I think there are two problems:
1. After probe codec is powered down
(https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/sound/pci/hda/hda_codec.c#n833),
even though according to power management it is still running
2. When stream is started before first suspend, resume function doesn't
run and it is a function which syncs cached registers. By resume
function I mean
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/sound/pci/hda/hda_codec.c#n2899
which calls snd_hda_regmap_sync() or through in case of the platform I
test it on codec->patch_ops.resume(codec) -> alc269_resume, which also
calls snd_hda_regmap_sync().
