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
71.14k stars 29.81k forks source link

Denon AVR integration fails with 403 error for all service calls #43049

Closed douglampe closed 3 years ago

douglampe commented 3 years ago

The problem

Denon AVR integration (denonavr) fails with 403 errors.

Environment

Problem-relevant configuration.yaml

media_player:
  - platform: denonavr
    host: 192.168.1.34
    zone1: true
    zone2: true

Traceback/Error logs

2020-11-10 17:31:23 ERROR (SyncWorker_4) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to POST command at end point /goform/AppCommand.xml
2020-11-10 17:31:23 ERROR (SyncWorker_4) [DenonAVR] Getting renamed and deleted sources failed.
2020-11-10 17:31:23 ERROR (SyncWorker_4) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-11-10 17:31:23 ERROR (ThreadPoolExecutor-0_1) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-11-10 17:31:23 ERROR (ThreadPoolExecutor-1_0) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXmlStatus.xml
2020-11-10 17:31:23 ERROR (ThreadPoolExecutor-1_1) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-11-10 17:31:25 ERROR (ThreadPoolExecutor-0_0) [DenonSSDP] During DenonAVR device identification, when trying to request http://192.168.1.34:8080/description.xml the following error occurred: HTTPConnectionPool(host='192.168.1.34', port=8080): Read timed out. (read timeout=2)
2020-11-10 17:31:25 ERROR (ThreadPoolExecutor-0_0) [DenonAVR] Unable to get device information of host 192.168.1.34, can not use the serial number as identification
2020-11-10 17:31:25 ERROR (ThreadPoolExecutor-2_1) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-11-10 17:31:25 ERROR (ThreadPoolExecutor-2_0) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXmlStatus.xml
2020-11-10 17:31:25 ERROR (SyncWorker_4) [DenonAVR] Missing status information from XML of Main for: Power, InputFuncSelect, Mute, MasterVolume
2020-11-10 17:31:30 ERROR (SyncWorker_4) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to POST command at end point /goform/AppCommand.xml
2020-11-10 17:31:30 ERROR (SyncWorker_4) [DenonAVR] Getting renamed and deleted sources failed.
2020-11-10 17:31:30 ERROR (SyncWorker_4) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to GET request at end point /goform/formZone2_Zone2XmlStatus.xml
2020-11-10 17:31:30 ERROR (ThreadPoolExecutor-4_0) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to GET request at end point /goform/formZone2_Zone2XmlStatus.xml
2020-11-10 17:31:32 ERROR (ThreadPoolExecutor-3_0) [DenonSSDP] During DenonAVR device identification, when trying to request http://192.168.1.34:8080/description.xml the following error occurred: HTTPConnectionPool(host='192.168.1.34', port=8080): Read timed out. (read timeout=2)
2020-11-10 17:31:32 ERROR (ThreadPoolExecutor-3_0) [DenonAVR] Unable to get device information of host 192.168.1.34, can not use the serial number as identification
2020-11-10 17:31:32 ERROR (ThreadPoolExecutor-5_0) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to GET request at end point /goform/formZone2_Zone2XmlStatus.xml
2020-11-10 17:31:32 ERROR (SyncWorker_4) [DenonAVR] Missing status information from XML of Zone2 for: Power, InputFuncSelect, Mute, MasterVolume
2020-11-10 17:31:37 ERROR (SyncWorker_4) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to POST command at end point /goform/AppCommand.xml
2020-11-10 17:31:37 ERROR (SyncWorker_4) [DenonAVR] Getting renamed and deleted sources failed.
2020-11-10 17:31:37 ERROR (SyncWorker_4) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to GET request at end point /goform/formZone3_Zone3XmlStatus.xml
2020-11-10 17:31:37 ERROR (ThreadPoolExecutor-7_0) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to GET request at end point /goform/formZone3_Zone3XmlStatus.xml
2020-11-10 17:31:39 ERROR (ThreadPoolExecutor-6_0) [DenonSSDP] During DenonAVR device identification, when trying to request http://192.168.1.34:8080/description.xml the following error occurred: HTTPConnectionPool(host='192.168.1.34', port=8080): Read timed out. (read timeout=2)
2020-11-10 17:31:39 ERROR (ThreadPoolExecutor-6_0) [DenonAVR] Unable to get device information of host 192.168.1.34, can not use the serial number as identification
2020-11-10 17:31:39 ERROR (ThreadPoolExecutor-8_0) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to GET request at end point /goform/formZone3_Zone3XmlStatus.xml
2020-11-10 17:31:39 ERROR (SyncWorker_4) [DenonAVR] Missing status information from XML of Zone3 for: Power, InputFuncSelect, Mute, MasterVolume
2020-11-10 17:31:54 ERROR (SyncWorker_8) [DenonAVR] Host 192.168.1.34 returned HTTP status code 403 to POST command at end point /goform/AppCommand.xml
2020-11-10 17:31:54 ERROR (SyncWorker_8) [DenonAVR] Getting renamed and deleted sources failed.

Additional information

Tried with both denon and denonavr platforms.

This seems to have started today. Restarted container to refresh some unrelated integrations and started seeing errors. State is not being updated in UI and cannot control input select, volume, etc.

douglampe commented 3 years ago

Denon iPhone app also appears to be failing. This may be an issue with the AVR and/or my network so will continue to troubleshoot on my end.

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

Hey there @scarface-4711, @starkillerog, mind taking a look at this issue as its been labeled with an integration (denonavr) you are listed as a codeowner for? Thanks! (message by CodeOwnersMention)

starkillerOG commented 3 years ago

@douglampe have you tried power cycling your AVR? This strongly looks like some problem with the actual physicall AVR or your network.

Besides the YAML config you posted is incorrect, denonavr uses config flow, so please remove the denonavr from your configuration.yaml and add it using the config flow (integrations page, it schould be discovered automatically).

douglampe commented 3 years ago

Ends up this was a local problem. I think there was a firmware update and unplugging and plugging in resolved the issue. As for the config, I was using denon and tried denonavr as I was troubleshooting.

ACrazyConcept commented 3 years ago

Ends up this was a local problem. I think there was a firmware update and unplugging and plugging in resolved the issue. As for the config, I was using denon and tried denonavr as I was troubleshooting.

Had the same issue. Power cycle reciever. Remove DenonAVR integration. Restart HA, Add DenonAVR integration. Working again.

planestoner commented 3 years ago

I also had the same issue. Denon iOS app was up the swanny too. Amp Power cycled off for 30secs. Restarted HA. Working again. Tres Bonne Rodney

douglampe commented 3 years ago

I might try disabling the integration for now to see if I stop having this issue with the app. I'm wondering if the AVR is considering the HA integration as a DDoS attack and shutting down the API. If it looks like the HA integration is somehow involved, I'll open a new issue. Otherwise, I am going to go with RS232 control instead of this integration. There is also another web API used by the built-in web server. Anything is better than cycling power.

JPHutchins commented 3 years ago

@douglampe I would like to know the outcome of your experiment if you have a chance. I am trying to pin down whether this was caused by a firmware update that broken the AVR 2016 API or if the denonavr library made a change that is causing the API to lock up. Thanks!

ACrazyConcept commented 3 years ago

Ends up this was a local problem. I think there was a firmware update and unplugging and plugging in resolved the issue. As for the config, I was using denon and tried denonavr as I was troubleshooting.

Had the same issue. Power cycle reciever. Remove DenonAVR integration. Restart HA, Add DenonAVR integration. Working again.

Status: I have had to power cycle my reciever (Marantz SR7013) about half a dozen times since. My Denon iOS remote app was also complaining. But I rarely use it so I can't be sure it is correlated.

douglampe commented 3 years ago

@JPHutchins I put a smart plug on the AVR because we rely too heavily on the integration and it seems to take about 24 hours for it to start throwing the 403s. I'll be off work after Christmas so maybe I will try removing the integration it then so I can be available for family tech support (AKA using the phone app).

kcTodd commented 3 years ago

I'm having similar issues with my Denon AVR-S740H but I started wondering if it's because I have a Logitech Harmony hub that is attached to the AVR. After all, the documentation does refer to such a problem (referring to a "URC" -- universal remote control).

I was seeing the same log entries reported by @douglampe so I then unplugged my Harmony hub and unplugged and plugged in my AVR. Now I'm not seeing those log entries and instead am seeing log entries like this:

2020-12-20 14:02:32 ERROR (MainThread) [homeassistant.helpers.entity] Update for media_player.denon_avr_s740h_2 fails Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 278, in async_update_ha_state await self.async_device_update() File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 474, in async_device_update raise exc File "/usr/local/lib/python3.8/concurrent/futures/thread.py", line 57, in run result = self.fn(*self.args, **self.kwargs) File "/usr/src/homeassistant/homeassistant/components/denonavr/media_player.py", line 144, in update self._receiver.update() File "/usr/local/lib/python3.8/site-packages/denonavr/denonavr.py", line 527, in update return bool(self._update_avr_2016()) File "/usr/local/lib/python3.8/site-packages/denonavr/denonavr.py", line 644, in _update_avr_2016 executor.submit(self._audyssey.update()) File "/usr/local/lib/python3.8/site-packages/denonavr/audyssey.py", line 109, in update self.dynamiceq = bool(int(param.text)) TypeError: int() argument must be a string, a bytes-like object or a number, not 'NoneType'

So it's not quite working again. I can turn on my AVR from HA but HA doesn't update the device status for the powered ON state. So I can't turn it off again.

So, for the others here, first consider if you have anything else attached to the network controller of the AVR such as a Harmony remote or hub. See if disconnecting that fixes the problem.

Hope this helps.

JPHutchins commented 3 years ago

@kcTodd This is a different issue that should be resolved with 2020.12.2 HA update (when it's out). See this thread for info: https://github.com/home-assistant/core/issues/44287

kcTodd commented 3 years ago

@kcTodd This is a different issue that should be resolved with 2020.12.2 HA update (when it's out). See this thread for info: #44287

Excellent. Thanks, @JPHutchins. Is it possible that my original issue (the log entries that were similar to those reported by @douglampe ) were caused by the Logitech Harmony hub?

JPHutchins commented 3 years ago

@kcTodd As a contributor to HA and denonavr, I would like to blame Logitech, URC, Denon, etc., but it is looking more likely that it is our fault lol - we have some fixes in the pipeline.

douglampe commented 3 years ago

Thanks @JPHutchins. FWIW, I am thinking about writing a for of the integration porting to use RS-232. It seems like that would be an extremely stable API and could also have lower latency.

JPHutchins commented 3 years ago

@douglampe I agree and I've been working on a library that uses the telnet interface (the commands are the same as RS 232 AFAIK.) I should be able to put it on github within a week.

ACrazyConcept commented 3 years ago

@douglampe I agree and I've been working on a library that uses the telnet interface (the commands are the same as RS 232 AFAIK.) I should be able to put it on github within a week.

I also use telnet for most commands. Extremely reliable. E.g. I made a volume control in node-red for an IKEA Symfonisk which would send MVUP or MVDOWN to the reciever with a frequency of 250ms. Just works. I don't know if the reciever or telnet has any hard limits, but the 250ms was not due to reaching any, but more so I wouldn't accidentally turn it up too much.

I had some issues getting the current audio mode, forgot which command it was though. But most likely it was me and not the reciever's fault.

douglampe commented 3 years ago

@JPHutchins @ACrazyConcept I finished my integration. This is my first custom component and first real project in python so I don't have any unit tests and the structure might not be great, but I wanted to get it working. I have switches you can setup for source selection (I was doing this with input_boolean before). You can also setup lights to keep things simple with Emulated Hue. Media Player is minimal and just supports power, volume, mute, and source select. There is also a sensor to help find codes/commands.

We should work together on creating a baseline TCP (telnet) client. Mine is a bit specific for the AVR but could easily use a base class for the read/write and just extend that for the AVR-specific logic I have. Likewise we can make my sensor, lights and switches generic for telnet too. If we used a factory to create the connection, we could handle telnet and serial with one client and then use that in the serial component and extend that to support the other entities.

JPHutchins commented 3 years ago

This is really great, I am eager to test! Sorry I was out of touch but I have been hard at work with this project, it's been a lot of fun! I'm afraid I've gotten into the weeds a bit. Take a look here: https://github.com/JPHutchins/pyavreceiver

There is no documentation yet so here is how to start it in async repl (needs python >= 3.8):

python3 -m asyncio
from pyavreceiver import factory
d = await factory("avr ip address")
await d.init()
d.power # see power status
d.set_power(True) # set power
d.main.volume # see volume
d.main.set_volume(-26)
d.main.set_volume_up()
d.main.volume

Of course this is using some "model matching" that is unproven. It's safer to init the device like so:

from pyavreceiver.denon.receiver import DenonReceiver
d = DenonReceiver("address")
await d.init()