philippe44 / AirConnect

Use AirPlay to stream to UPnP/Sonos & Chromecast devices
Other
3.55k stars 218 forks source link

Unable to play from airplay to UPnP device #284

Closed arobert3434 closed 3 years ago

arobert3434 commented 4 years ago

I'm running AirUPnP on a Mac to expose a Cambridge Audio Minx Xi (UPnP device) as an Airplay speaker. When airupnp starts up, it finds the device and exposes it, but if I try to play music to it from Apple Music (on Mac or iPhone) the device says only "Streaming from AirConnect" with a spinner or (if MP3 mode is selected in the config) goes quickly to "End of Queue". If I pause from the player the device says "Paused 00:00". In the logs, the key error always seems to be:

[13:14:52.868505] read_line:1186 fd: 17 read error: Connection reset by peer [13:14:52.868527] http_parse:1105 cannot read method [13:14:52.868538] http_thread_func:1079 HTTP close 17

The device works fine playing from all other UPnP/DLNA players I've tried. Logs, config, and device description XML attached.

Any ideas what the problem could be? One other person (issue #133) saw this before. Anyone else? Anything I can try to get more information?

config.xml.txt debug_flac.log debug_mp3.log debug_pcm.log description.xml.txt

philippe44 commented 3 years ago

Usually it's due to firewall issues. Looked at closed issues, I think some had the same problem on certain MacOS versions.

philippe44 commented 3 years ago

My comment was not updated... interesting

Anyway, the issue is not what I thought, it's a problem with your UPnP device, very likely. I've seen a lot of players with very bad HTTP/UPnP stacks, not respecting specifications. I think, in your case, that the HTTP stacks wants a content-length in the GET response and shuts off the connection when it does not get one. Feels like the attempt to re-open and read with an offset of 128k on mp3 although only ~30k have been sent confirms that.

This is very bad practice and not compilant. In HTTP, content-length is optional and they should not rely on it. There are many cases where the source simply does not know the length of what it's about to send. It's not a file, it's a stream. RFC1945 and RFC2616 are clear about that. Unfortunately, I've seen many really crappy HTTP stacks in commercial products. Mine is not a reference, but I don't sell anything :-)

I'm not trying to be picky, if I could, I would add content-length but the very nature of an AirPlay to UPnP bridge is that I receive a real time continuous/synchronous stream of audio that I transform into a ressource available asynchronously (with some rules to discard elapsed audio)

arobert3434 commented 3 years ago

Got it, thanks for the analysis. It makes sense. The device is made by a good audio company that has only been starting to venture into the software world. They device itself is prone to crashes, and their iOS apps are of similar quality. Other apps are able to play to the device from the same computer, but since they are not streaming but playing files, I guess they send content-length.

One longshot question. The device is able to play from standard audio stream URLs. Does anyone know of any apps that would collect the airplay audio and rebroadcast it as a stream that I could then point the device to? Or is this something a motivated hacker could add on to the AirUPnP code?

philippe44 commented 3 years ago

One longshot question. The device is able to play from standard audio stream URLs. Does anyone know of any apps that would collect the airplay audio and rebroadcast it as a stream that I could then point the device to? Or is this something a motivated hacker could add on to the AirUPnP code?

I might miss the point, but this is exactly what airupnp does

philippe44 commented 3 years ago

Can you try this https://www.dropbox.com/s/mgdkyx8dzgrjtio/airupnp-osx-multi?dl=0. I'm not even sure it works, but it's using HTTP 1.1 and chunked-encoding. Maybe your player will be happier with it

arobert3434 commented 3 years ago

I tried it but no difference unfortunately. I don't know much about what is going on behind the scenes, but from an outside perspective, if I direct the device itself (through its UI) to play a stream like this SomaFM one, it is a "pull operation" from the perspective of the device, and it works fine. Whereas in some sense AirUPnP is "pushing" the stream to the device and that is when things fail. I cannot see any significant difference in headers. Headers from the Soma stream are:

% wget --spider -S http://ice6.somafm.com/groovesalad-128-mp3
--2020-10-23 07:18:47--  http://ice6.somafm.com/groovesalad-128-mp3
Resolving ice6.somafm.com (ice6.somafm.com)... 208.64.184.36
Connecting to ice6.somafm.com (ice6.somafm.com)|208.64.184.36|:80... connected.
HTTP request sent, awaiting response... 
  HTTP/1.1 200 OK
  Content-Type: audio/mpeg
  Date: Fri, 23 Oct 2020 05:18:47 GMT
...
  Server: Icecast 2.4.0-kh10
  Cache-Control: no-cache, no-store
  Access-Control-Allow-Origin: *
  Access-Control-Allow-Headers: Origin, Accept, X-Requested-With, Content-Type
  Access-Control-Allow-Methods: GET, OPTIONS, HEAD
  Connection: Close
  Expires: Mon, 26 Jul 1997 05:00:00 GMT
Length: unspecified [audio/mpeg]
Remote file exists.

Note, also no content-length. If I request headers from the temporary stream AirUPnP makes:

% wget --spider -S http://192.168.100.4:63427/stream.mp3
--2020-10-23 07:21:38--  http://192.168.100.4:63427/stream.mp3
Connecting to 192.168.100.4:63427... connected.
HTTP request sent, awaiting response... 
  HTTP/1.1 200 OK
  Server: HairTunes
  Content-Type: audio/mp3
  Connection: Keep-Alive
  Transfer-Encoding: chunked
Length: unspecified [audio/mp3]
Remote file exists.

The 'chunked' is different but does not seem to affect behavior as said. The MIME type is different (audio/mp3 vs audio/mpeg) but I also suspect that does not matter.

I tried curl --trace on the Soma stream and AirUPnP's and could not see any difference. Both get one header and then just transfer data. So I'm still wondering, is the device behaving differently when it is given a stream from AirUPnP as opposed to getting one from its own UI? Is there any way to make AirUPnP just publish the stream at a URL (like http://192.168.100.4:63427 in the example above) and not try to do anything to the device itself, and then I can point the device at the URL from its UI?

debug2_mp3.log

philippe44 commented 3 years ago

It's not a push from AirUPnP, it's always a GET (pull) from the device, the only thing is that AirUPnP sends the command to push the device to make the pull :-)

philippe44 commented 3 years ago

Now, if it still does not work, there might be something with UPnP DIDL content, but that's difficult to investigate w/o the device. Easier solution would be that you can use wireshark to get me a capture of the exchange

arobert3434 commented 3 years ago

I'll try to gather that this weekend.

timtn commented 3 years ago

... The device works fine playing from all other UPnP/DLNA players I've tried. ...

If it's working with other DLNA sources, then could it be a ProtocolInfo issue...?

If you have access to a windows VM, you could try running DMRA to see what your device supports.

From what I could find re:Cambridge Audio, it looks like it doesn't support the default http-get:*:audio/mp3 but does support http-get:*:audio/mpeg:DLNA.ORG_PN=MP3.

You could try changing it in the config to see if that help.

arobert3434 commented 3 years ago

Thanks @timtn I tried that with no luck. I also ran the Whitebear analyzer and attached the report. (Whitebear was able to play an MP3 sample to the device using mime type audio/mpeg.)

Relevant audio capabilities were shown as

audio/L16       LPCM    Dlna    48000   2       16      Yes
audio/mpeg      MP3     Dlna    *       2       *       No

I collected wireshark logs where I'd start up airupnp, connect AppleMusic to it, play a song, wait for end-of-queue, disconnect, and finally ctrl-c airupnp.

One thing I noticed. For mp3, streams that work on the device plus Whitebear's sample send audio/mpeg. AirUPnP always sends audio/mp3 not audio/mpeg. Any way in the config file to get it to switch?

whitebear_CambridgeAudioMinxXi535.txt

wireshark_2.pcapng.gz wireshark_3.pcapng.gz

philippe44 commented 3 years ago

Is one of the capture the exchange with whitebear? I need to do a comparison

arobert3434 commented 3 years ago

Unfortunately no, and Whitebear seems to send gazillions of things back and forth with the device so is probably not a good example. I'll try to get something with another player Sunday.

mrlt8 commented 3 years ago

One thing I noticed. For mp3, streams that work on the device plus Whitebear's sample send audio/mpeg. AirUPnP always sends audio/mp3 not audio/mpeg. Any way in the config file to get it to switch?

Yes, you can specify the ProtocolInfo using a config file. You can generate a default config file by using -i config.xml and load it using -x config.xml

arobert3434 commented 3 years ago

Wireshark from playing an MP3 file from SofaPlay. (BTW @mrlt8 thanks, but I'm referring to the content type the "Hairtunes" stream itself sends in its response to the GET from the player. Unfortunately this does not follow what is written in the protocolInfo config (in my case and the default setting, 'audio/mpeg').

wireshark_sofaplay_1.pcapng.gz

philippe44 commented 3 years ago

This does not seem to be a full exchange - I can't see the UPnP play request and the GET action from the player to grab file/audio, so I'm missing all the important information

philippe44 commented 3 years ago

Sorry, I missed something in my filter but now what I have from sofaplay is a m4a file, so it's not useful for mp3 or flac comparison

arobert3434 commented 3 years ago

Attached for an mp3 file.

wireshark_sofaplay_2.pcapng.gz

philippe44 commented 3 years ago

It's strange - I see a "SetAVTransportURI" POST request that does not seem to be compliant to UPnP/DLNA specifications. Any chance you coud try a flac file with sofaplay and with AirConnect and take wireshark traces?

arobert3434 commented 3 years ago

Attached for a flac file.

wireshark_flac.pcapng.gz

philippe44 commented 3 years ago

Sorry, 7zip whines that the archive is corrupted

arobert3434 commented 3 years ago

Updated in-place above. (For some reason had .gz extension but was uncompressed.)

arobert3434 commented 3 years ago

Were there any clues from the network traces?

philippe44 commented 3 years ago

Seems that this is the same issue:

1/ In the "SetAVTransport" the DIDL header contains a "size" field which is known by sofaplay but can't be known in the can or AirPlay

2/ Then, the player requests first a chunk (range 0-127999) of 128k to, I assume, try to guess the size of the file to be received. Sofplay, which again knows the size of the file answers with a 206 and after that the player requests the full size that has been indicated in the 206.

Unfortunately, per my previous post, this is a non-compliant practice. When I receive the request for a range and I can't answer to that, I do one of the compliant answer which is a 200 with the whole file and no content-length. I'm going to upload in a few mins a version (0.2.28.5) with a bit more logs to confirm that w/o requiring you to take wireshark.

Maybe you can try to make sofaplay stream a webradio and do a wireshark capture so that, if it works, I can see if there is a way I can handle this non-compliant behavior w/o becoming non-compliant myself

arobert3434 commented 3 years ago

Sofaplay can't stream URLs so I experimented by reverse-proxying SomaFM with Apache on my same machine so I could capture the exchange. What I found was that the Cambridge Audio device could NOT play the stream in this setup whereas other software such as Music (iTunes) and internet streaming apps on my iPad could. (Logs attached.)

I've not yet been able to isolate the difference in what the device gets back when it connects through the reverse proxy and when it (successfully) connects directly. (I need to capture from my router to do that and don't have it working well yet.) I'll post back here if I get more information. I'm starting to believe the device might be a hopeless case.

ipad_proxied.pcapng.gz minx_proxied.pcapng.gz

philippe44 commented 3 years ago

These logs seems to be good HTTP 1.1 chunked exchanges (there is something funny with the minx one but that does not matter for our purpose here).

Now, where I'm confused a but is that earlier you said that the Cambridge Audio would play SomaFM when asked directly. Do I get that right? CA direct to SomaFM works but when proxied it fails?

Why not taking a wireshark of that exchange rather than proxying it? Is this because you can't "see" the packets due to your switches?

arobert3434 commented 3 years ago

Yes, I tried running tcdump over ssh from the router but it seemed to drop or corrupt the packets. I should be able to do it by using my computer as an intermediate link. I'll try that in the next couple of days.

arobert3434 commented 3 years ago

I put my box in the middle and recorded a successful connect from the device direct to the streaming server. Then I tried running nginx instead of Apache as the proxy. If I set proxy_buffering off;, proxied streaming works as well. I looked a bit at the difference and it seems like Apache wraps the HTTP response from the other end ("ICY 200 OK") in its own header, whereas the "buffering off" stopped nginx from doing that. (I couldn't find a way to turn buffering off in Apache.)

Nginx does complain: 2020/11/16 14:31:35 [error] 21#21: *5 upstream sent no valid HTTP/1.0 header while reading response header from upstream, client: 172.17.0.1, server: localhost, request: "GET /soma/fluid-128-mp3 HTTP/1.1", upstream: "http://198.24.44.211:80//fluid-128-mp3", host: "192.168.100.4:8085"

minx_direct.pcapng.gz minx_proxied_apache.pcapng.gz minx_proxied_nginx.pcapng.gz

philippe44 commented 3 years ago

What I found was that the Cambridge Audio device could NOT play the stream in this setup whereas other software such as Music (iTunes) and internet streaming apps on my iPad could. (Logs attached.)

BTW, the log is wrong in the case of minx for the following reason


HEAD /soma/fluid-128-mp3 HTTP/1.1
User-Agent: RMA/1.0.(compatible;.RealMedia)
Host: 192.168.10.4
Accept: */*

HTTP/1.1 200 OK Date: Sun, 15 Nov 2020 09:49:31 GMT Server: Apache/2.4.41 (Unix) PHP/7.3.11 Content-Length: 10

GET /soma/fluid-128-mp3 HTTP/1.1 User-Agent: RMA/1.0.(compatible;.RealMedia) Host: 192.168.10.4 Accept: /

HTTP/1.1 200 OK Date: Sun, 15 Nov 2020 09:49:32 GMT Server: Apache/2.4.41 (Unix) PHP/7.3.11 Transfer-Encoding: chunked

5a6 ICY 200 OKContent-Type: audio/mpeg Date: Sun, 15 Nov 2020 09:49:32 GMT icy-br:128 icy-genre:Hiphop Future Soul icy-name:Fluid: Drown in the electronic sound of instrumental hiphop, future soul and liquid trap. [SomaFM] icy-notice1:
This stream requires Winamp
icy-notice2:SHOUTcast Distributed Network Audio Server/Linux v1.9.5
icy-pub:0 icy-url:http://somafm.com Server: Icecast 2.4.0-kh10 Cache-Control: no-cache, no-store Access-Control-Allow-Origin: * Access-Control-Allow-Headers: Origin, Accept, X-Requested-With, Content-Type Access-Control-Allow-Methods: GET, OPTIONS, HEAD Connection: Close Expires: Mon, 26 Jul 1997 05:00:00 GMT

........*..o2`X..pi.J.D.X


You see that transfer-mode is chunked which means that data is divided in chunks. It means that each chunks starts with the size of the chunk and \r\n, then the data. Now HTTP headers are supposed to be first and not part of chunks, of course and what you see in that log is that HTTP headers seem to be in a chunk which would explain some of the issue
philippe44 commented 3 years ago

I put my box in the middle and recorded a successful connect from the device direct to the streaming server. Then I tried running nginx instead of Apache as the proxy. If I set proxy_buffering off;, proxied streaming works as well. I looked a bit at the difference and it seems like Apache wraps the HTTP response from the other end ("ICY 200 OK") in its own header, whereas the "buffering off" stopped nginx from doing that. (I couldn't find a way to turn buffering off in Apache.)

And the issue in your latest log is as mentioned previously, the proxy is confused by the "ICY" response and think it's body, so it makes it part of a "chunk"

philippe44 commented 3 years ago

Now, what happens here in general is that Minx is requesting the audio differently. It does not asks for a 128k block first, it does a more "normal" HTTP GET request. If you look at your initial logs, in the case of mp3, a part of the command AirConnect sends to the player is

[13:25:59.494974] AVTSetURI:89 [0x100156e80]: DIDL header: <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/">
<item id="1" parentID="0" restricted="1">
<dc:title>Streaming from AirConnect</dc:title>
<dc:creator></dc:creator>
<upnp:album></upnp:album>
<upnp:channelName>Streaming from AirConnect</upnp:channelName>
<upnp:channelNr>0</upnp:channelNr>
<upnp:class>object.item.audioItem.audioBroadcast</upnp:class>
<res protocolInfo="http-get:*:audio/mp3:DLNA.ORG_OP=00;DLNA.ORG_CI=0;DLNA.ORG_FLAGS=0d500000000000000000000000000000">http://192.168.100.4:50198/stream.mp3</res>
</item>
</DIDL-Lite>

And that "DIDL" header should tells it that it's a broadcast, not a regular file, unless it does not support DLNA extension. If it does not, then it means that it "thinks" that every command from an UPnP controller refers to a file, not a stream, so there is nothing to do. Now, at this point, the only option to know more would be to find any UPnP controller (BullbleUPnP, Foobar as a controller ...) and try to have it require the Minx to play a stream and capture that exchange.

arobert3434 commented 3 years ago

I could not get Foobar to play a stream to the Minx. It exhibited the same behavior as AirConnect. Then I recorded when the Minx's own app directs the player to play a stream, and it looks like it accomplishes this through a different protocol, maybe proprietary. When it directs it to play a file on the other hand, it uses the DIDL-UPnP method. So this likely means the device does not support DIDL for a stream.

I guess this can be closed. Sorry for the bother. All the investigation gave me an idea though, and I ended up running icecast in a Docker container along with shairport-sync. The latter gets piped to lame and then ezstream into icecast. (I couldn't get a flac stream to work on the device, unfortunately.) The Minx then happily connects to the local icecast URL.

minx_direct_cmd.pcapng.gz minx_file_cmd.pcapng.gz