Sound issue, audio source rapidly appearing and disappearing

egnawake · 2020-04-21 13:05:44

Hello! I've been trying to figure out a solution to this problem for the past couple of days but haven't gotten it yet.

When running a specific Steam game through Proton (Granblue Fantasy Versus), the sound begins to aggressively skip in very short intervals, at apparently random points while playing. Some actions that play a sound effect or a voice clip appear to stabilize the sound for a few seconds. If left alone playing only music, the issue appears again.

On the ProtonDB page for said game, there are reports of it running flawlessly on Arch Linux.

If I look at pavucontrol when the sound bugs out, I notice that the game's entry on the Playback list is rapidly flashing, as if the game's audio is being shut down and restarted continuously.

I have tried to follow the PulseAudio troubleshooting articles for glitches, skips or crackling, setting the default fragment number and buffer size and choppy or distorted sound. None of them had any effect.

I have tried DisplayPort audio through my monitor. The issue persists.

I have ran PulseAudio with the log level set to debug. Here is an excerpt from a period when the issue was present:

Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c: Created input 9 "ALSA Playback" on alsa_output.pci-0000_00_1b.0.analog-stereo with sample spec float32le 2ch 48000Hz and channel map front-l>
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     media.name = "ALSA Playback"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.name = "ALSA plug-in [wine64-preloader]"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     native-protocol.peer = "UNIX socket client"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     native-protocol.version = "33"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.process.id = "1958"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.process.user = "bincle"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.process.host = "spark"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.process.binary = "wine64-preloader"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.language = "en_US.UTF-8"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     window.x11.display = ":0"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.process.machine_id = "9246af2336cb429a8aec09dc18a0aa0a"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.process.session_id = "1"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     module-stream-restore.id = "sink-input-by-application-name:ALSA plug-in [wine64-preloader]"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] protocol-native.c: Requested tlength=64.00 ms, minreq=21.33 ms
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] protocol-native.c: Early requests mode enabled, configuring sink latency to minreq.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] protocol-native.c: Could not configure a sufficiently low latency. Early requests might not be satisfied.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] protocol-native.c: Requested latency=21.33 ms, Received latency=15.00 ms
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] memblockq.c: memblockq requested: maxlength=4194304, tlength=24576, base=8, prebuf=8192, minreq=8192 maxrewind=0
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=4194304, tlength=24576, base=8, prebuf=8192, minreq=8192 maxrewind=0
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] protocol-native.c: Final latency 79.00 ms = 21.33 ms + 2*21.33 ms + 15.00 ms
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Requested volume: front-left: 52887 /  81% / -5.59 dB,   front-right: 52887 /  81% / -5.59 dB
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Got hardware volume: front-left: 53066 /  81% / -5.50 dB,   front-right: 53066 /  81% / -5.50 dB
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Calculated software volume: front-left: 65315 / 100% / -0.09 dB,   front-right: 65315 / 100% / -0.09 dB (accurate-enough=yes)
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: Volume not changing
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Stream added for object /org/pulseaudio/core1/playback_stream9
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: state: IDLE -> RUNNING
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] protocol-native.c: Requesting rewind due to end of underrun.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Requested to rewind 2880 bytes.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Limited to 2592 bytes.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: before: 648
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: after: 648
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Rewound 2592 bytes.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: Processing rewind...
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: latency = 2119
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink-input.c: Have to rewind 2592 bytes on render memblockq.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] source.c: Processing rewind...
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] protocol-native.c: Implicit underrun of 'ALSA Playback'
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 640 bytes ago (2208 bytes ahead in playback buffer)
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 672 bytes ago (2208 bytes ahead in playback buffer)
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 704 bytes ago (2176 bytes ahead in playback buffer)
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 704 bytes ago (2176 bytes ahead in playback buffer)
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 896 bytes ago (1984 bytes ahead in playback buffer)
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 1856 bytes ago (1024 bytes ahead in playback buffer)
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 2688 bytes ago (192 bytes ahead in playback buffer)
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 2688 bytes ago (192 bytes ahead in playback buffer)
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 2816 bytes ago (64 bytes ahead in playback buffer)
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Stream removed from object /org/pulseaudio/core1/playback_stream9
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Requested volume: front-left: 52887 /  81% / -5.59 dB,   front-right: 52887 /  81% / -5.59 dB
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Got hardware volume: front-left: 53066 /  81% / -5.50 dB,   front-right: 53066 /  81% / -5.50 dB
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Calculated software volume: front-left: 65315 / 100% / -0.09 dB,   front-right: 65315 / 100% / -0.09 dB (accurate-enough=yes)
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: Volume not changing
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Requested to rewind 2880 bytes.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Limited to 2592 bytes.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: before: 648
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: after: 648
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Rewound 2592 bytes.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: Processing rewind...
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] sink.c: latency = 2241
Apr 20 22:48:42 spark pulseaudio[1725]: D: [alsa-sink-ALC888 Analog] source.c: Processing rewind...
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: state: RUNNING -> IDLE
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] core.c: Hmm, no streams around, trying to vacuum.
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c: Freeing input 9 "ALSA Playback"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] module-stream-restore.c: Restoring device for stream sink-input-by-application-name:ALSA plug-in [wine64-preloader].
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] module-intended-roles.c: Not setting device for stream ALSA Playback, because already set.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] sink-input.c: Negotiated format: pcm, format.sample_format = "\"float32le\""  format.rate = "48000"  format.channels = "2"  format.channel_map = "\"front->
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c: Trying to change sample spec
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] sink.c: Default and alternate sample rates are the same, so there is no point in switching.
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:ALSA plug-in [wine64-preloader].
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes busy, resuming.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] core.c: Hmm, no streams around, trying to vacuum.
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c: Freeing input 9 "ALSA Playback"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] module-stream-restore.c: Restoring device for stream sink-input-by-application-name:ALSA plug-in [wine64-preloader].
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] module-intended-roles.c: Not setting device for stream ALSA Playback, because already set.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] sink-input.c: Negotiated format: pcm, format.sample_format = "\"float32le\""  format.rate = "48000"  format.channels = "2"  format.channel_map = "\"front->
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c: Trying to change sample spec
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] sink.c: Default and alternate sample rates are the same, so there is no point in switching.
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:ALSA plug-in [wine64-preloader].
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes busy, resuming.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] resampler.c: Forcing resampler 'copy', because of fixed, identical sample rates.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] resampler.c: Resampler:
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] resampler.c:   rate 48000 -> 48000 (method copy)
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] resampler.c:   format float32le -> s16le (intermediate s16le)
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] resampler.c:   channels 2 -> 2 (resampling 2)
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] memblockq.c: memblockq requested: maxlength=33554432, tlength=0, base=4, prebuf=0, minreq=1 maxrewind=0
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=33554432, tlength=33554432, base=4, prebuf=0, minreq=4 maxrewind=0
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c: Created input 10 "ALSA Playback" on alsa_output.pci-0000_00_1b.0.analog-stereo with sample spec float32le 2ch 48000Hz and channel map front->
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     media.name = "ALSA Playback"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.name = "ALSA plug-in [wine64-preloader]"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     native-protocol.peer = "UNIX socket client"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     native-protocol.version = "33"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.process.id = "1958"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.process.user = "bincle"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.process.host = "spark"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.process.binary = "wine64-preloader"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.language = "en_US.UTF-8"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     window.x11.display = ":0"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.process.machine_id = "9246af2336cb429a8aec09dc18a0aa0a"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     application.process.session_id = "1"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] sink-input.c:     module-stream-restore.id = "sink-input-by-application-name:ALSA plug-in [wine64-preloader]"
Apr 20 22:48:42 spark pulseaudio[1725]: I: [pulseaudio] protocol-native.c: Requested tlength=64.00 ms, minreq=21.33 ms
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] protocol-native.c: Early requests mode enabled, configuring sink latency to minreq.
Apr 20 22:48:42 spark pulseaudio[1725]: D: [pulseaudio] protocol-native.c: Could not configure a sufficiently low latency. Early requests might not be satisfied.

From what I can see, inputs are being created, freed and created again, repeatedly - this lines up with the flickering I see in pavucontrol.

I have found a bug report and a thread describing similar issues, but neither of them has been of any help.

Thanks in advance for any input and suggestions!

V1del · 2020-04-21 13:12:39

Start with reverting the changes you did in an attempt to resolve this. Mucking with global state to fix a single problematic application is usually detrimental to the general system as a whole.

Wine/proton have supported pulseaudio for years now, if it's still attempting to use an ALSA plugin input then that usually means you don't have an underlying dependency installed. Which in this case should be lib32-libpulse.

egnawake · 2020-04-21 18:46:49

V1del wrote:

Start with reverting the changes you did in an attempt to resolve this. Mucking with global state to fix a single problematic application is usually detrimental to the general system as a whole.
Wine/proton have supported pulseaudio for years now, if it's still attempting to use an ALSA plugin input then that usually means you don't have an underlying dependency installed. Which in this case should be lib32-libpulse.

I tried launching the game once with the configuration reverted to default and again after installing lib32-libpulse. Both attempts were unsuccessful.

There has been a change though: the name of the input has changed from "ALSA plug-in [wine64-preloader]" to the name of the game's executable and it doesn't flicker anymore, even while the sound is glitching.

V1del · 2020-04-21 23:59:15

This is already an important change, as it means wine will now use pulseaudio, so pulse has better control over what happens with the stream. While it does that what do you get for

pacmd list-sink-inputs

maybe run/post a few times to see whether it actually allocates new sinks constantly or just requests too low of a latency.

egnawake · 2020-04-22 13:05:07

$ pacmd list-sink-inputs
1 sink input(s) available.
    index: 539
	driver: <protocol-native.c>
	flags:
	state: RUNNING
	sink: 1 <alsa_output.pci-0000_00_1b.0.analog-stereo>
	volume: front-left: 65536 / 100% / 0.00 dB,   front-right: 65536 / 100% / 0.00 dB
	        balance 0.00
	muted: no
	current latency: 1.19 ms
	requested latency: 21.33 ms
	sample spec: float32le 2ch 48000Hz
	channel map: front-left,front-right
	             Stereo
	resample method: copy
	module: 9
	client: 9 <ALSA plug-in [wine64-preloader]>
	properties:
		media.name = "ALSA Playback"
		application.name = "ALSA plug-in [wine64-preloader]"
		native-protocol.peer = "UNIX socket client"
		native-protocol.version = "33"
		application.process.id = "1725"
		application.process.user = "bincle"
		application.process.host = "spark"
		application.process.binary = "wine64-preloader"
		application.language = "en_US.UTF-8"
		window.x11.display = ":0"
		application.process.machine_id = "9246af2336cb429a8aec09dc18a0aa0a"
		application.process.session_id = "1"
		module-stream-restore.id = "sink-input-by-application-name:ALSA plug-in [wine64-preloader]"

According to the index there, it seems it's still allocating new sinks.
Is Proton using ALSA again? I don't understand, I didn't change anything since my previous post.

V1del · 2020-04-22 13:49:32

This is quite weird indeed, because I do know seeing that rapidfire sink issue with ALSA based wine audio and I have never seen it with an actual pulse sink. Something you might want to try regardless, is starting it with a fixed pulse latency request (not sure how this works with proton, if it's like normal steam games you should be able to do this) by adding

PULSE_LATENCY_MSEC=30 %command%

to the custom command line in the steam launchers per game preferences.

Is this the only proton game you are seeing this issue with? Have you tried running it with your system wine/different proton versions? Potentially important, is this a flatpak or a repository steam?

egnawake · 2020-04-22 19:42:59

I just tried running with PULSE_LATENCY_MSEC set to 30 as you suggested.

$ pacmd list-sink-inputs
1 sink input(s) available.
    index: 7
	driver: <protocol-native.c>
	flags:
	state: RUNNING
	sink: 1 <alsa_output.pci-0000_00_1b.0.analog-stereo>
	volume: front-left: 65536 / 100% / 0.00 dB,   front-right: 65536 / 100% / 0.00 dB
	        balance 0.00
	muted: no
	current latency: 13.67 ms
	requested latency: 7.50 ms
	sample spec: float32le 2ch 48000Hz
	channel map: front-left,front-right
	             Stereo
	resample method: copy
	module: 9
	client: 28 <GBVS-Win64-Shipping.exe>
	properties:
		media.name = "Simple DirectMedia Layer"
		application.name = "GBVS-Win64-Shipping.exe"
		native-protocol.peer = "UNIX socket client"
		native-protocol.version = "33"
		application.process.id = "1893"
		application.process.user = "bincle"
		application.process.host = "spark"
		application.process.binary = "wine64-preloader"
		application.language = "en_US.UTF-8"
		window.x11.display = ":0"
		application.process.machine_id = "9246af2336cb429a8aec09dc18a0aa0a"
		application.process.session_id = "1"
		module-stream-restore.id = "sink-input-by-application-name:GBVS-Win64-Shipping.exe"

The issue remains. No quick sink creation and deletion this time. The name is also back to normal.

The new pattern in the PulseAudio logs when the bug occurs:

Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] protocol-native.c: Implicit underrun of 'Simple DirectMedia Layer'
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 64 bytes ago (1376 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 608 bytes ago (832 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 608 bytes ago (832 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 1344 bytes ago (96 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] protocol-native.c: Requesting rewind due to end of underrun.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Requested to rewind 1440 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Limited to 1152 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: before: 288
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: after: 288
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Rewound 1152 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: Processing rewind...
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: latency = 1322
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink-input.c: Have to rewind 1152 bytes on render memblockq.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] source.c: Processing rewind...
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] protocol-native.c: Implicit underrun of 'Simple DirectMedia Layer'
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 32 bytes ago (1408 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 640 bytes ago (800 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 640 bytes ago (768 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 1376 bytes ago (64 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] protocol-native.c: Requesting rewind due to end of underrun.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Requested to rewind 1440 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Limited to 1152 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: before: 288
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: after: 288
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Rewound 1152 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: Processing rewind...
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: latency = 1200
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink-input.c: Have to rewind 1152 bytes on render memblockq.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] source.c: Processing rewind...
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] protocol-native.c: Implicit underrun of 'Simple DirectMedia Layer'
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 64 bytes ago (1344 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 736 bytes ago (704 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 736 bytes ago (672 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] protocol-native.c: Requesting rewind due to end of underrun.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Requested to rewind 1440 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Limited to 1088 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: before: 272
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: after: 272
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Rewound 1088 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: Processing rewind...
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: latency = 1271
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink-input.c: Have to rewind 1088 bytes on render memblockq.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] source.c: Processing rewind...
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] protocol-native.c: Implicit underrun of 'Simple DirectMedia Layer'
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 608 bytes ago (800 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 608 bytes ago (800 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 1344 bytes ago (96 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] protocol-native.c: Requesting rewind due to end of underrun.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Requested to rewind 1440 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Limited to 1152 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: before: 288
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: after: 288
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Rewound 1152 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: Processing rewind...
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: latency = 1281
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink-input.c: Have to rewind 1152 bytes on render memblockq.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] source.c: Processing rewind...
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] protocol-native.c: Implicit underrun of 'Simple DirectMedia Layer'
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 32 bytes ago (1408 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 640 bytes ago (800 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 640 bytes ago (800 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: alsa_output.pci-0000_00_1b.0.analog-stereo: Found underrun 1376 bytes ago (64 bytes ahead in playback buffer)
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] protocol-native.c: Requesting rewind due to end of underrun.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Requested to rewind 1440 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Limited to 1152 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: before: 288
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: after: 288
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] alsa-sink.c: Rewound 1152 bytes.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: Processing rewind...
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink.c: latency = 1283
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] sink-input.c: Have to rewind 1152 bytes on render memblockq.
Apr 22 18:52:32 spark pulseaudio[791]: D: [alsa-sink-ALC888 Analog] source.c: Processing rewind...

I have tried running another game with Proton. No issues here.

$ pacmd list-sink-inputs
1 sink input(s) available.
    index: 10
	driver: <protocol-native.c>
	flags: VARIABLE_RATE START_CORKED
	state: RUNNING
	sink: 1 <alsa_output.pci-0000_00_1b.0.analog-stereo>
	volume: front-left: 65536 / 100% / 0.00 dB,   front-right: 65536 / 100% / 0.00 dB
	        balance 0.00
	muted: no
	current latency: 12.49 ms
	requested latency: 5.00 ms
	sample spec: float32le 2ch 44100Hz
	channel map: front-left,front-right
	             Stereo
	resample method: speex-float-1
	module: 9
	client: 34 <Battlerite.exe>
	properties:
		media.name = "audio stream #1"
		application.name = "Battlerite.exe"
		native-protocol.peer = "UNIX socket client"
		native-protocol.version = "33"
		application.process.id = "2291"
		application.process.user = "bincle"
		application.process.host = "spark"
		application.process.binary = "wine-preloader"
		application.language = "en_US.UTF-8"
		window.x11.display = ":0"
		application.process.machine_id = "9246af2336cb429a8aec09dc18a0aa0a"
		application.process.session_id = "1"
		module-stream-restore.id = "sink-input-by-application-name:Battlerite.exe"

I tried two other Proton versions with no luck. I'm running Steam from the Arch repository.

Arch Linux

#1 2020-04-21 13:05:44

Sound issue, audio source rapidly appearing and disappearing

#2 2020-04-21 13:12:39

Re: Sound issue, audio source rapidly appearing and disappearing

#3 2020-04-21 18:46:49

Re: Sound issue, audio source rapidly appearing and disappearing

#4 2020-04-21 23:59:15

Re: Sound issue, audio source rapidly appearing and disappearing

#5 2020-04-22 13:05:07

Re: Sound issue, audio source rapidly appearing and disappearing

#6 2020-04-22 13:49:32

Re: Sound issue, audio source rapidly appearing and disappearing

#7 2020-04-22 19:42:59

Re: Sound issue, audio source rapidly appearing and disappearing

Board footer