UPnP/IGD integration tries to connect to a wrong address

The problem

The UPnP/IGD has stopped working at some point for me. It has worked before. I checked that I have UPnP enabled in my router. I also installed the async-upnp-client library and when I run the search command, it gets a lot of replies from my router and I can load the xml file. I don't get replies from anything else except the router.

I removed the integration and tried to reinstall it. When I try to install it, it shows a popup "No devices found on the network".

I enabled all possible log messages

logger:
  default: info
  logs:
    homeassistant.components.upnp: debug
    async_upnp_client: debug
    async_upnp_client.search: debug
    async_upnp_client.profiles.igd: debug
    async_upnp_client.traffic: debug

When I try to install the integration, the only message I get is:

DEBUG (MainThread) [homeassistant.components.upnp] async_step_user: user_input: None

When I restart Home Assistant, I get this:

DEBUG (MainThread) [async_upnp_client.client_factory] Creating device, description_url: http://[fe80::xxxx:xxxx:xxxx:xxxx%3]:2869/upnphost/udhisapi.dll?content=uuid:...
DEBUG (MainThread) [async_upnp_client.traffic.upnp] Sending request:
GET http://[fe80::xxxx:xxxx:xxxx:xxxx%3]:2869/upnphost/udhisapi.dll?content=uuid:...
Host: [fe80::xxxx:xxxx:xxxx:xxxx]:2869

And then:

DEBUG (MainThread) [async_upnp_client.aiohttp] ClientConnectorError(ConnectionKey(host='fe80::xxxx:xxxx:xxxx:xxxx%3', port=2869, is_ssl=False, ssl=None, proxy=None, proxy_auth=None, proxy_headers_hash=...), OSError(101, 'Network unreachable')) during request; retrying

AFAIK, there's no such IPv6 address in my network. It's not my router's address. My router does have a link-local IPv6 address, but no global IPv6 address. udhisapi.dll in the URL indicates that it could be a Windows machine, but that's not the address of my Windows laptop either.

So where does it get that URL from? I think the error message comes from here in AiohttpSessionRequester. I tried adding _LOGGER.debug(...) statements there but didn't see anything in the log, and gave up trying to understand the code.

I thought that maybe there's something cached in the Home Assistant database. I dumped the database to SQL, but couldn't find that URL there.

What version of Home Assistant Core has the issue?

core-2023.4.6

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant Container

Integration causing the issue

UPnP/IGD

Link to integration documentation on our website

https://www.home-assistant.io/integrations/upnp/

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

Hey there @stevenlooman, mind taking a look at this issue as it has been labeled with an integration (upnp) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of `upnp` can trigger bot actions by commenting: - `@home-assistant close` Closes the issue. - `@home-assistant rename Awesome new title` Renames the issue. - `@home-assistant reopen` Reopen the issue. - `@home-assistant unassign upnp` Removes the current integration label and assignees on the issue, add the integration domain after the command.

_{^{(message by CodeOwnersMention)}}

upnp documentation upnp source _{^{(message by IssueLinks)}}

Thank you for this issue @senarvi. Any URL the library is using came from the device itself. The device is either found through a response on a search request (a search is done regularly by home assistant, every two minutes if I remember correctly), or via an advertisement emitted by the device itself, emitted at regular intervals.

A search and advertisement contains a few HTTP-like headers. This (should) include(s) a header called location, which specifies where the device description can be found for this device, served by this device. As you're already dumping all traffic, I think you'll find the URL in one of those search responses or advertisements, in your logs.

The device itself reports this URL. No magic (e.g., constructing a URL from the source IP plus some path) is done to construct such as URL at the home assistant/library side. Thus, your device is reporting the IPv6 URL, even though the search response or advertisement came from that device over IPv4.

Unfortunately, there are many devices having flaky behavior regarding UPnP, such as reporting IPv6 addresses over IPv4.

Can you check your logs if you see the mentioned (IPv6) URL somewhere else in your logs? Either with or without the %3 attached.

Also, the discovery of devices is done by the ssdp-component. To better see what is happening you might want to enable the homeassistant.components.ssdp logger as well.

Thanks for getting back @StevenLooman . I enabled homeassistant.components.ssdp logging too. I see this when I start Home Assistant:

[async_upnp_client.advertisement] Start listening for advertisements
[async_upnp_client.ssdp] Creating socket,
  source: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_DGRAM: 2>, 17, '192...', ('192...', 0)),
  target: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_DGRAM: 2>, 17, '239.255.255.250', ('239.255.255.250', 1900))
[async_upnp_client.advertisement] Binding socket,
  socket: <socket.socket fd=17, family=AddressFamily.AF_INET, type=SocketKind.SOCK_DGRAM, proto=0, laddr=('0.0.0.0', 0)>, address: ('', 1900)
[async_upnp_client.advertisement] Start listening for advertisements
[async_upnp_client.ssdp] Creating socket,
  source: (<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 17, 'fe80::...%2', ('fe80::...', 0, 0, 2)),
  target: (<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 17, 'ff02::c%2', ('ff02::c', 1900, 0, 2))
[async_upnp_client.advertisement] Binding socket,
  socket: <socket.socket fd=18, family=AddressFamily.AF_INET6, type=SocketKind.SOCK_DGRAM, proto=0, laddr=('::', 0, 0, 0)>, address: ('', 1900)
[homeassistant.components.ssdp] Failed to setup listener for ('192...', 0): [Errno 98] Address in use
[homeassistant.components.ssdp] Failed to setup listener for ('fe80::...', 0, 0, 2): [Errno 98] Address in use
[homeassistant.components.ssdp] Could not set up UPnP/SSDP server, as a presentation URL could not be determined;
  Please configure your internal URL in the Home Assistant general configuration

I edited it a little bit to make it easier to read. 192... is the IPv4 address of my Home Assistant installation and fe80::... is its IPv6 address.

The "Address in use" messages are interesting. Does this mean that Home Assistant is not able to listen on port 1900 for advertisements, as something else is listening on that port already? Any idea what it could be?

I'm not sure if the internal URL has anything to do with this, but I configured it in the YAML. (I didn't find that option in the UI.) Now I see the same kind of messages multiple times:

INFO (MainThread) [homeassistant.setup] Setting up ssdp
[async_upnp_client.advertisement] Start listening for advertisements
[async_upnp_client.ssdp] Creating socket,
  source: (<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 17, 'fe80::...%2', ('fe80::...', 0, 0, 2)),
  target: (<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 17, 'ff02::c%2', ('ff02::c', 1900, 0, 2))
[async_upnp_client.advertisement] Binding socket,
  socket: <socket.socket fd=19, family=AddressFamily.AF_INET6, type=SocketKind.SOCK_DGRAM, proto=0, laddr=('::', 0, 0, 0)>, address: ('', 1900)                                                                                                                                                                                        2023-04-27 15:35:39.930 DEBUG (MainThread) [async_upnp_client.advertisement] Start listening for advertisements                                                                                                  2023-04-27 15:35:39.931 DEBUG (MainThread) [async_upnp_client.ssdp] Creating socket, source: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_DGRAM: 2>, 17, '192...', ('192...', 0)), target: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_DGRAM: 2>, 17, '239.255.255.250', ('239.255.255.250', 1900))                                                                                                                  2023-04-27 15:35:39.931 DEBUG (MainThread) [async_upnp_client.advertisement] Binding socket, socket: <socket.socket fd=20, family=AddressFamily.AF_INET, type=SocketKind.SOCK_DGRAM, proto=0, laddr=('0.0.0.0', 0)>, address: ('', 1900)                                                                                                                                                                                          2023-04-27 15:35:39.935 INFO (SyncWorker_4) [homeassistant.loader] Loaded media_player from homeassistant.components.media_player                                                                                2023-04-27 15:35:39.937 INFO (SyncWorker_2) [homeassistant.loader] Loaded met_eireann from homeassistant.components.met_eireann                                                                                  2023-04-27 15:35:39.940 DEBUG (MainThread) [homeassistant.components.ssdp] Failed to setup listener for ('fe80::...', 0, 0, 2): [Errno 98] Address in use                                        2023-04-27 15:35:39.940 DEBUG (MainThread) [homeassistant.components.ssdp] Failed to setup listener for ('192...', 0): [Errno 98] Address in use                                                            2023-04-27 15:35:39.941 INFO (SyncWorker_2) [homeassistant.loader] Loaded renault from homeassistant.components.renault                                                                                          2023-04-27 15:35:39.942 INFO (SyncWorker_2) [homeassistant.loader] Loaded sfr_box from homeassistant.components.sfr_box                                                                                          2023-04-27 15:35:39.944 INFO (SyncWorker_2) [homeassistant.loader] Loaded anthemav from homeassistant.components.anthemav                                                                                        2023-04-27 15:35:39.951 INFO (MainThread) [homeassistant.components.zeroconf] Starting Zeroconf broadcast                                                                                                        2023-04-27 15:35:39.952 INFO (SyncWorker_2) [homeassistant.loader] Loaded icloud from homeassistant.components.icloud                                                                                            2023-04-27 15:35:39.957 INFO (SyncWorker_2) [homeassistant.loader] Loaded toon from homeassistant.components.toon                                                                                                2023-04-27 15:35:39.960 DEBUG (MainThread) [homeassistant.components.ssdp] Binding UPnP HTTP server to: fe80::...%2:40000                                                                        2023-04-27 15:35:39.960 INFO (SyncWorker_2) [homeassistant.loader] Loaded homekit_controller from homeassistant.components.homekit_controller                                                                    2023-04-27 15:35:39.962 DEBUG (MainThread) [homeassistant.components.ssdp] Binding UPnP HTTP server to: 192...:40000                                                                                        2023-04-27 15:35:39.964 INFO (SyncWorker_2) [homeassistant.loader] Loaded solaredge from homeassistant.components.solaredge                                                                                      2023-04-27 15:35:40.607 INFO (MainThread) [homeassistant.setup] Setting up cloud                                                                                                                                 2023-04-27 15:35:40.608 DEBUG (MainThread) [async_upnp_client.server] Device listening at http://192...:40000/device.xml                                                                                    2023-04-27 15:35:40.608 DEBUG (MainThread) [async_upnp_client.server] Starting SSDP handling, source: ('192...', 0), target: ('239.255.255.250', 1900)                                                      2023-04-27 15:35:40.608 DEBUG (MainThread) [async_upnp_client.server] Start listening for search requests                                                                                                        2023-04-27 15:35:40.609 DEBUG (MainThread) [async_upnp_client.ssdp] Creating socket, source: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_DGRAM: 2>, 17, '192...', ('192...', 0)), target: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_DGRAM: 2>, 17, '239.255.255.250', ('239.255.255.250', 1900))                                                                                                                  2023-04-27 15:35:40.610 DEBUG (MainThread) [async_upnp_client.ssdp] Creating socket, source: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_DGRAM: 2>, 17, '192...', ('192...', 0)), target: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_DGRAM: 2>, 17, '239.255.255.250', ('239.255.255.250', 1900))                                                                                                                  2023-04-27 15:35:40.610 DEBUG (MainThread) [async_upnp_client.server] Binding socket, socket: <socket.socket fd=21, family=AddressFamily.AF_INET, type=SocketKind.SOCK_DGRAM, proto=0, laddr=('0.0.0.0', 0)>, address: ('', 1900)                                                                                                                                                                                                 2023-04-27 15:35:40.625 DEBUG (MainThread) [async_upnp_client.server] Device listening at http://[fe80::...%2]:40000/device.xml                                                                  2023-04-27 15:35:40.625 DEBUG (MainThread) [async_upnp_client.server] Starting SSDP handling, source: ('fe80::...', 0, 0, 2), target: ('FF02::C', 1900, 0, 2)                                    2023-04-27 15:35:40.625 DEBUG (MainThread) [async_upnp_client.server] Start listening for search requests                                                                                                        2023-04-27 15:35:40.625 DEBUG (MainThread) [async_upnp_client.ssdp] Creating socket, source: (<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 17, 'fe80::...%2', ('fe80::...', 0, 0, 2)), target: (<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 17, 'ff02::c%2', ('ff02::c', 1900, 0, 2))                                                                                  2023-04-27 15:35:40.626 DEBUG (MainThread) [async_upnp_client.ssdp] Creating socket, source: (<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 17, 'fe80::...%2', ('fe80::...', 0, 0, 2)), target: (<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 17, 'ff02::c%2', ('ff02::c', 1900, 0, 2))                                                                                  2023-04-27 15:35:40.627 DEBUG (MainThread) [async_upnp_client.server] Binding socket, socket: <socket.socket fd=16, family=AddressFamily.AF_INET6, type=SocketKind.SOCK_DGRAM, proto=0, laddr=('::', 0, 0, 0)>, address: ('', 1900)                                                                                                                                                                                               2023-04-27 15:35:40.665 DEBUG (MainThread) [homeassistant.components.ssdp] Failed to setup server for ('fe80::...', 0, 0, 2): [Errno 98] Address in use                                          2023-04-27 15:35:40.665 DEBUG (MainThread) [homeassistant.components.ssdp] Failed to setup server for ('192...', 0): [Errno 98] Address in use                                                              2023-04-27 15:35:40.665 INFO (MainThread) [homeassistant.setup] Setup of domain ssdp took 0.7 seconds
[homeassistant.setup] Setting up ssdp
[async_upnp_client.advertisement] Start listening for advertisements
[async_upnp_client.ssdp] Creating socket,
  source: (<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 17, 'fe80::...%2', ('fe80::...', 0, 0, 2)),
  target: (<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 17, 'ff02::c%2', ('ff02::c', 1900, 0, 2))
[async_upnp_client.advertisement] Binding socket,
  socket: <socket.socket fd=19, family=AddressFamily.AF_INET6, type=SocketKind.SOCK_DGRAM, proto=0, laddr=('::', 0, 0, 0)>, address: ('', 1900)
[async_upnp_client.advertisement] Start listening for advertisements
[async_upnp_client.ssdp] Creating socket,
  source: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_DGRAM: 2>, 17, '192...', ('192...', 0)),
  target: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_DGRAM: 2>, 17, '239.255.255.250', ('239.255.255.250', 1900))
[async_upnp_client.advertisement] Binding socket,
  socket: <socket.socket fd=20, family=AddressFamily.AF_INET, type=SocketKind.SOCK_DGRAM, proto=0, laddr=('0.0.0.0', 0)>, address: ('', 1900)
DEBUG (MainThread) [homeassistant.components.ssdp] Failed to setup listener for ('fe80::...', 0, 0, 2): [Errno 98] Address in use
DEBUG (MainThread) [homeassistant.components.ssdp] Failed to setup listener for ('192...', 0): [Errno 98] Address in use
[homeassistant.components.ssdp] Binding UPnP HTTP server to: fe80::...%2:40000
[homeassistant.components.ssdp] Binding UPnP HTTP server to: 192...:40000
[async_upnp_client.server] Device listening at http://192...:40000/device.xml
[async_upnp_client.server] Starting SSDP handling, source: ('192...', 0), target: ('239.255.255.250', 1900)
[async_upnp_client.server] Start listening for search requests
[async_upnp_client.ssdp] Creating socket,
  source: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_DGRAM: 2>, 17, '192...', ('192...', 0)),
  target: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_DGRAM: 2>, 17, '239.255.255.250', ('239.255.255.250', 1900))
[async_upnp_client.ssdp] Creating socket,
  source: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_DGRAM: 2>, 17, '192...', ('192...', 0)),
  target: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_DGRAM: 2>, 17, '239.255.255.250', ('239.255.255.250', 1900))
[async_upnp_client.server] Binding socket,
  socket: <socket.socket fd=21, family=AddressFamily.AF_INET, type=SocketKind.SOCK_DGRAM, proto=0, laddr=('0.0.0.0', 0)>, address: ('', 1900)
[async_upnp_client.server] Device listening at http://[fe80::...%2]:40000/device.xml
[async_upnp_client.server] Starting SSDP handling,
  source: ('fe80::...', 0, 0, 2),
  target: ('FF02::C', 1900, 0, 2)
[async_upnp_client.server] Start listening for search requests
[async_upnp_client.ssdp] Creating socket,
  source: (<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 17, 'fe80::...%2', ('fe80::...', 0, 0, 2)),
  target: (<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 17, 'ff02::c%2', ('ff02::c', 1900, 0, 2))
[async_upnp_client.ssdp] Creating socket,
  source: (<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 17, 'fe80::...%2', ('fe80::...', 0, 0, 2)),
  target: (<AddressFamily.AF_INET6: 10>, <SocketKind.SOCK_DGRAM: 2>, 17, 'ff02::c%2', ('ff02::c', 1900, 0, 2))
[async_upnp_client.server] Binding socket,
  socket: <socket.socket fd=16, family=AddressFamily.AF_INET6, type=SocketKind.SOCK_DGRAM, proto=0, laddr=('::', 0, 0, 0)>, address: ('', 1900)
[homeassistant.components.ssdp] Failed to setup server for ('fe80::...', 0, 0, 2): [Errno 98] Address in use
[homeassistant.components.ssdp] Failed to setup server for ('192...', 0): [Errno 98] Address in use

Finally, I get these messages:

[async_upnp_client.client_factory] Creating device,
  description_url: http://[fe80::xxxx:xxxx:xxxx:xxxx%3]:2869/upnphost/udhisapi.dll?content=uuid:...
[async_upnp_client.traffic.upnp] Sending request:
GET http://[fe80::xxxx:xxxx:xxxx:xxxx%3]:2869/upnphost/udhisapi.dll?content=uuid:...
Host: [fe80::xxxx:xxxx:xxxx:xxxx]:2869
[async_upnp_client.aiohttp] ClientConnectorError(ConnectionKey(host='fe80::xxxx:xxxx:xxxx:xxxx%3', port=2869, is_ssl=False, ssl=None, proxy=None, proxy_auth=None, proxy_headers_hash=666223133152203759), OSError(101, 'Network unreachable')) during request; retrying
[async_upnp_client.traffic.upnp] Sending request:
GET http://[fe80::xxxx:xxxx:xxxx:xxxx%3]:2869/upnphost/udhisapi.dll?content=uuid:...
Host: [fe80::xxxx:xxxx:xxxx:xxxx]:2869

fe80::xxxx:xxxx:xxxx:xxxx is the mystery IPv6 address. This is the only place in the log where it occurs. It's never saved in the database either? If what I assumed is true that Home Assistant is not able to listen to advertisements, then the URL has to come from a search done by Home Assistant. But how can I find out which device sends it? Maybe if you can show me the place where the search is done, I can try to repeat exactly the same thing. I noticed that Home Assistant uses the async-upnp-client library, so I installed it and ran upnp-client search. What I get is a bunch of replies from my router. All of them have the IPv4 URL of my router in the location and that URL works.

So the router seems to be working correctly. I guess it's still possible that there's another device in my network that's advertising an invalid URL, Home Assistant tries to access the invalid IPv6 URL, and won't try to connect to any other devices. In that case I wonder if we can make Home Assistant more robust so that it will try to connect to every UPnP device that it finds.

The "Address in use" messages are interesting. Does this mean that Home Assistant is not able to listen on port 1900 for advertisements, as something else is listening on that port already? Any idea what it could be?

This is possibly another application which uses SSDP to send advertisements and/or respond to search requests, perhaps something DLNA related such as minidlna or plex/emby/jellyfin. I had the same problem and switched from host-networking to macvlan to give all containers doing anything SSDP related their own IP.

Also, given that the address is already in use, possibly "the other listener" is replying to the search requests, from the same computer. Although you would not expect to see a Network unreachable error in this case.

fe80::xxxx:xxxx:xxxx:xxxx is the mystery IPv6 address. This is the only place in the log where it occurs. It's never saved in the database either? If what I assumed is true that Home Assistant is not able to listen to advertisements, then the URL has to come from a search done by Home Assistant. But how can I find out which device sends it? Maybe if you can show me the place where the search is done, I can try to repeat exactly the same thing. I noticed that Home Assistant uses the async-upnp-client library, so I installed it and ran upnp-client search. What I get is a bunch of replies from my router. All of them have the IPv4 URL of my router in the location and that URL works.

The seen devices are not stored in the database. I don't think this is something we want either as these advertisements/search responses are usually only valid for a limited time. The logs contain the information you seek. If not, perhaps the logging should be extended. Please feel free to propose any additions.

Next to the upnp-client search you can also run upnp-client advertisements. This will listen for any advertisements, as you might have guessed. Be sure to wait a while, as most devices only send advertisements periodically with a given time in between. There is also the --bind option for both these sub-commands to specify the IP to listen on. Perhaps this will help with the search.

My guess is that you are on Linux. The command ip -6 neigh give you additional information. lsof -i -P -n (run as root/with sudo) is another helpful command.

If you're looking for code in home assistant, please see https://github.com/home-assistant/core/blob/1f2da1217bb06348d47a4ae2b08ca248e29a179e/homeassistant/components/ssdp/__init__.py#L388 where to SSDP listeners are started. Note that the SsdpListener is a class which uses both advertisements as well as searching to find devices and keep track of these.

Your guess was right that the port was reserved by another container - the Unifi Controller. When I block the port for the Unifi Controller, the UPnP integration will find the (IPv4) router.

Still, a moment after booting Home Assistant up, I see an error message about not being able to create the UPnP device with the mystery URL http://[fe80::...%3]:2869/upnphost/udhisapi.dll?content=uuid:.... By the way, there's no interface 3 - that's probably why I see the "Network unreachable" error when Home Assistant tries to connect to it. As you can see from the logs above, the listeners are started on interface 2.

I was still curious where Home Assistant gets that URL from and why upnp-client doesn't find it. I figured that I have to specify --bind or --target to make upnp-client broadcast to IPv6 addresses. I tried also running those commands inside the Home Assistant container. The only IPv6 responses I get are from Home Assistant. Like you suggested, maybe the Unifi Controller could have been replying to the search requests, so I shut it down completely. Still the same error message pops up.

ip -6 neigh shows my laptop, printer, and router. ip -6 address shows a bunch of other IPv6 addresses that correspond to the network interface and the Docker containers. None of these is the address that I see in the UPnP URL.

I looked into the logging too. The first message I see is this "Creating device": https://github.com/StevenLooman/async_upnp_client/blob/development/async_upnp_client/client_factory.py#L71

As far as I can see, that function is called by Home Assistant here: https://github.com/home-assistant/core/blob/dev/homeassistant/components/upnp/device.py#L56

And I would expect to see messages like this "Device discovered": https://github.com/home-assistant/core/blob/dev/homeassistant/components/upnp/__init__.py#L61

But I don't see anything before the "Creating device". So maybe UpnpFactory.async_create_device is called also somewhere else. Maybe it's not even the UPnP integration that's causing that error. Anyway, I think it's probably not worth spending much more time on this.

I would suggest a small change, though. The level of the "Failed to setup listener for (...): [Errno 98] Address in use" message could be higher than DEBUG, since this is the only indication of why the integration doesn't work: https://github.com/home-assistant/core/blob/1f2da1217bb06348d47a4ae2b08ca248e29a179e/homeassistant/components/ssdp/__init__.py#L420

I would suggest a small change, though. The level of the "Failed to setup listener for (...): [Errno 98] Address in use" message could be higher than DEBUG, since this is the only indication of why the integration doesn't work:

https://github.com/home-assistant/core/blob/1f2da1217bb06348d47a4ae2b08ca248e29a179e/homeassistant/components/ssdp/__init__.py#L420

Perhaps. I think @bdraco can answer this better. What do you think @bdraco?

Regarding the earlier comment. Beware that other components also use the async-upnp-client library, from which the log messages can also be generated. Such as:

I do believe there are also a few components which can be installed via HACS which use async-upnp-client.

Perhaps. I think @bdraco can answer this better. What do you think @bdraco?

As long as that isn't expected to happen on systems normally, raising it to a warning seems fine

I am a bit hesitant about upgrading the message from debug to a warning. As soon as this will be (better) visible, and it happens often, a flood of issuse will come it. I would prefer to investigate this case - i.e., where does the 3rd adapter (%3) come from - further, before changing the log level.

Unfortunately, it is hard for me to investigate this, as I cannot reproduce this. @senarvi, are you able to look into this a bit more? For example, if you run ip address, is there a 3: entry?

@StevenLooman I can continue debugging the strange UPnP device message next week when I get back home, but I'm running out of ideas. There's no 3: network entry. This is unrelated to the "address in use" error, though.

I think the best way to handle the "address in use" error would be to check the error code, and if it's 98, display an error in the UI when the user tries to start the integration that another application is using the port so UPnP won't work. But I don't know how much work that would need, so it's totally up to you.

Perhaps we are approaching this from the wrong side and is there a bug in the network component/ifaddr library (note that home assistant uses ifaddr 0.1.7 instead of 0.2.0).

@StevenLooman I forgot to get back to this. Actually there is an entry for 3: when I run ip address - that's the wlan interface - but it's always down, because I have WiFi disabled.

I enabled debugging for those other three components that you mentioned, and found out that the "Creating device" message and the "ClientConnectorError" come from dlna_dms. Before those messages appear from the first time, I see the dlna_dms message Setting up config entry and Connecting to device at with the same URL.

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

home-assistant / core