search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
72.63k stars 30.4k forks source link

DLNA integration - YAS-209 become unavailable #70083

Closed itairaz1 closed 2 years ago

itairaz1 commented 2 years ago

The problem

Similar to https://github.com/home-assistant/core/issues/57240 Sometime my DLNA integration with my Yamaha YAS-209 become unavailable. Tuned on the debug log and before it become unavailable I see this line Device unavailable: UpnpConnectionError('[Errno None] Can not write request body for http://192.168.1.155:49152/upnp/control/rendertransport1', None) The IP replaced, and seemed correct.

Tried to remove and add back, but it didn't solve the issue

Thanks!

What version of Home Assistant Core has the issue?

core-2022.4.4

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

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?

No response

Additional information

No response

probot-home-assistant[bot] commented 2 years ago

dlna_dmr documentation dlna_dmr source (message by IssueLinks)

probot-home-assistant[bot] commented 2 years ago

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)

chishm commented 2 years ago

Thank you for the bug report. The other issue you linked was a bit tricky to diagnose, I was only able to do it from packet captures. Are you able to provide a packet capture for when the error occurs?

itairaz1 commented 2 years ago

Thanks @chishm for responding, Is there a convenient way to do that (build-in in HA?) to capture packets? or should I use my own sniffer? if I have to provide my own sniffer, do you have any recommendation how to do it, so I wouldn't miss any important data? If it will be easier, I can try perform manual requests to see the responses

chishm commented 2 years ago

I'm not aware of any sniffers built into HA, so in this case I'd recommend using Wireshark, or tcpdump if HA is running on a headless machine.

Running the capture on your HA machine, and capturing all traffic to/from the YAS-209, should be the best way to do this. I think you can use:

sudo tcpdump -i any -w /tmp/capture.pcap host 192.168.1.155

Where 192.168.1.155 is the IP address of your YAS-209 and /tmp/capture.pcap is the file that will be written.

While that is running, try getting HA to show the same problem (device becoming unavailable) using whatever steps you have previously. Perhaps try to play some media, or repeatedly change the volume.

itairaz1 commented 2 years ago

I'm not aware of any sniffers built into HA, so in this case I'd recommend using Wireshark, or tcpdump if HA is running on a headless machine.

Running the capture on your HA machine, and capturing all traffic to/from the YAS-209, should be the best way to do this. I think you can use:

sudo tcpdump -i any -w /tmp/capture.pcap host 192.168.1.155

Where 192.168.1.155 is the IP address of your YAS-209 and /tmp/capture.pcap is the file that will be written.

While that is running, try getting HA to show the same problem (device becoming unavailable) using whatever steps you have previously. Perhaps try to play some media, or repeatedly change the volume.

Thanks for the details I'm using Home Assistant OS, and I've tried to tcpdump in couple of method and it didn't capture the soundbar packages. I've looked on the web and didn't found a way to do that. Do you have any idea how to tcpdump in Home Assistant OS? Or maybe find another way? like put new logs, or use custom integration? I'm developer, I can try and help with that Here is the history showing the unavailability status change over the time (it happened independently of using the soundbar)

image

Thank you for all the effort

chishm commented 2 years ago

Sorry, I'm not familiar with Home Assistant OS. You may be able to install tcpdump on there following these instructions, then attach to the hassio Docker container's network in a similar way to the instructions here.

itairaz1 commented 2 years ago

I found a solution, I'm using SSH add on, but this add on uses hassio network, and I needed host network. I used Portainer in order to re-create the container with host network, and that solve the issue.

Attaching here the pcap file capture2.pcap.zip

Thanks!

chishm commented 2 years ago

This looks to be the same timing issue as before; the device is closing the TCP connection while HA is busy sending the next request on the same connection. I have an idea of something that should fix it, hopefully for good.

itairaz1 commented 2 years ago

This looks to be the same timing issue as before; the device is closing the TCP connection while HA is busy sending the next request on the same connection. I have an idea of something that should fix it, hopefully for good.

Thank you! Feel free to ask for assistant, I can test the fix when available, if needed.

chishm commented 2 years ago

I've made a fix to the async-upnp-client that should resolve this for you. Could you please test version 0.31.0 by pip installing async-upnp-client==0.31.0 inside your HA Docker container, then running HA with --skip-pip? It might be a bit tricky to do (I've never tried it within Docker before), but that should test the fix.

If all goes well, I'll submit a library bump pull request.

itairaz1 commented 2 years ago

I don't find a way to upgrade async-upnp-client. Stoping/restarting hass is killing the container

itairaz1 commented 2 years ago

Hi, thank you for the fix! it's seemed better now, here is a picture of the YAS history, and you can see clearly when HA was updated:

image

But now I have other, but, non-critical issue: every 10m the device become unavailable for a moment, with this debug log:

2022-06-15 21:16:31 DEBUG (MainThread) [homeassistant.components.dlna_dmr] SSDP SsdpChange.BYEBYE notification of device uuid:FFB8F002-B159-CD52-EBE5-CDCBFFB8F002::upnp:rootdevice at http://192.168.1.155:49152/description.xml
2022-06-15 21:16:31 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Disconnecting from YAS_209
2022-06-15 21:16:32 DEBUG (MainThread) [homeassistant.components.dlna_dmr] SSDP SsdpChange.ALIVE notification of device uuid:FFB8F002-B159-CD52-EBE5-CDCBFFB8F002::urn:schemas-upnp-org:device:MediaRenderer:1 at http://192.168.1.155:49152/description.xml
2022-06-15 21:16:32 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Connecting to device at http://192.168.1.155:49152/description.xml
2022-06-15 21:16:32 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Getting event handler for EventListenAddr(host='192.168.1.102', port=0, callback_url=None)
2022-06-15 21:16:32 DEBUG (MainThread) [homeassistant.components.dlna_dmr] Started event handler at http://192.168.1.102:45759/notify
image

Any idea?

StevenLooman commented 2 years ago

Your device is sending a notification that it will become unavailable with the SsdpChange.BYEBYE notification. This is what the UPnP Device Architecture says about it:

When a device and its services are going to be removed from the network, the device should multicast a ssdp:byebye message corresponding to each of the ssdp:alive messages it multicasted that have not already expired.

The next second it announces it is available/alive again with the SsdpChange.ALIVE notification. Is there any action you are doing which causes this?

itairaz1 commented 2 years ago

Sorry for the late answer - I re-checked and it seemed to be solved (not sure about the reason) Thank you for taking care!

chishm commented 2 years ago

I'm glad it's resolved, but a little worried it might happen again. If this should recur, please open a new issue and we might be able to get to the bottom of it.