Adapter no connection after some days
foxriver76 opened this issue · 6 comments
After some days the adapter cannot control speakers anymore as it says not connected to speaker. After adapter restart it immediately works again
v1.10.0
Do you have the exact error message still available in your log? I'm running v.1.11.4 for several weeks and have no issues.
In this scenario it seems, that my issue title is wrong. There was a system restart, which I no longer remember why. However, here are the logs of the adapter start, with the failing connection, it seems that he tries 3 times and then never tries again?
2023-02-12 09:22:28.822 - info: heos.0 (959) starting. Version 1.10.0 in /opt/iobroker/node_modules/iobroker.heos, node: v14.21.1, js-controller: 4.0.24
2023-02-12 09:22:28.867 - info: heos.0 (959) searching for HEOS devices ...
2023-02-12 09:22:28.877 - info: heos.0 (959) connecting to HEOS (192.168.178.90) ...
2023-02-12 09:22:28.908 - info: heos.0 (959) connected to HEOS (192.168.178.90)
2023-02-12 09:22:29.665 - info: heos.0 (959) [Speaker Pool] connect HEOS player Speaker Pool (-1202331414)
2023-02-12 09:22:29.696 - info: heos.0 (959) [Speaker Pool] connect HEOS player Speaker Pool (-1202331414)
2023-02-12 09:22:30.281 - info: heos.0 (959) [UDO AVR-X2400H ] connect HEOS player UDO AVR-X2400H (-1927616611)
2023-02-12 09:22:30.393 - warn: heos.0 (959) Announced player not found by HEOS. Activate "reboot on failure" in the configuration or reboot manually the device: 192.168.178.31
2023-02-12 09:22:30.393 - warn: heos.0 (959) Announced player not found by HEOS. Activate "reboot on failure" in the configuration or reboot manually the device: 192.168.178.79
2023-02-12 09:22:32.815 - warn: heos.0 (959) [setLastError] result=fail,text=Requested data not available,command=player/get_play_mode
2023-02-12 09:22:45.639 - error: heos.0 (959) [startPlayers] HEOS responded with invalid data.
2023-02-12 09:22:45.640 - info: heos.0 (959) reconnecting to HEOS ...
2023-02-12 09:22:45.640 - info: heos.0 (959) disconnecting from HEOS ...
2023-02-12 09:22:45.640 - info: heos.0 (959) [Speaker Pool] disconnect HEOS player Speaker Pool (-1202331414)
2023-02-12 09:22:45.641 - info: heos.0 (959) [UDO AVR-X2400H ] disconnect HEOS player UDO AVR-X2400H (-1927616611)
2023-02-12 09:22:45.642 - info: heos.0 (959) disconnected from HEOS
2023-02-12 09:22:50.643 - info: heos.0 (959) searching for HEOS devices ...
2023-02-12 09:22:52.002 - info: heos.0 (959) connecting to HEOS (192.168.178.140) ...
2023-02-12 09:22:52.003 - info: heos.0 (959) connected to HEOS (192.168.178.140)
2023-02-12 09:22:52.126 - info: heos.0 (959) [UDO AVR-X2400H ] connect HEOS player UDO AVR-X2400H (-1927616611)
2023-02-12 09:22:52.350 - info: heos.0 (959) [Speaker Pool] connect HEOS player Speaker Pool (-1202331414)
2023-02-12 09:23:08.137 - info: heos.0 (959) [UDO AVR-X2400H ] disconnect HEOS player UDO AVR-X2400H (-1927616611)
2023-02-12 09:23:08.137 - warn: heos.0 (959) Announced player not found by HEOS. Activate "reboot on failure" in the configuration or reboot manually the device: 192.168.178.79
2023-02-12 09:23:08.138 - warn: heos.0 (959) Announced player not found by HEOS. Activate "reboot on failure" in the configuration or reboot manually the device: 192.168.178.31
2023-02-12 09:23:08.138 - warn: heos.0 (959) Announced player not found by HEOS. Activate "reboot on failure" in the configuration or reboot manually the device: 192.168.178.140
2023-02-12 09:23:08.634 - info: heos.0 (959) [Denon AVR-X1700H] connect HEOS player Denon AVR-X1700H (-1280216177)
2023-02-12 09:23:08.873 - info: heos.0 (959) [Speaker Terrasse] connect HEOS player Speaker Terrasse (543608195)
2023-02-12 09:23:32.645 - info: heos.0 (959) [UDO AVR-X2400H ] connect HEOS player UDO AVR-X2400H (-1927616611)
2023-02-12 09:23:32.721 - info: heos.0 (959) [Speaker Terrasse] disconnect HEOS player Speaker Terrasse (543608195)
2023-02-12 09:23:32.721 - info: heos.0 (959) [Denon AVR-X1700H] disconnect HEOS player Denon AVR-X1700H (-1280216177)
2023-02-12 09:23:32.721 - warn: heos.0 (959) Announced player not found by HEOS. Activate "reboot on failure" in the configuration or reboot manually the device: 192.168.178.79
2023-02-12 09:23:32.721 - warn: heos.0 (959) Announced player not found by HEOS. Activate "reboot on failure" in the configuration or reboot manually the device: 192.168.178.31
It's not a bug, It's a feature :) Sometimes the HEOS API on the players itself is misbehaving and is answering with incomplete or wrong messages. The adapter detects multiple misbehaviours and reboots the player (if enabled in the adapter configuration). To prevent the adapter from working, if the reboot feature is disabled, I've added a "Reconnect" after the mentioned error appears. However this can lead to a reconnect loop, if the adapter always connects with the misbehaving player. Better would be to reboot the player.
I see your approach, however in many cases, the player will also come back by itself, like it did for me, where an adapter restart has helped. So what do you think of an approach where if reboot on failure is configured, do it like now, thus 3 connection attempts, then reboot attempt. If not configured follow a retry with backoff strategy with maybe a max timeout of 1 or 2 hours, so e. g. double connection timeout every attempt but let it not increase higher than 2 hours.
I looked again into this issue. The error message "Announced player not found by HEOS" is indicating a mismatch between players are announcing themselfs with SSDP and this players are not found by the leading HEOS player. In my experience this error mostly occurs with AV receivers. I removed the reboot for this kind of error and only keep the reconnect. However the errors are counted internally and a reboot is planned on a certain level based on the different error numbers. I will test the new way of handling errors some days as the error seems to be very rare...
No feedback