search

vwout / hass-zkaccess_c3

C3 Access Control Panel integration for Home Assistant
GNU General Public License v3.0
5 stars 1 forks source link

Component stopped working #6

Closed V1pr closed 10 months ago

V1pr commented 10 months ago

Hi,

I was able to add the integration with release 0.0.6 (manual install to custom_components). Got everything working, but yesterday the integration stopped working with "unavaliable". The C3-100 is still working with the zktbio app, the door is openable. HA is 2023.5.4

Upgraded component to 0.0.7, but nothing changed.

Logs:

# grep -iE '(c3|door)' home-assistant.log
2023-12-18 14:45:58.062 WARNING (SyncWorker_2) [homeassistant.loader] We found a custom integration zkaccess_c3 which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-12-18 14:46:08.186 DEBUG (MainThread) [C3] Sending: aa01760400fefefefe467755
2023-12-18 14:46:08.232 DEBUG (MainThread) [C3] Received header: aa01c90100
2023-12-18 14:46:08.232 DEBUG (MainThread) [C3] Receiving payload (data size 1): f313d955
2023-12-18 14:46:08.233 DEBUG (MainThread) [C3] Connection attempt with session to 192.168.3.29 failed: Error -13 received in reply: Command error: This command is not available
2023-12-18 14:46:08.233 DEBUG (MainThread) [C3] Sending: aa01010000503c55
2023-12-18 14:46:08.268 DEBUG (MainThread) [C3] Received header: aa01c80000
2023-12-18 14:46:08.269 DEBUG (MainThread) [C3] Connected without session
2023-12-18 14:46:08.270 DEBUG (MainThread) [C3] Sending: aa010441007e53657269616c4e756d6265722c4669726d5665722c4465766963654e616d652c4c6f636b436f756e742c417578496e436f756e742c4175784f7574436f756e74d06355
2023-12-18 14:46:08.316 DEBUG (MainThread) [C3] Received header: aa01c87400
2023-12-18 14:46:08.316 DEBUG (MainThread) [C3] Receiving payload (data size 116): 7e53657269616c4e756d6265723d414359543033323335323234362c4669726d5665723d41432056657220352e342e332e323030312053657020323520323031392c4465766963654e616d653d2c4c6f636b436f756e743d312c417578496e436f756e743d312c4175784f7574436f756e743d31ff7a55
2023-12-18 14:46:08.318 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry Entrance for zkaccess_c3
  File "/config/custom_components/zkaccess_c3/__init__.py", line 80, in async_setup_entry
    c3_coordinator = C3Coordinator(
  File "/config/custom_components/zkaccess_c3/coordinator.py", line 83, in __init__
2023-12-18 14:50:09.296 WARNING (MainThread) [homeassistant.helpers.service] Unable to find referenced entities lock.door_1 or it is/they are currently not available
2023-12-18 14:40:19.944 WARNING (SyncWorker_2) [homeassistant.loader] We found a custom integration zkaccess_c3 which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-12-18 14:40:24.742 DEBUG (MainThread) [C3] Sending: aa01760400fefefefe467755
2023-12-18 14:40:24.786 DEBUG (MainThread) [C3] Received header: aa01c90100
2023-12-18 14:40:24.787 DEBUG (MainThread) [C3] Receiving payload (data size 1): f313d955
2023-12-18 14:40:24.787 DEBUG (MainThread) [C3] Connection attempt with session to 192.168.3.29 failed: Error -13 received in reply: Command error: This command is not available
2023-12-18 14:40:24.787 DEBUG (MainThread) [C3] Sending: aa01010000503c55
2023-12-18 14:40:24.822 DEBUG (MainThread) [C3] Received header: aa01c80000
2023-12-18 14:40:24.822 DEBUG (MainThread) [C3] Connected without session
2023-12-18 14:40:24.823 DEBUG (MainThread) [C3] Sending: aa010441007e53657269616c4e756d6265722c4669726d5665722c4465766963654e616d652c4c6f636b436f756e742c417578496e436f756e742c4175784f7574436f756e74d06355
2023-12-18 14:40:24.870 DEBUG (MainThread) [C3] Received header: aa01c87400
2023-12-18 14:40:24.870 DEBUG (MainThread) [C3] Receiving payload (data size 116): 7e53657269616c4e756d6265723d414359543033323335323234362c4669726d5665723d41432056657220352e342e332e323030312053657020323520323031392c4465766963654e616d653d2c4c6f636b436f756e743d312c417578496e436f756e743d312c4175784f7574436f756e743d31ff7a55
2023-12-18 14:40:24.873 DEBUG (MainThread) [C3] Sending: aa010b0000703e55
2023-12-18 14:40:24.900 DEBUG (MainThread) [C3] Received header: aa01c86801
2023-12-18 14:40:24.901 DEBUG (MainThread) [C3] Receiving payload (data size 360): 000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000fabb55
2023-12-18 14:40:24.905 DEBUG (MainThread) [C3] Transition RT log mode to key/value
2023-12-18 14:40:24.906 DEBUG (MainThread) [C3] Sending: aa01790000d02555
2023-12-18 14:40:24.929 DEBUG (MainThread) [C3] Received header: aa01c80000
2023-12-18 14:40:24.930 DEBUG (MainThread) [C3] Sending: aa01790000d02555
2023-12-18 14:40:24.960 DEBUG (MainThread) [C3] Received header: aa01c82901
2023-12-18 14:40:24.960 DEBUG (MainThread) [C3] Receiving payload (data size 297): 74696d653d323032332d31322d31372032303a31343a32320970696e3d3009636172646e6f3d30096576656e74616464723d30096576656e743d32303609696e6f75747374617475733d3209766572696679747970653d32303009696e6465783d32310d0a74696d653d323032332d31322d31372032303a32383a32330970696e3d3009636172646e6f3d30096576656e74616464723d31096576656e743d3809696e6f75747374617475733d3209766572696679747970653d32303009696e6465783d32320d0a74696d653d323032332d31322d31382031333a32313a35350970696e3d3009636172646e6f3d30096576656e74616464723d31096576656e743d3809696e6f75747374617475733d3209766572696679747970653d32303009696e6465783d323354b655
2023-12-18 14:40:24.964 DEBUG (MainThread) [C3] Received RT k/v log (8): {'time': '2023-12-17 20:14:22', 'pin': '0', 'cardno': '0', 'eventaddr': '1', 'event': '8', 'inoutstatus': '2', 'verifytype': '200', 'index': '23'}
2023-12-18 14:40:24.971 DEBUG (MainThread) [C3] Sending: aa01790000d02555
2023-12-18 14:40:24.990 DEBUG (MainThread) [C3] Received header: aa01c83a00
2023-12-18 14:40:24.990 DEBUG (MainThread) [C3] Receiving payload (data size 58): 74696d653d323032332d31322d31382031333a32323a30320973656e736f723d30310972656c61793d303009616c61726d3d30303030303030303af155
2023-12-18 14:40:24.991 DEBUG (MainThread) [C3] Received RT k/v log (4): {'time': '2023-12-18 13:22:02', 'sensor': '01', 'relay': '00', 'alarm': '00000000'}
2023-12-18 14:40:24.991 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.119 seconds (success: True)
2023-12-18 14:40:40.426 DEBUG (MainThread) [C3] Sending: aa01790000d02555
2023-12-18 14:40:40.427 ERROR (MainThread) [custom_components.zkaccess_c3.coordinator] Realtime log update failed: Invalid response header received; expected 5 bytes, received b''
2023-12-18 14:40:40.433 DEBUG (MainThread) [C3] Sending: aa01020000a03c55
2023-12-18 14:40:40.433 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.008 seconds (success: True)
2023-12-18 14:40:50.426 ERROR (MainThread) [custom_components.zkaccess_c3.coordinator] Error fetching ZKAccess C3 @ 192.168.3.29:4370 data: Error communicating with API: [Errno 9] Bad file descriptor
2023-12-18 14:40:50.428 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.002 seconds (success: False)
2023-12-18 14:41:00.426 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.000 seconds (success: False)
2023-12-18 14:41:10.426 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.000 seconds (success: False)
2023-12-18 14:41:20.426 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.000 seconds (success: False)
2023-12-18 14:41:30.426 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.000 seconds (success: False)
2023-12-18 14:41:40.426 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.000 seconds (success: False)
2023-12-18 14:41:50.426 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.000 seconds (success: False)
2023-12-18 14:42:00.426 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.000 seconds (success: False)
2023-12-18 14:42:10.425 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.000 seconds (success: False)
V1pr commented 10 months ago

More logs, after restarting the zkt C3-100:

92.168.3.110', 1255); Retrying in background
2023-12-18 14:46:08.186 DEBUG (MainThread) [C3] Sending: aa01760400fefefefe467755
2023-12-18 14:46:08.232 DEBUG (MainThread) [C3] Received header: aa01c90100
2023-12-18 14:46:08.232 DEBUG (MainThread) [C3] Receiving payload (data size 1): f313d955
2023-12-18 14:46:08.233 DEBUG (MainThread) [C3] Connection attempt with session to 192.168.3.29 failed: Error -13 received in reply: Command error: This command is not available
2023-12-18 14:46:08.233 DEBUG (MainThread) [C3] Sending: aa01010000503c55
2023-12-18 14:46:08.268 DEBUG (MainThread) [C3] Received header: aa01c80000
2023-12-18 14:46:08.269 DEBUG (MainThread) [C3] Connected without session
2023-12-18 14:46:08.270 DEBUG (MainThread) [C3] Sending: aa010441007e53657269616c4e756d6265722c4669726d5665722c4465766963654e616d652c4c6f636b436f756e742c417578496e436f756e742c4175784f7574436f756e74d06355
2023-12-18 14:46:08.316 DEBUG (MainThread) [C3] Received header: aa01c87400
2023-12-18 14:46:08.316 DEBUG (MainThread) [C3] Receiving payload (data size 116): 7e53657269616c4e756d6265723d414359543033323335323234362c4669726d5665723d41432056657220352e342e332e323030312053657020323520323031392c4465766963654e616d653d2c4c6f636b436f756e743d312c417578496e436f756e743d312c4175784f7574436f756e743d31ff7a55
2023-12-18 14:46:08.318 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry Entrance for zkaccess_c3
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 387, in async_setup
    result = await component.async_setup_entry(hass, self)
  File "/config/custom_components/zkaccess_c3/__init__.py", line 80, in async_setup_entry
    c3_coordinator = C3Coordinator(
  File "/config/custom_components/zkaccess_c3/coordinator.py", line 83, in __init__
    device_registry.async_get_or_create(
TypeError: DeviceRegistry.async_get_or_create() got an unexpected keyword argument 'serial_number'
vwout commented 10 months ago

The reason for the error in the last log is caused by the fact that the integration doesn't support HA 2023.5 anymore. I expect this also is the issue in the first log, though not visible. I will see how I can implement backward compatibility.

V1pr commented 10 months ago

@vwout I've upgraded to v0.0.7, but that did not solve the issue. Afterwards I've upgraded the HA to 2024.1, but that did not solve the issue. The logs:

2024-01-04 13:42:00.736 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.000 seconds (success: False)
2024-01-04 13:42:07.940 DEBUG (MainThread) [C3] Sending: aa01760400fefefefe467755
2024-01-04 13:42:07.990 DEBUG (MainThread) [C3] Received header: aa01c90100
2024-01-04 13:42:07.991 DEBUG (MainThread) [C3] Receiving payload (data size 1): f313d955
2024-01-04 13:42:07.991 DEBUG (MainThread) [C3] Connection attempt with session to 192.168.3.29 failed: Error -13 received in reply: Command error: This command is not available
2024-01-04 13:42:07.991 DEBUG (MainThread) [C3] Sending: aa01010000503c55
2024-01-04 13:42:08.036 DEBUG (MainThread) [C3] Received header: aa01c80000
2024-01-04 13:42:08.038 DEBUG (MainThread) [C3] Connected without session
2024-01-04 13:42:08.039 DEBUG (MainThread) [C3] Sending: aa010441007e53657269616c4e756d6265722c4669726d5665722c4465766963654e616d652c4c6f636b436f756e742c417578496e436f756e742c4175784f7574436f756e74d06355
2024-01-04 13:42:08.097 DEBUG (MainThread) [C3] Received header: aa01c87400
2024-01-04 13:42:08.097 DEBUG (MainThread) [C3] Receiving payload (data size 116): 7e53657269616c4e756d6265723d414359543033323335323234362c4669726d5665723d41432056657220352e342e332e323030312053657020323520323031392c4465766963654e616d653d2c4c6f636b436f756e743d312c417578496e436f756e743d312c4175784f7574436f756e743d31ff7a55
2024-01-04 13:42:08.099 DEBUG (MainThread) [C3] Sending: aa010b0000703e55
2024-01-04 13:42:08.132 DEBUG (MainThread) [C3] Received header: aa01c86801
2024-01-04 13:42:08.132 DEBUG (MainThread) [C3] Receiving payload (data size 360): 000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000fabb55
2024-01-04 13:42:08.136 DEBUG (MainThread) [C3] Transition RT log mode to key/value
2024-01-04 13:42:08.136 DEBUG (MainThread) [C3] Sending: aa01790000d02555
2024-01-04 13:42:08.167 DEBUG (MainThread) [C3] Received header: aa01c80000
2024-01-04 13:42:08.168 DEBUG (MainThread) [C3] Sending: aa01790000d02555
2024-01-04 13:42:08.208 DEBUG (MainThread) [C3] Received header: aa01c8c600
2024-01-04 13:42:08.209 DEBUG (MainThread) [C3] Receiving payload (data size 198): 74696d653d323032332d31322d32302031323a30363a35340970696e3d3009636172646e6f3d30096576656e74616464723d30096576656e743d32303609696e6f75747374617475733d3209766572696679747970653d32303009696e6465783d32350d0a74696d653d323032342d30312d30342031323a32363a31350970696e3d3009636172646e6f3d30096576656e74616464723d31096576656e743d3809696e6f75747374617475733d3209766572696679747970653d32303009696e6465783d3236202255
2024-01-04 13:42:08.211 DEBUG (MainThread) [C3] Received RT k/v log (8): {'time': '2023-12-20 12:06:54', 'pin': '0', 'cardno': '0', 'eventaddr': '1', 'event': '8', 'inoutstatus': '2', 'verifytype': '200', 'index': '26'}
2024-01-04 13:42:08.212 DEBUG (MainThread) [C3] Sending: aa01790000d02555
2024-01-04 13:42:08.243 DEBUG (MainThread) [C3] Received header: aa01c83a00
2024-01-04 13:42:08.243 DEBUG (MainThread) [C3] Receiving payload (data size 58): 74696d653d323032342d30312d30342031323a32363a32320973656e736f723d30310972656c61793d303009616c61726d3d30303030303030303ec055
2024-01-04 13:42:08.244 DEBUG (MainThread) [C3] Received RT k/v log (4): {'time': '2024-01-04 12:26:22', 'sensor': '01', 'relay': '00', 'alarm': '00000000'}
2024-01-04 13:42:08.245 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.146 seconds (success: True)
2024-01-04 13:42:12.759 DEBUG (MainThread) [C3] Sending: aa01790000d02555
2024-01-04 13:42:12.761 ERROR (MainThread) [custom_components.zkaccess_c3.coordinator] Realtime log update failed: Invalid response header received; expected 5 bytes, received b''
2024-01-04 13:42:12.762 DEBUG (MainThread) [C3] Sending: aa01020000a03c55
2024-01-04 13:42:12.762 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.003 seconds (success: True)
2024-01-04 13:42:17.759 ERROR (MainThread) [custom_components.zkaccess_c3.coordinator] Error fetching ZKAccess C3 @ 192.168.3.29:4370 data: Error communicating with API: [Errno 9] Bad file descriptor
2024-01-04 13:42:17.760 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.001 seconds (success: False)
2024-01-04 13:42:22.759 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.000 seconds (success: False)
V1pr commented 10 months ago 
2024-01-04 14:01:17.584 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration zkaccess_c3 which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2024-01-04 14:01:29.791 DEBUG (MainThread) [C3] Sending: aa01760400fefefefe467755
2024-01-04 14:01:29.840 DEBUG (MainThread) [C3] Received header: aa01c90100
2024-01-04 14:01:29.841 DEBUG (MainThread) [C3] Receiving payload (data size 1): f313d955
2024-01-04 14:01:29.841 DEBUG (MainThread) [C3] Connection attempt with session to 192.168.3.29 failed: Error -13 received in reply: Command error: This command is not available
2024-01-04 14:01:29.841 DEBUG (MainThread) [C3] Sending: aa01010000503c55
2024-01-04 14:01:29.891 DEBUG (MainThread) [C3] Received header: aa01c80000
2024-01-04 14:01:29.892 DEBUG (MainThread) [C3] Connected without session
2024-01-04 14:01:29.893 DEBUG (MainThread) [C3] Sending: aa010441007e53657269616c4e756d6265722c4669726d5665722c4465766963654e616d652c4c6f636b436f756e742c417578496e436f756e742c4175784f7574436f756e74d06355
2024-01-04 14:01:29.950 DEBUG (MainThread) [C3] Received header: aa01c87400
2024-01-04 14:01:29.950 DEBUG (MainThread) [C3] Receiving payload (data size 116): 7e53657269616c4e756d6265723d414359543033323335323234362c4669726d5665723d41432056657220352e342e332e323030312053657020323520323031392c4465766963654e616d653d2c4c6f636b436f756e743d312c417578496e436f756e743d312c4175784f7574436f756e743d31ff7a55
2024-01-04 14:01:29.953 DEBUG (MainThread) [C3] Sending: aa010b0000703e55
2024-01-04 14:01:29.985 DEBUG (MainThread) [C3] Received header: aa01c86801
2024-01-04 14:01:29.985 DEBUG (MainThread) [C3] Receiving payload (data size 360): 000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000fabb55
2024-01-04 14:01:29.989 DEBUG (MainThread) [C3] Transition RT log mode to key/value
2024-01-04 14:01:29.989 DEBUG (MainThread) [C3] Sending: aa01790000d02555
2024-01-04 14:01:30.020 DEBUG (MainThread) [C3] Received header: aa01c80000
2024-01-04 14:01:30.021 DEBUG (MainThread) [C3] Sending: aa01790000d02555
2024-01-04 14:01:30.061 DEBUG (MainThread) [C3] Received header: aa01c8c600
2024-01-04 14:01:30.061 DEBUG (MainThread) [C3] Receiving payload (data size 198): 74696d653d323032332d31322d32302031323a30363a35340970696e3d3009636172646e6f3d30096576656e74616464723d30096576656e743d32303609696e6f75747374617475733d3209766572696679747970653d32303009696e6465783d32350d0a74696d653d323032342d30312d30342031323a32363a31350970696e3d3009636172646e6f3d30096576656e74616464723d31096576656e743d3809696e6f75747374617475733d3209766572696679747970653d32303009696e6465783d3236202255
2024-01-04 14:01:30.063 DEBUG (MainThread) [C3] Received RT k/v log (8): {'time': '2023-12-20 12:06:54', 'pin': '0', 'cardno': '0', 'eventaddr': '1', 'event': '8', 'inoutstatus': '2', 'verifytype': '200', 'index': '26'}
2024-01-04 14:01:30.071 DEBUG (MainThread) [C3] Sending: aa01790000d02555
2024-01-04 14:01:30.096 DEBUG (MainThread) [C3] Received header: aa01c83a00
2024-01-04 14:01:30.096 DEBUG (MainThread) [C3] Receiving payload (data size 58): 74696d653d323032342d30312d30342031323a32363a32320973656e736f723d30310972656c61793d303009616c61726d3d30303030303030303ec055
2024-01-04 14:01:30.097 DEBUG (MainThread) [C3] Received RT k/v log (4): {'time': '2024-01-04 12:26:22', 'sensor': '01', 'relay': '00', 'alarm': '00000000'}
2024-01-04 14:01:30.097 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.145 seconds (success: True)
2024-01-04 14:01:37.665 DEBUG (MainThread) [C3] Sending: aa01790000d02555
2024-01-04 14:01:37.666 ERROR (MainThread) [custom_components.zkaccess_c3.coordinator] Realtime log update failed: Invalid response header received; expected 5 bytes, received b''
2024-01-04 14:01:37.670 DEBUG (MainThread) [C3] Sending: aa01020000a03c55
2024-01-04 14:01:37.670 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.006 seconds (success: True)
2024-01-04 14:01:42.667 ERROR (MainThread) [custom_components.zkaccess_c3.coordinator] Error fetching ZKAccess C3 @ 192.168.3.29:4370 data: Error communicating with API: [Errno 9] Bad file descriptor
2024-01-04 14:01:42.667 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.001 seconds (success: False)
2024-01-04 14:01:47.666 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 192.168.3.29:4370 data in 0.000 seconds (success: False)
vwout commented 10 months ago

Over the past week I have done several improvement to the core library zkaccess-c3-py. I have seen similar issues while testing. During testing, fix https://github.com/vwout/zkaccess-c3-py/commit/980c14e7d3f8889ef7506f32d32533d23b4b1e14 resolved this. I will update the HA integration in the coming days as well (after some more testing).

vwout commented 10 months ago

I changed the connection handling of my library - more work was needed than mentioned earlier. My commit message closed this issues prematurely, however the last commit should resolve the issue. What I have noticed is that the C3 panels have issues with handling multiple connections, e.g. when using Hass and ZKAccess software in parallel. When this is the case, you may still see errors being logged, but the connection should automatically resume, so the status in Hass remains correct.

benofishal commented 9 months ago

Hi this doesn't appear to have fixed unfortunately. I have ZKAccess 5.2 which runs permanently in the background, the HASS connection loses ability to control the doors after about 24 hours (maybe less) and only a restart of home assistant fixes. Let me know if you need further info or testing.

vwout commented 9 months ago

This I can't fix. HomeAssistant will reconnect, but it may take a while when there are many disconnects. What I have seen is that the panel does not handle multiple connections well. So either ZKAccess or Hass will have trouble connecting.

Out of curiosity, why are you running both in parallel?

benofishal commented 9 months ago

No reason really, I'll disable the ZKAccess as I don't really use it, it's just been there running in the background for years. I'll shut it down and see how it goes.

benofishal commented 8 months ago

Hi VWOut, By way of update I have disabled ZKAccess and the problem persists. I lose ability to control doors after about 24 hours and the status does not update.

As soon as I restart HA control and status comes back so it is not the panel.

It starts off very responsive then seems to become laggy and slow as time passes before eventually becoming completely unresponsive.

Let me know what you would need from me?

benofishal commented 8 months ago

This should be helpful, its what starts in the logs

2024-02-07 01:26:56.200 ERROR (MainThread) [custom_components.zkaccess_c3.coordinator] Realtime log update failed: Invalid response header received; expected 5 bytes, received b'' 2024-02-07 01:27:04.198 ERROR (MainThread) [C3] Error while opening socket: [Errno 9] Bad file descriptor 2024-02-07 01:27:04.198 ERROR (MainThread) [custom_components.zkaccess_c3.coordinator] Realtime log update failed: No connection to C3 panel. 2024-02-07 01:41:52.201 ERROR (MainThread) [custom_components.zkaccess_c3.coordinator] Realtime log update failed: Invalid response header received; expected 5 bytes, received b'' 2024-02-07 01:41:57.197 ERROR (MainThread) [C3] Error while opening socket: [Errno 9] Bad file descriptor 2024-02-07 01:41:57.197 ERROR (MainThread) [custom_components.zkaccess_c3.coordinator] Realtime log update failed: No connection to C3 panel.

benofishal commented 8 months ago

Here is a log with debug enabled once it has become unresponsive

2024-02-09 13:57:22.199 DEBUG (MainThread) [C3] Sending: aa01760c00fefedf30353133353037303686e855 2024-02-09 13:57:22.208 DEBUG (MainThread) [C3] Received header: aa01c80400 2024-02-09 13:57:22.209 DEBUG (MainThread) [C3] Receiving payload (data size 4): 412fdf30f45555 2024-02-09 13:57:22.209 DEBUG (MainThread) [C3] Connected with Session ID 2f41 2024-02-09 13:57:22.209 DEBUG (MainThread) [C3] Sending: aa01790400412fe03044ae55 2024-02-09 13:57:22.345 DEBUG (MainThread) [C3] Received header: aa01c90500 2024-02-09 13:57:22.345 DEBUG (MainThread) [C3] Receiving payload (data size 5): 412fe030f3f5c255 2024-02-09 13:57:22.345 ERROR (MainThread) [custom_components.zkaccess_c3.coordinator] Realtime log update failed: Error -13 received in reply: Command error: This command is not available 2024-02-09 13:57:22.345 DEBUG (MainThread) [C3] Sending: aa01020400412fe1308e3955 2024-02-09 13:57:22.635 DEBUG (MainThread) [C3] Received header: aa01c80400 2024-02-09 13:57:22.635 DEBUG (MainThread) [C3] Receiving payload (data size 4): 412fe130e43555 2024-02-09 13:57:22.636 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 10.0.100.3:4370 data in 0.439 seconds (success: True) 2024-02-09 13:57:27.197 ERROR (MainThread) [C3] Error while opening socket: [Errno 9] Bad file descriptor 2024-02-09 13:57:27.197 ERROR (MainThread) [custom_components.zkaccess_c3.coordinator] Realtime log update failed: No connection to C3 panel. 2024-02-09 13:57:27.197 DEBUG (MainThread) [custom_components.zkaccess_c3.coordinator] Finished fetching ZKAccess C3 @ 10.0.100.3:4370 data in 0.000 seconds (success: True) 2024-02-09 13:57:28.937 ERROR (SyncWorker_3) [custom_components.zkaccess_c3.lock] Unlock of door 2 failure: No connection to C3 panel.