DLNA Digital Media Renderer fails to connect to Cambridge Audio CXN V2 #70611

swedishlars · 2022-04-25T00:39:20Z

The problem

After upgrading HA Core to 2022.4.7 dlna_dmr fails to connect to my Cambridge Audio CXN v2 music streamer.
Errors point to async_upnp_client.aiohttp and dlna_dmr, so not sure which is the culprit.

What version of Home Assistant Core has the issue?

core-2022.4.7

What was the last working version of Home Assistant Core?

core-2022.3.8

What type of installation are you running?

Home Assistant Core

Integration causing the issue

DLNA Digital Media Renderer

Link to integration documentation on our website

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

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

Logger: async_upnp_client.aiohttp
Source: /srv/homeassistant/lib/python3.9/site-packages/async_upnp_client/aiohttp.py:247
First occurred: 00:45:52 (12 occurrences)
Last logged: 01:22:58

Failed to create HTTP server at fe80::96c6:91ff:feaf:dc87:0: [Errno 22] error while attempting to bind on address ('fe80::96c6:91ff:feaf:dc87', 0, 0, 0): invalid argument

Logger: homeassistant.components.dlna_dmr
Source: components/dlna_dmr/media_player.py:267
Integration: DLNA Digital Media Renderer (documentation, issues)
First occurred: 00:46:40 (4 occurrences)
Last logged: 01:22:58

Failed connecting to recently alive device at http://[fe80::9a5d:adff:fe6d:65d6%2]:8050/eb46d37a-e84e-426b-9ce1-6776cbc4a1b1/description.xml: UpnpServerOSError(None)

Additional information

Please let me know if I can be of any further help!

Regards, Lars

probot-home-assistant · 2022-04-25T00:39:26Z

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

probot-home-assistant · 2022-04-25T00:39:29Z

Hey there @StevenLooman, @chishm, mind taking a look at this issue as it has been labeled with an integration (dlna_dmr) you are listed as a code owner for? Thanks!
_{^{(message by CodeOwnersMention)}}

swedishlars · 2022-05-07T13:48:11Z

Updated homeassistant core to 2022.5.2 and now with async-upnp-client 0.29.0 all errors have gone away.
However created entity is unavailable. Perhaps same issue as #71306?

chishm · 2022-05-10T12:50:15Z

Thank you for the bug report. I'll continue working through this issue in #71306. Feel free to post any relevant logs here or there (I'll monitor both issue threads).

DazWorrall · 2022-05-10T13:04:31Z

I am having a similar problemm to this and #71306 - no IPv6 in my setup though, so I'll post my logs here. dmr is an LG TV, I can setup the integration and the media player is available for a few seconds, and then unavailable:

2022-05-10 13:55:17 DEBUG (MainThread) [homeassistant.components.dlna_dmr.config_flow] async_step_user: user_input: None
2022-05-10 13:55:17 DEBUG (MainThread) [homeassistant.components.dlna_dmr.config_flow] _get_discoveries
2022-05-10 13:55:20 DEBUG (MainThread) [homeassistant.components.dlna_dmr.config_flow] async_step_user: user_input: {'host': 'Some TV'}
2022-05-10 13:55:20 DEBUG (MainThread) [homeassistant.components.dlna_dmr.config_flow] _async_set_info_from_discovery: location: http://XXX.XXX.XXX.XXX:1224/, UDN: uuid:1b5f0efb-2c25-745a-b94d-cd4a76600271
2022-05-10 13:55:20 DEBUG (MainThread) [homeassistant.components.dlna_dmr.config_flow] _async_create_entry: location: http://XXX.XXX.XXX.XXX:1224/, UDN: uuid:1b5f0efb-2c25-745a-b94d-cd4a76600271
2022-05-10 13:55:20 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Setting up config entry: uuid:1b5f0efb-2c25-745a-b94d-cd4a76600271
2022-05-10 13:55:20 DEBUG (MainThread) [homeassistant.components.dlna_dmr] media_player.async_setup_entry 5444621243253ce6fa3c29eeed208711 (Some TV)
2022-05-10 13:55:20 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Connecting to device at http://XXX.XXX.XXX.XXX:1224/
2022-05-10 13:55:20 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Getting event handler for EventListenAddr(host='YYY.YYY.YYY.YYY', port=0, callback_url=None)
2022-05-10 13:55:20 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Started event handler at http://YYY.YYY.YYY.YYY:37635/notify
2022-05-10 13:55:20 DEBUG (MainThread) [homeassistant.components.dlna_dmr] SSDP SsdpChange.ALIVE notification of device uuid:1b5f0efb-2c25-745a-b94d-cd4a76600271::urn:schemas-upnp-org:device:MediaRenderer:1 at http://XXX.XXX.XXX.XXX:1224/
2022-05-10 13:55:30 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Device unavailable: UpnpActionResponseError('Error during async_call(), status: 500, upnp error: 606 (Action not authorized)')
2022-05-10 13:55:30 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Disconnecting from Some TV

2022-05-10 13:55:30 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Device unavailable: UpnpActionResponseError('Error during async_call(), status: 500, upnp error: 606 (Action not authorized)')

Seems to be the relevant problem for me, not having much luck getting more info searching around for that.

swedishlars · 2022-05-10T18:19:25Z

Only relevant warning I find in my log today is this:

Failed connecting to recently alive device at http://[fe80::9a5d:adff:fe6d:65d6%2]:8050/eb46d37a-e84e-426b-9ce1-6776cbc4a1b1/description.xml: UpnpConnectionError('[Errno 104] Connection reset by peer', None)

So by the looks of it same ipv6 issue as #71306 ?

chishm · 2022-05-11T12:57:14Z

@swedishlars: Interesting, it's a link-local IPv6 address that it's connecting to. When you enable debug logging for the dlna_dmr component (as described at #71306 (comment)), can you see what address it uses for the event handler (look for "Getting event handler" and "Started event handler"). A full log would be even more useful.

DazWorrall · 2022-05-11T13:24:57Z

@chishm should I start a new issue for my permission error above?

swedishlars · 2022-05-11T13:48:35Z

Hi, attached full debug log. It shows full restart of homeassistant core. Around time code 2022-05-11 14:28:42 is when I add and configure dlna_dmr integration.

dlna_dmr_debug_log.txt

Let me know if I can help with further tests/logs

swedishlars · 2022-05-12T21:11:07Z

Hi @chishm, In case it helps, sifting through my log I see 3 lines for "Getting event handler". "started event handler" follows the same pattern.

Line 244, the host ip here is the Intel Nuc hosting my homeassistant core instance:
2022-05-11 14:29:08 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Getting event handler for EventListenAddr(host='192.168.50.146', port=0, callback_url=None)

Line 366:
2022-05-11 14:30:38 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Getting event handler for EventListenAddr(host='fe80::96c6:91ff:feaf:dc87%eno1', port=0, callback_url=None)

Line 606:
2022-05-11 14:32:38 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Getting event handler for EventListenAddr(host='fe80::96c6:91ff:feaf:dc87%eno1', port=0, callback_url=None)

chishm · 2022-05-16T12:44:43Z

@swedishlars, This line looks the most significant to me:

2022-05-11 14:29:18 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Device unavailable: UpnpActionResponseError('Error during async_call(), status: 500, upnp error: 602 (Not implemented)')

Unfortunately I can't see what caused that. Could you please retry the logging with the additional setting of async_upnp_client.traffic: debug? This will get the lower level messages to/from all UPnP devices.

chishm · 2022-05-16T12:52:08Z

@DazWorrall: I'm beginning to suspect yours and @swedishlars' problems are related to initial polling of state variables. If you could try the async_upnp_client.traffic: debug log setting too, then that will confirm. No need to open a separate issue just yet.

swedishlars · 2022-05-16T19:48:19Z

@chishm First of all, thank you so much for dedicating time to this. I'm a developer myself so I know how time consuming this is.
I wish I could help more but upnp/dlna tcp networking is Greek to me. I've attached a startup log with async_upnp_client.traffic debug enabled.

Let me know if there is anything else I can help with!

dlna_dmr_debug_log_2.txt

chishm · 2022-05-17T12:43:02Z

First of all, thank you so much for dedicating time to this. I'm a developer myself so I know how time consuming this is.
I wish I could help more but upnp/dlna tcp networking is Greek to me.

You're welcome! I've only got a few DLNA devices, so I'm relying on other people to tell me when something doesn't work and to help diagnose the problem.

I've attached a startup log with async_upnp_client.traffic debug enabled.

Thank you for the newest debug log. This does appear to be the same problem as in #71306.

Let me know if there is anything else I can help with!

I'll have to submit a fix to async_upnp_client for this to get resolved. When I've got something I'm happy with, I might get you to test it out before it gets merged.

chishm · 2022-05-17T13:28:15Z

If you'd like to test this, could you please try pip installing git+https://github.com/chishm/async_upnp_client@7408798b5ddb49cae2fe004376a1cb87824031ab into your HA test environment and seeing if that resolves your issue? You'll need to start HA with --skip-pip, so that it doesn't reinstall the PyPI version of the package.

swedishlars · 2022-05-17T14:21:02Z

Can you check the link please? It comes up empty for me.

…

On Tue, 17 May 2022, 14:28 Michael Chisholm, ***@***.***> wrote: If you'd like to test this, could you please try pip installing git+ ***@***.*** into your HA test environment and seeing if that resolves your issue? You'll need to start HA with --skip-pip, so that it doesn't reinstall the PyPI version of the package. — Reply to this email directly, view it on GitHub <#70611 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/ATQTTXWGDG74ILUKTXA2JK3VKONH5ANCNFSM5UHAQ6GQ> . You are receiving this because you were mentioned.Message ID: ***@***.***>

swedishlars · 2022-05-18T01:25:24Z

@chism Ignore me, I found your [poll-variables-gracefully] branch

swedishlars · 2022-05-18T02:28:45Z

Hi, I pip installed you branch, fired up hass with --skip-pip. Unfortunately dlna_dmr entity is still unavailable.

Tried removing integration, adding back, testing both auto discovered dmr and also manually adding url to description.xml.
Integration and device is added fine by the looks of it. But entity refuses to show up I'm afraid. I have attached the resulting log.

dlna_dmr_debug_log_3.txt

chishm · 2022-05-18T11:13:27Z

Hi @swedishlars, I've had a look at that 3rd log, and I don't think you've got the specific commit installed. The way to do it is a bit complicated. You have to enter the hass virtual environment (something like source /path-to-hass-installation/bin/active), then use the pip command:

pip install 'git+https://github.com/chishm/async_upnp_client@7408798b5ddb49cae2fe004376a1cb87824031ab'

You should then get some output like:

Collecting git+https://github.com/chishm/async_upnp_client@7408798b5ddb49cae2fe004376a1cb87824031ab
  Cloning https://github.com/chishm/async_upnp_client (to revision 7408798b5ddb49cae2fe004376a1cb87824031ab) to /tmp/pip-req-build-sxywtu2g

swedishlars · 2022-05-18T12:14:55Z

Hi @chishm , that's what I did and everything looked ok to me. But let me try again and get back to you.

chishm · 2022-05-18T12:30:34Z

Ok. You should be able to tell if it's installed the right version by using grep -r 'poll missing action' /path-to-hass-installation/.

swedishlars · 2022-05-18T13:04:43Z

@chishm Tried this again, installed into my ha venv /srv/homeassistant. But I do not get a grep result with:
grep -r 'poll missing action' /srv/homeassistant

swedishlars · 2022-05-18T13:21:35Z

Hmm, not sure what I am doing wrong here...

When I run (in my venv):
pip install 'git+https://github.com/chishm/async_upnp_client@7408798b5ddb49cae2fe004376a1cb87824031ab'

I get:

Collecting git+https://github.com/chishm/async_upnp_client@7408798b5ddb49cae2fe004376a1cb87824031ab
Cloning https://github.com/chishm/async_upnp_client (to revision 7408798b5ddb49cae2fe004376a1cb87824031ab) to /tmp/pip-req-build-eql6e0we
Running command git clone --filter=blob:none --quiet https://github.com/chishm/async_upnp_client /tmp/pip-req-build-eql6e0we
Running command git rev-parse -q --verify 'sha^7408798b5ddb49cae2fe004376a1cb87824031ab'
Running command git fetch -q https://github.com/chishm/async_upnp_client 7408798b5ddb49cae2fe004376a1cb87824031ab
Running command git checkout -q 7408798b5ddb49cae2fe004376a1cb87824031ab
Resolved https://github.com/chishm/async_upnp_client to commit 7408798b5ddb49cae2fe004376a1cb87824031ab
Preparing metadata (setup.py) ... done
Requirement already satisfied: aiohttp>=3.7.4 in /srv/homeassistant/lib/python3.9/site-packages (from async-upnp-client==0.29.0) (3.8.1)
Requirement already satisfied: async-timeout<5.0,>=3.0 in /srv/homeassistant/lib/python3.9/site-packages (from async-upnp-client==0.29.0) (4.0.2)
Requirement already satisfied: defusedxml>=0.6.0 in /srv/homeassistant/lib/python3.9/site-packages (from async-upnp-client==0.29.0) (0.7.1)
Requirement already satisfied: python-didl-lite~=1.3.2 in /srv/homeassistant/lib/python3.9/site-packages (from async-upnp-client==0.29.0) (1.3.2)
Requirement already satisfied: voluptuous>=0.12.1 in /srv/homeassistant/lib/python3.9/site-packages (from async-upnp-client==0.29.0) (0.13.1)
Requirement already satisfied: attrs>=17.3.0 in /srv/homeassistant/lib/python3.9/site-packages (from aiohttp>=3.7.4->async-upnp-client==0.29.0) (21.2.0)
Requirement already satisfied: frozenlist>=1.1.1 in /srv/homeassistant/lib/python3.9/site-packages (from aiohttp>=3.7.4->async-upnp-client==0.29.0) (1.2.0)
Requirement already satisfied: aiosignal>=1.1.2 in /srv/homeassistant/lib/python3.9/site-packages (from aiohttp>=3.7.4->async-upnp-client==0.29.0) (1.2.0)
Requirement already satisfied: multidict<7.0,>=4.5 in /srv/homeassistant/lib/python3.9/site-packages (from aiohttp>=3.7.4->async-upnp-client==0.29.0) (6.0.2)
Requirement already satisfied: yarl<2.0,>=1.0 in /srv/homeassistant/lib/python3.9/site-packages (from aiohttp>=3.7.4->async-upnp-client==0.29.0) (1.7.2)
Requirement already satisfied: charset-normalizer<3.0,>=2.0 in /srv/homeassistant/lib/python3.9/site-packages (from aiohttp>=3.7.4->async-upnp-client==0.29.0) (2.0.12)
Requirement already satisfied: idna>=2.0 in /srv/homeassistant/lib/python3.9/site-packages (from yarl<2.0,>=1.0->aiohttp>=3.7.4->async-upnp-client==0.29.0) (3.3)
WARNING: You are using pip version 22.0.4; however, version 22.1 is available.
You should consider upgrading via the '/srv/homeassistant/bin/python3 -m pip install --upgrade pip' command.

pip show async-upnp-client gives:

Name: async-upnp-client
Version: 0.29.0
Summary: Async UPnP Client
Home-page: https://github.com/StevenLooman/async_upnp_client
Author: Steven Looman
Author-email: steven.looman@gmail.com
License: Apache 2
Location: /srv/homeassistant/lib/python3.9/site-packages
Requires: aiohttp, async-timeout, defusedxml, python-didl-lite, voluptuous
Required-by:

probot-home-assistant bot added the integration: dlna_dmr label Apr 25, 2022

probot-home-assistant bot assigned StevenLooman Apr 25, 2022

chishm mentioned this issue May 17, 2022

Gracefully handle bad Get* state variable actions StevenLooman/async_upnp_client#137

Merged

chishm mentioned this issue May 19, 2022

DLNA Digital Media Server integration Issue Failed to set up #71890

Closed

StevenLooman closed this as completed in StevenLooman/async_upnp_client#137 May 19, 2022

chishm mentioned this issue May 21, 2022

Update async-upnp-client to 0.30.0 #72269

Merged

22 tasks

github-actions bot locked and limited conversation to collaborators Jun 18, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

DLNA Digital Media Renderer fails to connect to Cambridge Audio CXN V2 #70611

DLNA Digital Media Renderer fails to connect to Cambridge Audio CXN V2 #70611

swedishlars commented Apr 25, 2022

probot-home-assistant bot commented Apr 25, 2022

probot-home-assistant bot commented Apr 25, 2022

swedishlars commented May 7, 2022

chishm commented May 10, 2022

DazWorrall commented May 10, 2022

swedishlars commented May 10, 2022

chishm commented May 11, 2022

DazWorrall commented May 11, 2022

swedishlars commented May 11, 2022

swedishlars commented May 12, 2022

chishm commented May 16, 2022

chishm commented May 16, 2022

swedishlars commented May 16, 2022

chishm commented May 17, 2022

chishm commented May 17, 2022

swedishlars commented May 17, 2022 via email

swedishlars commented May 18, 2022

swedishlars commented May 18, 2022 •

edited

Loading

chishm commented May 18, 2022

swedishlars commented May 18, 2022

chishm commented May 18, 2022

swedishlars commented May 18, 2022

swedishlars commented May 18, 2022

DLNA Digital Media Renderer fails to connect to Cambridge Audio CXN V2 #70611

DLNA Digital Media Renderer fails to connect to Cambridge Audio CXN V2 #70611

Comments

swedishlars commented Apr 25, 2022

The problem

What version of Home Assistant Core has the issue?

What was the last working version of Home Assistant Core?

What type of installation are you running?

Integration causing the issue

Link to integration documentation on our website

Diagnostics information

Example YAML snippet

Anything in the logs that might be useful for us?

Additional information

probot-home-assistant bot commented Apr 25, 2022

probot-home-assistant bot commented Apr 25, 2022

swedishlars commented May 7, 2022

chishm commented May 10, 2022

DazWorrall commented May 10, 2022

swedishlars commented May 10, 2022

chishm commented May 11, 2022

DazWorrall commented May 11, 2022

swedishlars commented May 11, 2022

swedishlars commented May 12, 2022

chishm commented May 16, 2022

chishm commented May 16, 2022

swedishlars commented May 16, 2022

chishm commented May 17, 2022

chishm commented May 17, 2022

swedishlars commented May 17, 2022 via email

swedishlars commented May 18, 2022

swedishlars commented May 18, 2022 • edited Loading

chishm commented May 18, 2022

swedishlars commented May 18, 2022

chishm commented May 18, 2022

swedishlars commented May 18, 2022

swedishlars commented May 18, 2022

swedishlars commented May 18, 2022 •

edited

Loading