Errors thrown by Nuki integration preventing execution of scripts

Sir-Pandalot commented 4 years ago

The problem

The log shows many instances of this particular error "Update for lock.nuki_lock fails". However, operating the lock through Home Assistant seems to be working fine. Except when I execute a script, the script fails to run if the call to the Nuki-lock is the first action in the script. I worked around this issue by putting the command to lock the Nuki-lock at the end of the script. The script seems to execute fine now. However, I still see the errors in the log.

Environment

Home Assistant Core release with the issue: 0.111.4
Last working Home Assistant Core release (if known):
Operating environment (OS/Container/Supervised/Core): Home Assistant
Integration causing this issue: Nuki
Link to integration documentation on our website: https://www.home-assistant.io/integrations/nuki/

Problem-relevant `configuration.yaml`

lock:
  - platform: nuki
    host: 192.168.1.##
    token: !secret lock_nuki_token

Traceback/Error logs

2020-06-23 16:06:43 ERROR (MainThread) [homeassistant.helpers.entity] Update for lock.nuki_lock fails
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 279, in async_update_ha_state
    await self.async_device_update()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 472, in async_device_update
    await self.hass.async_add_executor_job(self.update)
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/nuki/lock.py", line 124, in update
    self._nuki_device.update(aggressive=level)
  File "/usr/local/lib/python3.7/site-packages/pynuki/device.py", line 90, in update
    "Failed to update data for lock. "
AssertionError: Failed to update data for lock. Nuki ID None volatized.

Additional information

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

Hey there @pvizeli, mind taking a look at this issue as its been labeled with an integration (nuki) you are listed as a codeowner for? Thanks! _{^{(message by CodeOwnersMention)}}

flowolf commented 4 years ago

I'm having a similar issue. The nuki integration works after starting HomeAssistant, but after a few hours it loses the connection.

currently I'm on 0.113.0 before I was on 0.110.x where it worked.

so it seems that from 0.110 to 0.111 something broke.

flowolf commented 4 years ago

It occured again, after restarting:

Traceback (most recent call last): File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/helpers/entity.py", line 272, in async_update_ha_state await self.async_device_update() File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/helpers/entity.py", line 466, in async_device_update self.update # type: ignore File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run result = self.fn(*self.args, **self.kwargs) File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/components/nuki/lock.py", line 124, in update self._nuki_device.update(aggressive=level) File "/srv/homeassistant/lib/python3.7/site-packages/pynuki/device.py", line 90, in update "Failed to update data for lock. " AssertionError: Failed to update data for lock. Nuki ID None volatized.

It's counted the error about 4400 times in 36 hours. My instance is up for 86 hours. So the Nuki went offline about after 50 hours.

The lock is shown as unavailable. I can, however lock via the Nuki App, so it is online, pingable and reachable in the network.

EDIT: just restartet HomeAssistant, and the Nuki is available and lockable again. I don't have the above error in the logs, just a 503 for trying to lock quickly after unlocking - might or might not be connected to the issue:

Traceback (most recent call last): File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/components/websocket_api/commands.py", line 130, in handle_call_service connection.context(msg), File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/core.py", line 1250, in async_call task.result() File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/core.py", line 1285, in _execute_service await handler.func(service_call) File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/helpers/entity_component.py", line 209, in handle_service self._platforms.values(), func, call, required_features File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/helpers/service.py", line 454, in entity_service_call future.result() # pop exception if have File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/helpers/entity.py", line 595, in async_request_call await coro File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/helpers/service.py", line 485, in _handle_entity_call await result File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/components/lock/__init__.py", line 104, in async_lock await self.hass.async_add_job(ft.partial(self.lock, **kwargs)) File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run result = self.fn(*self.args, **self.kwargs) File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/components/nuki/lock.py", line 158, in lock self._nuki_device.lock() File "/srv/homeassistant/lib/python3.7/site-packages/pynuki/lock.py", line 14, in lock return self._bridge.lock(nuki_id=self.nuki_id, block=block) File "/srv/homeassistant/lib/python3.7/site-packages/pynuki/bridge.py", line 245, in lock block=block, File "/srv/homeassistant/lib/python3.7/site-packages/pynuki/bridge.py", line 147, in lock_action return self.__rq("lockAction", params) File "/srv/homeassistant/lib/python3.7/site-packages/pynuki/bridge.py", line 106, in __rq result.raise_for_status() File "/srv/homeassistant/lib/python3.7/site-packages/requests/models.py", line 941, in raise_for_status raise HTTPError(http_error_msg, response=self) requests.exceptions.HTTPError: 503 Server Error: Service Unavailable for url: http://192.168.1.XXX:8080/lockAction?ts=2020-07-30T19:00:38Z&rnr=XXXXX&hash=00e3261a6e0d79c329445acd540fb2b07187a0dcf6017065c8814010283ac67f&nukiId=XXXXXXXX&deviceType=0&action=2&noWait=1

flowolf commented 4 years ago

There is a fix out: https://github.com/home-assistant/core/pull/38159

I just upgraded - we'll see in a few days ;)

this probably can be closed fingers crossed

jghaanstra commented 4 years ago

@flowolf is this issue fixed (and can it be closed)?

I might be switching from Homey to Home Assistant but need to make sure the Nuki integration offers similar functionality available in Homey. It seems this library polls the bridge instead of using the callback mechanism which is not the best approach since the bridge often returns a 503 error when it needs the handle multiple requests.

Just wondering if this is still an issue.

flowolf commented 4 years ago

I'll check tonight.

flowolf commented 4 years ago

@jghaanstra it still occurs :( 2020-09-22 18:21:51 ERROR (MainThread) [homeassistant.components.lock] Error while setting up nuki platform for lock Traceback (most recent call last): File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/helpers/entity_platform.py", line 193, in _async_setup_platform await asyncio.shield(task) File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run result = self.fn(*self.args, **self.kwargs) File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/components/nuki/lock.py", line 80, in setup_platform devices.extend([NukiOpenerEntity(opener) for opener in bridge.openers]) File "/srv/homeassistant/lib/python3.7/site-packages/pynuki/bridge.py", line 238, in openers return self._get_devices(device_type=const.DEVICE_TYPE_OPENER) File "/srv/homeassistant/lib/python3.7/site-packages/pynuki/bridge.py", line 199, in _get_devices for l in self.list(device_type=device_type): File "/srv/homeassistant/lib/python3.7/site-packages/pynuki/bridge.py", line 128, in list data = self.__rq("list") File "/srv/homeassistant/lib/python3.7/site-packages/pynuki/bridge.py", line 106, in __rq result.raise_for_status() File "/srv/homeassistant/lib/python3.7/site-packages/requests/models.py", line 941, in raise_for_status raise HTTPError(http_error_msg, response=self) requests.exceptions.HTTPError: 503 Server Error: Service Unavailable for url: http://192.168.YY.XXX:8080/list?ts=2020-09-22T18:21:51Z&rnr=37261&hash=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

just been upgrading to 115 from 113. it hasn't been an issue the last few weeks. the lock responded fine. but the issue is still here.

jghaanstra commented 4 years ago

@jghaanstra it still occurs :(

just been upgrading to 115 from 113. it hasn't been an issue the last few weeks. the lock responded fine. but the issue is still here.

I was afraid of this. It's due to limited resources in the Nuki Bridge. Polling the Bridge (what the integration now does) is not the best approach. It would be better to use the callback mechanism for status updates from the lock. I have posted a feature request to get this implemented here: https://community.home-assistant.io/t/nuki-use-callbacks-instead-of-unreliable-polling/229064

github-actions[bot] commented 3 years ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

home-assistant / core