trigger icon indicating copy to clipboard operation
trigger copied to clipboard

Nuki not working

Open weeman1337 opened this issue 3 years ago • 36 comments

Operating a nuki smart lock device isn't working.

I followed the guide from the documentation.
When pressing to "open" button that should connect the device I always get "Device is not in paring mode.".

  • Installed the latest version from F-Droid
  • On an Android 9 device.

If I can provide any other information that helps debugging just let me know.

weeman1337 avatar Oct 12 '21 19:10 weeman1337

Have you paired with the Nuki before?

  • Once on the Bluetooth level
  • Once for registering your device with the Nuki

mwarning avatar Oct 13 '21 05:10 mwarning

btw. has it been working before for you?

mwarning avatar Oct 13 '21 06:10 mwarning

Have you paired with the Nuki before?

Yes, I paired the phone with the lock.

btw. has it been working before for you?

No.

It works using the proprietary app.

weeman1337 avatar Oct 13 '21 18:10 weeman1337

hm, this is hard to debug, since it was working for me recently.

mwarning avatar Oct 13 '21 19:10 mwarning

You do not happen to be in Berlin? :P

mwarning avatar Oct 13 '21 19:10 mwarning

Do you know the version of the Nuki Smartlock firmware and what version of the Nuki SmartLock this is?

mwarning avatar Oct 14 '21 17:10 mwarning

hm, this is hard to debug, since it was working for me recently.

I can poke around in the code if you want and try things or write more debug output.

You do not happen to be in Berlin? :P

Nope. But if you visit Frankfurt in the next time… ;)

Do you know the version of the Nuki Smartlock firmware and what version of the Nuki SmartLock this is?

It is a Smart Lock 2.0 running firmware 2.11.8

weeman1337 avatar Oct 19 '21 19:10 weeman1337

hm, this is hard to debug, since it was working for me recently.

I can poke around in the code if you want and try things or write more debug output.

Yes please. Anything that helps us with figuring out the problem.

You do not happen to be in Berlin? :P

Nope. But if you visit Frankfurt in the next time… ;)

hehe, ok.

Do you know the version of the Nuki Smartlock firmware and what version of the Nuki SmartLock this is?

It is a Smart Lock 2.0 running firmware 2.11.8

hm, should work..

mwarning avatar Oct 20 '21 20:10 mwarning

Here are the adb logs when trying to connect

11-02 18:59:25.114 10011 10910 D BluetoothGatt: connect() - device: xx:xx:xx:xx:xx:xx, auto: false
11-02 18:59:25.114 10011 10910 D BluetoothGatt: registerApp()
11-02 18:59:25.114 10011 10910 D BluetoothGatt: registerApp() - UUID=yyyyyyyy-yyyy-yyyy-yyyy-yyyyyyyyyyyy
11-02 18:59:25.116  8675  8722 I bt_stack: [INFO:gatt_api.cc(948)] GATT_Register dddddddd-dddd-dddd-dddd-ddddddddddd
11-02 18:59:25.116  8675  8722 I bt_stack: [INFO:gatt_api.cc(968)] allocated gatt_if=5
11-02 18:59:25.117 10011 10858 D BluetoothGatt: onClientRegistered() - status=0 clientIf=5
11-02 18:59:25.121  8675  8697 D bt_btif_config: btif_get_address_type: Device [xx:xx:xx:xx:xx:xx] address type 0
11-02 18:59:25.121  8675  8697 D bt_btif_config: btif_get_device_type: Device [xx:xx:xx:xx:xx:xx] type 2
11-02 18:59:25.123  8675  8722 I bt_stack: [INFO:gatt_api.cc(1109)] GATT_Connectgatt_if=5 xx:xx:xx:xx:xx:xx
11-02 18:59:25.124   532   532 D [email protected]_handler: SerialClockVote: vote for UART CLK ON
11-02 18:59:25.128   532   532 D [email protected]_lock: Acquire wakelock is acquired 
11-02 18:59:25.128   532   532 I [email protected]_handler: DeviceWakeUp: Writing IBS_WAKE_IND
11-02 18:59:25.131   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_WAKE_ACK: 0xFC
11-02 18:59:25.132   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_WAKE_IND: 0xFD
11-02 18:59:25.133   532  8719 I [email protected]_handler: ProcessIbsCmd: Writing IBS_WAKE_ACK
11-02 18:59:25.173   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_SLEEP_IND: 0xFE
11-02 18:59:25.745   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_WAKE_IND: 0xFD
11-02 18:59:25.745   532  8719 I [email protected]_handler: ProcessIbsCmd: Writing IBS_WAKE_ACK
11-02 18:59:25.748  8675  8722 I bt_btm_ble: btm_ble_conn_complete unable to match and resolve random address
11-02 18:59:25.776  8675  8722 W bt_smp  : smp_br_connect_callback is called on unexpected transport 2
11-02 18:59:25.777  8675  8722 E bt_stack: [ERROR:gatt_sr.cc(752)] MTU request PDU with MTU size 247
11-02 18:59:25.777  8675  8722 E bt_btm  : BTM_SetBleDataLength failed, peer does not support request
11-02 18:59:25.778  8675  8722 W bt_stack: [WARNING:gatt_utils.cc(710)] Call back not found for application conn_id=3
11-02 18:59:25.778  8675  8722 W bt_stack: [WARNING:gatt_utils.cc(710)] Call back not found for application conn_id=4
11-02 18:59:25.778  8675  8722 W bt_stack: [WARNING:gatt_utils.cc(710)] Call back not found for application conn_id=5
11-02 18:59:25.778  8675  8722 W bt_btif : bta_dm_acl_change info: 0x0
11-02 18:59:25.779  8675  8722 I bt_stack: [INFO:bta_gattc_cache.cc(915)] bta_gattc_rebuild_cache 81
11-02 18:59:25.780  8675  8697 D bt_btif_dm: remote version info [xx:xx:xx:xx:xx:xx]: 0, 0, 0
11-02 18:59:25.789  8675  8722 E bt_btm  : No key available to encrypt the link
11-02 18:59:25.789 10011 10858 D BluetoothGatt: onClientConnectionState() - status=0 clientIf=5 device=xx:xx:xx:xx:xx:xx
11-02 18:59:25.789 10011 10858 D BluetoothGatt: discoverServices() - device: xx:xx:xx:xx:xx:xx
11-02 18:59:25.796  8675  8697 E bt_btif_gattc: btif_gattc_upstreams_evt: Unhandled event (7)!
11-02 18:59:25.797  8675  8697 I chatty  : uid=1002(bluetooth) BT Service Call identical 8 lines
11-02 18:59:25.797  8675  8697 E bt_btif_gattc: btif_gattc_upstreams_evt: Unhandled event (7)!
11-02 18:59:25.801  8675  8697 D bt_bta_gattc: bta_gattc_get_gatt_db
11-02 18:59:25.810 10011 10858 D BluetoothGatt: onSearchComplete() = Device=xx:xx:xx:xx:xx:xx Status=0
11-02 18:59:25.810 10011 10858 D BluetoothGatt: setCharacteristicNotification() - uuid: tttttttt-tttt-tttt-tttt-tttttttttttt enable: true
11-02 18:59:25.858   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_SLEEP_IND: 0xFE
11-02 18:59:25.864   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_WAKE_IND: 0xFD
11-02 18:59:25.864   532  8719 I [email protected]_handler: ProcessIbsCmd: Writing IBS_WAKE_ACK
11-02 18:59:25.906   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_SLEEP_IND: 0xFE
11-02 18:59:25.954   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_WAKE_IND: 0xFD
11-02 18:59:25.955   532  8719 I [email protected]_handler: ProcessIbsCmd: Writing IBS_WAKE_ACK
11-02 18:59:25.964  8675  8722 I bt_stack: [INFO:hearing_aid.cc(1430)] GetDeviceCount: Not initialized yet
11-02 18:59:26.039   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_SLEEP_IND: 0xFE
11-02 18:59:26.044   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_WAKE_IND: 0xFD
11-02 18:59:26.044   532  8719 I [email protected]_handler: ProcessIbsCmd: Writing IBS_WAKE_ACK
11-02 18:59:26.086   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_SLEEP_IND: 0xFE
11-02 18:59:26.089   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_WAKE_IND: 0xFD
11-02 18:59:26.089   532  8719 I [email protected]_handler: ProcessIbsCmd: Writing IBS_WAKE_ACK
11-02 18:59:26.100 10011 10858 D BluetoothGatt: close()
11-02 18:59:26.101 10011 10858 D BluetoothGatt: unregisterApp() - mClientIf=5
11-02 18:59:26.109  8675  8722 I bt_stack: [INFO:gatt_api.cc(1212)] GATT_Disconnect conn_id=5
11-02 18:59:26.115  8675  8697 E BtGatt.ContextMap: Context not found for ID 5
11-02 18:59:26.130   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_SLEEP_IND: 0xFE
11-02 18:59:26.133   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_WAKE_IND: 0xFD
11-02 18:59:26.133   532  8719 I [email protected]_handler: ProcessIbsCmd: Writing IBS_WAKE_ACK
11-02 18:59:26.168   924  5509 W NotificationService: Toast already killed. pkg=com.example.trigger callback=android.app.ITransientNotification$Stub$Proxy@941bc6c
11-02 18:59:26.174   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_SLEEP_IND: 0xFE
11-02 18:59:26.185   580   615 D SurfaceFlinger: duplicate layer name: changing Toast to Toast#1
11-02 18:59:26.358   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_WAKE_IND: 0xFD
11-02 18:59:26.358   532  8719 I [email protected]_handler: ProcessIbsCmd: Writing IBS_WAKE_ACK
11-02 18:59:26.399   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_SLEEP_IND: 0xFE
11-02 18:59:27.097   532  8725 I [email protected]_handler: DeviceSleep: TX Awake, Sending SLEEP_IND
11-02 18:59:27.098   532  8725 D [email protected]_handler: SerialClockVote: vote for UART CLK OFF
11-02 18:59:27.113   532   532 D [email protected]_handler: SerialClockVote: vote for UART CLK ON
11-02 18:59:27.114   532   532 I [email protected]_handler: DeviceWakeUp: Writing IBS_WAKE_IND
11-02 18:59:27.119   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_WAKE_ACK: 0xFC
11-02 18:59:27.120   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_WAKE_IND: 0xFD
11-02 18:59:27.120   532  8719 I [email protected]_handler: ProcessIbsCmd: Writing IBS_WAKE_ACK
11-02 18:59:27.134  8675  8722 W bt_stack: [WARNING:bta_gattc_act.cc(1040)] bta_gattc_conn_cback: cif=3 connected=0 conn_id=0x0003 reason=0x0016
11-02 18:59:27.135  8675  8722 W bt_stack: [WARNING:bta_gattc_act.cc(1040)] bta_gattc_conn_cback: cif=4 connected=0 conn_id=0x0004 reason=0x0016
11-02 18:59:27.135  8675  8722 I bt_btm_sec: btm_sec_disconnected clearing pending flag handle:11 reason:22
11-02 18:59:27.137  8675  8697 I btif_av : btif_av_acl_disconnected: Peer xx:xx:xx:xx:xx:xx : ACL Disconnected
11-02 18:59:27.137  8675  8722 I btif_av : BtifAvPeer *BtifAvSource::FindOrCreatePeer(const RawAddress &, tBTA_AV_HNDL): Create peer: peer_address=xx:xx:xx:xx:xx:xx bta_handle=0x41 peer_id=0
11-02 18:59:27.138  8675  8722 W bt_btif : btif_av_get_peer_sep: No active peer found
11-02 18:59:27.138  8675  8722 I bt_btif_a2dp: btif_a2dp_on_idle: ## ON A2DP IDLE ## peer_sep = 1
11-02 18:59:27.138  8675  8722 W bt_btif : btif_av_get_peer_sep: No active peer found
11-02 18:59:27.138  8675  8722 I bt_btif_a2dp_source: btif_a2dp_source_on_idle: state=STATE_OFF
11-02 18:59:27.138  8675  8722 W bt_btif : btif_av_get_peer_sep: No active peer found
11-02 18:59:27.139  8675  8722 I bt_btif_a2dp: btif_a2dp_on_idle: ## ON A2DP IDLE ## peer_sep = 1
11-02 18:59:27.139  8675  8722 W bt_btif : btif_av_get_peer_sep: No active peer found
11-02 18:59:27.139  8675  8722 I bt_btif_a2dp_source: btif_a2dp_source_on_idle: state=STATE_OFF
11-02 18:59:27.139  8675  8722 I btif_av : DeleteIdlePeers: Deleting idle peer: xx:xx:xx:xx:xx:xx bta_handle=0x41
11-02 18:59:27.158  8675  8675 D BluetoothMapService: onReceive: android.bluetooth.device.action.ACL_DISCONNECTED
11-02 18:59:27.170   532  8719 I [email protected]_handler: ProcessIbsCmd: Received IBS_SLEEP_IND: 0xFE
11-02 18:59:28.120   532  8725 I [email protected]_handler: DeviceSleep: TX Awake, Sending SLEEP_IND
11-02 18:59:28.120   532  8725 D [email protected]_handler: SerialClockVote: vote for UART CLK OFF
11-02 18:59:28.149   924  5509 W NotificationService: Toast already killed. pkg=com.example.trigger callback=android.app.ITransientNotification$Stub$Proxy@807f522
11-02 18:59:28.271   532  8711 D [email protected]_lock: Release wakelock is released 
11-02 18:59:28.651   924  1058 W WindowManager: Unable to start animation, surface is null or no children.

Maybe that helps you already :man_shrugging:

weeman1337 avatar Nov 02 '21 18:11 weeman1337

That does not look very helpful. Anyway, what Android version do you use?

mwarning avatar Nov 02 '21 20:11 mwarning

I have similar problem with Nuki not working, but i am not able to pair. The question is: does Trigger work with Nuki Smartlock, if the Smartlock is already paired with the Nuki Web Bridge?

vmario89 avatar Jan 16 '22 20:01 vmario89

Actually, I do not know.

Best thing would be if I can debug the situation. I can try to update the firmware on my nuki and see if that breaks anything :D

EDIT: if you can use the Nuki Web Bridge in parallel with the Nuki App (via Bluetooth), then it should also work with Trigger

mwarning avatar Jan 16 '22 21:01 mwarning

btw., is that a Nuki Smartlock 3? What firmware version do you use? I just saw that it came out.

mwarning avatar Jan 16 '22 21:01 mwarning

Hey, not its a Nuki Smartlock with first revision ever available on the market (about 3 years old). I have no idea to get some logs out of this on my Smartphone yet. I have a Huawei phone. Just my some documentation for myself right now: grafik

the errors while trying to pair (while nuki ring is lighting constantly white) are: failed to pair or "just look in the app"

vmario89 avatar Jan 16 '22 21:01 vmario89

Ok, without having a Smartlock of that version to debug the issue, it will be very hard to debug/fix this. Maybe there is some documentation available for the Nuki 1...

mwarning avatar Jan 16 '22 21:01 mwarning

I have asked a related question in the nuki forum: https://developer.nuki.io/t/bluetooth-api-for-nuki-1-0-2-0-3-0-compatibility/13722

mwarning avatar Jan 16 '22 22:01 mwarning

@vmario89 anyway, if you are not able to pair, then it does not have anything to do with Trigger.

mwarning avatar Jan 17 '22 07:01 mwarning

hi. thanks for the note. i was not sure how trigger is going to handle bluetooth. thanks for opening the thread on nuki. interested on how other people handle this

vmario89 avatar Jan 18 '22 09:01 vmario89

We have a Nuki Smart Lock 3 and tried with your app but with no luck. Phone: Fairphone 3+ OS: Android 11; Lineage 18.1 (MicroG edition)

After pairing the Smartphone using Bluetooth and adding the lock info in the app. There was a small message that pairing was successful, but the lock would not react after that. When trying to lock or unlock the door there was always a message "Bluetooth device busy" and after some seconds there was "Connection error: DISCONNECTED_BY_DEVICE". It could also not request the door status, it was always "unknown".

The Lock Identifier and Shared Key were successfully added after pairing in the app.

Your documentation only says the app was tested with the nuki smartlock 2. What information would you need to debug the problems with the version 3, how could i assist you with debugging?

The newest API version seems to be V2.2.1 from 22.06.2021. If you could tell me the API Version for which you know the app works i could figure out the changes.

Thorbijoern avatar Apr 29 '22 18:04 Thorbijoern

I am not certain, but I think I used the API specs V2.1 from 16.03.2020. The last time I was testing with my Nuki Smart Lock (2.0), it was working with Android 10 on LineageOS.

I suspect this to be a Bluetooth issue that needs to be made more robust. The best way to fix it is to try with a Smart Lock 3.0 myself. but I do not have one. You do not visit Berlin by any chance?

mwarning avatar Apr 29 '22 22:04 mwarning

Sorry, the Lock is allready in use and we only have one. We yesterday also tested with another phone (i think android 10, so pretty recent) but had the same problems/errors.

v.2.2.0 has just some Battery State additions/updates and v.2.2.1 from 22.06.2021:

    Updated the information regarding the [Keyturner Service](https://developer.nuki.io/page/nuki-smart-lock-api-2/2/#heading--keyturner-service) MTU size.
    Corrected information about how to set "Auto Lock" option in [Advanced Config](https://developer.nuki.io/page/nuki-smart-lock-api-2/2/#heading--advanced-config) to false for current firmware version.

that does not sound like any changes would be breaking changes. maybe the MTU? but i don't really know

i can't provide you with a smart lock version 3 for testing, but i can try testing for you with the smartlock we got here if you give me some indications.

Thorbijoern avatar Apr 30 '22 12:04 Thorbijoern

HI @Thorbijoern, I just tried with my Nuki Smart Lock 2.0. It was working without problems with Trigger 3.4.4.

The error message comes from here: https://github.com/mwarning/trigger/blob/7b674bf6e680a5617ac488762a3673271b852a0c/app/src/main/java/app/trigger/nuki/NukiRequestHandler.java#L361

I suspect the logic (e.g. for pairing) exits at some point without setting NukiRequestHandler.bluetooth_in_use back to false. I suspect a few cases where this might happen. I might be able to provide you with a modified Trigger to test that might fix this. I could also add a lot of debug output, but this only make sense if you know how to use Android Studio).

Have you tried to restart Trigger after pairing was successful?

mwarning avatar May 01 '22 21:05 mwarning

I don't know what is less work for you, making me a modified apk for testing or one with a lot of output for android studio? I'm new to android development and haven't done much with java, but I'm willing to learn using Android Studio a bit if it is more helpful to you. I already kow adb a bit and it seems like adb logcat could also be used to get debug info from the app: https://developer.android.com/studio/command-line/logcat but Android Studio might be simpler. The Android Developer docs are pretty good and extensive, so it's totally doable for me.

We have not tried restarting the app after pairing. I will try that if i get a chance.

Thorbijoern avatar May 05 '22 23:05 Thorbijoern

Hi, you only need a debug build. The log out is already there and will be printed to logcat. So adb might be fine. Adnroid Studio makes it easier to filter the messages, but that is up to you. Let me know how I can contact you, and I can send you a debug build (or build one yourself if that is easier).

mwarning avatar May 06 '22 06:05 mwarning

I've now set up Android Studio in a VM on my notebook. The emulator is running very poorly but i was able to push the app to my phone and debug it there. It was simpler than i expected, i probably won't start much android development but such a defined development ecosystem sure does simplify a lot.

I don't know if i have to make some extra settings or changes to the app but i allready got some debug output in either the Run or Debug Console-Tabs (depending on how i build/ran the app) and additionaly had the logcat output from the app in android studio. (all 3 outputs are pretty much the same, but maybe with different filtering options?) Do i need to change something to get the debug build?

Also: what do i have to look out for in the debug log when testing the app with the nuki v3 again? should i set specific filters or look for specific messages? https://developer.android.com/studio/command-line/logcat#filteringOutput logcat looks like the best option to view the debug output. the whole log might be a bit much to copy&paste here and filtering out the right messages just makes it more easy.

Thorbijoern avatar May 31 '22 00:05 Thorbijoern

Here you can set the Active Build Variant and to create a debug build: studio

You can use the logcat filter to only seee messages from the trigger process (I have to reselect the Trigger app every time the app restarts...). The output should not be too much. Look out for the Bluetooth busy => abort action warning output.

mwarning avatar May 31 '22 14:05 mwarning

So, I was able to test it today and it worked. You have to give the Lock some time, like half a minute, between actions but it actually was able to pair. new Nuki v3 Firmware: 3.2.8 between the first test an now there was an update. Is there some sensitive information in the log output or is it save to provide openly?

Thorbijoern avatar Jun 01 '22 16:06 Thorbijoern

Half a minute is rather long. For my Nuki 2 it is a matter of 3 seconds. The log output does not contain anything sensitive (no keys).

mwarning avatar Jun 01 '22 16:06 mwarning

I really wonder why the pairing takes that long, but maybe they changes something with the Nuki3.

mwarning avatar Jun 01 '22 18:06 mwarning

the pairing is rather quick i think, but between locking and unlocking you have to wait some time or it will just tell you its busy or disconnect. here is the log: https://gist.github.com/Thorbijoern/54b930ae27c6ed206395b4478e7c4c4b there are quite a few locks and unlocks there and also some bluetooth busy and disconnected by device errors when i tried locking/unlocking too fast. but i don't know if've done something different today, one month ago we were not able to lock or unlock the nuki using trigger on two separate phones...

Thorbijoern avatar Jun 01 '22 19:06 Thorbijoern