snd-hda-intel runtime PM fail after module reload

snd-hda-intel runtime PM fail after module reload

[Ville Syrjälä]

Hi,

My investigation into some sporadic i915 runtime PM failures seem to
point the finger at snd-hda-intel.

I just tried to play around unloding and reloading snd-hda-intel and
sometimes I get snd-hda-intel loaded with runtime PM supposedly enabled,
but actually the device won't runtime suspend. At which point frobbing
with power/control is enough to kick it back into submission.

# for i in `seq 1 3`; do sleep 1 ; grep . /sys/bus/pci/devices/0000\:00\:03.0/power/*  ; done
/sys/bus/pci/devices/0000:00:03.0/power/async:enabled
grep: /sys/bus/pci/devices/0000:00:03.0/power/autosuspend_delay_ms: Input/output error
/sys/bus/pci/devices/0000:00:03.0/power/control:auto
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_kids:0
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_time:117045
/sys/bus/pci/devices/0000:00:03.0/power/runtime_enabled:enabled
/sys/bus/pci/devices/0000:00:03.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:03.0/power/runtime_suspended_time:222657
/sys/bus/pci/devices/0000:00:03.0/power/runtime_usage:0
/sys/bus/pci/devices/0000:00:03.0/power/async:enabled
grep: /sys/bus/pci/devices/0000:00:03.0/power/autosuspend_delay_ms: Input/output error
/sys/bus/pci/devices/0000:00:03.0/power/control:auto
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_kids:0
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_time:117045
/sys/bus/pci/devices/0000:00:03.0/power/runtime_enabled:enabled
/sys/bus/pci/devices/0000:00:03.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:03.0/power/runtime_suspended_time:223666
/sys/bus/pci/devices/0000:00:03.0/power/runtime_usage:0
/sys/bus/pci/devices/0000:00:03.0/power/async:enabled
grep: /sys/bus/pci/devices/0000:00:03.0/power/autosuspend_delay_ms: Input/output error
/sys/bus/pci/devices/0000:00:03.0/power/control:auto
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_kids:0
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_time:117045
/sys/bus/pci/devices/0000:00:03.0/power/runtime_enabled:enabled
/sys/bus/pci/devices/0000:00:03.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:03.0/power/runtime_suspended_time:224674
/sys/bus/pci/devices/0000:00:03.0/power/runtime_usage:0
# rmmod snd-hda-intel
# modprobe snd-hda-intel
# for i in `seq 1 3`; do sleep 1 ; grep . /sys/bus/pci/devices/0000\:00\:03.0/power/*  ; done
/sys/bus/pci/devices/0000:00:03.0/power/async:enabled
grep: /sys/bus/pci/devices/0000:00:03.0/power/autosuspend_delay_ms: Input/output error
/sys/bus/pci/devices/0000:00:03.0/power/control:auto
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_kids:0
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_time:121454
/sys/bus/pci/devices/0000:00:03.0/power/runtime_enabled:enabled
/sys/bus/pci/devices/0000:00:03.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:03.0/power/runtime_suspended_time:228560
/sys/bus/pci/devices/0000:00:03.0/power/runtime_usage:0
/sys/bus/pci/devices/0000:00:03.0/power/async:enabled
grep: /sys/bus/pci/devices/0000:00:03.0/power/autosuspend_delay_ms: Input/output error
/sys/bus/pci/devices/0000:00:03.0/power/control:auto
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_kids:0
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_time:122463
/sys/bus/pci/devices/0000:00:03.0/power/runtime_enabled:enabled
/sys/bus/pci/devices/0000:00:03.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:03.0/power/runtime_suspended_time:228560
/sys/bus/pci/devices/0000:00:03.0/power/runtime_usage:0
/sys/bus/pci/devices/0000:00:03.0/power/async:enabled
grep: /sys/bus/pci/devices/0000:00:03.0/power/autosuspend_delay_ms: Input/output error
/sys/bus/pci/devices/0000:00:03.0/power/control:auto
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_kids:0
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_time:123472
/sys/bus/pci/devices/0000:00:03.0/power/runtime_enabled:enabled
/sys/bus/pci/devices/0000:00:03.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:03.0/power/runtime_suspended_time:228560
/sys/bus/pci/devices/0000:00:03.0/power/runtime_usage:0
# echo on > /sys/bus/pci/devices/0000:00:03.0/power/control
# echo auto > /sys/bus/pci/devices/0000:00:03.0/power/control
# for i in `seq 1 3`; do sleep 1 ; grep . /sys/bus/pci/devices/0000\:00\:03.0/power/*  ; done
/sys/bus/pci/devices/0000:00:03.0/power/async:enabled
grep: /sys/bus/pci/devices/0000:00:03.0/power/autosuspend_delay_ms: Input/output error
/sys/bus/pci/devices/0000:00:03.0/power/control:auto
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_kids:0
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_time:141459
/sys/bus/pci/devices/0000:00:03.0/power/runtime_enabled:enabled
/sys/bus/pci/devices/0000:00:03.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:03.0/power/runtime_suspended_time:231699
/sys/bus/pci/devices/0000:00:03.0/power/runtime_usage:0
/sys/bus/pci/devices/0000:00:03.0/power/async:enabled
grep: /sys/bus/pci/devices/0000:00:03.0/power/autosuspend_delay_ms: Input/output error
/sys/bus/pci/devices/0000:00:03.0/power/control:auto
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_kids:0
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_time:141459
/sys/bus/pci/devices/0000:00:03.0/power/runtime_enabled:enabled
/sys/bus/pci/devices/0000:00:03.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:03.0/power/runtime_suspended_time:232706
/sys/bus/pci/devices/0000:00:03.0/power/runtime_usage:0
/sys/bus/pci/devices/0000:00:03.0/power/async:enabled
grep: /sys/bus/pci/devices/0000:00:03.0/power/autosuspend_delay_ms: Input/output error
/sys/bus/pci/devices/0000:00:03.0/power/control:auto
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_kids:0
/sys/bus/pci/devices/0000:00:03.0/power/runtime_active_time:141459
/sys/bus/pci/devices/0000:00:03.0/power/runtime_enabled:enabled
/sys/bus/pci/devices/0000:00:03.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:03.0/power/runtime_suspended_time:233713
/sys/bus/pci/devices/0000:00:03.0/power/runtime_usage:0

-- 
Ville Syrjälä
Intel OTC
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: snd-hda-intel runtime PM fail after module reload

[Takashi Iwai]

On Thu, 25 Feb 2016 20:19:08 +0100,
Ville Syrjälä wrote:
> 
> Hi,
> 
> My investigation into some sporadic i915 runtime PM failures seem to
> point the finger at snd-hda-intel.
> 
> I just tried to play around unloding and reloading snd-hda-intel and
> sometimes I get snd-hda-intel loaded with runtime PM supposedly enabled,
> but actually the device won't runtime suspend. At which point frobbing
> with power/control is enough to kick it back into submission.

Which platform are you testing?  If it's SKL, BSW or later, multiple
codecs are on a single HD-audio bus.  In general, you have to adjust
the runtime PM of all these codecs in addition to the runtime PM of
the controller.  Some of them are immediately runtime PM enabled but
some of them aren't, left the default as is.

It might be that your desktop environment adjusts the runtime PM of
HD-audio stuff, often depending on the power state.  But when you
reload, this adjustment is also lost, so you'd have to adjust
manually.


Takashi
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: snd-hda-intel runtime PM fail after module reload

[Ville Syrjälä]

On Thu, Feb 25, 2016 at 09:28:59PM +0100, Takashi Iwai wrote:
> On Thu, 25 Feb 2016 20:19:08 +0100,
> Ville Syrjälä wrote:
> > 
> > Hi,
> > 
> > My investigation into some sporadic i915 runtime PM failures seem to
> > point the finger at snd-hda-intel.
> > 
> > I just tried to play around unloding and reloading snd-hda-intel and
> > sometimes I get snd-hda-intel loaded with runtime PM supposedly enabled,
> > but actually the device won't runtime suspend. At which point frobbing
> > with power/control is enough to kick it back into submission.
> 
> Which platform are you testing?  If it's SKL, BSW or later, multiple
> codecs are on a single HD-audio bus.  In general, you have to adjust
> the runtime PM of all these codecs in addition to the runtime PM of
> the controller.  Some of them are immediately runtime PM enabled but
> some of them aren't, left the default as is.

This was on a HSW.

I also have CONFIG_SND_HDA_POWER_SAVE_DEFAULT=1 which I presume should
enable codec power saving by deafault?

> It might be that your desktop environment adjusts the runtime PM of
> HD-audio stuff, often depending on the power state.  But when you
> reload, this adjustment is also lost, so you'd have to adjust
> manually.

There's no desktop environment. Well, unless you count systemd as such.
As you can see from the log I included at least the pci device power/control
file stayed at 'auto' the whole time until I flipped it to 'on' and then
back to 'auto' to fix the problem.

Also the problem didn't happen on every reload AFAICS, so there's
something rather non-deterministic happening.

-- 
Ville Syrjälä
Intel OTC
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: snd-hda-intel runtime PM fail after module reload

[Takashi Iwai]

On Thu, 25 Feb 2016 22:57:34 +0100,
Ville Syrjälä wrote:
> 
> On Thu, Feb 25, 2016 at 09:28:59PM +0100, Takashi Iwai wrote:
> > On Thu, 25 Feb 2016 20:19:08 +0100,
> > Ville Syrjälä wrote:
> > > 
> > > Hi,
> > > 
> > > My investigation into some sporadic i915 runtime PM failures seem to
> > > point the finger at snd-hda-intel.
> > > 
> > > I just tried to play around unloding and reloading snd-hda-intel and
> > > sometimes I get snd-hda-intel loaded with runtime PM supposedly enabled,
> > > but actually the device won't runtime suspend. At which point frobbing
> > > with power/control is enough to kick it back into submission.
> > 
> > Which platform are you testing?  If it's SKL, BSW or later, multiple
> > codecs are on a single HD-audio bus.  In general, you have to adjust
> > the runtime PM of all these codecs in addition to the runtime PM of
> > the controller.  Some of them are immediately runtime PM enabled but
> > some of them aren't, left the default as is.
> 
> This was on a HSW.

OK, then the HDMI/DP has its own controller.

> I also have CONFIG_SND_HDA_POWER_SAVE_DEFAULT=1 which I presume should
> enable codec power saving by deafault?

Yes, unless something overwrites it.  Often there are udev rules to
override something for that.

> > It might be that your desktop environment adjusts the runtime PM of
> > HD-audio stuff, often depending on the power state.  But when you
> > reload, this adjustment is also lost, so you'd have to adjust
> > manually.
> 
> There's no desktop environment. Well, unless you count systemd as such.
> As you can see from the log I included at least the pci device power/control
> file stayed at 'auto' the whole time until I flipped it to 'on' and then
> back to 'auto' to fix the problem.

It implies that the problem is the PM layer itself...

> Also the problem didn't happen on every reload AFAICS, so there's
> something rather non-deterministic happening.

In anyway, please check the runtime PM status in the codec devices,
i.e. /sys/bus/hdaudio/devices/*.   The controller runtime PM is
activated only when the codec is power-saved.

If the codec is in runtime-suspended but the controller still doesn't,
put some debug codes in azx_runtime_idle() in
sound/pci/hda/hda_intel.c, whether any EBUSY condition there hits.


Takashi
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/intel-gfx