ol-iver / denonavr

Automation Library for Denon AVR receivers.
MIT License
176 stars 67 forks source link

Media_player entity not available after 0.118 upgrade #166

Closed mniquette closed 3 years ago

mniquette commented 3 years ago

I have a denon s730H that has been working fine through 0.117.6. When I upgraded to 0.118 I started the following errors in the log file and the media-player has become unavailable. This has also been reported by several other people on the HA message board in the past day.

Also the DenonAVR documentation page link to "edit the github" at the top of the page appears to be broken,.

Errors from the log: Missing status information from XML of Main for: Power, InputFuncSelect, Mute, MasterVolume 3:35:58 PM – /usr/local/lib/python3.8/site-packages/denonavr/denonavr.py (ERROR) - message first occurred at 9:42:07 AM and shows up 2122 times Host 192.168.1.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml 3:35:58 PM – /usr/local/lib/python3.8/site-packages/denonavr/denonavr.py (ERROR) - message first occurred at 9:42:05 AM and shows up 6369 times Getting renamed and deleted sources failed. 3:35:58 PM – /usr/local/lib/python3.8/site-packages/denonavr/denonavr.py (ERROR) - message first occurred at 9:42:05 AM and shows up 2122 times Host 192.168.1.34 returned HTTP status code 403 to POST command at end point /goform/AppCommand.xml 3:35:58 PM – /usr/local/lib/python3.8/site-packages/denonavr/denonavr.py (ERROR) - message first occurred at 9:42:05 AM and shows up 2122 times

ol-iver commented 3 years ago

There was no change of this library in HA 0.118. Did you update the Firmware of your receiver? Otherwise please restart it. This helps in many cases.

ScottJWhite commented 3 years ago

Well i suppose im not the only one, I've been getting a 403 error for the past week or so. Power cycling the receiver does fix the issue but after a day or 2 the error comes back.

mniquette commented 3 years ago

No i haven't updated the firmware. When was the last update to the integration? I will try restarting the unit and see where that takes things.

JPHutchins commented 3 years ago

I was thinking misclassification of the receivers causing them to point to the wrong endpoints. But it's hard to understand when both the /goform/AppCommand.xml and /goform/formMainZone_MainZoneXml.xml are getting 403.

Coincidentally, I am working on a project to provide a base class for AV receivers that gets "capabilities" from the receivers themselves instead of relying on the complex model number classification.

ol-iver commented 3 years ago

167 and this issue are not related. HA 0.118.2 is still using version 0.9.5

https://github.com/home-assistant/core/tree/0.118.2/homeassistant/components/denonavr Thus, we should discuss the audyssey issue there. I like to fix it rather than going back.

mniquette commented 3 years ago

Update. I reset my denon and HA as suggested. Over the past week I've lost connection two additional times. My s730H is hardwired to the network. Not sure where to go from here.

MoshiBin commented 3 years ago

I am also seeing this issue after updating Home Assistant to 0.118. My AVR was pointing to a defunct address as its DNS for a few months now, so it's unlikely that its firmware has been upgraded reently.

MoshiBin commented 3 years ago

Okay, hard-rebooting the AVR (by unplugging it, not using the remote) has solved the issue. For what it's worth, when the AVR was returning 403 for every request, I was also unable to control it from the Denon iOS app. Seems like a bug in the AVR firmware itself.

I'll see if this issue surfaces again like it has on mniquette's setup. If it does, I wonder if we're hitting some sort of rate limiting here.

JPHutchins commented 3 years ago

What we currently have planned is simply avoiding bombing the logs repeatedly - not really addressing the connectivity problem.

The origin of the issue remains a mystery since firmware update seems unlikely. I am wondering if it is caused by a request being sent repeatedly without timeout or backoff that is locking up the server on the AVR? I've had it happen to my X1500H a few weeks ago when I was simultaneously using the DenonAVR 2016 App, HA (denonavr.py), and UPnP commands. Efforts are being made to streamline the structure of requests and better conform to HA's expectations.

Tommatheussen commented 3 years ago

The theory about too many connections could indeed the cause. A couple of days ago I switched my Home Assistent HEOS integration from using the AVR as starting point, to another HEOS device I have connected. So far no issues yet hold wood Another thing I could think of, is the addition of the new 'Screen Saver' function they added for the 2020 lineup, maybe it's putting too many things to sleep? (Although that wouldn't explain the 403 errors...)

mandrill-pie commented 3 years ago

If this helps, I am facing a likely similar issue, but have not updated HA (I'm on 0.117.6) for quite some time. I have a Marantz SR5012 connected to the LAN by wire at IP 10.0.0.3. I get thousands of messages like:

2020-12-12 16:18:44 ERROR (SyncWorker_7) [DenonAVR] Host 10.0.0.3 returned HTTP status code 403 to POST command at end point /goform/AppCommand.xml                                                                                        
2020-12-12 16:18:44 ERROR (SyncWorker_7) [DenonAVR] Getting renamed and deleted sources failed.                                                                                                                                            
2020-12-12 16:18:44 ERROR (SyncWorker_7) [DenonAVR] Host 10.0.0.3 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml                                                                           
2020-12-12 16:18:44 ERROR (ThreadPoolExecutor-10290_1) [DenonAVR] Host 10.0.0.3 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml                                                             
2020-12-12 16:18:44 ERROR (ThreadPoolExecutor-10290_0) [DenonAVR] Host 10.0.0.3 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXmlStatus.xml                                                       
2020-12-12 16:18:44 ERROR (SyncWorker_7) [DenonAVR] Missing status information from XML of Main for: Power, InputFuncSelect, Mute, MasterVolume

While this happens, media player or any commands from HA interface do not work and state is not retrieved (does not matter if AVR is on or off). An important note, I think, using the "Marantz 2016 AVR Remote" app on my android phone detects the AVR but won't let me control it (stuck showing a loading spinner and goes back to a list of "Detected Marantz AVRs" after a while). So it doesn't necessarily feel like a denonavr integration or HA issue?

Marantz firmware is 4600-6195-8161-3085 with DTS version 3.90.50.00 (and AVR says this is the latest version). Power cycle (unplugging the power cord) temporarily fixes all issues (both HA and Remote app issues). I have not measured the time, but it feels like the problem reappears every day and it doesn't matter if I use the AVR at all or not (error appeared in logs while I was away on vacation and I have no automations that involve the AVR).

Hope this helps someone. DenonAVR is quite a helpful integration for me, btw; thanks were thanks are due

ol-iver commented 3 years ago

From my point of view many issues are related to the stability of Denon/Marrantz web interfaces. Which is not very good imho. Every interface which is simply returning a status should be easily able to handle 3 requests in 10 seconds. Unfortunately that's not the case here. Especially the HTTP POST interface seems to be quite unstable. We cannot change the receiver, thus I'll aggregate the different POST requests and remove parallel requests as a first measurement, to see what happens.

ol-iver commented 3 years ago

Ok, done. Reducing the number of POST calls was not that nice because AppCommand.xml responds with an error when a <tx> element contain more than 5 <cmd> elements. Funnily enough it accepts calls with multiple XML root elements. That's again really weird... I split up the <tx> tags into chunks, to be able to reduce the number of API calls. @JPHutchins could you please verify that this query returns an error

<?xml version="1.0" encoding="utf-8"?>
<tx>
    <cmd id="1">GetAllZonePowerStatus</cmd>
    <cmd id="1">GetAllZoneSource</cmd>
    <cmd id="1">GetAllZoneVolume</cmd>
    <cmd id="1">GetAllZoneMuteStatus</cmd>
    <cmd id="1">GetSurroundModeStatus</cmd>
    <cmd id="1">GetToneControl</cmd>
</tx>

and this one is working

<?xml version="1.0" encoding="utf-8"?>
<tx>
    <cmd id="1">GetAllZonePowerStatus</cmd>
    <cmd id="1">GetAllZoneSource</cmd>
    <cmd id="1">GetAllZoneVolume</cmd>
    <cmd id="1">GetAllZoneMuteStatus</cmd>
    <cmd id="1">GetSurroundModeStatus</cmd>
</tx>
<tx>
    <cmd id="1">GetToneControl</cmd>
</tx>

Another option could be removing the Audyssey update from the main update method. Afaik HA standard functions are not using it. Anyone using it in custom command could take care about calling the Audyssey update by himself.

JPHutchins commented 3 years ago

@scarface-4711 That is super clever! I noticed the same error as you but it never occurred to me to send multiple tx blocks! Another observation I've made is that the Denon API seems to prioritize some calls. For example, the bundle that Denon AVR 2016 issues every 1 second as a heartbeat has a short (8ms) response time whereas an update that mixes in other commands, like requesting tone control status, audyssey, etc can take up to 80m or even 300ms! Of course this is based on my observations with my one Denon receiver...

I can test these bundled commands on my X1500H and see what response times look like. Either way, making one request is just more manageable!

JPHutchins commented 3 years ago

@scarface-4711 Confirmed that the commands with multiple tx roots are working - also I got an excellent 1.8ms response time on that request.

Agree to remove audyssey update from the regular update method and add tone control into this bundle.

Another followup re: response time - I added "GetECO" to the second block and it works but response time was 300ms. Next time it's called the response goes back down to 3ms. So the Denon is doing some caching.

If I add an unsupported command: <cmd id="1">dsfdgd</cmd> it fails gracefully specifying an error for that command but returning the others as usual - no increase in response time.

This bundling should make it quite simple to add an aiohttp or other async update method.

Truly absurd that if fails on TX bundles larger than 5 but accepts multiple bundles!

chris669 commented 3 years ago

Almost same issue for me with my Marantz NR1508. It worked fine for a couple of days, then HA couldn't find it. Strange also my Marantz app couldn't connect too. What is even more strange is that the HEOS app is working perfectly. And the DENON HEOS in HA is working. I hard reseted my Marantz pushing the power button more than 2 seconds, uninstalled the 2 components on HA and then it discovered it again. But after one day and a reboot it stopped working again. It seems to create new instances like marantz_nr_1508_2, marantz_nr_1508_3 ...

ol-iver commented 3 years ago

@JPHutchins it is not the first time a Denon API surprised me 😅

I have some more changes on the way to async methods in mind. The number of attributes in the main class is very high and should be reduced and the whole thing could be restructured as it is grown over the time. It would be nice to support sync and async methods. I like httpx because it can handle both so there would be only one dependency for HTTP calls. As you said it should not be too complicated. Most of the tasks look like "Get data from an endpoint -> Save them"

chris669 commented 3 years ago

Something related to this? https://marantz-uk.custhelp.com/app/answers/detail/a_id/7254

stale[bot] commented 3 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.