pipewire-pulse unhandled seek and offset spam
Trying out pipewire today I started having lots of stuttering while playing music with Lollypop
and my bluetooth headset. When I inspect the pipewire-pulse
logs I see this:
-- Journal begins at Mon 2020-12-21 16:21:26 PST, ends at Mon 2020-12-21 16:34:20 PST. --
Dec 21 16:21:38 foucault systemd[4999]: Started PipeWire PulseAudio.
Dec 21 16:21:42 foucault pipewire-pulse[5071]: pulse-server 0x18e1060: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:12 error:19 (Operation not supported)
Dec 21 16:21:42 foucault pipewire-pulse[5071]: pulse-server 0x18e1060: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:13 error:19 (Operation not supported)
Dec 21 16:21:42 foucault pipewire-pulse[5071]: pulse-server 0x18e1060: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:14 error:19 (Operation not supported)
Dec 21 16:21:42 foucault pipewire-pulse[5071]: pulse-server 0x18e1060: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:15 error:19 (Operation not supported)
Dec 21 16:21:42 foucault pipewire-pulse[5071]: pulse-server 0x18e1060: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:17 error:19 (Operation not supported)
Dec 21 16:21:42 foucault pipewire-pulse[5071]: pulse-server 0x18e1060: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:19 error:19 (Operation not supported)
Dec 21 16:21:42 foucault pipewire-pulse[5071]: pulse-server 0x18e1060: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:21 error:19 (Operation not supported)
Dec 21 16:22:03 foucault pipewire-pulse[5071]: pulse-server 0x198ba00: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:12 error:19 (Operation not supported)
Dec 21 16:22:03 foucault pipewire-pulse[5071]: pulse-server 0x198ba00: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:13 error:19 (Operation not supported)
Dec 21 16:22:03 foucault pipewire-pulse[5071]: pulse-server 0x198ba00: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:14 error:19 (Operation not supported)
Dec 21 16:22:03 foucault pipewire-pulse[5071]: pulse-server 0x198ba00: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:15 error:19 (Operation not supported)
Dec 21 16:22:03 foucault pipewire-pulse[5071]: pulse-server 0x198ba00: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:17 error:19 (Operation not supported)
Dec 21 16:22:03 foucault pipewire-pulse[5071]: pulse-server 0x198ba00: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:19 error:19 (Operation not supported)
Dec 21 16:22:03 foucault pipewire-pulse[5071]: pulse-server 0x198ba00: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:21 error:19 (Operation not supported)
Dec 21 16:22:03 foucault pipewire-pulse[5071]: pulse-server 0x198ba00: [PulseAudio Volume Control] ERROR command:87 (EXTENSION) tag:22 error:19 (Operation not supported)
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled seek flags:01
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled seek flags:01
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled offset:00007fd0
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled seek flags:01
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled offset:0000ffd0
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled seek flags:01
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled offset:000113a0
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled seek flags:01
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled offset:00012168
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled seek flags:01
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled offset:00012f30
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled seek flags:01
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled offset:00013cf8
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled seek flags:01
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled offset:00014ac0
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled seek flags:01
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled offset:00015888
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled seek flags:01
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled offset:00016650
Dec 21 16:23:29 foucault pipewire-pulse[5071]: pulse-server 0x18634c0: unhandled seek flags:01
...
It just keeps on going. For as long as sound is playing the logs are filled with the above at an incredible rate. The logs for the pipewire service don't have any similar behavior, for what it's worth:
-- Journal begins at Mon 2020-12-21 16:21:26 PST, ends at Mon 2020-12-21 16:36:40 PST. --
Dec 21 16:21:38 foucault systemd[4999]: Started Multimedia Service.
Dec 21 16:21:38 foucault pipewire[5076]: Failed to receive portal pid: org.freedesktop.DBus.Error.NameHasNoOwner: Could not get PID of name 'org.freedesktop.portal.Desktop': no such name
Dec 21 16:21:38 foucault pipewire-media-session[5085]: oFono: Register() failed: org.freedesktop.DBus.Error.ServiceUnknown
Dec 21 16:21:38 foucault pipewire-media-session[5085]: RegisterApplication() failed: org.freedesktop.DBus.Error.ServiceUnknown
Dec 21 16:22:48 foucault pipewire-media-session[5085]: no node found for 90
Dec 21 16:22:48 foucault pipewire-media-session[5085]: no node found for 121
Dec 21 16:22:51 foucault pipewire-media-session[5085]: no node found for 120
Dec 21 16:22:54 foucault pipewire-media-session[5085]: no node found for 123
Dec 21 16:22:54 foucault pipewire-media-session[5085]: no node found for 118
Dec 21 16:22:59 foucault pipewire[5076]: (PulseAudio Volume Control-122) client too slow! status:triggered
Dec 21 16:22:59 foucault pipewire[5076]: (api.bluez5.a2dp.sink.WH-1000XM2-125) client too slow! status:triggered
Dec 21 16:22:59 foucault pipewire[5076]: (api.bluez5.a2dp.sink.WH-1000XM2-125) client too slow! status:triggered
Dec 21 16:22:59 foucault pipewire-media-session[5085]: (api.bluez5.a2dp.sink.WH-1000XM2-18) client missed 1 wakeups
Most importantly though, I get fairly frequent stutters in the sound. And I've verified that even if I play the same file with pw-play
the stuttering happens, although then I don't get the seek/offset spam in the logs.