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
71.06k stars 29.73k forks source link

denon integration broken #43670

Closed frankpol1972 closed 2 years ago

frankpol1972 commented 3 years ago

The problem

the services created for this DENON integration is not working anymore. don't know for sure if this was already in 0.118.0 but now i'm running 0.118.3 and power on power off is failing

Environment

Problem-relevant configuration.yaml

Traceback/Error logs

Logger: DenonAVR Source: /usr/local/lib/python3.8/site-packages/denonavr/denonavr.py:590 First occurred: 9:20:48 AM (3652 occurrences) Last logged: 7:29:22 PM

Missing status information from XML of Main for: Power, InputFuncSelect, Mute, MasterVolume

Additional information

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

denonavr documentation denonavr source (message by IssueLinks)

likellindil commented 3 years ago

I met with the same issue. It worked well without any problem until about one week ago. I have tried to delete and re-install the integration, re-power the amplifier, etc.. It just stops working after a period of time.

There is also the same issue with my Epson projector and Vacuum. It seems that all devices added via IP address won't work correctly now.

Fietspomp86 commented 3 years ago

Are you sure it's not like the other issues already posted? Apparently there was a firmware update last week and you need to power cycle your amplifier and remove and re-add the amp to Home Assistant. This worked for me and my X2500.

43049

43229

Sprakeloos commented 3 years ago

Not sure if it is related but my Denon keeps on filling the logfile with 403 errors. The solution in the other two mentioned issues, power cycle and reinstall integration, works only temporary for me.

Fietspomp86 commented 3 years ago

Not sure if it is related but my Denon keeps on filling the logfile with 403 errors. The solution in the other two mentioned issues, power cycle and reinstall integration, works only temporary for me.

Yes that's what I had as well, continues 403, I was already wondering why my automations regarding the receiver weren't working. Removed power for a few minutes and re-adding to HASS worked for me

frankpol1972 commented 3 years ago

I can confirm this works, after unplug the power and replug this, the control of the receiver returns.

Thanks

Sprakeloos commented 3 years ago

Did the unplug twice last week after which control returned but for me it's only a temporary fix. After some time the 403's are back again but haven't found out yet what triggers it. Will try another unplug this weekend, last one was with 0.118.3 and haven't tried with 0.118.4 yet.

likellindil commented 3 years ago

I don't know why but today I tried to recycle the power and re-install the integration and it worked well this time. I will see how long it could last this time.

doug-hoffman commented 3 years ago

I'm seeing this on a X8500H with firmware 7000-6144-5161-3085 and HA 0.118.2:

2020-11-30 14:57:39 ERROR (SyncWorker_0) [DenonAVR] Host 192.168.123.45 returned HTTP status code 403 to POST command at end point /goform/AppCommand.xml
2020-11-30 14:57:39 ERROR (SyncWorker_0) [DenonAVR] Getting renamed and deleted sources failed.
2020-11-30 14:57:39 ERROR (SyncWorker_0) [DenonAVR] Host 192.168.123.45 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-11-30 14:57:39 ERROR (ThreadPoolExecutor-1_1) [DenonAVR] Host 192.168.123.45 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-11-30 14:57:39 ERROR (ThreadPoolExecutor-2_0) [DenonAVR] Host 192.168.123.45 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXmlStatus.xml
2020-11-30 14:57:39 ERROR (ThreadPoolExecutor-2_1) [DenonAVR] Host 192.168.123.45 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-11-30 14:57:41 ERROR (ThreadPoolExecutor-1_0) [DenonSSDP] During DenonAVR device identification, when trying to request http://192.168.123.45:8080/description.xml the following error occurred: HTTPConnectionPool(host='192.168.123.45', port=8080): Read timed out. (read timeout=2)
2020-11-30 14:57:41 ERROR (ThreadPoolExecutor-1_0) [DenonAVR] Unable to get device information of host 192.168.123.45, can not use the serial number as identification
2020-11-30 14:57:41 ERROR (ThreadPoolExecutor-3_0) [DenonAVR] Host 192.168.123.45 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXmlStatus.xml
2020-11-30 14:57:41 ERROR (ThreadPoolExecutor-3_0) [DenonAVR] Host 192.168.123.45 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-11-30 14:57:41 ERROR (SyncWorker_0) [DenonAVR] Missing status information from XML of Main for: Power, InputFuncSelect, Mute, MasterVolume

Have power cycled probably 5-10 times over the past few weeks, but the problem always comes back. I'll try to remove the integration, power cycle, then re-configure it, to see if that is any more permanent.

Fietspomp86 commented 3 years ago

I'm not sure what the correct sequence is, but I definitely removed the integration, power off for 5 minutes, power on, restart home assistant and added integration again.

It's now working fine for over 2 days, let's hope it stays this way.

Tommatheussen commented 3 years ago

For me it has been working on and off for the last week, I still have yet to find why this is happening, at first I thought it was due to using the HEOS integration, and too many connections being open at the same time (2 android devices and an iOS device using the HEOS app and then Home Assistant as well), but so far I can't seem to replicate it...

ofeksit commented 3 years ago

I have Denon 3600h and it's not working too.... When I unplug and plug back the AVR it goes back to work but after couple of days it gets off.

Any suggestions?

matejdro commented 3 years ago

Yeah, receiver reboot is only a temporary fix. Issue comes back after couple of days.

Are there any known workarounds that do not involve physical access to the receiver? So I could set up an automation to reset the integration or something every couple of days.

Note to developers of the integration: other Denon protocol that emulates RS-232 over ethernet seems to still work fine, so maybe addon could be transitioned to that?

grantclem commented 3 years ago

+1

dennisbakhuis commented 3 years ago

I have a Denon avr-x2700h and can confirm that the power-cycle method solves the issue only temporarily. On very random moments, it loses connection and the log is flooded with errors. A notable error is:

No connection to /goform/AppCommand.xml end point on host 192.168.1.11

The receiver is reachable using the regular web-interface.

I have also mentioned this, including a couple of others in the community forum: link.

I am on the latest Home-Assistant (0.118.4) in Docker on a NUC.

I found a github issue that mentions Appcommand.xml but I am not yet sure if that merge is included in the latest release: issue

Fietspomp86 commented 3 years ago

Yes same here again. Has been working for 5 days straight, but this morning started throwing errors again:

2020-12-05 11:44:07 ERROR (ThreadPoolExecutor-130115_1) [DenonAVR] No connection to /goform/AppCommand.xml end point on host 192.168.1.XX
2020-12-05 11:44:07 ERROR (ThreadPoolExecutor-130115_1) [DenonAVR] Getting tone control failed.

Removed power of receiver and put back after 1 minute or so, working again. Didn't need to remove integration or restart Home Assistant.

Guess I'll just put one of my energy plugs behind it and switch it off every night for a minute, until it's fixed.

Sprakeloos commented 3 years ago

Did a reset last Sunday and it worked without a problem the whole week until I just now restarted HA after updating to 0.118.5 It's 403 all over again on several xml files. Web interface of the receiver is functioning in a browser though.

DanielNL commented 3 years ago

Same issues here, started after updating from 0.116.4 to 0.118.5. Checked the firmware on my Denon AVR-S950H and it has been auto updated to a version from mid november.

First visible error in my log:

During DenonAVR device identification, when trying to request http://192.168.1.20:8080/description.xml the following error occurred: HTTPConnectionPool(host='192.168.1.20', port=8080): Read timed out. (read timeout=2)

After which i get the same errors as already stated.

Edit:

I just downgraded HA to 0.116.4 through a snapshot i had and the problem persisted. I guess the cause lies with the firmware upgrade on the receiver.

FransTwisk commented 3 years ago

Same here on my new Denon X3700H. Also hard to say if it happened after a Home Assistant update or firmware upgrade of Denon, but like @DanielNL tested: it's probably a change on Denon's side...

2020-12-07 17:45:49 WARNING (MainThread) [homeassistant.components.media_player] Updating denonavr media_player took longer than the scheduled update interval 0:00:10
2020-12-07 17:45:49 ERROR (ThreadPoolExecutor-236143_0) [DenonAVR] No connection to /goform/AppCommand.xml end point on host 192.168.0.20
2020-12-07 17:45:49 ERROR (SyncWorker_21) [DenonAVR] Update failed.
2020-12-07 17:45:49 ERROR (ThreadPoolExecutor-236143_1) [DenonAVR] No connection to /goform/AppCommand.xml end point on host 192.168.0.20
2020-12-07 17:45:49 ERROR (ThreadPoolExecutor-236143_1) [DenonAVR] Getting tone control failed.

In more information is needed, I'm happy to provide.

nkempe commented 3 years ago

Same issue with Denon X3500H. Firmware Version | 2600-8113-8161-3085

I'd be happy to help test things or submitting bugs at Denon, as it seems to me that their update caused these issues. Unfortunately I don't know what exactly to tell them other than "I think you guys broke the Home Assistant integration!". :)

(If their official app development reflects the firmware we might need a lot of patience though)

ricarva commented 3 years ago

Just chiming in: same issues here, but probably due to mid-November Denon firmware update.

It has broken not only the HA integration, but Denon's own AVR Remote app. When this bug kicks in, the app also becomes unable to connect to the AVR.

JPHutchins commented 3 years ago

If anyone can tryout the changes in #44159 that'd be great! It does not resolve the root of the problem, which I now believe to be a firmware update, but it is intended to silence the log messages after providing the advice to power cycle the receiver.

I am working on a base class for UPnP capable receivers that seeks to provide a unified async interface for all AVRs. The repository is not up yet but I have a PR here, a necessary dependency, if anyone has time to take a look.

Ideally the use of UPnP pub/sub and asyncio can reduce or eliminate polling IO and result in a more resilient platform.

matejdro commented 3 years ago

It has broken not only the HA integration, but Denon's own AVR Remote app. When this bug kicks in, the app also becomes unable to connect to the AVR.

Is it possible that their app just never triggers the bug? If not, it could mean that it will potentially never get fixed, so we might need to find the trigger and prevent it.

JPHutchins commented 3 years ago

@matejdro @ricarva My only other theory has to do with this addition from two months ago. In order to update state multiple requests are made. The change linked below does so using a thread pool so that it's parallel. In HA this means that this bundle of requests is executed every 10 seconds.

https://github.com/scarface-4711/denonavr/commit/a473168e7fbcbda24137cf62cf96c01f98a06728#diff-c3f890d1b2ff64f5cd27d1f7fd2500e269560b37acf9babbdf66f3ef7aed3a29L648-R660

Unless the Denon API is handling requests in a multi threaded manner I don't see much reason for this - the bottle neck is the Denon API and it will still be the Denon API regardless of how fast we make requests.

Looks like this was included first in the Oct 2 release of denonavr, 0.9.5 also bumped and merged into HA on Oct 2. Not sure when that made it to HA release. https://github.com/home-assistant/core/pull/41058

@DanielNL - 116.4 might not have been before the change I am talking about.

Sanity check: Denon did issue firmware updates mid November and updated release notes for DenonAVR 2016 mentioning "power cycle the receiver".

ricarva commented 3 years ago

@matejdro and @JPHutchins

Is it possible that their app just never triggers the bug? If not, it could mean that it will potentially never get fixed, so we might need to find the trigger and prevent it.

Perhaps, though I'm more inclined to this being due to a change in Denon's November update. I could try deleting the HA integration for a couple of weeks and pinging the AVR only with the Denon AVR Remote app to try and test.

If this was being triggered by HA, it might align with JP's theory above, so it might indeed warrant a test anyway.

What I have noticed, though, is that this issue seems to popup at random, yes, but after a specific event: it only seems to happen on putting the AVR into Standby. I've witnessed this twice: once by sheer coincidence, and the last time by checking my AVR integration systematically on every shutdown. This last time the error messages started showing up in HA right after setting the AVR to standby, and I couldn't bring it back without a power cycle. Could you guys also keep an eye out for this?

A related question: how do you guys turn off your AVR? Through HA, IR remote, HDMI CEC, or directly at the AVR button?

For reference, there are "Restart" and "Network Reset" procedures available for Denon AVRs, and I might also try those next time this issue happens: "Restart" might be an option to power cycling, and "Network Reset" could help in clearing some kind of settings error that might be leading to this. Again, this needs testing.

Any thoughts on how we can debug this further?

matejdro commented 3 years ago

requests is executed every 10 seconds

Wow that sounds like a pretty aggressive polling. Denon receivers also have telnet protocol that pushes all events in real time. Maybe addon could be migrated to this? I will have some more free time after a week or so, I can help with the migration then if you want.

JPHutchins commented 3 years ago

The official Denon AVR 2016 app makes multiple requests for updated state every 1 second based on my packet sniffing. I am not aware that the telnet protocol pushes state Connected via telnet now and see state push - the denon (rather than denonavr) integration uses telnet. This would be huge since we have documentation that can be parsed to generate every possible telnet command. Since it's telnet I would like to add some QoS. I will be modeling the schema of this library: https://github.com/andrewsayre/pyheos

To their credit, Denon does do a good job of maintaining backwards compatibility.

doug-hoffman commented 3 years ago

@matejdro There is already an integration that implements the serial protocol over tcp: https://www.home-assistant.io/integrations/denon/.

I've used the denon integration in the past with a 4308CI and for a short while on the X8500H, until I realized there was a better integration, and it needs work. It breaks when the volume level isn't an integer. It also breaks when there is output received other than the response to a command it issues, such as changing volume levels drastically from the IR remote. It wasn't unusual for the volume in HA to be wrong or the state to be "off" for short periods while it was actually on. And, on models that support using the MultiEQ app for Audyssey, you have to disable the denon integration to do Audyssey calibrations.

I never got around to seeing what it would take to fix – but that will need done, if you want it to be reliable.

matejdro commented 3 years ago

Huh I did not realize that. Thanks, will take a look at this integration and possibly fix some issues.

doug-hoffman commented 3 years ago

After 2 weeks, I finally experienced another failure of the integration while restarting Home Assistant and had been capturing packets at the time. Initial analysis points at the integration as the trigger for the AVR failing, for two reasons: 1) since all requests made by the integration except the final round prior to until restarting HA were successful, and 2) the final round of requests was terminated by the integration (TCP FIN) before receiving a response, which seems to have put the web server on port 8080 in a bad state (wireshark was failing to correctly reassemble packets, for a yet unknown reason, that made it appear as though there was no response to some of the final connections until reassembly was disabled).

Prior to restarting, the integration was making a burst of 6 requests every 10 seconds, all resulting in 200 OKs. Comparing the final round of requests that failed against the penultimate round that succeeded didn't yield any obvious difference.

After HA restarted, the integration was unable to successfully complete requests against port 8080, and began POSTing on port 80 instead. Presumably, this is due to a failure of the model detection logic in denonavr that depends on successfully retrieving "/goform/Deviceinfo.xml" on port 8080, which it couldn't.

At this point, restarting the AVR alone was insufficient – the integration continued to use port 80 in error. I also had to restart HA to force the integration to reattempt model detection (reloading the integration likely would have had the same outcome).

JPHutchins commented 3 years ago

@doug-hoffman Excellent analysis and absolutely stunning that you had packet capture going! Your insight around the port 80 thing is accurate - in the failed state even the Device Info does not respond. Technically we can get it from the UPnP on port 60006 but that's a whole other story...

@scarface-4711 I would like to propose rolling back the addition of Audyssey parameters as well as starting a conversation around the execution of the update requests in parallel. I noticed also that we changed some timeout parameters? This is a pain and I am happy to help with PRs and testing - I realize I am proposing rolling back several versions.

If this is triggered by a HA restart it kinda sounds like "more than 6 requests" might get blasted out on the HA restart? Like initialization and first update. Which makes me wonder if the Denon API is storing a buffer of requests as it receives them and we are managing to fill it by sending requests without waiting for previous response? If this theory is correct then it may be that adding the Audyssey update call was simply the straw that broke the camel's back but not the real root of the problem.

I will try to test by blasting a bunch of requests simultaneously to see if I can break mine.

doug-hoffman commented 3 years ago

@JPHutchins I only ever saw 6 requests within a second over the several days I captured, and even in the final round before the restart. Actually, the final round was sent in two chunks – 3 requests, followed by a 10 second gap, followed by 3 requests. None of the final 6 requests got a response from the AVR.

doug-hoffman commented 3 years ago

Captured another AVR failure while restarting HA today. The AVR worked up until the last round of requests then failed. In the last round, 3 of the 6 requests succeeded this time (alternating success/failure with the first succeeding). No obvious explanation for why each failed and succeeded.

I'm not sure what's different about the two HA restarts yesterday and today. I've been making tons of config changes lately (restarting at least once daily for the past two weeks) and not seen any other crashes in that time. My gut says some sort of timing issue with HA shutdown that makes the integration sometimes do things that make the AVR unhappy. I'm only capturing to/from the AVR IP – it's possible the problem is some broadcast/multicast being sent from HA/integration during shutdown, so I'll expand my filter.

I can confirm cycling power and reloading the integration is sufficient to recover from the problem.

ricarva commented 3 years ago

@doug-hoffman and @JPHutchins

While you're going down this rabbit hole, something I've found and that might make recovering from the problem slightly more user-friendly: instead of power-cycling the AVR, just put it to standby and then press and hold the standby button until "Restart" shows up on the display. There might even be an alternative to reloading the integration after that, but I still have to make sure it's actually a thing.

JPHutchins commented 3 years ago

@ricarva Good insight - I can confirm that this is a functionality available on most brands and models of receiver - it is effectively the same as pulling the plug.

ricarva commented 3 years ago

@doug-hoffman, @JPHutchins, have you been able to get any more insight into this?

doug-hoffman commented 3 years ago

@ricarva, not yet. Still waiting for the issue to be triggered since I've broadened the capture filter. Five restarts since my last comment, zero occurrences. Until someone can figure out how to reliably trigger it on demand, it's a bit of a waiting game.

JPHutchins commented 3 years ago

I was not able to trigger it sending out sequences of 2,000 updates (which includes all 6 requests) with 50 in parallel. And this was repeated 50 times over a few hours never getting the receiver into the "locked" state. I was able to observe the endpoints taking longer to reply (up to 3 seconds).

doug-hoffman commented 3 years ago

Finally, another crash. In an attempt to gather more info, I sandwiched nginx between HA and the AVR. Here are the last few requests seen by nginx toward the avr on port 8080:

192.168.123.45 - - [23/Dec/2020:14:30:04 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 216 "-" "python-requests/2.25.0" 0.002 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetToneControl</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<status>0</status>\x0A<adjust></adjust>\x0A<basslevel></basslevel>\x0A<bassvalue></bassvalue>\x0A<treblelevel></treblelevel>\x0A<treblevalue></treblevalue>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:05 -0500] "POST /goform/AppCommand0300.xml HTTP/1.1" 200 301 "-" "python-requests/2.25.0" 0.064 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x223\x22><name>GetAudyssey</name><list><param name=\x22dynamiceq\x22 /><param name=\x22reflevoffset\x22 /><param name=\x22dynamicvol\x22 /><param name=\x22multeq\x22 /></list></cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<name>GetAudyssey</name>\x0A<list>\x0A<param name=\x22dynamiceq\x22 control=\x222\x22>1</param>\x0A<param name=\x22reflevoffset\x22 control=\x222\x22>0</param>\x0A<param name=\x22dynamicvol\x22 control=\x222\x22>0</param>\x0A<param name=\x22multeq\x22 control=\x222\x22>3</param>\x0A</list>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:05 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 868 "-" "python-requests/2.25.0" 0.064 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetAllZonePowerStatus</cmd><cmd id=\x221\x22>GetAllZoneSource</cmd><cmd id=\x221\x22>GetAllZoneVolume</cmd><cmd id=\x221\x22>GetAllZoneMuteStatus</cmd><cmd id=\x221\x22>GetSurroundModeStatus</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<zone1>OFF</zone1>\x0A<zone2>OFF</zone2>\x0A<zone3>OFF</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<source>MPLAY</source>\x0A</zone1>\x0A<zone2>\x0A<source>MPLAY</source>\x0A</zone2>\x0A<zone3>\x0A<source>NET</source>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<volume>-25.0</volume>\x0A<state>variable</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-25.0dB</dispvalue>\x0A</zone1>\x0A<zone2>\x0A<volume>0</volume>\x0A<state>fixed</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>0dB</dispvalue>\x0A</zone2>\x0A<zone3>\x0A<volume>-40</volume>\x0A<state>variable</state>\x0A<limit>-10.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-40dB</dispvalue>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>off</zone1>\x0A<zone2>off</zone2>\x0A<zone3>off</zone3>\x0A</cmd>\x0A<cmd>\x0A<surround>Multi In + DSur                                                </surround>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:05 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 868 "-" "python-requests/2.25.0" 0.001 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetAllZonePowerStatus</cmd><cmd id=\x221\x22>GetAllZoneSource</cmd><cmd id=\x221\x22>GetAllZoneVolume</cmd><cmd id=\x221\x22>GetAllZoneMuteStatus</cmd><cmd id=\x221\x22>GetSurroundModeStatus</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<zone1>OFF</zone1>\x0A<zone2>OFF</zone2>\x0A<zone3>OFF</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<source>MPLAY</source>\x0A</zone1>\x0A<zone2>\x0A<source>MPLAY</source>\x0A</zone2>\x0A<zone3>\x0A<source>NET</source>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<volume>-25.0</volume>\x0A<state>variable</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-25.0dB</dispvalue>\x0A</zone1>\x0A<zone2>\x0A<volume>0</volume>\x0A<state>fixed</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>0dB</dispvalue>\x0A</zone2>\x0A<zone3>\x0A<volume>-40</volume>\x0A<state>variable</state>\x0A<limit>-10.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-40dB</dispvalue>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>off</zone1>\x0A<zone2>off</zone2>\x0A<zone3>off</zone3>\x0A</cmd>\x0A<cmd>\x0A<surround>Multi In + DSur                                                </surround>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:05 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 216 "-" "python-requests/2.25.0" 0.002 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetToneControl</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<status>0</status>\x0A<adjust></adjust>\x0A<basslevel></basslevel>\x0A<bassvalue></bassvalue>\x0A<treblelevel></treblelevel>\x0A<treblevalue></treblevalue>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:05 -0500] "POST /goform/AppCommand0300.xml HTTP/1.1" 200 301 "-" "python-requests/2.25.0" 0.062 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x223\x22><name>GetAudyssey</name><list><param name=\x22dynamiceq\x22 /><param name=\x22reflevoffset\x22 /><param name=\x22dynamicvol\x22 /><param name=\x22multeq\x22 /></list></cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<name>GetAudyssey</name>\x0A<list>\x0A<param name=\x22dynamiceq\x22 control=\x222\x22>1</param>\x0A<param name=\x22reflevoffset\x22 control=\x222\x22>0</param>\x0A<param name=\x22dynamicvol\x22 control=\x222\x22>0</param>\x0A<param name=\x22multeq\x22 control=\x222\x22>3</param>\x0A</list>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:15 -0500] "POST /goform/AppCommand0300.xml HTTP/1.1" 200 301 "-" "python-requests/2.25.0" 0.063 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x223\x22><name>GetAudyssey</name><list><param name=\x22dynamiceq\x22 /><param name=\x22reflevoffset\x22 /><param name=\x22dynamicvol\x22 /><param name=\x22multeq\x22 /></list></cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<name>GetAudyssey</name>\x0A<list>\x0A<param name=\x22dynamiceq\x22 control=\x222\x22>1</param>\x0A<param name=\x22reflevoffset\x22 control=\x222\x22>0</param>\x0A<param name=\x22dynamicvol\x22 control=\x222\x22>0</param>\x0A<param name=\x22multeq\x22 control=\x222\x22>3</param>\x0A</list>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:15 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 216 "-" "python-requests/2.25.0" 0.064 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetToneControl</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<status>0</status>\x0A<adjust></adjust>\x0A<basslevel></basslevel>\x0A<bassvalue></bassvalue>\x0A<treblelevel></treblelevel>\x0A<treblevalue></treblevalue>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:15 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 868 "-" "python-requests/2.25.0" 0.065 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetAllZonePowerStatus</cmd><cmd id=\x221\x22>GetAllZoneSource</cmd><cmd id=\x221\x22>GetAllZoneVolume</cmd><cmd id=\x221\x22>GetAllZoneMuteStatus</cmd><cmd id=\x221\x22>GetSurroundModeStatus</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<zone1>OFF</zone1>\x0A<zone2>OFF</zone2>\x0A<zone3>OFF</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<source>MPLAY</source>\x0A</zone1>\x0A<zone2>\x0A<source>MPLAY</source>\x0A</zone2>\x0A<zone3>\x0A<source>NET</source>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<volume>-25.0</volume>\x0A<state>variable</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-25.0dB</dispvalue>\x0A</zone1>\x0A<zone2>\x0A<volume>0</volume>\x0A<state>fixed</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>0dB</dispvalue>\x0A</zone2>\x0A<zone3>\x0A<volume>-40</volume>\x0A<state>variable</state>\x0A<limit>-10.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-40dB</dispvalue>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>off</zone1>\x0A<zone2>off</zone2>\x0A<zone3>off</zone3>\x0A</cmd>\x0A<cmd>\x0A<surround>Multi In + DSur                                                </surround>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:15 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 868 "-" "python-requests/2.25.0" 0.002 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetAllZonePowerStatus</cmd><cmd id=\x221\x22>GetAllZoneSource</cmd><cmd id=\x221\x22>GetAllZoneVolume</cmd><cmd id=\x221\x22>GetAllZoneMuteStatus</cmd><cmd id=\x221\x22>GetSurroundModeStatus</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<zone1>OFF</zone1>\x0A<zone2>OFF</zone2>\x0A<zone3>OFF</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<source>MPLAY</source>\x0A</zone1>\x0A<zone2>\x0A<source>MPLAY</source>\x0A</zone2>\x0A<zone3>\x0A<source>NET</source>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<volume>-25.0</volume>\x0A<state>variable</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-25.0dB</dispvalue>\x0A</zone1>\x0A<zone2>\x0A<volume>0</volume>\x0A<state>fixed</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>0dB</dispvalue>\x0A</zone2>\x0A<zone3>\x0A<volume>-40</volume>\x0A<state>variable</state>\x0A<limit>-10.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-40dB</dispvalue>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>off</zone1>\x0A<zone2>off</zone2>\x0A<zone3>off</zone3>\x0A</cmd>\x0A<cmd>\x0A<surround>Multi In + DSur                                                </surround>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:15 -0500] "POST /goform/AppCommand0300.xml HTTP/1.1" 200 301 "-" "python-requests/2.25.0" 0.062 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x223\x22><name>GetAudyssey</name><list><param name=\x22dynamiceq\x22 /><param name=\x22reflevoffset\x22 /><param name=\x22dynamicvol\x22 /><param name=\x22multeq\x22 /></list></cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<name>GetAudyssey</name>\x0A<list>\x0A<param name=\x22dynamiceq\x22 control=\x222\x22>1</param>\x0A<param name=\x22reflevoffset\x22 control=\x222\x22>0</param>\x0A<param name=\x22dynamicvol\x22 control=\x222\x22>0</param>\x0A<param name=\x22multeq\x22 control=\x222\x22>3</param>\x0A</list>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:15 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 216 "-" "python-requests/2.25.0" 0.063 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetToneControl</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<status>0</status>\x0A<adjust></adjust>\x0A<basslevel></basslevel>\x0A<bassvalue></bassvalue>\x0A<treblelevel></treblelevel>\x0A<treblevalue></treblevalue>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:24 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 868 "-" "python-requests/2.25.0" 0.002 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetAllZonePowerStatus</cmd><cmd id=\x221\x22>GetAllZoneSource</cmd><cmd id=\x221\x22>GetAllZoneVolume</cmd><cmd id=\x221\x22>GetAllZoneMuteStatus</cmd><cmd id=\x221\x22>GetSurroundModeStatus</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<zone1>OFF</zone1>\x0A<zone2>OFF</zone2>\x0A<zone3>OFF</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<source>MPLAY</source>\x0A</zone1>\x0A<zone2>\x0A<source>MPLAY</source>\x0A</zone2>\x0A<zone3>\x0A<source>NET</source>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<volume>-25.0</volume>\x0A<state>variable</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-25.0dB</dispvalue>\x0A</zone1>\x0A<zone2>\x0A<volume>0</volume>\x0A<state>fixed</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>0dB</dispvalue>\x0A</zone2>\x0A<zone3>\x0A<volume>-40</volume>\x0A<state>variable</state>\x0A<limit>-10.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-40dB</dispvalue>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>off</zone1>\x0A<zone2>off</zone2>\x0A<zone3>off</zone3>\x0A</cmd>\x0A<cmd>\x0A<surround>Multi In + DSur                                                </surround>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:25 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 216 "-" "python-requests/2.25.0" 0.001 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetToneControl</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<status>0</status>\x0A<adjust></adjust>\x0A<basslevel></basslevel>\x0A<bassvalue></bassvalue>\x0A<treblelevel></treblelevel>\x0A<treblevalue></treblevalue>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:25 -0500] "POST /goform/AppCommand0300.xml HTTP/1.1" 200 301 "-" "python-requests/2.25.0" 0.063 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x223\x22><name>GetAudyssey</name><list><param name=\x22dynamiceq\x22 /><param name=\x22reflevoffset\x22 /><param name=\x22dynamicvol\x22 /><param name=\x22multeq\x22 /></list></cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<name>GetAudyssey</name>\x0A<list>\x0A<param name=\x22dynamiceq\x22 control=\x222\x22>1</param>\x0A<param name=\x22reflevoffset\x22 control=\x222\x22>0</param>\x0A<param name=\x22dynamicvol\x22 control=\x222\x22>0</param>\x0A<param name=\x22multeq\x22 control=\x222\x22>3</param>\x0A</list>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:25 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 868 "-" "python-requests/2.25.0" 0.001 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetAllZonePowerStatus</cmd><cmd id=\x221\x22>GetAllZoneSource</cmd><cmd id=\x221\x22>GetAllZoneVolume</cmd><cmd id=\x221\x22>GetAllZoneMuteStatus</cmd><cmd id=\x221\x22>GetSurroundModeStatus</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<zone1>OFF</zone1>\x0A<zone2>OFF</zone2>\x0A<zone3>OFF</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<source>MPLAY</source>\x0A</zone1>\x0A<zone2>\x0A<source>MPLAY</source>\x0A</zone2>\x0A<zone3>\x0A<source>NET</source>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<volume>-25.0</volume>\x0A<state>variable</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-25.0dB</dispvalue>\x0A</zone1>\x0A<zone2>\x0A<volume>0</volume>\x0A<state>fixed</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>0dB</dispvalue>\x0A</zone2>\x0A<zone3>\x0A<volume>-40</volume>\x0A<state>variable</state>\x0A<limit>-10.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-40dB</dispvalue>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>off</zone1>\x0A<zone2>off</zone2>\x0A<zone3>off</zone3>\x0A</cmd>\x0A<cmd>\x0A<surround>Multi In + DSur                                                </surround>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:25 -0500] "POST /goform/AppCommand0300.xml HTTP/1.1" 200 301 "-" "python-requests/2.25.0" 0.071 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x223\x22><name>GetAudyssey</name><list><param name=\x22dynamiceq\x22 /><param name=\x22reflevoffset\x22 /><param name=\x22dynamicvol\x22 /><param name=\x22multeq\x22 /></list></cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<name>GetAudyssey</name>\x0A<list>\x0A<param name=\x22dynamiceq\x22 control=\x222\x22>1</param>\x0A<param name=\x22reflevoffset\x22 control=\x222\x22>0</param>\x0A<param name=\x22dynamicvol\x22 control=\x222\x22>0</param>\x0A<param name=\x22multeq\x22 control=\x222\x22>3</param>\x0A</list>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:25 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 216 "-" "python-requests/2.25.0" 0.069 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetToneControl</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<status>0</status>\x0A<adjust></adjust>\x0A<basslevel></basslevel>\x0A<bassvalue></bassvalue>\x0A<treblelevel></treblelevel>\x0A<treblevalue></treblevalue>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:35 -0500] "POST /goform/AppCommand0300.xml HTTP/1.1" 200 301 "-" "python-requests/2.25.0" 0.062 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x223\x22><name>GetAudyssey</name><list><param name=\x22dynamiceq\x22 /><param name=\x22reflevoffset\x22 /><param name=\x22dynamicvol\x22 /><param name=\x22multeq\x22 /></list></cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<name>GetAudyssey</name>\x0A<list>\x0A<param name=\x22dynamiceq\x22 control=\x222\x22>1</param>\x0A<param name=\x22reflevoffset\x22 control=\x222\x22>0</param>\x0A<param name=\x22dynamicvol\x22 control=\x222\x22>0</param>\x0A<param name=\x22multeq\x22 control=\x222\x22>3</param>\x0A</list>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:35 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 868 "-" "python-requests/2.25.0" 0.062 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetAllZonePowerStatus</cmd><cmd id=\x221\x22>GetAllZoneSource</cmd><cmd id=\x221\x22>GetAllZoneVolume</cmd><cmd id=\x221\x22>GetAllZoneMuteStatus</cmd><cmd id=\x221\x22>GetSurroundModeStatus</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<zone1>OFF</zone1>\x0A<zone2>OFF</zone2>\x0A<zone3>OFF</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<source>MPLAY</source>\x0A</zone1>\x0A<zone2>\x0A<source>MPLAY</source>\x0A</zone2>\x0A<zone3>\x0A<source>NET</source>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<volume>-25.0</volume>\x0A<state>variable</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-25.0dB</dispvalue>\x0A</zone1>\x0A<zone2>\x0A<volume>0</volume>\x0A<state>fixed</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>0dB</dispvalue>\x0A</zone2>\x0A<zone3>\x0A<volume>-40</volume>\x0A<state>variable</state>\x0A<limit>-10.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-40dB</dispvalue>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>off</zone1>\x0A<zone2>off</zone2>\x0A<zone3>off</zone3>\x0A</cmd>\x0A<cmd>\x0A<surround>Multi In + DSur                                                </surround>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:35 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 216 "-" "python-requests/2.25.0" 0.063 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetToneControl</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<status>0</status>\x0A<adjust></adjust>\x0A<basslevel></basslevel>\x0A<bassvalue></bassvalue>\x0A<treblelevel></treblelevel>\x0A<treblevalue></treblevalue>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:35 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 868 "-" "python-requests/2.25.0" 0.002 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetAllZonePowerStatus</cmd><cmd id=\x221\x22>GetAllZoneSource</cmd><cmd id=\x221\x22>GetAllZoneVolume</cmd><cmd id=\x221\x22>GetAllZoneMuteStatus</cmd><cmd id=\x221\x22>GetSurroundModeStatus</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<zone1>OFF</zone1>\x0A<zone2>OFF</zone2>\x0A<zone3>OFF</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<source>MPLAY</source>\x0A</zone1>\x0A<zone2>\x0A<source>MPLAY</source>\x0A</zone2>\x0A<zone3>\x0A<source>NET</source>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<volume>-25.0</volume>\x0A<state>variable</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-25.0dB</dispvalue>\x0A</zone1>\x0A<zone2>\x0A<volume>0</volume>\x0A<state>fixed</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>0dB</dispvalue>\x0A</zone2>\x0A<zone3>\x0A<volume>-40</volume>\x0A<state>variable</state>\x0A<limit>-10.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-40dB</dispvalue>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>off</zone1>\x0A<zone2>off</zone2>\x0A<zone3>off</zone3>\x0A</cmd>\x0A<cmd>\x0A<surround>Multi In + DSur                                                </surround>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:35 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 216 "-" "python-requests/2.25.0" 0.001 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetToneControl</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<status>0</status>\x0A<adjust></adjust>\x0A<basslevel></basslevel>\x0A<bassvalue></bassvalue>\x0A<treblelevel></treblelevel>\x0A<treblevalue></treblevalue>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:35 -0500] "POST /goform/AppCommand0300.xml HTTP/1.1" 200 301 "-" "python-requests/2.25.0" 0.063 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x223\x22><name>GetAudyssey</name><list><param name=\x22dynamiceq\x22 /><param name=\x22reflevoffset\x22 /><param name=\x22dynamicvol\x22 /><param name=\x22multeq\x22 /></list></cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<name>GetAudyssey</name>\x0A<list>\x0A<param name=\x22dynamiceq\x22 control=\x222\x22>1</param>\x0A<param name=\x22reflevoffset\x22 control=\x222\x22>0</param>\x0A<param name=\x22dynamicvol\x22 control=\x222\x22>0</param>\x0A<param name=\x22multeq\x22 control=\x222\x22>3</param>\x0A</list>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:45 -0500] "POST /goform/AppCommand0300.xml HTTP/1.1" 200 301 "-" "python-requests/2.25.0" 0.062 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x223\x22><name>GetAudyssey</name><list><param name=\x22dynamiceq\x22 /><param name=\x22reflevoffset\x22 /><param name=\x22dynamicvol\x22 /><param name=\x22multeq\x22 /></list></cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<name>GetAudyssey</name>\x0A<list>\x0A<param name=\x22dynamiceq\x22 control=\x222\x22>1</param>\x0A<param name=\x22reflevoffset\x22 control=\x222\x22>0</param>\x0A<param name=\x22dynamicvol\x22 control=\x222\x22>0</param>\x0A<param name=\x22multeq\x22 control=\x222\x22>3</param>\x0A</list>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:45 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 868 "-" "python-requests/2.25.0" 0.063 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetAllZonePowerStatus</cmd><cmd id=\x221\x22>GetAllZoneSource</cmd><cmd id=\x221\x22>GetAllZoneVolume</cmd><cmd id=\x221\x22>GetAllZoneMuteStatus</cmd><cmd id=\x221\x22>GetSurroundModeStatus</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<zone1>OFF</zone1>\x0A<zone2>OFF</zone2>\x0A<zone3>OFF</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<source>MPLAY</source>\x0A</zone1>\x0A<zone2>\x0A<source>MPLAY</source>\x0A</zone2>\x0A<zone3>\x0A<source>NET</source>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<volume>-25.0</volume>\x0A<state>variable</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-25.0dB</dispvalue>\x0A</zone1>\x0A<zone2>\x0A<volume>0</volume>\x0A<state>fixed</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>0dB</dispvalue>\x0A</zone2>\x0A<zone3>\x0A<volume>-40</volume>\x0A<state>variable</state>\x0A<limit>-10.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-40dB</dispvalue>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>off</zone1>\x0A<zone2>off</zone2>\x0A<zone3>off</zone3>\x0A</cmd>\x0A<cmd>\x0A<surround>Multi In + DSur                                                </surround>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:45 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 216 "-" "python-requests/2.25.0" 0.063 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetToneControl</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<status>0</status>\x0A<adjust></adjust>\x0A<basslevel></basslevel>\x0A<bassvalue></bassvalue>\x0A<treblelevel></treblelevel>\x0A<treblevalue></treblevalue>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:45 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 868 "-" "python-requests/2.25.0" 0.002 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetAllZonePowerStatus</cmd><cmd id=\x221\x22>GetAllZoneSource</cmd><cmd id=\x221\x22>GetAllZoneVolume</cmd><cmd id=\x221\x22>GetAllZoneMuteStatus</cmd><cmd id=\x221\x22>GetSurroundModeStatus</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<zone1>OFF</zone1>\x0A<zone2>OFF</zone2>\x0A<zone3>OFF</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<source>MPLAY</source>\x0A</zone1>\x0A<zone2>\x0A<source>MPLAY</source>\x0A</zone2>\x0A<zone3>\x0A<source>NET</source>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>\x0A<volume>-25.0</volume>\x0A<state>variable</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-25.0dB</dispvalue>\x0A</zone1>\x0A<zone2>\x0A<volume>0</volume>\x0A<state>fixed</state>\x0A<limit>  0.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>0dB</dispvalue>\x0A</zone2>\x0A<zone3>\x0A<volume>-40</volume>\x0A<state>variable</state>\x0A<limit>-10.0</limit>\x0A<disptype>RELATIVE</disptype>\x0A<dispvalue>-40dB</dispvalue>\x0A</zone3>\x0A</cmd>\x0A<cmd>\x0A<zone1>off</zone1>\x0A<zone2>off</zone2>\x0A<zone3>off</zone3>\x0A</cmd>\x0A<cmd>\x0A<surround>Multi In + DSur                                                </surround>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:45 -0500] "POST /goform/AppCommand0300.xml HTTP/1.1" 200 301 "-" "python-requests/2.25.0" 0.063 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x223\x22><name>GetAudyssey</name><list><param name=\x22dynamiceq\x22 /><param name=\x22reflevoffset\x22 /><param name=\x22dynamicvol\x22 /><param name=\x22multeq\x22 /></list></cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<name>GetAudyssey</name>\x0A<list>\x0A<param name=\x22dynamiceq\x22 control=\x222\x22>1</param>\x0A<param name=\x22reflevoffset\x22 control=\x222\x22>0</param>\x0A<param name=\x22dynamicvol\x22 control=\x222\x22>0</param>\x0A<param name=\x22multeq\x22 control=\x222\x22>3</param>\x0A</list>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:30:45 -0500] "POST /goform/AppCommand.xml HTTP/1.1" 200 216 "-" "python-requests/2.25.0" 0.063 REQUEST:"<?xml version='1.0' encoding='utf-8'?>\x0A<tx><cmd id=\x221\x22>GetToneControl</cmd></tx>" RESPONSE:"<?xml version=\x221.0\x22 encoding=\x22utf-8\x22 ?>\x0A<rx>\x0A<cmd>\x0A<status>0</status>\x0A<adjust></adjust>\x0A<basslevel></basslevel>\x0A<bassvalue></bassvalue>\x0A<treblelevel></treblelevel>\x0A<treblevalue></treblevalue>\x0A</cmd>\x0A</rx>\x0A"
192.168.123.45 - - [23/Dec/2020:14:31:42 -0500] "GET /goform/Deviceinfo.xml HTTP/1.1" 499 0 "-" "python-requests/2.25.0" 10.008 REQUEST:"-" RESPONSE:""
192.168.123.45 - - [23/Dec/2020:14:31:44 -0500] "GET /description.xml HTTP/1.1" 499 0 "-" "python-requests/2.25.0" 2.004 REQUEST:"-" RESPONSE:""
192.168.123.45 - - [23/Dec/2020:14:31:54 -0500] "GET /goform/Deviceinfo.xml HTTP/1.1" 499 0 "-" "python-requests/2.25.0" 10.008 REQUEST:"-" RESPONSE:""
192.168.123.45 - - [23/Dec/2020:14:31:56 -0500] "GET /description.xml HTTP/1.1" 499 0 "-" "python-requests/2.25.0" 2.001 REQUEST:"-" RESPONSE:""

As you can see, the last successful request was at 14:30:45, when HA was restarted. The entries in that final round were no different than those shortly prior, either by request or response values. Also notice that the request time (between the user agent and REQUEST) remains consistently below 1 second, even in the last round. No sign anything was amiss until after HA restarted, when port 8080 stopped responding.

There were no requests seen by nginx on either 80 or 60006 until after the restart.

Adding nginx in the middle gives me some confidence that this isn't a ip/tcp/http protocol-level violation on the HA/denonavr end.

Expanding the packet capture filter didn't add much information to the picture. In addition to ports 80, 8080, and 60006, I'm also seeing the HEOS integration on tcp 1255. HEOS is the first to connect on 1255, followed by denonavr on 80, then 8080. There isn't any unexpected multicast/broadcast traffic seen around the time of the restart (only ARP, IGMP, MDNS, and SSDP) and most of it occurred after the point that tcp 8080 failed.

Based on the new information, my best guess is the problem is triggered by requesting /goform/Deviceinfo.xml on either port 80 or 8080 after the HA restart. Perhaps there's a memory leak on the AVR that causes that request to become fatal over time. It may also be related to the HEOS integration, but that seems unlikely.

ETA: Another interesting find... HA began restarting prior to the last round of connections.

2020-12-23T14:30:33.980892-05:00 container[979]: [cont-finish.d] executing container finish scripts...
2020-12-23T14:30:33.981116-05:00 container[979]: [cont-finish.d] done.
2020-12-23T14:30:33.981249-05:00 container[979]: [s6-finish] waiting for services.
2020-12-23T14:30:42.707950-05:00 container[979]: #033[31m2020-12-23 14:30:42 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /homeassistant/restart request#033[0m
2020-12-23T14:30:53.481714-05:00 container[979]: s6-svscanctl: fatal: unable to control /var/run/s6/services: supervisor not listening
2020-12-23T14:30:53.689955-05:00 container[979]: [s6-finish] sending all processes the TERM signal.
2020-12-23T14:30:56.702623-05:00 container[979]: [s6-finish] sending all processes the KILL signal and exiting.
imregmelig commented 3 years ago

Filed a support request through the Denon website…

After the november update, the API to control my Denon AVX-X1600H DAB is no longer responding. The Denon and HEOS app both still function fine. Many people use other apps (like Home Assistant) to control the Denon or Marantz receivers, which is one of the awesome features (!).

See also: https://github.com/home-assistant/core/issues/43670

Could you please confirm on the issue? Could you investigate this issue and make this a priority?

Thanks in advance for the service and the follow up.

ricarva commented 3 years ago

Filed a support request through the Denon website…

After the november update, the API to control my Denon AVX-X1600H DAB is no longer responding. The Denon and HEOS app both still function fine. Many people use other apps (like Home Assistant) to control the Denon or Marantz receivers, which is one of the awesome features (!). See also: #43670 Could you please confirm on the issue? Could you investigate this issue and make this a priority? Thanks in advance for the service and the follow up.

@imregmelig

Is it really the case that when you lose HA connectivity you keep full use of the Denon AVR Remote app? That hasn't been the case for the rest of the users above.

ricarva commented 3 years ago

@doug-hoffman

Regarding your last post, and after another drop-out in my setup, I'll leave a couple of observations.

As I've stated before, the issue has manifested for me way before I even had Home Assistant deployed; I would notice because the Denon app would be rendered unable to connect.

It was allot more infrequent, though, so maybe the HA integration somehow exacerbates the issue by triggering it more often.

Also, and while I've never gone as deep into debugging as some of you, my lock-ups never seemed to be a function of HA restarts. They do seem to be linked to times when my AVR goes into standby, though.

imregmelig commented 3 years ago

Is it really the case that when you lose HA connectivity you keep full use of the Denon AVR Remote app? That hasn't been the case for the rest of the users above.

@ricarva As a matter of fact I don't, no, I'm sorry. I misread this post where it's suggested to report this with Denon / Marantz and to make sure to mention the Denon and Heos apps are still working fine. I missed the last part assuming it was working fine. I now notice for the first time, the Denon and Heos apps are pratically unresponsive. :-(

doug-hoffman commented 3 years ago

@ricarva, How often do you use the Denon app? I have it installed on my phone, but never use it. I'm going to try uninstalling to see if that makes any difference. (I do occasionally use the HEOS app – unsure if it calls anything on port 8080 it only uses tcp 80/60006 though.)

On the 24th, I experienced the first known failure that wasn't related to HA restarting. The AVR was in standby and had been for at least 12 hours. The packet capture showed nothing abnormal – HA was doing the normal /goform/AppCommand.xml and /goform/AppCommand0300.xml POSTs, then just failed. Power cycling the AVR was sufficient to recover in that case.

Later that day, to test my suspicion of the /goform/Deviceinfo.xml endpoint being problematic, I had a few instances of this loop running for about 2 hours:

while true; do curl http://avr:8080/goform/Deviceinfo.xml > /dev/null; done

The AVR still hasn't failed. I just kicked off an instance again and it's still good.

I had hoped having nginx in the middle as a reverse proxy would help clean up any protocol-level problems, but can't say with certainty that it would in all cases. At this point, I'm back to believing it's some protocol-level abnormality that triggers this, as I can't find any direct correlation between endpoint requests and port 8080 failing.

In case this is related to some other traffic hitting the AVR, other than what originates from HA, I'm going to try doing a packet capture of the AVR's switch port, rather than on the box running HA.

Hopefully Denon decides to take a look. That may be the only realistic path toward a workaround or full resolution.

ricarva commented 3 years ago

@doug-hoffman I never used the Denon App much; latelly I've used it a bit more to tweak Audyssey parameters every once in a while: I really should learn hot to do this automatically from HA, but I've found few (rather none) examples of how to accomplish this.

matejdro commented 3 years ago

Just my two cents: I never used Denon or HEOS app (never had it installed on my phone), API is solely used by the HA. And I'm experiencing those same issues.

DevSecNinja commented 3 years ago

I'm facing the same issue. I was hoping that the new 2020.12.2 version fixed it but unfortunately it didn't. This integration has been rock solid for months on my Home Assistant instance.

2020-12-30 15:21:33 INFO (SyncWorker_0) [DenonAVR] Identified receiver type: 'avr' on port: '80'
2020-12-30 15:21:33 ERROR (SyncWorker_0) [DenonAVR] Host 192.168.12.34 returned HTTP status code 403 to POST command at end point /goform/AppCommand.xml
2020-12-30 15:21:33 ERROR (SyncWorker_0) [DenonAVR] Getting renamed and deleted sources failed.
2020-12-30 15:21:33 ERROR (SyncWorker_0) [DenonAVR] Host 192.168.12.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-12-30 15:21:33 ERROR (ThreadPoolExecutor-156_1) [DenonAVR] Host 192.168.12.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-12-30 15:21:33 INFO (ThreadPoolExecutor-156_1) [DenonAVR] Receiver name could not be determined. Using standard name: Denon AVR.
2020-12-30 15:21:33 ERROR (ThreadPoolExecutor-157_0) [DenonAVR] Host 192.168.12.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXmlStatus.xml
2020-12-30 15:21:33 ERROR (ThreadPoolExecutor-157_1) [DenonAVR] Host 192.168.12.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-12-30 15:21:35 ERROR (ThreadPoolExecutor-156_0) [DenonSSDP] During DenonAVR device identification, when trying to request http://192.168.12.34:8080/description.xml the following error occurred: HTTPConnectionPool(host='192.168.12.34', port=8080): Read timed out. (read timeout=2)
2020-12-30 15:21:35 ERROR (ThreadPoolExecutor-156_0) [DenonAVR] Unable to get device information of host 192.168.12.34, can not use the serial number as identification
2020-12-30 15:21:35 ERROR (ThreadPoolExecutor-158_0) [DenonAVR] Host 192.168.12.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXmlStatus.xml
2020-12-30 15:21:35 ERROR (ThreadPoolExecutor-158_1) [DenonAVR] Host 192.168.12.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-12-30 15:21:35 ERROR (SyncWorker_0) [DenonAVR] Missing status information from XML of Main for: Power, InputFuncSelect, Mute, MasterVolume
2020-12-30 15:21:36 ERROR (MainThread) [homeassistant.components.denonavr.config_flow] Could not get serial number of host 192.168.12.34, unique_id's will not be available
2020-12-30 15:21:46 INFO (SyncWorker_1) [DenonAVR] Identified receiver type: 'avr' on port: '80'
2020-12-30 15:21:46 ERROR (SyncWorker_1) [DenonAVR] Host 192.168.12.34 returned HTTP status code 403 to POST command at end point /goform/AppCommand.xml
2020-12-30 15:21:46 ERROR (SyncWorker_1) [DenonAVR] Getting renamed and deleted sources failed.
2020-12-30 15:21:46 ERROR (SyncWorker_1) [DenonAVR] Host 192.168.12.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-12-30 15:21:46 ERROR (ThreadPoolExecutor-159_1) [DenonAVR] Host 192.168.12.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-12-30 15:21:46 INFO (ThreadPoolExecutor-159_1) [DenonAVR] Receiver name could not be determined. Using standard name: Denon AVR.
2020-12-30 15:21:46 ERROR (ThreadPoolExecutor-160_0) [DenonAVR] Host 192.168.12.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXmlStatus.xml
2020-12-30 15:21:46 ERROR (ThreadPoolExecutor-160_1) [DenonAVR] Host 192.168.12.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-12-30 15:21:48 ERROR (ThreadPoolExecutor-159_0) [DenonSSDP] During DenonAVR device identification, when trying to request http://192.168.12.34:8080/description.xml the following error occurred: HTTPConnectionPool(host='192.168.12.34', port=8080): Read timed out. (read timeout=2)
2020-12-30 15:21:48 ERROR (ThreadPoolExecutor-159_0) [DenonAVR] Unable to get device information of host 192.168.12.34, can not use the serial number as identification
2020-12-30 15:21:48 ERROR (ThreadPoolExecutor-161_1) [DenonAVR] Host 192.168.12.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXml.xml
2020-12-30 15:21:48 ERROR (ThreadPoolExecutor-161_0) [DenonAVR] Host 192.168.12.34 returned HTTP status code 403 to GET request at end point /goform/formMainZone_MainZoneXmlStatus.xml
2020-12-30 15:21:48 ERROR (SyncWorker_1) [DenonAVR] Missing status information from XML of Main for: Power, InputFuncSelect, Mute, MasterVolume
2020-12-30 15:21:48 INFO (MainThread) [homeassistant.components.media_player] Setting up media_player.denonavr
grantclem commented 3 years ago

Same issues as above with latest release of 2020.12.2

JPHutchins commented 3 years ago

Sorry for the slow process! 2020.12.2 includes denonavr 0.9.8 which we had hoped would resolve these issues. It does resolve the issue for people getting the "audyssey problem".
denonavr is now on 0.9.9 https://github.com/scarface-4711/denonavr/releases/tag/0.9.9 which reverts to serial instead of parallel API calls - it is our hope that this gets us back to the stability we enjoyed prior to November.

It would be nice to be able to test - I am not sure how to manually bump the denonavr requirement to 0.9.9 but you can see the changes that we make to bump version here: https://github.com/home-assistant/core/pull/44194/files

JPHutchins commented 3 years ago

We're still trying to manually trigger the errors BTW - if anyone wants to futz around here is a script where we are attempting to prove that parallel requests were the problem in the first place (no success proving this so far). Note that on my receiver GET and POST work and GET causes more problems

import requests
from concurrent.futures import ThreadPoolExecutor
from datetime import datetime

HOST = "192.168.0.119"

print("Running")

def make_xml_request(commands: list) -> bytes:
        """Prepare XML body for Denon API."""
        xml_parts = ['<?xml version="1.0" encoding="utf-8"?>\n', "<tx>"]
        cmd_l = '<cmd id="1">'
        cmd_r = "</cmd>"
        for i, command in enumerate(commands):
            if i != 0 and i % 5 == 0:
                # API allows multiple XML roots, limit 5 commands each
                xml_parts.append("</tx><tx>")
            xml_parts.append(f"{cmd_l}{command}{cmd_r}")
        xml_parts.append("</tx>")
        return "".join(xml_parts).encode()

xml = make_xml_request(["GetRenameSource", "GetDeletedSource"])

def r1():
    return requests.get(f"http://{HOST}:8080/goform/Deviceinfo.xml").status_code

def r1a():
    return requests.get(f"http://{HOST}:80/description.xml")

def r1b():
    return requests.get(f"http://{HOST}:60006/upnp/desc/aios_device/aios_device.xml").status_code

def r2(xml):
    # print(datetime.utcnow())
    return requests.get(f"http://{HOST}:8080/goform/AppCommand.xml", data=xml, headers = {'Content-Type': 'application/xml'})

e = ThreadPoolExecutor(max_workers=50)
out = []
for _ in range(100):
    out.append(e.submit(r1))
    out.append(e.submit(r1b))
    e.submit(r2, xml)
    # out.append(e.submit(r2, xml))
    # out.append(e.submit(r2, xml))

for resp in out:
    print((resp.result(timeout=5)))