Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

AVR stops responding a while after putting into standby #51

Open
crowbarz opened this issue Nov 27, 2024 · 4 comments
Open

AVR stops responding a while after putting into standby #51

crowbarz opened this issue Nov 27, 2024 · 4 comments

Comments

@crowbarz
Copy link
Owner

Originally posted by @dondonini in #48 (comment)

Hia, it seems I'm having the same issue as the OP, but mine also disconnects when it's on standby after a long time. The time of how long it will be controllable until it disconnects is unknown to me. When it does disconnect it spits out...

2024-11-21 21:47:34.371 INFO (MainThread) [aiopioneer.pioneer_avr] Starting aiopioneer 0.7.0
2024-11-21 21:47:34.372 INFO (MainThread) [aiopioneer.pioneer_avr] determining available listening modes
2024-11-21 21:47:37.453 ERROR (MainThread) [custom_components.pioneer_async] exception on initialising Pioneer AVR: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-21 21:47:37.454 WARNING (MainThread) [aiopioneer.pioneer_avr] AVR not connected, skipping disconnect
...
2024-11-21 21:48:57.920 INFO (MainThread) [aiopioneer.pioneer_avr] Starting aiopioneer 0.7.0
2024-11-21 21:48:57.921 INFO (MainThread) [aiopioneer.pioneer_avr] determining available listening modes
2024-11-21 21:49:00.973 ERROR (MainThread) [custom_components.pioneer_async] exception on initialising Pioneer AVR: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-21 21:49:00.974 WARNING (MainThread) [aiopioneer.pioneer_avr] AVR not connected, skipping disconnect
...
2024-11-21 21:50:21.167 INFO (MainThread) [aiopioneer.pioneer_avr] Starting aiopioneer 0.7.0
2024-11-21 21:50:21.168 INFO (MainThread) [aiopioneer.pioneer_avr] determining available listening modes
2024-11-21 21:50:24.237 ERROR (MainThread) [custom_components.pioneer_async] exception on initialising Pioneer AVR: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-21 21:50:24.238 WARNING (MainThread) [aiopioneer.pioneer_avr] AVR not connected, skipping disconnect

... every few minutes.

I can get it working again if I turn on my receiver and reload the integration.

Originally posted by @dondonini in #48 (comment)

This is what I got:

HA History:
image

HA Core Log:

2024-11-26 04:24:54.627 INFO (MainThread) [aiopioneer.pioneer_avr] Zone 1: volume: 57 -> 55 (055)
2024-11-26 04:24:54.628 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
2024-11-26 04:24:55.027 INFO (MainThread) [aiopioneer.pioneer_avr] Zone 1: volume: 55 -> 53 (053)
2024-11-26 04:24:55.027 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
2024-11-26 04:24:55.347 INFO (MainThread) [aiopioneer.pioneer_avr] Zone 1: volume: 53 -> 47 (047)
2024-11-26 04:24:55.347 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
2024-11-26 04:24:55.668 INFO (MainThread) [aiopioneer.pioneer_avr] Zone 1: volume: 47 -> 41 (041)
2024-11-26 04:24:55.669 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
2024-11-26 04:24:59.291 INFO (MainThread) [aiopioneer.pioneer_avr] Zone 1: volume: 41 -> 39 (039)
2024-11-26 04:24:59.292 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
2024-11-26 04:24:59.626 INFO (MainThread) [aiopioneer.pioneer_avr] Zone 1: volume: 39 -> 37 (037)
2024-11-26 04:24:59.627 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
2024-11-26 04:24:59.977 INFO (MainThread) [aiopioneer.pioneer_avr] Zone 1: volume: 37 -> 35 (035)
2024-11-26 04:24:59.978 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
...
2024-11-26 10:50:15.849 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.disconnect() started
2024-11-26 10:50:15.850 DEBUG (MainThread) [aiopioneer.pioneer_avr] disconnecting AVR connection
2024-11-26 10:50:15.850 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
2024-11-26 10:50:15.866 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
2024-11-26 10:50:15.869 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR._updater() completed
2024-11-26 10:50:15.980 DEBUG (MainThread) [aiopioneer.pioneer_avr] closing AVR connection
2024-11-26 10:50:15.981 DEBUG (MainThread) [aiopioneer.pioneer_avr] ignoring disconnect exception: [Errno 110] Operation timed out
2024-11-26 10:50:15.981 INFO (MainThread) [aiopioneer.pioneer_avr] AVR connection closed
2024-11-26 10:50:15.981 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR._reconnect_schedule()
2024-11-26 10:50:15.982 INFO (MainThread) [aiopioneer.pioneer_avr] reconnecting to AVR
2024-11-26 10:50:15.982 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.disconnect() completed
2024-11-26 10:50:15.982 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR._connection_listener() completed
2024-11-26 10:50:15.983 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.reconnect() started
2024-11-26 10:50:15.983 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 4s before retrying connection
...
2024-11-26 10:50:20.662 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-26 10:50:20.663 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-26 10:50:23.721 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: OSError: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-26 10:50:23.721 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 4s before retrying connection
2024-11-26 10:50:28.476 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-26 10:50:28.477 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-26 10:50:31.529 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: OSError: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-26 10:50:31.529 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 4s before retrying connection
2024-11-26 10:50:35.973 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-26 10:50:35.973 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-26 10:50:39.049 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: OSError: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-26 10:50:39.050 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 8s before retrying connection
2024-11-26 10:50:47.071 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-26 10:50:47.071 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-26 10:50:50.153 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: OSError: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-26 10:50:50.153 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 16s before retrying connection
...
2024-11-26 10:51:06.930 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-26 10:51:06.930 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-26 10:51:07.339 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: OSError: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-26 10:51:07.339 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 32s before retrying connection
...
2024-11-26 10:51:40.177 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-26 10:51:40.178 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-26 10:51:43.241 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: OSError: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-26 10:51:43.242 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 64s before retrying connection
...
2024-11-26 10:52:47.644 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-26 10:52:47.644 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-26 10:52:50.697 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: OSError: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-26 10:52:50.698 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 64s before retrying connection

I just realized that it never detects when I turn off the receiver. I turned it off at around 10 am.
@crowbarz crowbarz mentioned this issue Nov 27, 2024
Open
@crowbarz
Copy link
Owner Author

The timeline of events would appear to be:

  • ~10:00: AVR is put into standby by pressing the power button on the AVR (or via the AVR remote)
  • ~10:50: integration can no longer communicate with the AVR, and initiates disconnection/reconnection.

I just realized that it never detects when I turn off the receiver. I turned it off at around 10 am.

@dondonini What were the logs immediately before and after you pressed the power button? This should show an INFO update showing Zone 1: power: True -> False (1) and reflecting in the HA UI as powered off.

Also, what are the logs immediately preceding the disconnect log lines:

2024-11-26 10:50:15.849 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.disconnect() started
2024-11-26 10:50:15.850 DEBUG (MainThread) [aiopioneer.pioneer_avr] disconnecting AVR connection

There are only a handful of cases where the integration triggers a disconnection, and it would be useful here to validate which case you hit. It is likely to have disconnected because to the network connection to the AVR timing out, due to the AVR no longer responding to the integration, and the logs should confirm this.

If this is the case, the suggestion in #48 (comment) (increase polling rate by decreasing polling interval) may solve your problem. The polling interval needs to be decreased until you see updating AVR status (or refreshing AVR status in later releases) in your logs when nothing is happening. I would start by decreasing the polling interval to 30s.

@dondonini
Copy link

@dondonini What were the logs immediately before and after you pressed the power button? This should show an INFO update showing Zone 1: power: True -> False (1) and reflecting in the HA UI as powered off.

My HA is a mess so my apologies. Here is my log between 10am to 10:50am.

Also, what are the logs immediately preceding the disconnect log lines:

Here's the complete log for a small section. Sorry for the mess again:

2024-11-26 10:50:15.849 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.disconnect() started
2024-11-26 10:50:15.850 DEBUG (MainThread) [aiopioneer.pioneer_avr] disconnecting AVR connection
2024-11-26 10:50:15.850 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
2024-11-26 10:50:15.866 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
2024-11-26 10:50:15.869 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR._updater() completed
2024-11-26 10:50:15.980 DEBUG (MainThread) [aiopioneer.pioneer_avr] closing AVR connection
2024-11-26 10:50:15.981 DEBUG (MainThread) [aiopioneer.pioneer_avr] ignoring disconnect exception: [Errno 110] Operation timed out
2024-11-26 10:50:15.981 INFO (MainThread) [aiopioneer.pioneer_avr] AVR connection closed
2024-11-26 10:50:15.981 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR._reconnect_schedule()
2024-11-26 10:50:15.982 INFO (MainThread) [aiopioneer.pioneer_avr] reconnecting to AVR
2024-11-26 10:50:15.982 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.disconnect() completed
2024-11-26 10:50:15.982 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR._connection_listener() completed
2024-11-26 10:50:15.983 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.reconnect() started
2024-11-26 10:50:15.983 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 4s before retrying connection
2024-11-26 10:50:16.931 WARNING (MainThread) [switchbot.devices.device] E8-6E-49-EA-6F-F6 (E8:6E:49:EA:6F:F6): Device unexpectedly disconnected; RSSI: -84
2024-11-26 10:50:19.945 ERROR (MainThread) [wyzeapy.services.update_manager] Unknown error happened during updating device info
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/wyzeapy/services/update_manager.py", line 42, in update
    self.device = await self.service.update(self.device)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/wyzeapy/services/camera_service.py", line 53, in update
    state_response: List[Tuple[PropertyIDs, Any]] = await self._get_property_list(camera)
                                                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/wyzeapy/services/base_service.py", line 167, in _get_property_list
    check_for_errors_standard(self, response_json)
  File "/usr/local/lib/python3.12/site-packages/wyzeapy/utils.py", line 85, in check_for_errors_standard
    raise UnknownApiError(response_json)
wyzeapy.exceptions.UnknownApiError: {'code': '3005', 'ts': 1732636219899, 'msg': 'unauthorized operation', 'data': {}, 'traceId': '3cabedfbdae22a3de91c9606dd72eed1'}
2024-11-26 10:50:20.238 WARNING (MainThread) [switchbot.devices.device] E8-6E-49-EA-6F-F6 (E8:6E:49:EA:6F:F6): Device unexpectedly disconnected; RSSI: -84
2024-11-26 10:50:20.662 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-26 10:50:20.663 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-26 10:50:21.566 WARNING (MainThread) [switchbot.devices.device] E8-6E-49-EA-6F-F6 (E8:6E:49:EA:6F:F6): Device unexpectedly disconnected; RSSI: -84
2024-11-26 10:50:23.721 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: OSError: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-26 10:50:23.721 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 4s before retrying connection
2024-11-26 10:50:26.181 WARNING (MainThread) [switchbot.devices.device] E8-6E-49-EA-6F-F6 (E8:6E:49:EA:6F:F6): Device unexpectedly disconnected; RSSI: -84
2024-11-26 10:50:28.157 WARNING (MainThread) [switchbot.devices.device] E8-6E-49-EA-6F-F6 (E8:6E:49:EA:6F:F6): Device unexpectedly disconnected; RSSI: -84
2024-11-26 10:50:28.476 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-26 10:50:28.477 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-26 10:50:29.472 WARNING (MainThread) [switchbot.devices.device] E8-6E-49-EA-6F-F6 (E8:6E:49:EA:6F:F6): Device unexpectedly disconnected; RSSI: -84
2024-11-26 10:50:31.529 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: OSError: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-26 10:50:31.529 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 4s before retrying connection
2024-11-26 10:50:32.862 WARNING (MainThread) [switchbot.devices.device] E8-6E-49-EA-6F-F6 (E8:6E:49:EA:6F:F6): Device unexpectedly disconnected; RSSI: -84
2024-11-26 10:50:35.973 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-26 10:50:35.973 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-26 10:50:39.049 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: OSError: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-26 10:50:39.050 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 8s before retrying connection
2024-11-26 10:50:41.306 WARNING (MainThread) [switchbot.devices.device] E8-6E-49-EA-6F-F6 (E8:6E:49:EA:6F:F6): Device unexpectedly disconnected; RSSI: -84
2024-11-26 10:50:44.269 WARNING (MainThread) [switchbot.devices.device] E8-6E-49-EA-6F-F6 (E8:6E:49:EA:6F:F6): Device unexpectedly disconnected; RSSI: -84
2024-11-26 10:50:46.229 WARNING (MainThread) [switchbot.devices.device] E8-6E-49-EA-6F-F6 (E8:6E:49:EA:6F:F6): Device unexpectedly disconnected; RSSI: -84
2024-11-26 10:50:47.071 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-26 10:50:47.071 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-26 10:50:50.153 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: OSError: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-26 10:50:50.153 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 16s before retrying connection
2024-11-26 10:50:54.308 WARNING (MainThread) [switchbot.devices.device] E8-6E-49-EA-6F-F6 (E8:6E:49:EA:6F:F6): Device unexpectedly disconnected; RSSI: -84
2024-11-26 10:50:55.133 ERROR (MainThread) [wyzeapy.services.update_manager] Unknown error happened during updating device info

Right after this, its a repeat of what you've seen already lol

@crowbarz
Copy link
Owner Author

Unfortunately I didn't see anything with pioneer in the attached log, so not sure you attached the right file there.

Let us know if reducing the polling interval successfully prevents your AVR from disconnecting from the network.

@dondonini
Copy link

dondonini commented Nov 28, 2024 •
edited
Loading

Unfortunately I didn't see anything with pioneer in the attached log, so not sure you attached the right file there.

Yeah, they were both correct logs. I was not sure what to send cause I recalled not seeing any Pioneer-related logs between the times you asked. That was my raw logs between those times.

Anyway, I reloaded my integration and did a few more tests and I got a better log result that might hold more information for troubleshooting:

2024-11-27 20:29:57.826 INFO (MainThread) [aiopioneer.pioneer_avr] Zone 1: power: True -> False (2)
2024-11-27 20:29:57.826 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
2024-11-27 20:29:57.844 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
2024-11-27 20:30:18.285 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.disconnect() started
2024-11-27 20:30:18.285 DEBUG (MainThread) [aiopioneer.pioneer_avr] disconnecting AVR connection
2024-11-27 20:30:18.285 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
2024-11-27 20:30:18.296 DEBUG (MainThread) [custom_components.pioneer_async.coordinator] Manually updated pioneer_async data
2024-11-27 20:30:18.299 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR._updater() completed
2024-11-27 20:30:18.301 DEBUG (MainThread) [aiopioneer.pioneer_avr] closing AVR connection
2024-11-27 20:30:18.301 DEBUG (MainThread) [aiopioneer.pioneer_avr] ignoring disconnect exception: [Errno 110] Operation timed out
2024-11-27 20:30:18.302 INFO (MainThread) [aiopioneer.pioneer_avr] AVR connection closed
2024-11-27 20:30:18.302 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR._reconnect_schedule()
2024-11-27 20:30:18.302 INFO (MainThread) [aiopioneer.pioneer_avr] reconnecting to AVR
2024-11-27 20:30:18.302 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.disconnect() completed
2024-11-27 20:30:18.302 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR._connection_listener() completed
2024-11-27 20:30:18.303 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.reconnect() started
2024-11-27 20:30:18.303 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 4s before retrying connection
2024-11-27 20:30:21.919 WARNING (MainThread) [async_upnp_client.profiles.profile] Failed (re-)subscribing to: uuid:ca888fad-e4e8-16db-adbf-3f0c1938d349, reason: UpnpConnectionError("UpnpConnectionTimeoutError('TimeoutError()', None)", None)
2024-11-27 20:30:22.500 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-27 20:30:22.500 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
...
2024-11-27 20:30:27.502 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: TimeoutError: 
2024-11-27 20:30:27.503 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 4s before retrying connection
2024-11-27 20:30:31.876 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-27 20:30:31.877 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-27 20:30:33.166 WARNING (MainThread) [homeassistant.components.media_player] Updating dlna_dmr media_player took longer than the scheduled update interval 0:00:10
2024-11-27 20:30:33.166 WARNING (MainThread) [homeassistant.helpers.entity] Update of media_player.vsx_822 is taking over 10 seconds
2024-11-27 20:30:36.879 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: TimeoutError: 
2024-11-27 20:30:36.879 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 4s before retrying connection
2024-11-27 20:30:39.917 WARNING (MainThread) [async_upnp_client.profiles.profile] Failed (re-)subscribing to: uuid:2c440838-4649-17fe-b34a-d04adac61437, reason: UpnpConnectionError("UpnpConnectionTimeoutError('TimeoutError()', None)", None)
2024-11-27 20:30:41.151 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-27 20:30:41.151 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-27 20:30:43.167 WARNING (MainThread) [homeassistant.components.media_player] Updating dlna_dmr media_player took longer than the scheduled update interval 0:00:10
2024-11-27 20:30:46.153 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: TimeoutError: 
2024-11-27 20:30:46.153 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 8s before retrying connection
2024-11-27 20:30:53.168 WARNING (MainThread) [homeassistant.components.media_player] Updating dlna_dmr media_player took longer than the scheduled update interval 0:00:10
2024-11-27 20:30:55.089 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-27 20:30:55.090 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-27 20:30:55.114 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: OSError: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-27 20:30:55.115 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 16s before retrying connection
2024-11-27 20:31:11.955 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-27 20:31:11.956 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-27 20:31:15.017 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: OSError: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-27 20:31:15.018 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 32s before retrying connection
2024-11-27 20:31:47.101 DEBUG (MainThread) [aiopioneer.pioneer_avr] >> PioneerAVR.connect() started
2024-11-27 20:31:47.101 DEBUG (MainThread) [aiopioneer.pioneer_avr] opening AVR connection
2024-11-27 20:31:50.153 DEBUG (MainThread) [aiopioneer.pioneer_avr] could not reconnect to AVR: OSError: [Errno 113] Connect call failed ('192.168.50.59', 8102)
2024-11-27 20:31:50.154 DEBUG (MainThread) [aiopioneer.pioneer_avr] waiting 64s before retrying connection

Edit: Removed unrelated logs

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@crowbarz @dondonini