Bug 93651

Created attachment 120929 [details]
pulseaudio -vvv before I blacklist snd-hda-intel

Created attachment 120930 [details]
pulseaudio -vvv after I blacklisted snd-hda-intel

You can diff it with "before" for better reading

Created attachment 120932 [details]
pulseaudio -vvv with builtin audio enabled

It seems that it's not really about hdmi/dp sound, but snd-hda-intel in general. I just enabled the builtin realtek hd audio, similar thing happen to it as well, while it has no hdmi PCM. My Xonar STX, which use snd-virtuoso instead, has both the analog and iec958 PCMs just like the realtek, but it doesn't suffer from this issue.

[tom@localhost ~]$ aplay -l
**** List of PLAYBACK Hardware Devices ****
card 0: STX [Xonar STX], device 0: Multichannel [Multichannel]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 0: STX [Xonar STX], device 1: Digital [Digital]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 1: PCH [HDA Intel PCH], device 0: ALC887-VD Analog [ALC887-VD Analog]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 1: PCH [HDA Intel PCH], device 1: ALC887-VD Digital [ALC887-VD Digital]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 2: NVidia [HDA NVidia], device 3: HDMI 0 [HDMI 0]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 2: NVidia [HDA NVidia], device 7: HDMI 1 [HDMI 1]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 2: NVidia [HDA NVidia], device 8: HDMI 2 [HDMI 2]
  Subdevices: 1/1
  Subdevice #0: subdevice #0

[tom@localhost ~]$ aplay -L
null
    Discard all samples (playback) or generate zero samples (capture)
pulse
    PulseAudio Sound Server
default:CARD=STX
    Xonar STX, Multichannel
    Default Audio Device
sysdefault:CARD=STX
    Xonar STX, Multichannel
    Default Audio Device
front:CARD=STX,DEV=0
    Xonar STX, Multichannel
    Front speakers
surround21:CARD=STX,DEV=0
    Xonar STX, Multichannel
    2.1 Surround output to Front and Subwoofer speakers
surround40:CARD=STX,DEV=0
    Xonar STX, Multichannel
    4.0 Surround output to Front and Rear speakers
surround41:CARD=STX,DEV=0
    Xonar STX, Multichannel
    4.1 Surround output to Front, Rear and Subwoofer speakers
surround50:CARD=STX,DEV=0
    Xonar STX, Multichannel
    5.0 Surround output to Front, Center and Rear speakers
surround51:CARD=STX,DEV=0
    Xonar STX, Multichannel
    5.1 Surround output to Front, Center, Rear and Subwoofer speakers
surround71:CARD=STX,DEV=0
    Xonar STX, Multichannel
    7.1 Surround output to Front, Center, Side, Rear and Woofer speakers
iec958:CARD=STX,DEV=0
    Xonar STX, Multichannel
    IEC958 (S/PDIF) Digital Audio Output
default:CARD=PCH
    HDA Intel PCH, ALC887-VD Analog
    Default Audio Device
sysdefault:CARD=PCH
    HDA Intel PCH, ALC887-VD Analog
    Default Audio Device
front:CARD=PCH,DEV=0
    HDA Intel PCH, ALC887-VD Analog
    Front speakers
surround21:CARD=PCH,DEV=0
    HDA Intel PCH, ALC887-VD Analog
    2.1 Surround output to Front and Subwoofer speakers
surround40:CARD=PCH,DEV=0
    HDA Intel PCH, ALC887-VD Analog
    4.0 Surround output to Front and Rear speakers
surround41:CARD=PCH,DEV=0
    HDA Intel PCH, ALC887-VD Analog
    4.1 Surround output to Front, Rear and Subwoofer speakers
surround50:CARD=PCH,DEV=0
    HDA Intel PCH, ALC887-VD Analog
    5.0 Surround output to Front, Center and Rear speakers
surround51:CARD=PCH,DEV=0
    HDA Intel PCH, ALC887-VD Analog
    5.1 Surround output to Front, Center, Rear and Subwoofer speakers
surround71:CARD=PCH,DEV=0
    HDA Intel PCH, ALC887-VD Analog
    7.1 Surround output to Front, Center, Side, Rear and Woofer speakers
iec958:CARD=PCH,DEV=0
    HDA Intel PCH, ALC887-VD Digital
    IEC958 (S/PDIF) Digital Audio Output
hdmi:CARD=NVidia,DEV=0
    HDA NVidia, HDMI 0
    HDMI Audio Output
hdmi:CARD=NVidia,DEV=1
    HDA NVidia, HDMI 1
    HDMI Audio Output
hdmi:CARD=NVidia,DEV=2
    HDA NVidia, HDMI 2
    HDMI Audio Output

If the sound card probing takes several seconds, it's an issue in the alsa kernel driver. It shouldn't take that long.

PulseAudio tries to access those nonexistent devices, because the best way to figure out whether a given alsa device can be used is to actually try to use it. Also, PulseAudio doesn't directly use the /dev/snd/* files; instead, PulseAudio uses logical device names like "front", "surround51", "iec958" and "hdmi". Alsa's configuration files define how those names map to the actual device files. The seemingly random selection of device numbers is due to the hdmi device numbering convention in alsa. PulseAudio probes devices named "hdmi:x,[0-7]", and the hdmi devices numbered 0-7 typically correspond to actual device numbers 3 and 7-13 (I don't know the history behind that convention).

The easy way is use conf file for hda intel if hdmi devices are not common in other sound card

http://cgit.freedesktop.org/pulseaudio/pulseaudio/tree/src/modules/alsa/mixer/profile-sets/default.conf

http://cgit.freedesktop.org/pulseaudio/pulseaudio/tree/src/modules/alsa/mixer/profile-sets

If you pass the --log-time command line option, each log message will have a timestamp. That will help to pinpoint, or at least narrow down, the operation(s) that are causing the delay.

(In reply to Tanu Kaskinen from comment #4)
> PulseAudio tries to access those nonexistent devices, because the best way
> to figure out whether a given alsa device can be used is to actually try to
> use it.

Well yes, but I don't suppose keep trying and failing on things doesn't exist is an efficient way, even if assume it's not bugged? Shouldn't there be faster way to filter out what's on the "list" does not exist first?

> PulseAudio uses logical device names like "front", "surround51", "iec958"
> and "hdmi". Alsa's configuration files define how those names map to the
> actual device files.

But now it seems like PulseAudio even try to open hdmi logical devices on a card even when the card does not have a single one itself, as per aplay -L

Will attach another log with timestamps with all my three cards enabled.

(In reply to Tom Yan from comment #7)
> Well yes, but I don't suppose keep trying and failing on things doesn't
> exist is an efficient way, even if assume it's not bugged? Shouldn't there
> be faster way to filter out what's on the "list" does not exist first?

Failing due to non-exitent device should be very fast. If there is a faster way, patches are welcome to improve the code, but the speed gains will be rather minimal in any case. I expect your delays to be caused by devices that actually exist.

(In reply to Tanu Kaskinen from comment #8)
> (In reply to Tom Yan from comment #7)
> > Well yes, but I don't suppose keep trying and failing on things doesn't
> > exist is an efficient way, even if assume it's not bugged? Shouldn't there
> > be faster way to filter out what's on the "list" does not exist first?
> 
> Failing due to non-exitent device should be very fast. If there is a faster
> way, patches are welcome to improve the code, but the speed gains will be
> rather minimal in any case. I expect your delays to be caused by devices
> that actually exist.

Seems you're right. And it seems the issue only affect the hdmi/dp sound devices on my nvidia card particularly, no matter which or whether any drm driver is loaded or whether a monitor is connected to it. I just enabled my iGPU and I didn't experience the same huge delay with it, if I set "id=NVidia enable=0" to snd-hda-intel.

I am gonna post an ouput of `pulseaudio -vvv --log-time` with my only DP monitor connected to my motherboard's DP port instead, plus the nvidia blob driver uninstalled, and these:

[tom@localhost ~]$ grep . /etc/modprobe.d/*
/etc/modprobe.d/nouveau.conf:blacklist nouveau
/etc/modprobe.d/snd-hda-intel.conf:options snd-hda-intel id=HDMI enable=0
/etc/modprobe.d/snd-virtuoso.conf:blacklist snd-virtuoso

So the only card left is:

[tom@localhost ~]$ aplay -l
**** List of PLAYBACK Hardware Devices ****
card 0: NVidia [HDA NVidia], device 3: HDMI 0 [HDMI 0]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 0: NVidia [HDA NVidia], device 7: HDMI 1 [HDMI 1]
  Subdevices: 1/1
  Subdevice #0: subdevice #0
card 0: NVidia [HDA NVidia], device 8: HDMI 2 [HDMI 2]
  Subdevices: 1/1
  Subdevice #0: subdevice #0

Created attachment 120937 [details]
pulseaudio -vvv --log-time

In case it matters:

01:00.0 VGA compatible controller [0300]: NVIDIA Corporation GM107 [GeForce GTX 750 Ti] [10de:1380] (rev a2) (prog-if 00 [VGA controller])
	Subsystem: eVga.com. Corp. Device [3842:3751]

01:00.1 Audio device [0403]: NVIDIA Corporation Device [10de:0fbc] (rev a1)
	Subsystem: eVga.com. Corp. Device [3842:3751]

FWIW I've got this card for quite a while and I didn't experience this issue in the past. Then after some time I started to have snd-hda-intel blacklisted since I no longer needed the HDMI sound. And recently I needed snd-hda-intel back for some testing so I noticed this issue, but I don't know when did it started.

http://git.alsa-project.org/?p=alsa-lib.git;a=tree;f=src/conf/cards;hb=HEAD

Most sound card does not support multi streamingand they don't have multiple HDMI devices

(In reply to Raymond from comment #13)
> http://git.alsa-project.org/?p=alsa-lib.git;a=tree;f=src/conf/cards;hb=HEAD
> 
> Most sound card does not support multi streamingand they don't have multiple
> HDMI devices

That's not true. Most graphic cards these days have more than 1 hdmi / dp port. For example, both my motherboard and my nvidia card has an hdmi port AND a dp++ port (dp/tmds), that's why there are three sound devices listed in aplay.

I do think multi streaming is possible on them, because I recall I have tried that when I have more than 1 monitor.

And what does it have to do with the issue anyway?

I saw in the log that the pauses are exactly one second long, so may I wildly guess that when this happens, you will also see something like
"Codec timeout, polling the codec once" messages in dmesg when this happens?

cat /proc/asound/card0/pcm0p/sub0/status


You can add pa_alsa_dump(PA_LOG_INFO, u->pcm_handle);

 when underrun occur

http://cgit.freedesktop.org/pulseaudio/pulseaudio/tree/src/modules/alsa/alsa-sink.c

if (!u->first && !u->after_rewind) 
     if (pa_log_ratelimit(PA_LOG_INFO)) 
          pa_log_info("Underrun!"); }

(In reply to David Henningsson from comment #15)
> I saw in the log that the pauses are exactly one second long, so may I
> wildly guess that when this happens, you will also see something like
> "Codec timeout, polling the codec once" messages in dmesg when this happens?

Nope, just checked with journalctl -k.

-- GitLab Migration Automatic Message --

This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity.

You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/pulseaudio/pulseaudio/issues/357.