No output on Airplay device (raop-sink)
Configuration
- PipeWire version (
pipewire --version
): 0.3.56 - Distribution and distribution version (
PRETTY_NAME
from/etc/os-release
): Debian GNU/Linux bookworm/sid - Desktop Environment: GNOME 42.4
- Kernel version (
uname -r
): 5.18.0-4-amd64
Description of the problem
I cannot say exactly which version introduced the probelm since there were multiple updates while I was traveling, but at some point playback to my Airplay device, which worked fine before, got broken. From the application it looks as if everything is playing fine, but there is in fact no output on the device. I increased the log level in my pipewire config and include below what I believe is the relevant part of the log.
Immediately after I start playback, the raop-sink changes states to "disconnected". I suspect the "binary response received" just before may have something do with it, but I am not sure.
Sep 4 10:13:34 lucre pipewire[48526]: mod.raop-discover: loading module args:'{ "raop.hostname": "192.168.86.33", "raop.port": 1025, "node.description": "Piano", "audio.channels": 2, "raop.audio.codec": "PCM", "raop.encryption.type": "auth_setup", "audio.rate": 44100, "audio.format": "S16", "raop.transport": "udp", "device.model": "XW-SMA3" stream.props = { }}'
...
Sep 4 10:13:34 lucre pipewire[48526]: pw.node: (raop-sink-48526-86-0) latency:0/0 -> 352/44100
Sep 4 10:13:34 lucre pipewire[48526]: pw.node: (raop-sink-48526-86-0) creating -> suspended
...
Sep 4 10:20:04 lucre pipewire[49509]: pw.node: (Clementine-91) suspended -> running
Sep 4 10:20:04 lucre pipewire[49509]: pw.node: (raop-sink-49509-80-0) idle -> running
Sep 4 10:20:04 lucre pipewire[49509]: pw.node: (raop-sink-49509-80-82) suspended -> running
Sep 4 10:20:04 lucre pipewire[49509]: default: status: RTSP/1.0 200 OK
Sep 4 10:20:04 lucre pipewire[49509]: default: Public: ANNOUNCE, SETUP, RECORD, PAUSE, FLUSH, TEARDOWN, OPTIONS, GET_PARAMETER, SET_PARAMETER, POST, GET
Sep 4 10:20:04 lucre pipewire[49509]: default: Server: AirTunes/103.2
Sep 4 10:20:04 lucre pipewire[49509]: default: CSeq: 1
Sep 4 10:20:04 lucre pipewire[49509]: mod.raop-sink: options 200
Sep 4 10:20:04 lucre pipewire[49509]: default: sent: POST /auth-setup RTSP/1.0#015#012CSeq: 2#015#012Client-Instance: 569b7fd079b1eb75#015#012Apple-Challenge: KWqQtP4u+kcdrqzYBHXHrg#015#012User-Agent: iTunes/11.0.4 (Windows; N)#015#012Content-Type: application/octet-stream#015#012Content-Length: 33#015#012#015#012#001Y#002��#015N�L��c0#003�#007�M�PتF[]�#001*#014~#035N
Sep 4 10:20:06 lucre pipewire[49509]: default: status: RTSP/1.0 200 OK
Sep 4 10:20:06 lucre pipewire[49509]: default: Content-Type: application/octet-stream
Sep 4 10:20:06 lucre pipewire[49509]: default: Content-Length: 1078
Sep 4 10:20:06 lucre pipewire[49509]: default: Server: AirTunes/103.2
Sep 4 10:20:06 lucre pipewire[49509]: default: CSeq: 2
Sep 4 10:20:06 lucre pipewire[49509]: default: binary response received
Sep 4 10:20:06 lucre pipewire[49509]: mod.raop-sink: disconnected
Sep 4 10:20:40 lucre pipewire[49509]: pw.context: 0x5625403ed6a0: busy:0 reason:node deactivate
Sep 4 10:20:40 lucre pipewire[49509]: pw.node: (raop-sink-49509-80-82) -> change driver (Dummy-Driver-29 -> raop-sink-49509-80-82)
Sep 4 10:20:40 lucre pipewire[49509]: pw.link: (91.0 -> 82.0) deactivated
Sep 4 10:20:40 lucre pipewire[49509]: pw.link: (91.0 -> 82.0) active -> paused
Sep 4 10:20:40 lucre pipewire[49509]: pw.link: (91.1 -> 82.1) deactivated
Sep 4 10:20:40 lucre pipewire[49509]: pw.link: (91.1 -> 82.1) active -> paused
Sep 4 10:20:40 lucre pipewire[49509]: pw.node: (Clementine-91) client too slow! rate:256/48000 pos:1720320 status:triggered
Sep 4 10:20:40 lucre pipewire[49509]: pw.node: (Clementine-91) -> change driver (Dummy-Driver-29 -> Clementine-91)
Sep 4 10:20:40 lucre pipewire[49509]: pw.node: (Clementine-91) destroy
Sep 4 10:20:40 lucre pipewire[49509]: pw.link: (91.0 -> 82.0) paused -> init
Sep 4 10:20:40 lucre pipewire[49509]: pw.context: 0x5625403ed6a0: busy:0 reason:link unprepared
Sep 4 10:20:40 lucre pipewire[49509]: pw.link: (91.1 -> 82.1) paused -> init
Sep 4 10:20:40 lucre pipewire[49509]: pw.context: 0x5625403ed6a0: busy:0 reason:link unprepared
Sep 4 10:20:40 lucre pipewire[49509]: pw.node: (Clementine-91) running -> suspended
Sep 4 10:20:40 lucre pipewire[49509]: pw.link: (91.0 -> 82.0) destroy
Please let me know in case you need more information. I suppose I could increase the log level even further.