owntone / owntone-server

Linux/FreeBSD DAAP (iTunes) and MPD audio server with support for AirPlay 1 and 2 speakers (multiroom), Apple Remote (and compatibles), Chromecast, Spotify and internet radio.
https://owntone.github.io/owntone-server
GNU General Public License v2.0
2.09k stars 237 forks source link

raop: Could not send playback sync to device 'RX-V477...': Invalid argument #1568

Closed cagney closed 1 year ago

cagney commented 1 year ago

Trying to get owntone to send music to a RX-V477 from a NetBSD m/c:

The raop part of the logs contain:

[2023-01-16 15:25:10] [DEBUG]     raop: Event for AirPlay device 'RX-V477 ...' (port 1026, id )
[2023-01-16 15:25:10] [ INFO]     raop: Adding AirPlay device 'RX-V477 ...': metadata: 5, type Other, address 192.168.15.12:1026
[2023-01-16 15:25:32] [DEBUG]     raop: device_start: Sending OPTIONS to 'RX-V477 ...'
[2023-01-16 15:25:32] [DEBUG]     raop: startup_options: Sending auth-setup to 'RX-V477 ...'
[2023-01-16 15:25:33] [DEBUG]     raop: startup_auth_setup: Sending ANNOUNCE to 'RX-V477 ...'
[2023-01-16 15:25:33] [DEBUG]     raop: Local address: 192.168.15.14 (LL: no) port 65248
[2023-01-16 15:25:33] [ INFO]     raop: Setting up AirPlay session 381853291 (192.168.15.14 -> 192.168.15.12)
[2023-01-16 15:25:33] [DEBUG]     raop: startup_announce: Sending SETUP to 'RX-V477 ...'
[2023-01-16 15:25:33] [ SPAM]     raop: token: unicast
[2023-01-16 15:25:33] [ SPAM]     raop: token: mode
[2023-01-16 15:25:33] [ SPAM]     raop: token: record
[2023-01-16 15:25:33] [ SPAM]     raop: token: server_port
[2023-01-16 15:25:33] [ SPAM]     raop: token: control_port
[2023-01-16 15:25:33] [ SPAM]     raop: token: timing_port
[2023-01-16 15:25:33] [DEBUG]     raop: Negotiated AirTunes v2 UDP streaming session 1; ports s=1342 c=1344 t=1346
[2023-01-16 15:25:33] [DEBUG]     raop: startup_setup: Sending RECORD to 'RX-V477 ...'
[2023-01-16 15:25:33] [DEBUG]     raop: RTP-Info is seq=51243;rtptime=848177855
[2023-01-16 15:25:33] [DEBUG]     raop: RAOP audio latency is 4096
[2023-01-16 15:25:33] [DEBUG]     raop: volume_internal: Sending SET_PARAMETER to 'RX-V477 ...'
[2023-01-16 15:25:33] [  LOG]     raop: Could not send playback sync to device 'RX-V477 ...': Invalid argument
[2023-01-16 15:25:33] [DEBUG]     raop: Start sync packet sent to 'RX-V477 ...': cur_pos=848089655, cur_ts=830789.275181608, clock=830789.295166785, rtptime=848177855
[2023-01-16 15:25:33] [DEBUG]     raop: volume_internal: Sending SET_PARAMETER to 'RX-V477 ...'
[2023-01-16 15:25:34] [  LOG]     raop: Could not send playback sync to device 'RX-V477 ..': Invalid argument
[2023-01-16 15:25:37] [ INFO]     raop: Failed to retrieve artwork for file '/home/music/FLAC/...
[2023-01-16 15:25:37] [ SPAM]     raop: start=848177855, display=848162495, pos=848178296, end=860231840, rtp_session.pos=848266911, cur_stamp.pos=848178296
[2023-01-16 15:25:37] [DEBUG]     raop: send_progress: Sending SET_PARAMETER to 'RX-V477 ...'
[2023-01-16 15:25:37] [DEBUG]     raop: send_text: Sending SET_PARAMETER to 'RX-V477 ...'
cagney commented 1 year ago

I'm guessing the call is:

  ret = sendto(rs->control_svc->fd, pkt->data, pkt->data_len, 0, &rs->naddr.sa, addrlen);
  if (ret < 0)
    DPRINTF(E_LOG, L_RAOP, "Could not send playback sync to device '%s': %s\n", rs->devname, strerror(errno));

off hand, how does owntone handle the optional .sin_len and .sin6_len?

cagney commented 1 year ago

To answer my own question, getaddrinfo(3) et.al. are being used so that field shouldn't be a problem. Nice!

ejurgensen commented 1 year ago

Nice work looking into the error, sounds like you are familiar with C/networking? Sorry to hear the amp isn't working. As you could see it looks like it just isn't accepting the sync packets, which is odd. I haven't heard of an error like this before. There is no firewall in-between, right? You could try forcing Airplay 2 with the raop_disable setting in the config file, but I'm not too optimistic it will be any different.

Since the amp supports Airplay 1 another, more difficult, thing you could try would be try with another Airplay 1 client, for instance iTunes for Windows, and then grab the traffic with Wireshark. Airplay 1 is unencrypted, so if it works it might be possible to spot the difference or a clue.

cagney commented 1 year ago

"Invalid argument" suggests EINVAL so, presumably, one of the parameters to sendto() isn't right.

ejurgensen commented 1 year ago

Yes, that's true, I was thinking it was the fd. That code is pretty battle-tested, so I think it is unlikely to be anything else, unless it's something that just shows up in NetBSD. Can you run OwnTone in gdb and print the parameter values?

If you have a Linux platform it might also be worth checking if OwnTone on that displays the same behavior.

ejurgensen commented 1 year ago

Closing, no feedback