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.11k stars 29.79k forks source link

Ads-Integration has ADSTimouts since update to 0.113.0 #38150

Closed punzenbergerpeter closed 4 years ago

punzenbergerpeter commented 4 years ago

The problem

This morning I updated the HomeAssistant from version 0.112 to 0.113.0, and since then the connection to my ads device does not work anymore. As you can see in the logs (Log 1), ADSTimeouts always occur when registering the notifications of the individual variables. Only with the 1st variable the registration works. While looking through the commits of the ads component (https://github.com/home-assistant/core/tree/dev/homeassistant/components/ads) I found a commit of @balloob (0bf772b68b632e1cc6a26de803cac349a5cd244e) where the version of pyads was increased from 3.0.7 to 3.1.3. After undoing this commit on my system everything works as expected again (see log 2). It seems that the behaviour of the new version of pyads has some kind of negative effect on the component.

BR Peter

Environment

arch x86_64
dev false
docker true
hassio false
installation_type Home Assistant Container
os_name Linux
os_version 4.19.0-9-amd64
python_version 3.8.3
timezone Europe/Vienna
version 0.113.0
virtualenv false

Problem-relevant configuration.yaml

ads:
  device: '192.168.5.10.1.1'
  port: 801
  ip_address: '192.168.5.10'

switch:
  - platform: ads
    adsvar: '.g_heating_with_wood'
    name: 'Heizen mit Holz'
  - platform: ads
    adsvar: '.g_override_boiler_enable'
    name: 'Boiler override'

Traceback/Error logs

Log 1

2020-07-24 09:51:46 INFO (MainThread) [homeassistant.setup] Setting up ads
2020-07-24 09:51:47 INFO (MainThread) [homeassistant.setup] Setup of domain ads took 0.6 seconds
2020-07-24 09:51:47 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 09:51:47 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 09:51:47 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 09:51:47 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 09:51:47 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 09:51:47 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 09:51:47 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 09:51:47 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 09:51:47 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 09:51:47 INFO (MainThread) [homeassistant.components.switch] Setting up switch.ads
2020-07-24 09:51:47 INFO (MainThread) [homeassistant.components.switch] Setting up switch.ads
2020-07-24 09:51:48 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 09:51:48 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 09:51:48 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 09:51:48 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 09:51:48 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 09:51:48 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 09:51:48 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 09:51:48 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 09:51:48 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 09:51:48 DEBUG (SyncWorker_3) [homeassistant.components.ads] Added device notification 11 for variable .g_heating_circle_needs_warm_water
2020-07-24 09:51:48 DEBUG (SyncWorker_3) [homeassistant.components.ads] Added device notification 12 for variable .g_output_pump_heating_circle_enable
2020-07-24 09:51:48 DEBUG (Dummy-7) [homeassistant.components.ads] Received notification 12
2020-07-24 09:51:53 ERROR (SyncWorker_3) [homeassistant.components.ads] Error subscribing to .g_input_boiler_signal: ADSError: timeout elapsed (1861).
  File "/usr/local/lib/python3.8/site-packages/pyads/pyads_ex.py", line 849, in wrapper
  File "/usr/src/homeassistant/homeassistant/components/ads/__init__.py", line 244, in _device_notification_callback
2020-07-24 09:51:53 DEBUG (SyncWorker_4) [homeassistant.components.ads] Added device notification 13 for variable .g_boiler_needs_warm_water
2020-07-24 09:51:53 DEBUG (Dummy-7) [homeassistant.components.ads] Received notification 13
2020-07-24 09:51:57 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform ads is taking over 10 seconds.
2020-07-24 09:51:57 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform ads is taking over 10 seconds.
2020-07-24 09:51:57 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform ads is taking over 10 seconds.
2020-07-24 09:51:57 WARNING (MainThread) [homeassistant.components.switch] Setup of switch platform ads is taking over 10 seconds.
2020-07-24 09:51:58 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform ads is taking over 10 seconds.
2020-07-24 09:51:58 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform ads is taking over 10 seconds.
2020-07-24 09:51:58 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform ads is taking over 10 seconds.
2020-07-24 09:51:58 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform ads is taking over 10 seconds.
2020-07-24 09:51:58 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform ads is taking over 10 seconds.
2020-07-24 09:51:58 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform ads is taking over 10 seconds.
2020-07-24 09:51:58 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform ads is taking over 10 seconds.
2020-07-24 09:51:58 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform ads is taking over 10 seconds.
2020-07-24 09:51:58 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform ads is taking over 10 seconds.
2020-07-24 09:51:58 DEBUG (MainThread) [homeassistant.components.ads] Variable .g_heating_circle_needs_warm_water: Timeout during first update
2020-07-24 09:51:58 DEBUG (MainThread) [homeassistant.components.ads] Variable .g_output_pump_heating_circle_enable: Timeout during first update
2020-07-24 09:51:58 ERROR (SyncWorker_1) [homeassistant.components.ads] Error subscribing to .g_output_pump_boiler_enable: ADSError: timeout elapsed (1861).
2020-07-24 09:52:03 DEBUG (MainThread) [homeassistant.components.ads] Variable .g_input_boiler_signal: Timeout during first update
2020-07-24 09:52:03 DEBUG (MainThread) [homeassistant.components.ads] Variable .g_boiler_needs_warm_water: Timeout during first update
2020-07-24 09:52:03 ERROR (SyncWorker_0) [homeassistant.components.ads] Error subscribing to .g_output_oil_burner_enable: ADSError: timeout elapsed (1861).
2020-07-24 09:52:08 DEBUG (MainThread) [homeassistant.components.ads] Variable .g_output_pump_boiler_enable: Timeout during first update
2020-07-24 09:52:08 ERROR (SyncWorker_7) [homeassistant.components.ads] Error subscribing to .g_input_wood_burner_steam_signal: ADSError: timeout elapsed (1861).
2020-07-24 09:52:13 ERROR (SyncWorker_2) [homeassistant.components.ads] Error subscribing to .g_input_wood_burner_preflow_signal: ADSError: timeout elapsed (1861).

Logs 2


2020-07-24 10:03:24 INFO (SyncWorker_0) [homeassistant.util.package] Attempting install of pyads==3.0.7
2020-07-24 10:03:30 INFO (MainThread) [homeassistant.setup] Setting up ads
2020-07-24 10:03:31 INFO (MainThread) [homeassistant.setup] Setup of domain ads took 0.5 seconds
2020-07-24 10:03:31 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 10:03:31 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 10:03:31 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 10:03:31 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 10:03:31 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 10:03:31 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 10:03:31 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 10:03:31 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 10:03:31 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ads
2020-07-24 10:03:31 INFO (MainThread) [homeassistant.components.switch] Setting up switch.ads
2020-07-24 10:03:31 INFO (MainThread) [homeassistant.components.switch] Setting up switch.ads
2020-07-24 10:03:31 DEBUG (SyncWorker_5) [homeassistant.components.ads] Added device notification 21 for variable .g_heating_circle_needs_warm_water
2020-07-24 10:03:31 DEBUG (Dummy-32) [homeassistant.components.ads] Received notification 21
2020-07-24 10:03:31 DEBUG (SyncWorker_7) [homeassistant.components.ads] Added device notification 22 for variable .g_output_pump_heating_circle_enable
2020-07-24 10:03:32 DEBUG (SyncWorker_5) [homeassistant.components.ads] Added device notification 23 for variable .g_input_boiler_signal
2020-07-24 10:03:32 DEBUG (Dummy-32) [homeassistant.components.ads] Variable .g_heating_circle_needs_warm_water changed its value to 0
2020-07-24 10:03:32 DEBUG (Dummy-32) [homeassistant.components.ads] Received notification 22
2020-07-24 10:03:32 DEBUG (SyncWorker_7) [homeassistant.components.ads] Added device notification 24 for variable .g_boiler_needs_warm_water
2020-07-24 10:03:32 DEBUG (SyncWorker_2) [homeassistant.components.ads] Added device notification 25 for variable .g_output_pump_boiler_enable
2020-07-24 10:03:33 DEBUG (SyncWorker_5) [homeassistant.components.ads] Added device notification 26 for variable .g_output_oil_burner_enable
2020-07-24 10:03:33 DEBUG (Dummy-32) [homeassistant.components.ads] Variable .g_output_pump_heating_circle_enable changed its value to 0
2020-07-24 10:03:33 DEBUG (Dummy-32) [homeassistant.components.ads] Received notification 23
2020-07-24 10:03:33 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 10:03:33 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 10:03:33 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 10:03:33 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 10:03:33 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 10:03:33 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 10:03:33 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 10:03:33 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 10:03:33 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.ads
2020-07-24 10:03:34 DEBUG (SyncWorker_7) [homeassistant.components.ads] Added device notification 27 for variable .g_input_wood_burner_steam_signal
2020-07-24 10:03:34 DEBUG (SyncWorker_2) [homeassistant.components.ads] Added device notification 28 for variable .g_input_wood_burner_preflow_signal
2020-07-24 10:03:34 DEBUG (SyncWorker_5) [homeassistant.components.ads] Added device notification 29 for variable .g_input_wood_burner_preflow_70Degrees_signal
2020-07-24 10:03:34 DEBUG (Dummy-32) [homeassistant.components.ads] Variable .g_input_boiler_signal changed its value to 0
2020-07-24 10:03:34 DEBUG (Dummy-32) [homeassistant.components.ads] Received notification 24
2020-07-24 10:03:34 DEBUG (SyncWorker_3) [homeassistant.components.ads] Added device notification 30 for variable .g_heating_with_wood
2020-07-24 10:03:34 DEBUG (SyncWorker_7) [homeassistant.components.ads] Added device notification 31 for variable .g_heating_valve_actual_value_in_percent
2020-07-24 10:03:34 DEBUG (SyncWorker_6) [homeassistant.components.ads] Added device notification 32 for variable .g_override_boiler_enable
2020-07-24 10:03:34 DEBUG (Dummy-32) [homeassistant.components.ads] Variable .g_boiler_needs_warm_water changed its value to 0
2020-07-24 10:03:34 DEBUG (Dummy-32) [homeassistant.components.ads] Received notification 25
2020-07-24 10:03:34 DEBUG (SyncWorker_5) [homeassistant.components.ads] Added device notification 33 for variable .g_woodburner_command_value_in_percent
2020-07-24 10:03:34 DEBUG (SyncWorker_2) [homeassistant.components.ads] Added device notification 34 for variable .g_real_value_window_childs_room_1_percent
2020-07-24 10:03:34 DEBUG (SyncWorker_3) [homeassistant.components.ads] Added device notification 35 for variable .g_real_value_window_childs_room_2_1_percent
2020-07-24 10:03:35 DEBUG (SyncWorker_7) [homeassistant.components.ads] Added device notification 36 for variable .g_real_value_window_childs_room_2_2_percent
2020-07-24 10:03:35 DEBUG (SyncWorker_6) [homeassistant.components.ads] Added device notification 37 for variable .g_real_value_window_living_room_door_percent
2020-07-24 10:03:35 DEBUG (Dummy-32) [homeassistant.components.ads] Variable .g_output_pump_boiler_enable changed its value to 0
2020-07-24 10:03:35 DEBUG (Dummy-32) [homeassistant.components.ads] Received notification 26
``´
## Additional information
punzenbergerpeter commented 4 years ago

Possibly this issue is related: #35945

P.

MartinHjelmare commented 4 years ago

@stlehmann do you know what version of pyads we can upgrade to that requires the least amount of changes to the integration, while fixing the issues?

stlehmann commented 4 years ago

@MartinHjelmare I need to do some investigations on this one. It might have to do with the change from sync to async connection to ADS. I'll come back to you here.

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

ads documentation ads source (message by IssueLinks)

gijbelsy commented 4 years ago

Same problem here, issues started since upgrade to 0.103(.1)

VDHeerJu commented 4 years ago

Same here. Since update from version 0.112 to 0.113.0. Ads integration no longer works.

gijbelsy commented 4 years ago

Since I've started with HA, ADS integration has always been a sore to make and keep it running properly. There are some absolutely necessary features missing, and every time HA gets an update, I hold my breath to whether or not it's still working after the update.

stlehmann commented 4 years ago

Hm, I'm still struggling to setup a test environment. It has been a long while since I have used home-assistant. I'm on it but I have only limited time at the moment. A temporary solution would be to revert the commit https://github.com/home-assistant/core/commit/0bf772b68b632e1cc6a26de803cac349a5cd244e and downgrade the pyads-dependency back to 3.0.7. I hope to get a working test environment ready soon.

MartinHjelmare commented 4 years ago

Version 3.0.7 depends on typing which conflicts with the built in typing module on Python versions 3.6+. See https://github.com/home-assistant/core/pull/37707.

gijbelsy commented 4 years ago

Hm, I'm still struggling to setup a test environment. It has been a long while since I have used home-assistant. I'm on it but I have only limited time at the moment. A temporary solution would be to revert the commit 0bf772b and downgrade the pyads-dependency back to 3.0.7. I hope to get a working test environment ready soon.

I can set-up a new VM for testing. If the updated version becomes available, I can test this and report back.

stlehmann commented 4 years ago

I finally was able to setup a test environment an reproduce the error. It seems that somewhere between 3.0.7 and 3.1.3 the return type of DeviceNotifications changed. Instead of returning bytes as contents.data we now have an integer. Because of that struct.unpack results in an error:

2020-07-28 16:07:54 ERROR (Dummy-4) [root] Uncaught exception
Traceback (most recent call last):
  File "_ctypes/callbacks.c", line 237, in 'calling callback function'
  File "/home/stefan/.homeassistant/deps/lib/python3.8/site-packages/pyads/pyads_ex.py", line 849, in wrapper
    return callback(notification, data)
  File "/home/stefan/Dokumente/python/forks/home-assistant/homeassistant/components/ads/__init__.py", line 244, in _device_notification_callback
    value = bool(struct.unpack("<?", bytearray(data)[:1])[0])
struct.error: unpack requires a buffer of 1 bytes

The effected area in the code is the following (init.py):

def _device_notification_callback(self, notification, name):
    """Handle device notifications."""
    contents = notification.contents

    hnotify = int(contents.hNotification)
    _LOGGER.debug("Received notification %d", hnotify)
    data = contents.data

    try:
        with self._lock:
            notification_item = self._notification_items[hnotify]
    except KeyError:
        _LOGGER.error("Unknown device notification handle: %d", hnotify)
        return

    # Parse data to desired datatype
    if notification_item.plc_datatype == self.PLCTYPE_BOOL:
        value = bool(struct.unpack("<?", bytearray(data)[:1])[0])
    elif notification_item.plc_datatype == self.PLCTYPE_INT:
        value = struct.unpack("<h", bytearray(data)[:2])[0]
    elif notification_item.plc_datatype == self.PLCTYPE_BYTE:
        value = struct.unpack("<B", bytearray(data)[:1])[0]
    elif notification_item.plc_datatype == self.PLCTYPE_UINT:
        value = struct.unpack("<H", bytearray(data)[:2])[0]
    elif notification_item.plc_datatype == self.PLCTYPE_DINT:
        value = struct.unpack("<i", bytearray(data)[:4])[0]
    elif notification_item.plc_datatype == self.PLCTYPE_UDINT:
        value = struct.unpack("<I", bytearray(data)[:4])[0]
    else:
        value = bytearray(data)
        _LOGGER.warning("No callback available for this datatype")

    notification_item.callback(notification_item.name, value)

I still need to find out why contents.data changed and will come back to you.

stlehmann commented 4 years ago

I created a PR fixing this issue: #38402.

gijbelsy commented 4 years ago

@stlehmann : Is it possible to implement extra features while you're at it?

stlehmann commented 4 years ago

@gijbelsy Depends on what you are asking for 😏 What do you have in mind?

gijbelsy commented 4 years ago

'just' two things 😄 :

One of the problems with the code above is that this only works with sensor. domain.

VDHeerJu commented 4 years ago

I have 0.113.3 now. With ADS I have several switches declared in automation.yaml. Since update today only 1 or 2 out of 10 are working now. rest of entities are unavailable. When I reboot I get 1 or 2 other switches to work. The ones that worked before are unavailable again. Random, no pattern. ??

gijbelsy commented 4 years ago

Same issues here, had to roll back to previous version of HA. Still getting 'ADS timeout' errors in the logs. Had no time to further investigate.

stlehmann commented 4 years ago

@gijbelsy, @VDHeerJu that is odd. I just checked: 0.113.3 should contain the patch. Can you please provide a minimal configuration and the corresponding logs for it so I can do further investigations.

gijbelsy commented 4 years ago

Will do, but I'm afraid that's not for today neither tomorrow, possible for Tuesday.

VDHeerJu commented 4 years ago
2020-08-02 00:31:46 WARNING (SyncWorker_0) [homeassistant.util.yaml.loader] YAML file /config/configuration.yaml contains duplicate key "automation". Check lines 5 and 232
2020-08-02 00:31:48 WARNING (MainThread) [homeassistant.components.http] The 'base_url' option is deprecated, please remove it from your configuration
2020-08-02 00:31:59 ERROR (SyncWorker_2) [homeassistant.components.ads] Error subscribing to .HA_VW_ACTIEF_Keuken: ADSError: timeout elapsed (1861). 
2020-08-02 00:32:02 WARNING (MainThread) [homeassistant.setup] Setup of timer is taking over 10 seconds.
2020-08-02 00:32:02 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds.
2020-08-02 00:32:03 WARNING (MainThread) [homeassistant.setup] Setup of zeroconf is taking over 10 seconds.
2020-08-02 00:32:03 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform ads is taking over 10 seconds.
2020-08-02 00:32:03 WARNING (MainThread) [homeassistant.components.switch] Setup of switch platform ads is taking over 10 seconds.
2020-08-02 00:32:03 WARNING (MainThread) [homeassistant.components.switch] Setup of switch platform ads is taking over 10 seconds.
2020-08-02 00:32:03 WARNING (MainThread) [homeassistant.components.light] Setup of light platform ads is taking over 10 seconds.
2020-08-02 00:32:04 ERROR (SyncWorker_3) [homeassistant.components.ads] Error subscribing to .HA_VW_ACTIEF_Slaapkamer1: ADSError: timeout elapsed (1861). 
2020-08-02 00:32:04 WARNING (MainThread) [homeassistant.components.weather] Setup of weather platform met is taking over 10 seconds.
2020-08-02 00:32:04 ERROR (MainThread) [metno] https://aa015h6buqvih86i1.api.met.no/weatherapi/locationforecast/1.9/ returned 
2020-08-02 00:32:04 ERROR (MainThread) [homeassistant.components.met.weather] Retrying in 20 minutes
2020-08-02 00:32:04 WARNING (MainThread) [homeassistant.setup] Setup of mobile_app is taking over 10 seconds.
2020-08-02 00:32:09 ERROR (SyncWorker_4) [homeassistant.components.ads] Error subscribing to .HA_VW_ACTIEF_Slaapkamer2: ADSError: timeout elapsed (1861). 
2020-08-02 00:32:14 ERROR (SyncWorker_6) [homeassistant.components.ads] Error subscribing to .HA_VW_ACTIEF_Slaapkamer3: ADSError: timeout elapsed (1861). 
2020-08-02 00:32:19 ERROR (SyncWorker_5) [homeassistant.components.ads] Error subscribing to .HA_VW_ACTIEF_Slaapkamer4: ADSError: timeout elapsed (1861). 
2020-08-02 00:32:24 ERROR (SyncWorker_0) [homeassistant.components.ads] Error subscribing to .HA_SL_KEU_Tafel: ADSError: timeout elapsed (1861). 
2020-08-02 00:32:29 ERROR (SyncWorker_2) [homeassistant.components.ads] Error subscribing to .HA_SL_KEU_Raam: ADSError: timeout elapsed (1861). 
2020-08-02 00:32:34 ERROR (SyncWorker_1) [homeassistant.components.ads] Error subscribing to .HA_SL_KEU_Eiland: ADSError: timeout elapsed (1861). 
2020-08-02 00:32:39 ERROR (SyncWorker_4) [homeassistant.components.ads] Error subscribing to .HA_SL_ZH_Centraal: ADSError: timeout elapsed (1861). 
2020-08-02 00:32:44 ERROR (SyncWorker_6) [homeassistant.components.ads] Error subscribing to .HA_SL_EH_Centraal: ADSError: timeout elapsed (1861). 
2020-08-02 00:32:49 ERROR (SyncWorker_5) [homeassistant.components.ads] Error subscribing to .HA_SL_Inkom_achter: ADSError: timeout elapsed (1861). 
2020-08-02 00:32:52 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: timer, input_boolean, mobile_app
2020-08-02 00:32:54 ERROR (SyncWorker_0) [homeassistant.components.ads] Error subscribing to .HA_SL_WC_beneden: ADSError: timeout elapsed (1861). 
2020-08-02 00:32:59 ERROR (SyncWorker_0) [homeassistant.components.ads] Error subscribing to .HA_SL_Overloop2: ADSError: timeout elapsed (1861). 
2020-08-02 00:33:04 ERROR (SyncWorker_2) [homeassistant.components.ads] Error subscribing to .HA_SL_Berging: ADSError: timeout elapsed (1861). 
2020-08-02 00:33:09 ERROR (SyncWorker_2) [homeassistant.components.ads] Error subscribing to .HA_SL_SLPK1: ADSError: timeout elapsed (1861). 
2020-08-02 00:33:14 ERROR (SyncWorker_2) [homeassistant.components.ads] Error subscribing to .HA_SL_SLPK2: ADSError: timeout elapsed (1861). 
2020-08-02 00:33:19 ERROR (SyncWorker_6) [homeassistant.components.ads] Error subscribing to .HA_SL_Dressing: ADSError: timeout elapsed (1861). 
2020-08-02 00:33:24 ERROR (SyncWorker_5) [homeassistant.components.ads] Error subscribing to .HA_SL_Overloop1: ADSError: timeout elapsed (1861). 
2020-08-02 00:33:29 ERROR (SyncWorker_7) [homeassistant.components.ads] Error subscribing to .HA_SL_Badkamer: ADSError: timeout elapsed (1861). 
2020-08-02 00:33:34 ERROR (SyncWorker_0) [homeassistant.components.ads] Error subscribing to .HA_SL_Overloop3: ADSError: timeout elapsed (1861). 
2020-08-02 00:33:39 ERROR (SyncWorker_1) [homeassistant.components.ads] Error subscribing to .HA_SL_Kelder: ADSError: timeout elapsed (1861). 
2020-08-02 00:33:44 ERROR (SyncWorker_3) [homeassistant.components.ads] Error subscribing to .HA_SL_Buitenberging: ADSError: timeout elapsed (1861). 
2020-08-02 00:33:49 ERROR (SyncWorker_2) [homeassistant.components.ads] Error subscribing to .HA_SL_SLPK3: ADSError: timeout elapsed (1861). 
2020-08-02 00:33:52 WARNING (MainThread) [homeassistant.bootstrap] Waiting on integrations to complete setup: mobile_app
2020-08-02 00:33:54 ERROR (SyncWorker_4) [homeassistant.components.ads] Error subscribing to .HA_SL_SLPK4: ADSError: timeout elapsed (1861). 
2020-08-02 00:33:59 ERROR (SyncWorker_5) [homeassistant.components.ads] Error subscribing to .HA_SVW_Badkamer: ADSError: timeout elapsed (1861). 
2020-08-02 00:34:04 ERROR (SyncWorker_7) [homeassistant.components.ads] Error subscribing to .HA_SVW_Keuken: ADSError: timeout elapsed (1861). 
2020-08-02 00:34:09 ERROR (SyncWorker_0) [homeassistant.components.ads] Error subscribing to .HA_SVW_Living: ADSError: timeout elapsed (1861). 
2020-08-02 00:34:14 ERROR (SyncWorker_1) [homeassistant.components.ads] Error subscribing to .HA_SVW_Slaapkamer1: ADSError: timeout elapsed (1861). 
2020-08-02 00:34:19 ERROR (SyncWorker_3) [homeassistant.components.ads] Error subscribing to .HA_SVW_Slaapkamer2: ADSError: timeout elapsed (1861). 
2020-08-02 00:34:24 ERROR (SyncWorker_2) [homeassistant.components.ads] Error subscribing to .HA_SVW_Slaapkamer3: ADSError: timeout elapsed (1861). 
2020-08-02 00:34:29 ERROR (SyncWorker_4) [`homeassistant.components.ads`] Error subscribing to .HA_SVW_Slaapkamer4: ADSError: timeout elapsed (1861). 
2020-08-02 00:34:34 ERROR (SyncWorker_6) [homeassistant.components.ads] Error subscribing to .living_licht1_aan: ADSError: timeout elapsed (1861). 
VDHeerJu commented 4 years ago
# ADS Beckhoff
ads:
  device: '5.8.143.247.1.1'
  port: 801
  ip_address: '192.168.0.114'

binary_sensor:
  - platform: ads
    adsvar: .HA_VW_ACTIEF_Badkamer
    name: Verwarming Badkamer actief
  - platform: ads
    adsvar: .HA_VW_ACTIEF_Keuken
    name: Verwarming Keuken actief
  - platform: ads
    adsvar: .HA_VW_ACTIEF_Living
    name: Verwarming Living actief
  - platform: ads
    adsvar: .HA_VW_ACTIEF_Slaapkamer1
    name: Verwarming Slaapkamer 1 actief
  - platform: ads
    adsvar: .HA_VW_ACTIEF_Slaapkamer2
    name: Verwarming Slaapkamer 2 actief
  - platform: ads
    adsvar: .HA_VW_ACTIEF_Slaapkamer3
    name: Verwarming Slaapkamer 3 actief
  - platform: ads
    adsvar: .HA_VW_ACTIEF_Slaapkamer4
    name: Verwarming Slaapkamer 4 actief   

sensor:
  - platform: ads
    adsvar: .I_Temperatuur_Keuken
    unit_of_measurement: '°C'
    adstype: int    

light:
  - platform: ads
    adsvar: .living_licht1_aan
    adsvar_brightness: .living_lichtsterkte_licht1
    name: Living 1
  - platform: ads
    adsvar: .living_licht2_aan
    adsvar_brightness: .living_lichtsterkte_licht2
    name: Living 2

switch:
  - platform: ads
    adsvar: .HA_SL_KEU_Tafel
    name: tafel
  - platform: ads
    adsvar: .HA_SL_KEU_Raam
    name: raam
  - platform: ads
    adsvar: .HA_SL_KEU_Eiland
    name: eiland
  - platform: ads
    adsvar: .HA_SL_KEU_Werkblad
    name: werkblad
  - platform: ads
    adsvar: .HA_SL_ZH_Centraal
    name: Zithoek
  - platform: ads
    adsvar: .HA_SL_EH_Centraal
    name: Eethoek
  - platform: ads
    adsvar: .HA_SL_Inkom_achter
    name: Inkom achter
  - platform: ads
    adsvar: .HA_SL_WC_beneden
    name: WC Beneden
  - platform: ads
    adsvar: .HA_SL_Badkamer
    name: Badkamer
  - platform: ads
    adsvar: .HA_SL_Berging
    name: Berging
  - platform: ads
    adsvar: .HA_SL_Kelder
    name: Kelder
  - platform: ads
    adsvar: .HA_SL_Buitenberging
    name: Buitenberging
  - platform: ads
    adsvar: .HA_SL_Gang
    name: Gang
  - platform: ads
    adsvar: .HA_SL_Dressing
    name: Dressing
  - platform: ads
    adsvar: .HA_SL_Overloop1
    name: Overloop1
  - platform: ads
    adsvar: .HA_SL_Overloop2
    name: Overloop2
  - platform: ads
    adsvar: .HA_SL_Overloop3
    name: Overloop3
  - platform: ads
    adsvar: .HA_SL_SLPK1
    name: Slaapkamer 1
  - platform: ads
    adsvar: .HA_SL_SLPK2
    name: Slaapkamer 2
  - platform: ads
    adsvar: .HA_SL_SLPK3
    name: Slaapkamer 3
  - platform: ads
    adsvar: .HA_SL_SLPK4
    name: Slaapkamer 4
  - platform: ads
    adsvar: .HA_SL_Zolder
    name: Zolder

  - platform: ads
    adsvar: .HA_SVW_Badkamer
    name: Verwarming Badkamer
  - platform: ads
    adsvar: .HA_SVW_Keuken
    name: Verwarming Keuken
  - platform: ads
    adsvar: .HA_SVW_Living
    name: Verwarming Living
  - platform: ads
    adsvar: .HA_SVW_Slaapkamer1
    name: Verwarming Slaapkamer 1
  - platform: ads
    adsvar: .HA_SVW_Slaapkamer2
    name: Verwarming Slaapkamer 2
  - platform: ads
    adsvar: .HA_SVW_Slaapkamer3
    name: Verwarming Slaapkamer 3
  - platform: ads
    adsvar: .HA_SVW_Slaapkamer4
    name: Verwarming Slaapkamer 4
gijbelsy commented 4 years ago

The output of my logs are similar.

Flupke1979 commented 4 years ago

Same problem here, even after update to 0113.3.

stlehmann commented 4 years ago

I can confirm this. The issue occurs if I add more then two variables. I don't know the reason for this, though. Need to take a closer look at it.

pconfig commented 4 years ago

Any updates? My home assistant is not functional at the moment. Cannot go back to a previous version

stlehmann commented 4 years ago

Sorry to keep you waiting. This issue seems to be a tricky one. I couldn' t locate it, yet.

stlehmann commented 4 years ago

@MartinHjelmare As the fix didn't completely resolve the issue apparently I want to ask you to repopen the issue.

stlehmann commented 4 years ago

As my time is very limited at the moment I can not estimate when a fix for the issue with the current version of pyads will be ready. However, I think a workaround to make the ads component work again would be to take the latest working version of pyads (should be 3.0.7) and make a small modification to remove the typing requirement. I could release the patched version as 3.0.7.1 and we could change the requirement in homeassistant. @MartinHjelmare would this be a way to go?

MartinHjelmare commented 4 years ago

That could work. Your release history might look a bit weird after that with non incremental version ordering when sorting chronologically. Should be fine.

ghost commented 4 years ago

Same problem here, i try a new HA installation and a new Twincat2 Programm. Only 5 Bool declared in HA(light) and in Twincat --> the 2 first declared Bool Working and the other generate TimeOut Error I try multiple inversion in the declaration HA & Twincat --> Always the same error.

gijbelsy commented 4 years ago

Same happens with TwinCAT 3

murcin commented 4 years ago

any ideas what we should do ? wait for some new release or reinstall and use 0.112 ?

stlehmann commented 4 years ago

I'm on vacation this week. I'll create a PR for solving the issue beginning/mid next week.

stlehmann commented 4 years ago

It seems downgrading the pyads version does not fix the issue either. So for now I think it is best for all affected to downgrade home-assistant to 0.112 until the issue is fixed. 😞

stlehmann commented 4 years ago

It seems like the response from the ADS device gets lost once in a while. @MartinHjelmare is there a switch to start homeassistant only with one worker for testing purposes? This would help me a great deal debugging.

carstenschroeder commented 4 years ago

It seems downgrading the pyads version does not fix the issue either.

You mean pyads 3.0.7 w/o the typing requirement does not fix the issue? That's odd, as 3.0.7 worked with no issues.

If I can be of any help for testing etc., just let me know.

carstenschroeder commented 4 years ago

@MartinHjelmare: Wouldn't it be wise to revert #37748 and #38402 as long, as we have no fix for this? #37748 doesn't seem like a must have. Currently two other integrations also require typing.

MartinHjelmare commented 4 years ago

We won't allow reverting the PRs. The typing package breaks virtual environments. Users that are prepared to handle this can always copy an older version of the integration as a custom integration until the library and bugs have been fixed.

stlehmann commented 4 years ago

OK I seem to get a grip on it. It seems to be an issue with the underlying aslib.so If I use the old version from 3.0.7 everything seems to work fine with both version of pyads (3.0.7 and 3.2.1).

With the current version of adslib.so there seems to be a timeout issue.

stlehmann commented 4 years ago

@carstenschroeder Could you try checking out adslib #b56d01, build the adslib.so with make and put it in your .homeassistant/deps/lib/python3.8/site-packages/pyads/pyads directory. Hopefully this does the job.

carstenschroeder commented 4 years ago

@stlehmann I can confirm that it works with adslib #b56d01.

stlehmann commented 4 years ago

Great. @pbruenn do you have an idea what could lead adslib to ignore incoming responses? Is this already a known issue?

carstenschroeder commented 4 years ago

We won't allow reverting the PRs. The typing package breaks virtual environments. Users that are prepared to handle this can always copy an older version of the integration as a custom integration until the library and bugs have been fixed.

A maintenance PR is allowed to break functionality for multiple releases. That's how it works at home assistant these days...no surprise on my side

stlehmann commented 4 years ago

@carstenschroeder I think it is very hard for the maintainers to keep track of alle the components and their dependencies. It is almost inevitable that some components break during the update process. But it is not the right way to revert sensible changes due to some broken components. It is important that the components get fixed to meet the requirements.

pbruenn commented 4 years ago

@stlehmann Sorry, I have no idea. I think your adslib #b56d01 matches upstream https://github.com/Beckhoff/ADS/commit/286a06297d5bbd045e354cefa24621baf88d0c6b thats more than two years old, so I have no idea which change breaks your usecase. Maybe you could give me a hint on how to reproduce this in AdsLib or you might be able to bisect the bad commit yourself.

carstenschroeder commented 4 years ago

@stlehmann I agree in all you say, except one topic: the PR that broke things is not sensible as it is only a preparation for the removal of the workaround for the typing issue. Currently the workaround is still needed because two other integrations also require typing. So the whole change could have been done w/o breaking ADS for so long. It has been left broken to generate pressure to fix the library at the expense of the user experience. Just my 2 cents

@MartinHjelmare @stlehmann This is by no means a criticism on you both. It is always a pleasure to work with you and I really appreciate your contributions to home assistant.

stlehmann commented 4 years ago

@pbruenn thanks for the feedback I will do some further investigations on this issue and try to bisect the commit that causes the issue.

stlehmann commented 4 years ago

In the meantime this workaround can be used to keep current installations working:

Could you try checking out adslib #b56d01, build the adslib.so with make and put it in your .homeassistant/deps/lib/python3.8/site-packages/pyads/pyads directory. Hopefully this does the job.

pconfig commented 4 years ago

Would it be an idea to put this workaround in the next point release?

tomation7 commented 4 years ago

In the meantime this workaround can be used to keep current installations working:

Could you try checking out adslib #b56d01, build the adslib.so with make and put it in your .homeassistant/deps/lib/python3.8/site-packages/pyads/pyads directory. Hopefully this does the job.

I can confirm this workaround works for me. I'm using a Raspberry Pi 3 with a virtual environment