search

sammoth / foo_out_pulse

PulseAudio output for foobar2000
GNU Lesser General Public License v3.0
19 stars 2 forks source link

foobar2000 stops the playback randomly #3

Open perHub opened 3 years ago

perHub commented 3 years ago

Hello, I would like to report a bug I am experiencing since a recent PulseAudio update. As the title says, foobar2000 stops the playback randomly (it doesn't matter what the song file type is or what time it is currently playing at) I've checked the foobar console and found:

Foobar console: Error: Pulseaudio: connection failed: Connection terminated

Since that message doens't provide enough information (except for the fact pulseaudio is involved) I decided to check the PA console log when the bug occurs:

W: [pulseaudio] pstream.c: Received memblock frame with invalid seek mode.

Of course I'm not sure if it is right to report this as a foo_out_pulse bug since it started happening after a PA update (I'm at 14.2 at this moment) but I want to at least know if someone else is experiencing this issue.

Thanks for this awesome plugin!

tullo-x86 commented 3 years ago

Just started noticing this recently myself.

System config:

tullo-x86 commented 3 years ago

Update: I noticed this happening FAR more often when playing 96KHz/24bit 6-channel audio, which leads me to suspect that a TCP throughput limitation could be causing the issue. After adding the SSRC resampler set to 48kHz (the sample rate used by my USB DAC, and the default sample rate for my PA configuration), I was able to play 280 seconds of audio (up from 14 seconds) before playback stopped.

Curiously, my pulseaudio log shows the following:

WITHOUT resampler

Jun 23 08:58:30 pulseaudio[29830]: Created 8 "Native client (TCP/IP client from 127.0.0.1:57350)"
Jun 23 08:58:30 pulseaudio[29830]: Client authenticated by IP ACL.
Jun 23 08:58:30 pulseaudio[29830]: Trying to change sample spec
Jun 23 08:58:30 pulseaudio[29830]: Restoring volume for sink input sink-input-by-application-id:foobar2000.
Jun 23 08:58:30 pulseaudio[29830]: Restoring mute state for sink input sink-input-by-application-id:foobar2000.
Jun 23 08:58:30 pulseaudio[29830]: Trying resume...
Jun 23 08:58:30 pulseaudio[29830]: Cannot disable ALSA period wakeups
Jun 23 08:58:30 pulseaudio[29830]: ALSA period wakeups were not disabled
Jun 23 08:58:30 pulseaudio[29830]: Time scheduling watermark is 5.00ms
Jun 23 08:58:30 pulseaudio[29830]: Resumed successfully...
Jun 23 08:58:30 pulseaudio[29830]: Starting playback.
Jun 23 08:58:30 pulseaudio[29830]: Using generic matrix remapping
Jun 23 08:58:30 pulseaudio[29830]: Choosing speex quality setting 9.
Jun 23 08:58:30 pulseaudio[29830]: Created input 3 "Audio" on alsa_output.usb-Sennheiser_GSX_1000_Main_Audio_5698800279039916-00.analog-output-surround71 with sample spec float32le 6ch 96000Hz and channel map front-left,front-right,front-center,lfe,rear-left,rear-right
Jun 23 08:58:30 pulseaudio[29830]:     media.name = "Audio"
Jun 23 08:58:30 pulseaudio[29830]:     application.name = "foobar2000"
Jun 23 08:58:30 pulseaudio[29830]:     native-protocol.peer = "TCP/IP client from 127.0.0.1:57350"
Jun 23 08:58:30 pulseaudio[29830]:     native-protocol.version = "33"
Jun 23 08:58:30 pulseaudio[29830]:     application.id = "foobar2000"
Jun 23 08:58:30 pulseaudio[29830]:     application.icon_name = "foobar2000"
Jun 23 08:58:30 pulseaudio[29830]:     application.process.id = "1340"
Jun 23 08:58:30 pulseaudio[29830]:     application.process.user = "tully"
Jun 23 08:58:30 pulseaudio[29830]:     application.process.host = "REDACTED"
Jun 23 08:58:30 pulseaudio[29830]:     application.process.binary = "foobar2000.exe"
Jun 23 08:58:30 pulseaudio[29830]:     application.language = "C"
Jun 23 08:58:30 pulseaudio[29830]:     window.x11.display = ":0"
Jun 23 08:58:30 pulseaudio[29830]:     application.process.machine_id = "REDACTED"
Jun 23 08:58:30 pulseaudio[29830]:     application.process.session_id = "2"
Jun 23 08:58:30 pulseaudio[29830]:     module-stream-restore.id = "sink-input-by-application-id:foobar2000"
Jun 23 08:58:30 pulseaudio[29830]: Requested tlength=1550.00 ms, minreq=775.00 ms
Jun 23 08:58:30 pulseaudio[29830]: Final latency 1550.50 ms = 0.00 ms + 2*775.00 ms + 0.50 ms
Jun 23 08:58:30 pulseaudio[29830]: Underrun!
Jun 23 08:58:30 pulseaudio[29830]: Increasing minimal latency to 1.00 ms
Jun 23 08:58:30 pulseaudio[29830]: Underrun!
Jun 23 08:58:30 pulseaudio[29830]: Increasing minimal latency to 2.00 ms
Jun 23 08:58:30 pulseaudio[29830]: Underrun!
Jun 23 08:58:30 pulseaudio[29830]: Increasing minimal latency to 4.00 ms
Jun 23 08:58:30 pulseaudio[29830]: Underrun!
Jun 23 08:58:30 pulseaudio[29830]: Increasing minimal latency to 8.00 ms
Jun 23 08:58:48 pulseaudio[29830]: Received invalid frame size: 3380824636
*** NOTE: AUDIO HALTED HERE ***
Jun 23 08:58:48 pulseaudio[29830]: Freeing input 3 "Audio"
Jun 23 08:58:48 pulseaudio[29830]: Freed 8 "foobar2000"
Jun 23 08:58:48 pulseaudio[29830]: Connection died.
Jun 23 08:58:53 pulseaudio[29830]: Sink alsa_output.usb-Sennheiser_GSX_1000_Main_Audio_5698800279039916-00.analog-output-surround71 idle for too long, suspending ...
Jun 23 08:58:53 pulseaudio[29830]: Device suspended...

WITH SSRC resampler in FB2k set to 48kHz

Jun 23 09:00:01 pulseaudio[29830]: Created 9 "Native client (TCP/IP client from 127.0.0.1:57354)"
Jun 23 09:00:01 pulseaudio[29830]: Client authenticated by IP ACL.
Jun 23 09:00:01 pulseaudio[29830]: Trying to change sample spec
Jun 23 09:00:01 pulseaudio[29830]: Restoring volume for sink input sink-input-by-application-id:foobar2000.
Jun 23 09:00:01 pulseaudio[29830]: Restoring mute state for sink input sink-input-by-application-id:foobar2000.
Jun 23 09:00:01 pulseaudio[29830]: Trying resume...
Jun 23 09:00:01 pulseaudio[29830]: Cannot disable ALSA period wakeups
Jun 23 09:00:01 pulseaudio[29830]: ALSA period wakeups were not disabled
Jun 23 09:00:01 pulseaudio[29830]: Time scheduling watermark is 5.00ms
Jun 23 09:00:01 pulseaudio[29830]: Resumed successfully...
Jun 23 09:00:01 pulseaudio[29830]: Starting playback.
Jun 23 09:00:01 pulseaudio[29830]: Forcing resampler 'copy', because of fixed, identical sample rates.
Jun 23 09:00:01 pulseaudio[29830]: Using generic matrix remapping
Jun 23 09:00:01 pulseaudio[29830]: Created input 4 "Audio" on alsa_output.usb-Sennheiser_GSX_1000_Main_Audio_5698800279039916-00.analog-output-surround71 with sample spec float32le 6ch 48000Hz and channel map front-left,front-right,front-center,lfe,rear-left,rear-right
Jun 23 09:00:01 pulseaudio[29830]:     media.name = "Audio"
Jun 23 09:00:01 pulseaudio[29830]:     application.name = "foobar2000"
Jun 23 09:00:01 pulseaudio[29830]:     native-protocol.peer = "TCP/IP client from 127.0.0.1:57354"
Jun 23 09:00:01 pulseaudio[29830]:     native-protocol.version = "33"
Jun 23 09:00:01 pulseaudio[29830]:     application.id = "foobar2000"
Jun 23 09:00:01 pulseaudio[29830]:     application.icon_name = "foobar2000"
Jun 23 09:00:01 pulseaudio[29830]:     application.process.id = "1340"
Jun 23 09:00:01 pulseaudio[29830]:     application.process.user = "tully"
Jun 23 09:00:01 pulseaudio[29830]:     application.process.host = "REDACTED"
Jun 23 09:00:01 pulseaudio[29830]:     application.process.binary = "foobar2000.exe"
Jun 23 09:00:01 pulseaudio[29830]:     application.language = "C"
Jun 23 09:00:01 pulseaudio[29830]:     window.x11.display = ":0"
Jun 23 09:00:01 pulseaudio[29830]:     application.process.machine_id = "REDACTED"
Jun 23 09:00:01 pulseaudio[29830]:     application.process.session_id = "2"
Jun 23 09:00:01 pulseaudio[29830]:     module-stream-restore.id = "sink-input-by-application-id:foobar2000"
Jun 23 09:00:01 pulseaudio[29830]: Requested tlength=1550.00 ms, minreq=775.00 ms
Jun 23 09:00:01 pulseaudio[29830]: Final latency 1550.50 ms = 0.00 ms + 2*775.00 ms + 0.50 ms
Jun 23 09:00:01 pulseaudio[29830]: Underrun!
Jun 23 09:00:01 pulseaudio[29830]: Increasing minimal latency to 1.00 ms
Jun 23 09:00:01 pulseaudio[29830]: Underrun!
Jun 23 09:00:01 pulseaudio[29830]: Increasing minimal latency to 2.00 ms
Jun 23 09:00:01 pulseaudio[29830]: Underrun!
Jun 23 09:00:01 pulseaudio[29830]: Increasing minimal latency to 4.00 ms
Jun 23 09:00:01 pulseaudio[29830]: Underrun!
Jun 23 09:00:01 pulseaudio[29830]: Increasing minimal latency to 8.00 ms
Jun 23 09:04:23 pulseaudio[29830]: Underrun!
Jun 23 09:04:23 pulseaudio[29830]: Increasing minimal latency to 16.00 ms
Jun 23 09:04:26 pulseaudio[29830]: Underrun!
Jun 23 09:04:26 pulseaudio[29830]: Increasing wakeup watermark to 8.00 ms
Jun 23 09:04:41 pulseaudio[29830]: Received SHM frame on a socket where SHM is disabled.
*** NOTE: AUDIO HALTED HERE ***
Jun 23 09:04:41 pulseaudio[29830]: Freeing input 4 "Audio"
Jun 23 09:04:41 pulseaudio[29830]: Freed 9 "foobar2000"
Jun 23 09:04:41 pulseaudio[29830]: Connection died.
Jun 23 09:04:46 pulseaudio[29830]: Sink alsa_output.usb-Sennheiser_GSX_1000_Main_Audio_5698800279039916-00.analog-output-surround71 idle for too long, suspending ...
Jun 23 09:04:46 pulseaudio[29830]: Device suspended...
perHub commented 3 years ago

This is probably not the best workaround but when I reduced the buffer length to 50 ms this issue disappeared completely.

tullo-x86 commented 3 years ago

when I reduced the buffer length to 50 ms this issue disappeared completely.

FB2k's buffer or PA's?

perHub commented 3 years ago

foobar's.

tullo-x86 commented 3 years ago

Not sure how that fixed it, but I just listened to over an hour of audio (some multichannel, some stereo) and it hasn't stopped once. Thanks for the tip!

perHub commented 3 years ago

A little follow-up about the issue: I just migrated completely to pipewire and I'm using this plugin thanks to pipewire-pulse and by configuring the tcp port in /etc/pipewire/pipewire-pulse.conf. The good news is that this issue doesn't happen with this configuration, it's not even necessary to use the previous workaround, it works as before the PA update.

tullo-x86 commented 3 years ago

I'm hesitant to switch to Pipewire since my DAC required a really specific PA configuration to work right, and I really don't feel like repeating that process in an unfamiliar framework. I'll definitely be snapshotting my drive before attempting anything.

perHub commented 3 years ago

yeah, while pipewire-pulse tries to be compatible with pulseaudio I'd guess not all features are available so it's understandable to be way of it but I mentioned it because it's a nice alternative that works with this plugin, which honestly I find it really awesome :P

pLuster commented 2 years ago

I've also switched to PipeWire and created ~/.config/pipewire/pipewire-pulse.conf.d/foobar2000.conf containing:

pulse.properties = {
    server.address = [
        "unix:native"                      # needed for normal operation
        "tcp:127.0.0.1:4713"               # for foo_out_pulse
    ]
}
tullo-x86 commented 1 year ago

By a twist of fate, my SSD died recently so I'll be rebuilding my system "from scratch", so I've been handed the perfect opportunity to see how much of a bother it is to get my DAC working under Pipewire.