philippe44 / AirConnect

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

Cannot find any UPnP devices #338

Closed Lunchb0ne closed 3 years ago

Lunchb0ne commented 3 years ago

Hi, I've been trying to get this working on my Win 10 device for the past day. Whenever I run the UPnP version, all I get is

[19:11:55.302] main:1419 Starting airupnp version: v0.2.50.4 (Mar 13 2021 @ 17:32:01)
[19:11:55.341] Start:1129 Binding to 10.0.0.117:49152

Using the cast version discovers my Chromecast and I've tried turning the firewall off and trying it but doesn't seem to work either. What can I do to debug why it's failing to discover my device?

pwt commented 3 years ago

You could try running airupnp with the command line log option -d all=sdebug to see if that tells you anything.

What UPnP device(s) are you expecting to appear?

Lunchb0ne commented 3 years ago

I'm trying to get my SONOS Play:1 to appear, it's available on the network at 10.0.0.141.

Trying with the log option:

[19:31:33.451] main:1419 Starting airupnp version: v0.2.50.4 (Mar 13 2021 @ 17:32:01)
[19:31:33.501] Start:1129 Binding to 10.0.0.117:49152
[19:31:53.006] MasterHandler:581 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[19:31:53.007] UpdateThread:725 Presence checking
[19:32:09.178] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:09.299] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:13.014] MasterHandler:581 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[19:32:13.015] UpdateThread:725 Presence checking
[19:32:23.213] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:23.426] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:23.464] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:23.626] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:23.720] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:23.830] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:23.975] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:24.235] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:24.467] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:24.727] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:24.967] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:25.221] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:25.468] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:25.719] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:25.970] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:26.232] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:26.477] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:26.721] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:26.973] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:27.222] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:27.473] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:27.723] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:27.973] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:28.230] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:28.493] MasterHandler:581 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[19:32:33.006] MasterHandler:581 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[19:32:33.007] UpdateThread:725 Presence checking
[19:32:53.005] MasterHandler:581 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[19:32:53.006] UpdateThread:725 Presence checking
[19:33:13.004] MasterHandler:581 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[19:33:13.005] UpdateThread:725 Presence checking
[19:33:33.006] MasterHandler:581 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[19:33:33.006] UpdateThread:725 Presence checking
[19:33:53.016] MasterHandler:581 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[19:33:53.018] UpdateThread:725 Presence checking
[19:34:13.011] MasterHandler:581 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[19:34:13.011] UpdateThread:725 Presence checking
[19:34:33.011] MasterHandler:581 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[19:34:33.012] UpdateThread:725 Presence checking
[19:34:53.012] MasterHandler:581 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[19:34:53.013] UpdateThread:725 Presence checking
[19:35:13.006] MasterHandler:581 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[19:35:13.006] UpdateThread:725 Presence checking
[19:35:33.014] MasterHandler:581 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[19:35:33.016] UpdateThread:725 Presence checking
[19:35:53.008] MasterHandler:581 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[19:35:53.009] UpdateThread:725 Presence checking

I let it run for some time, but it doesn't find anything.

pwt commented 3 years ago

A Play:1 should definitely work OK.

If you've eliminated possible firewall issues on the host, the next thing to check is whether anything on the network could be interfering with the SSDP multicast traffic used for speaker discovery. For example, some routers/networks don't do a good job of forwarding multicast packets between interfaces.

Lunchb0ne commented 3 years ago

I don't really think there's anything interfering with the multicast traffic, how can I really check if anything is interfering?

pwt commented 3 years ago

I don't really think there's anything interfering with the multicast traffic, how can I really check if anything is interfering?

Can't help with that, sorry. However, if the Play:1 and the Win 10 device are on the same network, then something is impeding the discovery traffic.

Others with better networking knowledge may be able to help further.

Lunchb0ne commented 3 years ago

Alright, thanks a lot for the help! I'll try checking other configs. Is there a way to manually point to the IP of the device? Maybe in the config.xml?

pwt commented 3 years ago

Is there a way to manually point to the IP of the device? Maybe in the config.xml?

Not that I'm aware of.

As an outside bet, if you can handle installing and running a Python package, you could install my SoCo-CLI program [1], and try running the following:

sonos "<Name_of_your_Play:1>" volume --log=info e.g. sonos "Kitchen" volume --log=info.

This may provide some insight into how speaker discovery is working, including which interface is the right one, etc.

[1] https://github.com/avantrec/soco-cli (install with Pip using pip install soco-cli)

Lunchb0ne commented 3 years ago

Alright, so I ran a query for my device and it did work

(base) λ sonos "Kids Bedroom" volume --log=info
2021-03-21 21:03:34,614 sonos.py:211 - main() - Ignoring 'SPKR' environment variable
2021-03-21 21:03:34,614 sonos.py:232 - main() - Found 1 action sequence(s): [['Kids Bedroom', 'volume']]
2021-03-21 21:03:34,614 utils.py:556 - get_speaker() - Trying direct cache lookup
2021-03-21 21:03:34,615 utils.py:559 - get_speaker() - Trying indirect cache lookup
2021-03-21 21:03:34,615 utils.py:562 - get_speaker() - Trying standard discovery with network scan fallback
2021-03-21 21:03:34,625 discovery.py:578 - _find_ipv4_addresses() - Set of attached IPs: {'10.0.0.16', '10.0.0.166', '100.107.27.105'}
2021-03-21 21:03:34,625 discovery.py:114 - discover() - Sending discovery packets on [<socket.socket fd=816, family=AddressFamily.AF_INET, type=SocketKind.SOCK_DGRAM, proto=17>, <socket.socket fd=824, family=AddressFamily.AF_INET, type=SocketKind.SOCK_DGRAM, proto=17>, <socket.socket fd=868, family=AddressFamily.AF_INET, type=SocketKind.SOCK_DGRAM, proto=17>]
2021-03-21 21:03:34,739 discovery.py:173 - discover() - Falling back to network scan discovery
2021-03-21 21:03:34,744 discovery.py:550 - _find_ipv4_networks() - Set of networks to search: {IPv4Network('10.0.0.0/24')}
2021-03-21 21:03:34,765 discovery.py:647 - _sonos_scan_worker_thread() - Found open port 1400 at IP '10.0.0.141'
2021-03-21 21:03:34,783 services.py:478 - send_command() - Sending GetZoneGroupState [] to 10.0.0.141
2021-03-21 21:03:34,814 services.py:486 - send_command() - Received status 200 from 10.0.0.141
2021-03-21 21:03:34,814 discovery.py:649 - _sonos_scan_worker_thread() - Confirmed Sonos device at IP '10.0.0.141'
2021-03-21 21:03:34,820 discovery.py:335 - scan_network() - Created 256 scanner threads
2021-03-21 21:03:35,827 discovery.py:340 - scan_network() - All 256 scanner threads terminated
2021-03-21 21:03:35,827 discovery.py:361 - scan_network() - Include_invisible: False | multi_household: False | 1 Zones: {SoCo("10.0.0.141")}
2021-03-21 21:03:35,828 utils.py:393 - cache_speakers() - Adding speakers to cache: {SoCo("10.0.0.141")}
2021-03-21 21:03:35,829 match_speaker_names.py:18 - speaker_name_matches() - Found exact speaker name match for 'Kids Bedroom'
2021-03-21 21:03:35,829 utils.py:570 - get_speaker() - Successful speaker discovery
2021-03-21 21:03:35,829 services.py:478 - send_command() - Sending GetVolume [('InstanceID', 0), ('Channel', 'Master')] to 10.0.0.141
2021-03-21 21:03:35,837 services.py:486 - send_command() - Received status 200 from 10.0.0.141
2021-03-21 21:03:35,838 api.py:110 - run_command() - Return value: (0, '84', '')
84

It binds to the correct interface and returns the volume

pwt commented 3 years ago

Great. This is useful, because it's telling you that normal multicast (SSDP) discovery is not working (same thing as you're seeing with airupnp), and SoCo-CLI is having to fall back to probing every IP on the network to find your Sonos device. SoCo-CLI will also have tried SSDP discovery on every interface, so it eliminates interface choice as a possible issue.

This supports the hypothesis that there's a problem with SSDP multicast traffic somewhere between the Windows machine and the Play:1, so that's where to focus. Hopefully someone with more experience debugging such network issues will be able to help further. (I would double check that it's not a firewall issue as a first step.)

P.S. Tell the kids to turn their music down :)

Lunchb0ne commented 3 years ago

Great. This is useful, because it's telling you that normal multicast (SSDP) discovery is not working (same thing as you're seeing with airupnp), and SoCo-CLI is having to fall back to probing every IP on the network to find your Sonos device. SoCo-CLI will also have tried SSDP discovery on every interface, so it eliminates interface choice as a possible issue.

This supports the hypothesis that there's a problem with SSDP multicast traffic somewhere between the Windows machine and the Play:1, so that's where to focus. Hopefully someone with more experience debugging such network issues will be able to help further. (I would double check that it's not a firewall issue as a first step.)

P.S. Tell the kids to turn their music down :)

Alright, that seems to be the problem. The thing is I tried running Wireshark on another device and I can see the SSDP traffic originating from my device when I run airupnp. So that's definitely some weird behaviour.

BTW, that soco cli is really neat. I was just trying out all the diff commands it lets me use.