core icon indicating copy to clipboard operation
core copied to clipboard

UPnP/IGD integration fails due to communication error

Open 1Argenteus opened this issue 2 years ago • 5 comments

The problem

There are some similar UPnP/IGD integartion issues, but I haven't seen this exact one.

My D-Link modem/router is auto detected, but immediately fails integration due to 'Unable to communicate iwth IGD at http://<modemIPaddress>:5556/DeviceDescription.xml; Retrying in background'.

No issues loading the XML directly.

What version of Home Assistant Core has the issue?

2022.8.1

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

uPnP

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?

Logger: homeassistant.config_entries
Source: config_entries.py:1031
First occurred: 22:06:00 (1 occurrences)
Last logged: 22:06:00

Config entry 'DSL-X1852E' for upnp integration not ready yet: Unable to communicate with IGD at: http://192.168.20.1:5556/DeviceDescription.xml; Retrying in background

Additional information

I've already set
homeassistant.components.upnp: debug in logger.

XML from the modem:

<root xmlns="urn:schemas-upnp-org:device-1-0">
<specVersion>
<major>1</major>
<minor>0</minor>
</specVersion>
<URLBase>http://192.168.20.1:5556</URLBase>
<device>
<deviceType>urn:schemas-upnp-org:device:InternetGatewayDevice:1</deviceType>
<friendlyName>DSL-X1852E</friendlyName>
<manufacturer>D-link</manufacturer>
<manufacturerURL>http://www.dlink.com</manufacturerURL>
<modelDescription>DSL-X1852E</modelDescription>
<modelName>DSL-X1852E</modelName>
<modelNumber>MDSL-X1852E</modelNumber>
<modelURL>http://www.dlink.com</modelURL>
<serialNumber>00000001</serialNumber>
<UDN>uuid:00000001-0000-0000-0000-001122446688</UDN>
<UPC>000000000001</UPC>
<iconList>
<icon>
<mimetype>image/png</mimetype>
<width>48</width>
<height>48</height>
<depth>8</depth>
<url>/Images/L48x48x8</url>
</icon>
<icon>
<mimetype>image/png</mimetype>
<width>32</width>
<height>32</height>
<depth>8</depth>
<url>/Images/L32x32x8</url>
</icon>
<icon>
<mimetype>image/png</mimetype>
<width>16</width>
<height>16</height>
<depth>8</depth>
<url>/Images/L16x16x8</url>
</icon>
</iconList>
<serviceList>
<service>
<serviceType>urn:schemas-upnp-org:service:Layer3Forwarding:1</serviceType>
<serviceId>urn:upnp-org:serviceId:L3Forwarding1</serviceId>
<SCPDURL>/L3Fwd.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?1</controlURL>
<eventSubURL>/sub?1</eventSubURL>
</service>
<service>
<serviceType>urn:dslforum-org:service:LANConfigSecurity:1</serviceType>
<serviceId>urn:upnp-org:serviceId:LANCfgSecurity2</serviceId>
<SCPDURL>/LanCfgSec.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?2</controlURL>
<eventSubURL>/sub?2</eventSubURL>
</service>
<service>
<serviceType>urn:dslforum-org:service:DeviceConfig:1</serviceType>
<serviceId>urn:upnp-org:serviceId:DeviceCfg3</serviceId>
<SCPDURL>/DeviceCfg.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?3</controlURL>
<eventSubURL>/sub?3</eventSubURL>
</service>
<service>
<serviceType>urn:dslforum-org:service:DeviceInfo:1</serviceType>
<serviceId>urn:upnp-org:serviceId:DeviceInfo4</serviceId>
<SCPDURL>/DeviceInfo.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?4</controlURL>
<eventSubURL>/sub?4</eventSubURL>
</service>
<service>
<serviceType>urn:dslforum-org:service:ManagementServer:1</serviceType>
<serviceId>urn:upnp-org:serviceId:LANMgmtSrv5</serviceId>
<SCPDURL>/LanMgmtSrv.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?5</controlURL>
<eventSubURL>/sub?5</eventSubURL>
</service>
<service>
<serviceType>urn:dslforum-org:service:Time:1</serviceType>
<serviceId>urn:upnp-org:serviceId:Time6</serviceId>
<SCPDURL>/Time.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?6</controlURL>
<eventSubURL>/sub?6</eventSubURL>
</service>
</serviceList>
<deviceList>
<device>
<deviceType>urn:schemas-upnp-org:device:WANDevice:1</deviceType>
<friendlyName>urn:schemas-upnp-org:device:WANDevice:1</friendlyName>
<manufacturer>Econet</manufacturer>
<manufacturerURL>http://www.mediatek.com</manufacturerURL>
<modelDescription>urn:schemas-upnp-org:device:WANDevice:1</modelDescription>
<modelName>urn:schemas-upnp-org:device:WANDevice:1</modelName>
<modelNumber>Econet</modelNumber>
<modelURL>http://www.mediatek.com</modelURL>
<serialNumber>00000001</serialNumber>
<UDN>uuid:00000002-0000-0000-0000-001122446688</UDN>
<UPC>000000000001</UPC>
<serviceList>
<service>
<serviceType>urn:schemas-upnp-org:service:WANCommonInterfaceConfig:1</serviceType>
<serviceId>urn:upnp-org:serviceId:WANCommonIFC7</serviceId>
<SCPDURL>/WanCommonIfc1.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?7</controlURL>
<eventSubURL>/sub?7</eventSubURL>
</service>
<service>
<serviceType>urn:dslforum-org:service:WANDSLInterfaceConfig:1</serviceType>
<serviceId>urn:upnp-org:serviceId:WANDslItfCfg8</serviceId>
<SCPDURL>/WanDslItfCfg.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?8</controlURL>
<eventSubURL>/sub?8</eventSubURL>
</service>
<service>
<serviceType>urn:dslforum-org:service:WANDSLConnectionManagement:1</serviceType>
<serviceId>urn:upnp-org:serviceId:WANDslCntMgmt9</serviceId>
<SCPDURL>/WanDslCntMgmt.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?9</controlURL>
<eventSubURL>/sub?9</eventSubURL>
</service>
</serviceList>
<deviceList>
<device>
<deviceType>urn:schemas-upnp-org:device:WANConnectionDevice:1</deviceType>
<friendlyName>urn:schemas-upnp-org:device:WANConnectionDevice:1</friendlyName>
<manufacturer>Econet</manufacturer>
<manufacturerURL>http://www.mediatek.com</manufacturerURL>
<modelDescription>urn:schemas-upnp-org:device:WANConnectionDevice:1</modelDescription>
<modelName>urn:schemas-upnp-org:device:WANConnectionDevice:1</modelName>
<modelNumber>Econet</modelNumber>
<modelURL>http://www.mediatek.com</modelURL>
<serialNumber>00000001</serialNumber>
<UDN>uuid:00000003-0000-0000-0000-001122446688</UDN>
<UPC>000000000001</UPC>
<serviceList>
<service>
<serviceType>urn:schemas-upnp-org:service:WANDSLLinkConfig:1</serviceType>
<serviceId>urn:upnp-org:serviceId:WANDSLLinkC10</serviceId>
<SCPDURL>/WanDslLink.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?10</controlURL>
<eventSubURL>/sub?10</eventSubURL>
</service>
<service>
<serviceType>urn:schemas-upnp-org:service:WANIPConnection:1</serviceType>
<serviceId>urn:upnp-org:serviceId:WANIPConn11</serviceId>
<SCPDURL>/WanIpConn.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?11</controlURL>
<eventSubURL>/sub?11</eventSubURL>
</service>
<service>
<serviceType>urn:dslforum-org:service:WANPPPConnection:1</serviceType>
<serviceId>urn:upnp-org:serviceId:WANPPPConn12</serviceId>
<SCPDURL>/WanPpp.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?12</controlURL>
<eventSubURL>/sub?12</eventSubURL>
</service>
</serviceList>
</device>
</deviceList>
</device>
<device>
<deviceType>urn:schemas-upnp-org:device:LANDevice:1</deviceType>
<friendlyName>urn:schemas-upnp-org:device:LANDevice:1</friendlyName>
<manufacturer>Econet</manufacturer>
<manufacturerURL>http://www.mediatek.com</manufacturerURL>
<modelDescription>urn:schemas-upnp-org:device:LANDevice:1</modelDescription>
<modelName>urn:schemas-upnp-org:device:LANDevice:1</modelName>
<modelNumber>Econet</modelNumber>
<modelURL>http://www.mediatek.com</modelURL>
<serialNumber>00000001</serialNumber>
<UDN>uuid:00000004-0000-0000-0000-001122446688</UDN>
<UPC>000000000001</UPC>
<serviceList>
<service>
<serviceType>urn:schemas-upnp-org:service:LANHostConfigManagement:1</serviceType>
<serviceId>urn:upnp-org:serviceId:LANHostCfg13</serviceId>
<SCPDURL>/LanHostCfgMgmt.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?13</controlURL>
<eventSubURL>/sub?13</eventSubURL>
</service>
<service>
<serviceType>urn:dslforum-org:service:WLANConfiguration:1</serviceType>
<serviceId>urn:upnp-org:serviceId:WLANCfg14</serviceId>
<SCPDURL>/WLanCfg.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?14</controlURL>
<eventSubURL>/sub?14</eventSubURL>
</service>
<service>
<serviceType>urn:dslforum-org:service:LANEthernetInterfaceConfig:1</serviceType>
<serviceId>urn:upnp-org:serviceId:LANEnetItfCfg15</serviceId>
<SCPDURL>/LanEnetItfCfg.xml</SCPDURL>
<controlURL>http://192.168.20.1:5556/ctrl?15</controlURL>
<eventSubURL>/sub?15</eventSubURL>
</service>
</serviceList>
</device>
</deviceList>
<presentationURL>http://192.168.20.1:80</presentationURL>
</device>
</root>```

1Argenteus avatar Aug 07 '22 12:08 1Argenteus

upnp documentation upnp source (message by IssueLinks)

Hey there @stevenlooman, @ehendrix23, 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! (message by CodeOwnersMention)

I got the same issue today with my sky router Config entry 'Sky ADSL Router' for upnp integration not ready yet: Device not discovered: uuid:1182868f-4624-468a-8f8a-148fe50151cb::urn:schemas-upnp-org:device:InternetGatewayDevice:1; Retrying in background.

I had the same issue a couple of weeks ago.
HA had just restarted following a system update so restarted the router to make sure a clean start Issue not solved in HA so tried to reload the integration but no fix. Restarted HA and now back up again

I notice that the integration had actually failed on the 2 days ago so adding an alert so I know when it fails. I plan to use this for determining if HA should restart the router in the event of network failure but have not yet got around to doing that.

snigehere avatar Aug 08 '22 13:08 snigehere

Thank you for the issue @1Argenteus. Can you add more to the logging configuration:

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

After that, can restart your Home Assistant installation, wait a while (to fill the logs) and let the upnp-component retry for some time, and post the logs here/mail them to me? Be aware that the logs can grow quite large, dependent on how many devices you have on your network.

StevenLooman avatar Aug 08 '22 17:08 StevenLooman

Find attached, @StevenLooman Logs.txt Approximately 30 minutes of logs.

1Argenteus avatar Aug 09 '22 22:08 1Argenteus

Thank you for the logs.

Your logs include lines like these, repeating over time:

2022-08-10 08:26:19.973 DEBUG (MainThread) [homeassistant.components.upnp] Getting traffic statistics from device: IGD Device: DSL-X1852E/uuid:00000001-0000-0000-0000-001122446688::urn:schemas-upnp-org:device:InternetGatewayDevice:1
2022-08-10 08:26:19.975 DEBUG (MainThread) [homeassistant.components.upnp] Getting status for device: IGD Device: DSL-X1852E/uuid:00000001-0000-0000-0000-001122446688::urn:schemas-upnp-org:device:InternetGatewayDevice:1
2022-08-10 08:26:20.051 DEBUG (MainThread) [homeassistant.components.upnp] Caught exception when updating device: IGD Device: DSL-X1852E/uuid:00000001-0000-0000-0000-001122446688::urn:schemas-upnp-org:device:InternetGatewayDevice:1, exception: Error during async_call(), status: 500, upnp error: 501 (Action Failed)
2022-08-10 08:26:20.051 DEBUG (MainThread) [homeassistant.components.upnp] Finished fetching DSL-X1852E data in 0.082 seconds (success: False)
2022-08-10 08:26:20.052 WARNING (MainThread) [homeassistant.config_entries] Config entry 'DSL-X1852E' for upnp integration not ready yet: Unable to communicate with IGD at: http://192.168.20.1:5556/DeviceDescription.xml; Retrying in background

The device was found earlier on the network:

2022-08-10 08:25:53.762 DEBUG (MainThread) [async_upnp_client.search] Received search response, USN: uuid:00000001-0000-0000-0000-001122446688::urn:schemas-upnp-org:device:InternetGatewayDevice:1, location: http://192.168.20.1:5556/DeviceDescription.xml

What happens is that Home Assistant tries to initialize the component, but fails due the device/router returning an error. It finds the router on your network (the log line above contains the discovery, it is saved and sent to the upnp component). Then, to be certain the router works as expected, it tries to do an update. I.e., it tries to get the values for the sensors such as traffic in bytes and traffic in packets. For some reason, the router returns a UPnP-error 501.

The UPnP spec says this about the 501 error: Error code: 501 Error Description: Description: Action Failed Is allowed to be returned if current state of service prevents invoking that action.

What this means is that your router is (unexpectedly) returning this error causing the upnp-component to fail. Some routers don't allow getting statistics like these at all. Some routers contains problems/bugs which prevents upnp working successfully. Other routers need to be configured to allow upnp-access, and block any upnp-communication otherwise.

What brand/model do you have? If other people experience the same problems, perhaps this issue can references/found. Also, can you check if your router has any settings regarding upnp, perhaps called IGD/Internet Gateway Device (the official name)?

StevenLooman avatar Aug 20 '22 17:08 StevenLooman

Also, perhaps you can try another program, such as UPnP Tester (in case you're running Windows.) I'm sure there are other programs as well in case you're running another Operating System.

As always, be careful what you download and run!

StevenLooman avatar Aug 20 '22 18:08 StevenLooman

I'm using a D-LInk DSL-X1852E, tested on the 1.0 and 1.11 firmware (released since this issue was opened). It's a pretty unfriendly interface! - No luck finding a IGD setting, UPNP is enabled. Access control is set to 'allow' all from the LAN (with 'Web', 'Telnet' and 'Ping' called out as specific options). However even with these, SSH isn't permitted (Telnet works).

UPnP Tester works and can pull some data - It seems to work with some commands (including being able to pull the router password! Good trick), but unfortunately I'm not sure what I'm looking for.

1Argenteus avatar Aug 31 '22 07:08 1Argenteus

(including being able to pull the router password! Good trick)

Interesting, that shouldn't be possible via UPnP I think?

UPnP Tester works and can pull some data

What kind of data? Are you able to pull the traffic counters, such as with the GetTotalBytesReceived action?

StevenLooman avatar Sep 05 '22 20:09 StevenLooman

(including being able to pull the router password! Good trick)

Interesting, that shouldn't be possible via UPnP I think?

Deviceinfo > Getinfo > x_GetAccess gives the output of my root password for the modem/router.

Don't ask me to explain it. :)

UPnP Tester works and can pull some data

What kind of data? Are you able to pull the traffic counters, such as with the GetTotalBytesReceived action?

Some things give expected results; many things give 'Error processing response (0x80040216)' or 'Action Request Failed (0x80040210)'

The firmware for this device is quite buggy, I wouldn't be surprised if it's non-compliant with the upnp standard. - I'd suggest the easiest solution to this problem is allowing home assistant to take what information it can get to complete configuration, rather than expecting specifics. Happy to keep troubleshooting however.

1Argenteus avatar Sep 11 '22 03:09 1Argenteus

Deviceinfo > Getinfo > x_GetAccess gives the output of my root password for the modem/router.

I don't see that option on my own router, thankfully.

I'd suggest the easiest solution to this problem is allowing home assistant to take what information it can get to complete configuration, rather than expecting specifics.

This is a possibility, but I'm afraid then there will be bug reports stating no data is provided by this integration. Let me think about it for a while...

StevenLooman avatar Sep 14 '22 15:09 StevenLooman