[alsa-devel] snd_pcm_open() taking very long, starting from kernel 4.17

[Arnaud Rebillout]

  Dear ALSA maintainers,

I noticed big change in how long `snd_pcm_open()` takes, between kernel 4.16
and 4.17. With a kernel 4.16, this function consistently returns in less
than 1
millisecond, with occasional, but rare, peaks that go up to 25ms. While with
kernel 4.17 and above, I measure an average of 40ms, with frequent peaks
to 1s.
The maximum I measured was 3 seconds!

Is this change known, intended? Or is it a regression?

Please read below for more details, thanks.

----

  The long story

Starting with kernel 4.17, I started to experience frequent lags on
mylaptop,
which seemed to happen in the terminal, while hitting the TAB for
completion.
I clearly didn't experience this behavior with 4.16. Later on, 4.18 was
released, I tried it: same issue. So I kept using the kernel 4.16.

So it took me a while to investigate this issue. What happens is that
the GNOME
terminal, or Emacs, might generate event sounds when you hit tab, or
something.
This happen fairly often (you know, this kind of bell sound), it's very
annoying, so usually the first thing I'd do is to disable these sounds.

Turns out that, even when disabled, this sounds are still generated, because
GNOME doesn't really disable it, it just mutes it [1].

After understanding that, I tracked down how these event sounds are
generated.
As incredible as it seems, it all happens synchronously, from the
calling app,
through GTK, then mutter, then libcanberra, and ultimately the call ends
up in
pulseaudio.  Pulseaudio is the one calling `snd_pcm_open()`, so that's
where I
did my measurements.

Like I said, it's all synchronous, so when the call takes 3 seconds to
return,
I wait 3 seconds in front of my screen :) Pulseaudio has a plugin
(enabled by
default in my distrib) `suspend-on-idle`, which means that it closes the
soundcard connection on inactivity, and re-opens it again with
`snd_pcm_open()`
when a sound is played.

So, to sum that up: during a normal workday on my laptop, PA will constantly
close the soundcard connection (due to the suspend-on-idle plugin), and
open it
again (due to event sounds generated by GNOME, despite being disabled).
And all
of that synchronously, in the GTK mainloop. While this could go
un-noticed for
a while, starting with kernel 4.17, the call `snd_pcm_open()` might take
up to
3 seconds to return, and it made my system almost unusable.

I found out that it's possible to disable these event sounds finally,
it's just
not possible through the GNOME settings, it needs to be done from the
command-
line. So I live happy, no problem for me. I'm merely reporting the
problem, as
you might be interested.

[1] https://gitlab.gnome.org/GNOME/gnome-control-center/issues/259

----

  Some hardware details:

$ sudo dmidecode | grep 'System Information' -A 2
System Information
    Manufacturer: Dell Inc.
    Product Name: XPS 13 9360

$ cat /proc/asound/cards
 0 [PCH            ]: HDA-Intel - HDA Intel PCH
                      HDA Intel PCH at 0xdc428000 irq 144

$ aplay --list-devices
**** List of PLAYBACK Hardware Devices ****
card 0: PCH [HDA Intel PCH], device 0: ALC3246 Analog [ALC3246 Analog]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 0: PCH [HDA Intel PCH], device 3: HDMI 0 [HDMI 0]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 0: PCH [HDA Intel PCH], device 7: HDMI 1 [HDMI 1]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 0: PCH [HDA Intel PCH], device 8: HDMI 2 [HDMI 2]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 0: PCH [HDA Intel PCH], device 9: HDMI 3 [HDMI 3]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 0: PCH [HDA Intel PCH], device 10: HDMI 4 [HDMI 4]
  Subdevices: 1/1
  Subdevice #0: subdevice #0

$ sudo lspci -v | grep -i audio -A 7
00:1f.3 Audio device: Intel Corporation Sunrise Point-LP HD Audio (rev
21) (prog-if 80)
    Subsystem: Dell Sunrise Point-LP HD Audio
    Flags: bus master, fast devsel, latency 32, IRQ 128
    Memory at dc428000 (64-bit, non-prefetchable) [size=16K]
    Memory at dc400000 (64-bit, non-prefetchable) [size=64K]
    Capabilities: [50] Power Management version 3
    Capabilities: [60] MSI: Enable+ Count=1/1 Maskable- 64bit+
    Kernel driver in use: snd_hda_intel
    Kernel modules: snd_hda_intel, snd_soc_skl

----

Feel free to ask more details, I'd be glad to help.

Best regards,

  Arnaud