UPnP Broken After Restart - 0.92.2 #23728

chamberlain2007 · 2019-05-06T23:55:20Z

Last working Home Assistant release (if known): Unknown

Operating environment (Hass.io/Docker/Windows/etc.): Hass.io

Component/platform: UPnP (https://www.home-assistant.io/components/upnp/)

Description of problem:
I add a UPnP integration for my NetGear R8000 router, including port forwarding. This works well, and I see the sensor data and the port forwarding rules setup. However, if I restart home assistant the sensors and port forwarding no longer work. The integration says "entity unavailable". If I remove and re-add the integration, it works again. See https://gfycat.com/pertinentraggedflee for a video example.

Problem-relevant configuration.yaml entries and (fill out even if it seems unimportant):

upnp:
  port_mapping: true
  ports:
    443: hass
    8883: 8883

Related Issue: #22787

The text was updated successfully, but these errors were encountered:

dgomes · 2019-05-09T23:53:53Z

Possibly fixed by #23763 ?

@StevenLooman

ghost · 2019-05-09T23:55:02Z

Hey there @robbiet480, mind taking a look at this issue as its been labeled with a integration (upnp) you are listed as a codeowner for? Thanks!

This is a automatic comment generated by codeowners-mention to help ensure issues and pull requests are seen by the right people.

StevenLooman · 2019-05-11T10:13:17Z

Possibly fixed by #23763 ?

I think so.

chamberlain2007 · 2019-05-19T19:57:36Z

Just upgraded to 0.93.1, problem is not fixed.

StevenLooman · 2019-05-21T19:20:13Z

Are you certain you don't have a custom component installed?
Can you turn on logging, add the device and report the output? Preferably for multiple runs. Add this to you configuration to enable debug-logging:

logger:
  default: warning
  logs:
    homeassistant.components.upnp: debug
    async_upnp_client: debug
    async_upnp_client.traffic: info

Also, what about others, @DavidFW1960, @lweberru?

lweberru · 2019-05-22T11:23:42Z

Also still not fixed. Still devices are unavailable after a restart.

lweberru · 2019-05-22T11:25:35Z

And the other issue with the ordering, also still exists (0.93.1), the devices I get using the integration switch randomly.

DavidFW1960 · 2019-05-22T11:47:26Z

Same issue here for me. What custom_component are you asking about @StevenLooman ? I have always had custom_components.

Sometimes HA starts and all devices are there, sometimes none and sometimes half are there. This only started in the HA version I stated when I originally opened that was closed prematurely.

lweberru · 2019-05-26T07:48:21Z

I activated logging:

2019-05-26 09:42:33 DEBUG (MainThread) [homeassistant.components.upnp] Discovering UPnP/IGD devices
2019-05-26 09:42:38 INFO (MainThread) [homeassistant.components.upnp] No UPnP/IGD devices discovered
2019-05-26 09:42:38 INFO (MainThread) [homeassistant.components.upnp] Unable to create UPnP/IGD, aborting

Hope this helps

StevenLooman · 2019-05-28T17:39:00Z

This is unexpected, but gives another thing to try.

@DavidFW1960 Modifications to upnp to test changes for this issue or any of its predecessors.
Can you enable logging as well and report the output?

StevenLooman · 2019-05-28T19:03:38Z

@lweberru I've changed the upnp-component a bit to 'bind' on the USN (Unique Service Name) instead of the UDN (Unique Device Name.) Hopefully this will actually prevent the switching you're seeing.
If you know how, please test the https://github.com/StevenLooman/home-assistant/tree/upnp_usn branch.
If you do not know, please let me know and we'll figure it out together. Otherwise you can also apply the changes from this change manually: StevenLooman@4e157e0
Note that you'll have to re-add the integration.

I am able to reproduce the entity-unavaiable problem by:

Adding the integration
Stopping home assistant
Disconnect the router or change the code such that no device is discovered
Start home assistant

I'm not sure if this is the same problem as you are having. From the logging by @lweberru it appears to be so. Either your router does not want to be found (too many requests/preventing attacks?) or is unable to respond in time. It is possible to increase the time allowed to search (4 seconds, as specified by the UPnP standard) to something more generous, but 4 seconds is already a lot.

DavidFW1960 · 2019-05-29T00:39:55Z

Do I just copy the whole upnp and make that a custom_component in hass.io? I'm running docker on debian so I could also edit the __init__.py if I can find it lol.

StevenLooman · 2019-05-30T09:06:41Z

Copy the whole upnp directory to custom_components (the directory itself, such that you'll have custom_components/upnp/__init__.py etc.

To enable logging for the custom component you'll have to add this to your configuration (note the first line in the logs-entry):

logger:
  default: warning
  logs:
    custom_components.upnp: debug
    homeassistant.components.upnp: debug
    async_upnp_client: debug
    async_upnp_client.traffic: info

DavidFW1960 · 2019-06-02T08:28:49Z

Ok so I have not had time to try the custom component yet @StevenLooman but with 0.94.0b4 here is the UPnP/IDG errors in the log:
https://codeshare.io/5DJWPl

StevenLooman · 2019-06-02T11:33:01Z

@DavidFW1960 Thanks! Your device is not responding in time (within 5 seconds.) It is likely this is also the cause for the entity unavailable. Did your router have a firmware-upgrade recently?

DavidFW1960 · 2019-06-02T23:56:22Z

It has but the issue predates that..

lweberru · 2019-06-19T08:05:07Z

Any news within this issue? The same issue still exists. Only a manual re-add works. Can I change the timeout setting just to find out if it going into that direction?

StevenLooman · 2019-06-19T08:32:31Z

Sorry for the long delay, other things keep popping up. Hope to work on this soon.

lweberru · 2019-06-19T13:01:04Z

I changed the timeout value within ssdp.py from 4 to 10 secs (SSDP_MX = 10). Now it seems to work :-)
So please increase the timeout value. During a restart all components do a discovery and there might be a big load during this phase...

StevenLooman · 2019-06-22T07:18:59Z

Thank you @fabaff.

Molodax · 2019-10-29T09:19:21Z

Hi,

I am experiencing exactly the same issue with my Ubiquiti Amplifi HD router. I see the sensor data if I completely reboot homeassistant. However, if I restart homeassistant the sensors no longer work.

2019-10-27 10:16:28 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry UPnP/IGD for upnp
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/async_upnp_client/aiohttp.py", line 103, in async_do_http_request
    async with self._session.request(method, url, headers=headers, data=body) as response:
  File "/usr/local/lib/python3.7/site-packages/aiohttp/client.py", line 1012, in __aenter__
    self._resp = await self._coro
  File "/usr/local/lib/python3.7/site-packages/aiohttp/client.py", line 504, in _request
    await resp.start(conn)
  File "/usr/local/lib/python3.7/site-packages/aiohttp/client_reqrep.py", line 847, in start
    message, payload = await self._protocol.read()  # type: ignore  # noqa
  File "/usr/local/lib/python3.7/site-packages/aiohttp/streams.py", line 591, in read
    await self._waiter
concurrent.futures._base.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 190, in async_setup
    hass, self
  File "/usr/src/homeassistant/homeassistant/components/upnp/__init__.py", line 147, in async_setup_entry
    device = await async_discover_and_construct(hass, config_entry.data.get("udn"))
  File "/usr/src/homeassistant/homeassistant/components/upnp/__init__.py", line 116, in async_discover_and_construct
    return await Device.async_create_device(hass, ssdp_description)
  File "/usr/src/homeassistant/homeassistant/components/upnp/device.py", line 62, in async_create_device
    upnp_device = await factory.async_create_device(ssdp_description)
  File "/usr/local/lib/python3.7/site-packages/async_upnp_client/client_factory.py", line 52, in async_create_device
    root = await self._async_get_url_xml(description_url)
  File "/usr/local/lib/python3.7/site-packages/async_upnp_client/client_factory.py", line 290, in _async_get_url_xml
    await self.requester.async_http_request('GET', url)
  File "/usr/local/lib/python3.7/site-packages/async_upnp_client/client.py", line 70, in async_http_request
    body_type=body_type)
  File "/usr/local/lib/python3.7/site-packages/async_upnp_client/aiohttp.py", line 113, in async_do_http_request
    resp_body = None
  File "/usr/local/lib/python3.7/site-packages/async_timeout/__init__.py", line 55, in __aexit__
    self._do_exit(exc_type)
  File "/usr/local/lib/python3.7/site-packages/async_timeout/__init__.py", line 92, in _do_exit
    raise asyncio.TimeoutError
concurrent.futures._base.TimeoutError

StevenLooman · 2019-11-01T15:17:56Z

What do you mean with rebooting home assistant vs restarting home assistant?

It seems your router stops responding in time to requests. Does your router have a static IP?

Molodax · 2019-11-01T20:03:22Z

What do you mean with rebooting home assistant vs restarting home assistant?

I use hass.io and I can either reboot the whole system (hassio) or just restart homeassistant.

My router has a static IP.

StevenLooman · 2019-11-02T10:45:05Z

Does the rpi get a new IP when it is rebooted?

Molodax · 2019-11-06T08:11:16Z

Does the rpi get a new IP when it is rebooted?

It is still the same IP

StevenLooman · 2019-11-10T17:18:26Z

Another try... what if you stop home assistant, wait a few minutes, and then start home assistant? This mimics the behavior of a restart with regard to timing.

It is very hard to reproduce the problem without having the device myself. I'm uncertain we will be able to fix it this way.

StevenLooman · 2019-11-10T17:19:05Z

See also #26869.

Jpsy · 2020-03-31T02:36:09Z

Hi @StevenLooman,
unfortunately this bug seems to be still alive and kicking in Home Assistant 0.107.7.

My router is a Fritz!Box 6590. HA is running as hass.io on a Raspi 3b.
Whenever I restart HA the entities of the UPNP integration become unavailable.
To solve that I have to remove the integration and add it again.

I have a feeling that this bug is still somehow connected to the name binding that you mentioned above . Here is why:
Every now and then, when I remove and re-add the integration, it comes up with device and entity names that differ from the names normally found (see screenshots below). When I remove and re-add it a second time, the original names most often re-appear. This happens about 1 or 2 times in 10.

Normal names start with: InternetGatewayDeviceV2 - FRITZ!Box 6590 Cable
Wrong names start with: FRITZ!Box 6590 Cable

Could it be, that on HA restarts the wrong names are found and thus the known entities with the original names become unavailable?

Correct device name:

Wrong device name:

Correct entity names of device:

Wrong entity names of device:

Correct single entity:

Wrong single entity:

StevenLooman · 2020-04-02T14:58:01Z

It is possible that your router advertises multiple services. Are you able to run a command from within the virtualenv/docket/... where you run your Home Assistant?

Please run this and post the results:

$ upnp-client search

This will command will do a SSDP/UPnP-scan for devices in your network. Each line contains a JSON-object with information. The results will look something like this:

{"Cache-Control": "max-age=1900", "Location": "http://192.168.178.1:80/RootDevice.xml", "Server": "UPnP/1.0 UPnP/1.0 UPnP-Device-Host/1.0", "ST": "upnp:rootdevice", "USN": "uuid:upnp-InternetGatewayDevice-1_0-889ffacb9043::upnp:rootdevice", "EXT": "", "_timestamp": "2020-04-02 16:55:13.390264", "_address": "192.168.178.1:1900", "_udn": "uuid:upnp-InternetGatewayDevice-1_0-889ffacb9043", "_source": "search"}

Please feel free to lines which are not related to your router. You can probably filter on the LOCATION-attribute, if it does not contain the IP of your router then it is not relevant.

Jpsy · 2020-04-02T18:30:53Z

@StevenLooman I have "SSH & Web Terminal" by Frenck installed on my hass.io system and so I have shell access. But I do not know how to run commands from within a certain docker environment. Can you give me some advice? I would be happy to assist.

Jpsy · 2020-04-03T05:19:14Z

Ok, I think I see now that you want me to run a command in a Python virtual env. But I can't find out how to do that. Using the shell? Using HA's "Python Scripts" integration? Please provide some instructions and I will proceed. Thanks.

StevenLooman · 2020-04-05T07:05:08Z

It seems the "SSH & Web terminal" is the best option, judging from SSH & Web Terminal in Hass.io

Start a new Terminal (first screenshot in the article) and type in the command:

upnp-client search

That should do it.

PS No need to do the steps about Putty from that article.

ObiKaiKenobi · 2020-04-06T18:41:48Z

Hi Steven,

im having the same issue with my AVM 7490 Router.
I am running Home Assistant 0.107.7 in Docker on Ubuntu and this is the output by the command:

output.txt
(Lines not related to router 192.168.178.1 removed)

Hope that helps...

BTW: should we open a new issue or reopen this one (if possible)?

Jpsy · 2020-04-06T18:58:53Z

Start a new Terminal (first screenshot in the article) and type in the command:
upnp-client search

Issuing upnp-client search in the HA shell was the first thing I tried. But the command upnp-clientis unknown:

➜  ~ upnp-client search  
zsh: command not found: upnp-client

That's why I asked if I have to execute it from within one of the existing docker containers.

@ObiKaiKenobi how did you manage to execute that command?

ObiKaiKenobi · 2020-04-07T04:59:08Z

@Jpsy Im managing my docker container with portainer.
Here I have an option to connect directly to the console...

StevenLooman · 2020-04-07T19:06:06Z

@Jpsy I have no exprience with hass.io so it is hard for me to help. Perhaps you can SSH into your installation by using a client such as PuTTY if you're on windows.

@ObiKaiKenobi Thank you for the output. Your router advertises itself as a IGD1 and IGD2 device:

{"LOCATION": "http://192.168.178.1:49000/igddesc.xml", "SERVER": "FRITZ!Box 7490 UPnP/1.0 AVM FRITZ!Box 7490 113.07.12", "CACHE-CONTROL": "max-age=1800", "EXT": "", "ST": "urn:schemas-upnp-org:device:InternetGatewayDevice:1", "USN": "uuid:75802409-bccb-40e7-8e6c-3481C4A93988::urn:schemas-upnp-org:device:InternetGatewayDevice:1", "_timestamp": "2020-04-06 20:27:37.446917", "_address": "192.168.178.1:1900", "_udn": "uuid:75802409-bccb-40e7-8e6c-3481C4A93988", "_source": "search"}
{"LOCATION": "http://192.168.178.1:49000/igd2desc.xml", "SERVER": "FRITZ!Box 7490 UPnP/1.0 AVM FRITZ!Box 7490 113.07.12", "CACHE-CONTROL": "max-age=1800", "EXT": "", "ST": "urn:schemas-upnp-org:device:InternetGatewayDevice:2", "USN": "uuid:75802409-bccb-40e7-9f6c-3481C4A93988::urn:schemas-upnp-org:device:InternetGatewayDevice:2", "_timestamp": "2020-04-06 20:27:37.450272", "_address": "192.168.178.1:1900", "_udn": "uuid:75802409-bccb-40e7-9f6c-3481C4A93988", "_source": "search"}

As noted by @Jpsy, this problem is properly not solved. It is hard for me to reproduce this, as my router only advertises as a IGD1 device.

There is some code which tries to enforce the greatest version:

core/homeassistant/components/upnp/__init__.py

Lines 105 to 106 in d4615fd

    
           filtered = sorted(filtered, key=itemgetter("st"), reverse=True) 
        
           discovery_info = filtered[0]

My guess (pure speculation!) is that sometimes IGD2 is not discovered and IGD1 is used, which results in sensors with different names/ids and thus different sensors for home assistant. The screenshots shown by @Jpsy seem to show this.

I am uncertain what to do. Perhaps we can store the IGD-version and enforce this. I.e., if IGD2 does not respond then home assistant will report no device found/integration not ready and possibly try again later. Hopefully I can experiment with this during the weekend.

StevenLooman · 2020-04-07T19:10:49Z

@Jpsy can you open a new issue for this? You can use the text from this comment: #23728 (comment). Also please link to this issue.

dgomes · 2020-04-07T19:18:37Z

@StevenLooman what about keeping track of the version in the device registry ? Therefore enforcing you always use the same IGD version ?

StevenLooman · 2020-04-07T19:55:58Z

Storing the version somewhere was my plan indeed. The device registry seems the perfect place, thank you.

Jpsy · 2020-04-08T19:00:36Z

New issue opened: #33827

The new issue also contains my upnp-client search result.

The problem with creating that search was, that the upnp-client command is not available in the zsh of my add-on "SSH & Web Terminal". I had to run that command explicitly in a bash within the homeassistant docker container:

➜  ~ docker exec -it homeassistant bash                                   
bash-5.0# upnp-client search

flashydave · 2020-04-13T17:34:13Z

I am seeing the same issue on latest docker container stable version 107.5 with my Vodafone Vox3 router.
upnp-client search returns valid results.

StevenLooman · 2020-04-13T18:17:53Z

I am seeing the same issue on latest docker container stable version 107.5 with my Vodafone Vox3 router.
upnp-client search returns valid results.

Please report this in #33827 .

Do not that this is hopefully solved with #33108.

StevenLooman · 2020-04-13T18:18:19Z

@dgomes Can further comments be closed for this issue?

dgomes added the integration: upnp label May 9, 2019

ghost assigned robbiet480 May 9, 2019

StevenLooman mentioned this issue Jun 21, 2019

Upgrade to async_upnp_client==0.14.10 and increase search timeout #24685

Merged

7 tasks

fabaff closed this as completed in #24685 Jun 22, 2019

Jpsy mentioned this issue Apr 8, 2020

UPnP/IGD broken after restart in HA 0.107.7 #33827

Closed

home-assistant locked as resolved and limited conversation to collaborators Apr 13, 2020

UPnP Broken After Restart - 0.92.2 #23728

UPnP Broken After Restart - 0.92.2 #23728

Comments

chamberlain2007 commented May 6, 2019 • edited by dgomes Loading

dgomes commented May 9, 2019

ghost commented May 9, 2019

StevenLooman commented May 11, 2019

chamberlain2007 commented May 19, 2019

StevenLooman commented May 21, 2019

lweberru commented May 22, 2019

lweberru commented May 22, 2019

DavidFW1960 commented May 22, 2019

lweberru commented May 26, 2019

StevenLooman commented May 28, 2019

StevenLooman commented May 28, 2019

DavidFW1960 commented May 29, 2019

StevenLooman commented May 30, 2019

DavidFW1960 commented Jun 2, 2019

StevenLooman commented Jun 2, 2019 • edited Loading

DavidFW1960 commented Jun 2, 2019

lweberru commented Jun 19, 2019

StevenLooman commented Jun 19, 2019

lweberru commented Jun 19, 2019

StevenLooman commented Jun 22, 2019

Molodax commented Oct 29, 2019

StevenLooman commented Nov 1, 2019

Molodax commented Nov 1, 2019

StevenLooman commented Nov 2, 2019

Molodax commented Nov 6, 2019

StevenLooman commented Nov 10, 2019

StevenLooman commented Nov 10, 2019

Jpsy commented Mar 31, 2020 • edited Loading

StevenLooman commented Apr 2, 2020

Jpsy commented Apr 2, 2020

Jpsy commented Apr 3, 2020

StevenLooman commented Apr 5, 2020 • edited Loading

ObiKaiKenobi commented Apr 6, 2020 • edited Loading

Jpsy commented Apr 6, 2020 • edited Loading

ObiKaiKenobi commented Apr 7, 2020

StevenLooman commented Apr 7, 2020 • edited Loading

StevenLooman commented Apr 7, 2020

dgomes commented Apr 7, 2020

StevenLooman commented Apr 7, 2020 • edited Loading

Jpsy commented Apr 8, 2020

flashydave commented Apr 13, 2020

StevenLooman commented Apr 13, 2020

StevenLooman commented Apr 13, 2020

chamberlain2007 commented May 6, 2019 •

edited by dgomes

Loading

StevenLooman commented Jun 2, 2019 •

edited

Loading

Jpsy commented Mar 31, 2020 •

edited

Loading

StevenLooman commented Apr 5, 2020 •

edited

Loading

ObiKaiKenobi commented Apr 6, 2020 •

edited

Loading

Jpsy commented Apr 6, 2020 •

edited

Loading

StevenLooman commented Apr 7, 2020 •

edited

Loading

StevenLooman commented Apr 7, 2020 •

edited

Loading