Nuki Smart Lock 4 (non-pro) fails to setup on Raspberry Pi 3b+

Duncank commented 7 months ago

System Health details

System Information

version	core-2024.2.2
installation_type	Home Assistant OS
dev	false
hassio	true
docker	true
user	root
virtualenv	false
python_version	3.12.1
os_name	Linux
os_version	6.1.63-haos-raspi
arch	armv7l
timezone	Europe/Amsterdam
config_dir	/config

Home Assistant Community Store

AccuWeather

can_reach_server | ok -- | -- remaining_requests | 42

Home Assistant Cloud

Home Assistant Supervisor

Dashboards

Recorder

Spotify

api_endpoint_reachable | ok -- | --

Checklist

[X] I have enabled debug logging for my installation.
[X] I have filled out the issue template to the best of my ability.
[X] This issue only contains 1 issue (if you have multiple issues, open one issue for each issue).
[X] This issue is not a duplicate issue of currently previous issues..

Describe the issue

My Nuki v4 is discovered by HA and this integration, but 'failed to setup' every time, with multiple errors showing up in the logs. The Nuki is located within 1.5 meters of my Raspberry Pi 3B+ running home assistant and the default onboard bluetooth.

Reproduction steps

Install Nuki BT from Hacs
Restart, and wait for the 'discovered new devices' notification
Add the nuki via the automatic pairing process, after putting the lock in pairing mode.
See the integration showing up as 'failed to setup' every time.

Debug logs

I see three errors in the logs coming from this integration, from first to last:  

Logger: homeassistant.config_entries
Source: config_entries.py:444
First occurred: 12:01:04 (2 occurrences)
Last logged: 12:31:54

Error setting up entry Nuki_39EF3B35 for hass_nuki_bt
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 444, in async_setup
    result = await component.async_setup_entry(hass, self)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/hass_nuki_bt/__init__.py", line 86, in async_setup_entry
    if not await coordinator.async_wait_ready():
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/hass_nuki_bt/coordinator.py", line 151, in async_wait_ready
    await self._async_update()
  File "/config/custom_components/hass_nuki_bt/coordinator.py", line 110, in _async_update
    await self.device.update_state()
  File "/usr/local/lib/python3.12/site-packages/pyNukiBT/nuki.py", line 420, in update_state
    await self.connect() # connect so we can identify the device type and update self._const accordingly
    ^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/pyNukiBT/nuki.py", line 384, in connect
    logger.debug(f"Services {[str(s) for s in self._client.services]}")
                                              ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/bleak/__init__.py", line 686, in services
    if not self._backend.services:
           ^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'services'

Deze fout is ontstaan door een aangepaste integratie.

Logger: custom_components.hass_nuki_bt
Source: components/bluetooth/active_update_coordinator.py:129
Integration: Nuki BT (documentation, issues)
First occurred: 12:01:28 (2 occurrences)
Last logged: 12:32:22

54:D2:72:EF:3B:35: Failure while polling
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/pyNukiBT/nuki.py", line 362, in _send_command
    msg = await self._notify_future
          ^^^^^^^^^^^^^^^^^^^^^^^^^
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/bluetooth/active_update_coordinator.py", line 129, in _async_poll
    self.data = await self._async_poll_data(self._last_service_info)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/bluetooth/active_update_coordinator.py", line 122, in _async_poll_data
    return await self._poll_method(last_service_info)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/hass_nuki_bt/coordinator.py", line 110, in _async_update
    await self.device.update_state()
  File "/usr/local/lib/python3.12/site-packages/pyNukiBT/nuki.py", line 421, in update_state
    msg = await self._send_encrtypted_command(
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/pyNukiBT/nuki.py", line 189, in _send_encrtypted_command
    return await self._send_command(
           ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/pyNukiBT/nuki.py", line 361, in _send_command
    async with async_timeout.timeout(self.command_response_timeout):
  File "/usr/local/lib/python3.12/site-packages/async_timeout/__init__.py", line 141, in __aexit__
    self._do_exit(exc_type)
  File "/usr/local/lib/python3.12/site-packages/async_timeout/__init__.py", line 228, in _do_exit
    raise asyncio.TimeoutError
TimeoutError

Logger: pyNukiBT.nuki
Source: runner.py:188
First occurred: 12:01:08 (80 occurrences)
Last logged: 12:32:02

was expecting KEYTURNER_STATES
parse error Error in path (parsing) -> crc wrong checksum, read 37376, computed 31989
Got unexpected message length for command 14703. got length:81 expecting length:8
Got 73 unknown bytes with value: b'9\xdb\xf4\x82\x9c\x8fWRdG&\x8c3\xe7kC\x97\xe91D\x02\x003\x00\xf3\x02e\xd4\xc6\xbf_\xbf\xd1t\x0bK\xec(\x0e\xfc\t\xda\x8c\x1a\xd0\xd4<\x15\n\x92\xce\x17\x1a\xa2\x88\xb66Im\x89 B\xe7\xd7=u4\xdd\xb7\x93\xc2\xbe\xef'
HomeAssistant: Received unsolicited notification: Container: auth_id = b'gM"L' (total 4) command = (enum) (unknown) 14703 payload = None crc = 56121



### Diagnostics dump

_No response_

ronengr commented 5 months ago

@Duncank connection timeout errors are usually due to poor connection quality. can you try putting the BT adapter closer to the door?

Duncank commented 5 months ago

I've upgraded this addon to the latest version (0.0.11) and moved the raspberry pi a bit closer to my door, so the distance is just a little over a meter now.
The integration no longer shows as 'failed to setup', but just shows '0 devices, 0 entities' now. The logs show four errors, a;; with the same traceback but with different paths in it for sensor.py, lock.py, button.py and binary_sensor.py:

Logger: homeassistant.components.sensor
Bron: helpers/entity_platform.py:356
integratie: Sensor (documentatie, problemen)
Eerst voorgekomen: 6 april 2024 om 14:11:53 (2 gebeurtenissen)
Laatst gelogd: 6 april 2024 om 14:13:42

Error while setting up hass_nuki_bt platform for sensor
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 356, in _async_setup_platform
    await asyncio.shield(awaitable)
  File "/config/custom_components/hass_nuki_bt/sensor.py", line 116, in async_setup_entry
    entities = [NukiSensor(coordinator, sensor) for sensor in SENSOR_TYPES]
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/hass_nuki_bt/sensor.py", line 125, in __init__
    super().__init__(coordinator)
  File "/config/custom_components/hass_nuki_bt/entity.py", line 42, in __init__
    str(x) for x in coordinator.device.config["hardware_revision"]
                    ~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^
KeyError: 'hardware_revision'

Terabyte2000 commented 5 months ago

Hello

I have the same problem with the Addon and Nuki 4.0

After pairing I can not see Entities.

Error is the same

ronengr commented 5 months ago

@Terabyte2000 @Duncank can you please share full logs? especially i'm interested to see if the config was retrieved successfully from the lock, and if the hw rev is part of that config.

Terabyte2000 commented 5 months ago

@ronengr

Is this log correct? error_log.txt

ronengr commented 5 months ago

thanks @Terabyte2000 it seems there is an issue getting config info from the lock

can you enable full debug log in the integration, so i can see the full flow? just go to the nuki lock integration, click on "enable debug logging", reload the integration, give it a few minutes, and then disable the debug logs. this will automatically download the logs to your computer.

Terabyte2000 commented 5 months ago

@ronengr

I hope this is the right log. It seems that there are logs of all Errors in it

error_log-2.txt

ronengr commented 5 months ago

@Terabyte2000 thanks. it seems that getting the lock state is succesfull, only issue is with getting the config. They might have changes some things in how the "config" works in nuki4. I didn't see any documentation about that.

let me check if I can maybe make the integration run without full config info.

Terabyte2000 commented 5 months ago

@ronengr

Thanks

Let me know if i you need anything else

ronengr commented 5 months ago

@Terabyte2000 I've released a new version, that should be able to handle the case of filing to retrieve config info. there will be some missing info (like no Nuki HW/SW info, etc), and there will still be an error in the log, but helpfully other functionality should work.

without the lock itself, or some online info on the changes they made in how "config" works for the new lock, I'm afraid this is all i can do at the moment.

Let me know if this works for you.

Terabyte2000 commented 5 months ago

@ronengr

Entities are here now.

Edit: seems to work

Some errors in log. Do you need them?

Terabyte2000 commented 5 months ago

error_log-3.txt

ronengr commented 5 months ago

@Terabyte2000 thanks. the issues are to be expected. as i said, it seems something has changed with the format of the "config" msg in nuki4. as i couldn't find any documentation for this change, there is currently nothing much i can do.

but at lease the lock and integration should work for most functionality (lock/unlock etc), even if there are some errors in the log.

ronengr / hass_nuki_bt