search

lynxis / keyblepy

KeyBLE python implementation
7 stars 3 forks source link

Is this repository still working? #4

Open schlagmichdoch opened 10 months ago

schlagmichdoch commented 10 months ago

As the original keyble does not run anymore at all we try to find an alternative.

@lynxis Does this repository still work for you?

We tried to use the following command on a Raspberry Pi 3B to open a lock with credentials that we still had from when the original library was still working (credentials redacted):

python3 keyble.py --device 00:00:00:00:00:00 --user-id 3 --user-key abcdefabcdefabcdefabcdefabcdefab --open

The Python script does not throw any error messages and returns device open but the lock does not do anything.

Running the same command with --verbose seems to show that the devices indeed connect but I have no idea what the problem is.

Could you give me an idea how to debug this repository or do you have any idea what we should do differently?

Logs:

click to expand ``` /opt/keyblepy/venv/bin/python3 /opt/keyblepy/keyble.py --device 00:00:00:00:00:00 --user-id 3 --user-key abcdefabcdefabcdefabcdefabcdefab --open --verbose 2023-10-19 16:30:52,045 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-19 16:30:52,046 DEBUG transitions.core Initiating transition from state disconnected to state connected... 2023-10-19 16:30:52,046 DEBUG transitions.core Executed callbacks before conditions. 2023-10-19 16:30:52,046 DEBUG transitions.core Executed callback before transition. 2023-10-19 16:30:52,046 DEBUG transitions.core Exiting state disconnected. Processing callbacks... 2023-10-19 16:30:52,047 INFO transitions.core Finished processing state disconnected exit callbacks. 2023-10-19 16:30:52,047 DEBUG transitions.core Entering state connected. Processing callbacks... 2023-10-19 16:30:52,047 DEBUG messages Encoding: '2' '3' '5029532017888092525' 2023-10-19 16:30:52,048 INFO transitions.core Executed callback 'on_enter_connected' 2023-10-19 16:30:52,048 INFO transitions.core Finished processing state connected enter callbacks. 2023-10-19 16:30:52,048 DEBUG transitions.core Executed callback after transition. 2023-10-19 16:30:52,048 DEBUG transitions.core Executed machine finalize callbacks 2023-10-19 16:30:52,145 DEBUG lowerlayer Connecting to BLE 2023-10-19 16:30:56,867 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-19 16:30:56,868 DEBUG transitions.core Initiating transition from state disconnected to state connected... 2023-10-19 16:30:56,869 DEBUG transitions.core Executed callbacks before conditions. 2023-10-19 16:30:56,869 DEBUG transitions.core Executed callback before transition. 2023-10-19 16:30:56,869 DEBUG transitions.core Exiting state disconnected. Processing callbacks... 2023-10-19 16:30:56,870 INFO transitions.core Finished processing state disconnected exit callbacks. 2023-10-19 16:30:56,872 DEBUG transitions.core Entering state connected. Processing callbacks... 2023-10-19 16:30:56,873 INFO transitions.core Executed callback 'on_enter_connected' 2023-10-19 16:30:56,873 INFO transitions.core Finished processing state connected enter callbacks. 2023-10-19 16:30:56,874 DEBUG transitions.core Executed callback after transition. 2023-10-19 16:30:56,874 DEBUG transitions.core Executed machine finalize callbacks 2023-10-19 16:30:57,876 DEBUG lowerlayer Sending message to BLE 2023-10-19 16:30:57,877 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-19 16:30:57,878 DEBUG transitions.core Initiating transition from state connected to state send... 2023-10-19 16:30:57,878 DEBUG transitions.core Executed callbacks before conditions. 2023-10-19 16:30:57,879 DEBUG transitions.core Executed callback before transition. 2023-10-19 16:30:57,879 DEBUG transitions.core Exiting state connected. Processing callbacks... 2023-10-19 16:30:57,880 INFO transitions.core Finished processing state connected exit callbacks. 2023-10-19 16:30:57,881 DEBUG transitions.core Entering state send. Processing callbacks... 2023-10-19 16:30:57,882 DEBUG lowerlayer OnSend: No fragment, try generating fragments 2023-10-19 16:30:57,883 DEBUG messages Before pad len pdu 11 2023-10-19 16:30:57,885 DEBUG messages After pad len pdu 16 2023-10-19 16:30:57,885 DEBUG lowerlayer OnSend: Encoded 1 fragments 2023-10-19 16:30:57,886 DEBUG lowerlayer send_fragment 1 0 2023-10-19 16:30:57,939 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-19 16:30:57,940 DEBUG transitions.core Initiating transition from state send to state wait_answer... 2023-10-19 16:30:57,941 DEBUG transitions.core Executed callbacks before conditions. 2023-10-19 16:30:57,942 DEBUG transitions.core Executed callback before transition. 2023-10-19 16:30:57,943 DEBUG transitions.core Exiting state send. Processing callbacks... 2023-10-19 16:30:57,944 INFO transitions.core Finished processing state send exit callbacks. 2023-10-19 16:30:57,946 DEBUG transitions.core Entering state wait_answer. Processing callbacks... 2023-10-19 16:30:57,947 INFO transitions.core Executed callback 'on_enter_wait_answer' 2023-10-19 16:30:57,948 INFO transitions.core Finished processing state wait_answer enter callbacks. 2023-10-19 16:30:57,949 DEBUG transitions.core Executed callback after transition. 2023-10-19 16:30:57,950 DEBUG transitions.core Executed machine finalize callbacks 2023-10-19 16:30:57,951 INFO transitions.core Executed callback 'on_enter_send' 2023-10-19 16:30:57,952 INFO transitions.core Finished processing state send enter callbacks. 2023-10-19 16:30:57,953 DEBUG transitions.core Executed callback after transition. 2023-10-19 16:30:57,954 DEBUG transitions.core Executed machine finalize callbacks 2023-10-19 16:30:57,955 INFO lowerlayer Received on 421 data : b'\x80\x03\x03\xc3$b\x00\xf0mK\xe9\x00\x10\x17\x00\x00' 2023-10-19 16:30:57,957 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-19 16:30:57,958 DEBUG transitions.core Initiating transition from state wait_answer to state connected... 2023-10-19 16:30:57,959 DEBUG transitions.core Executed callbacks before conditions. 2023-10-19 16:30:57,959 DEBUG transitions.core Executed callback before transition. 2023-10-19 16:30:57,961 DEBUG transitions.core Exiting state wait_answer. Processing callbacks... 2023-10-19 16:30:57,962 INFO transitions.core Finished processing state wait_answer exit callbacks. 2023-10-19 16:30:57,964 DEBUG transitions.core Entering state connected. Processing callbacks... 2023-10-19 16:30:57,965 INFO transitions.core Executed callback 'on_enter_connected' 2023-10-19 16:30:57,966 INFO transitions.core Finished processing state connected enter callbacks. 2023-10-19 16:30:57,967 DEBUG transitions.core Executed callback after transition. 2023-10-19 16:30:57,968 DEBUG transitions.core Executed machine finalize callbacks 2023-10-19 16:30:57,969 INFO lowerlayer Received message type 0x3 2023-10-19 16:30:57,970 INFO lowerlayer Received decoded message <- 0303c3246200f06d4be90010170000 2023-10-19 16:30:57,971 INFO fsm Receive message 2023-10-19 16:30:57,972 INFO fsm Receive ConnectionInfoMessage 2023-10-19 16:30:57,973 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-19 16:30:57,974 DEBUG transitions.core Initiating transition from state connected to state exchanged_nonce... 2023-10-19 16:30:57,975 DEBUG transitions.core Executed callbacks before conditions. 2023-10-19 16:30:57,976 DEBUG transitions.core Executed callback before transition. 2023-10-19 16:30:57,977 DEBUG transitions.core Exiting state connected. Processing callbacks... 2023-10-19 16:30:57,978 INFO transitions.core Finished processing state connected exit callbacks. 2023-10-19 16:30:57,979 DEBUG transitions.core Entering state exchanged_nonce. Processing callbacks... 2023-10-19 16:30:57,980 INFO fsm Exchanged nonce reached 2023-10-19 16:30:57,980 INFO transitions.core Executed callback 'on_enter_exchanged_nonce' 2023-10-19 16:30:57,981 INFO transitions.core Finished processing state exchanged_nonce enter callbacks. 2023-10-19 16:30:57,983 DEBUG transitions.core Executed callback after transition. device open 2023-10-19 16:30:57,984 DEBUG transitions.core Executed machine finalize callbacks 2023-10-19 16:30:57,985 DEBUG lowerlayer Sending message to BLE 2023-10-19 16:30:57,986 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-19 16:30:57,987 DEBUG transitions.core Initiating transition from state connected to state send... 2023-10-19 16:30:57,987 DEBUG transitions.core Executed callbacks before conditions. 2023-10-19 16:30:57,988 DEBUG transitions.core Executed callback before transition. 2023-10-19 16:30:57,989 DEBUG transitions.core Exiting state connected. Processing callbacks... 2023-10-19 16:30:57,990 INFO transitions.core Finished processing state connected exit callbacks. 2023-10-19 16:30:57,990 DEBUG transitions.core Entering state send. Processing callbacks... 2023-10-19 16:30:57,991 DEBUG lowerlayer OnSend: No fragment, try generating fragments 2023-10-19 16:30:57,991 DEBUG messages Before pad len pdu 16 2023-10-19 16:30:57,992 DEBUG messages After pad len pdu 16 2023-10-19 16:30:57,993 DEBUG lowerlayer OnSend: Encoded 1 fragments 2023-10-19 16:30:57,993 DEBUG lowerlayer send_fragment 1 0 2023-10-19 16:30:58,085 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-19 16:30:58,086 DEBUG transitions.core Initiating transition from state send to state wait_answer... 2023-10-19 16:30:58,087 DEBUG transitions.core Executed callbacks before conditions. 2023-10-19 16:30:58,088 DEBUG transitions.core Executed callback before transition. 2023-10-19 16:30:58,089 DEBUG transitions.core Exiting state send. Processing callbacks... 2023-10-19 16:30:58,090 INFO transitions.core Finished processing state send exit callbacks. 2023-10-19 16:30:58,092 DEBUG transitions.core Entering state wait_answer. Processing callbacks... 2023-10-19 16:30:58,093 INFO transitions.core Executed callback 'on_enter_wait_answer' 2023-10-19 16:30:58,093 INFO transitions.core Finished processing state wait_answer enter callbacks. 2023-10-19 16:30:58,094 DEBUG transitions.core Executed callback after transition. 2023-10-19 16:30:58,095 DEBUG transitions.core Executed machine finalize callbacks 2023-10-19 16:30:58,096 INFO transitions.core Executed callback 'on_enter_send' 2023-10-19 16:30:58,097 INFO transitions.core Finished processing state send enter callbacks. 2023-10-19 16:30:58,097 DEBUG transitions.core Executed callback after transition. 2023-10-19 16:30:58,098 DEBUG transitions.core Executed machine finalize callbacks 2023-10-19 16:30:58,099 INFO lowerlayer Received on 421 data : b'\x80\x01\x81\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' 2023-10-19 16:30:58,100 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-19 16:30:58,101 DEBUG transitions.core Initiating transition from state wait_answer to state connected... 2023-10-19 16:30:58,102 DEBUG transitions.core Executed callbacks before conditions. 2023-10-19 16:30:58,103 DEBUG transitions.core Executed callback before transition. 2023-10-19 16:30:58,104 DEBUG transitions.core Exiting state wait_answer. Processing callbacks... 2023-10-19 16:30:58,105 INFO transitions.core Finished processing state wait_answer exit callbacks. 2023-10-19 16:30:58,106 DEBUG transitions.core Entering state connected. Processing callbacks... 2023-10-19 16:30:58,106 INFO transitions.core Executed callback 'on_enter_connected' 2023-10-19 16:30:58,107 INFO transitions.core Finished processing state connected enter callbacks. 2023-10-19 16:30:58,107 DEBUG transitions.core Executed callback after transition. 2023-10-19 16:30:58,107 DEBUG transitions.core Executed machine finalize callbacks 2023-10-19 16:30:58,108 INFO lowerlayer Received message type 0x1 2023-10-19 16:30:58,108 INFO lowerlayer Received decoded message <- 018100000000000000000000000000 2023-10-19 16:30:58,109 INFO fsm Receive message 2023-10-19 16:30:58,823 INFO fsm Receive error from lower layer Exception occured Device disconnected ```
lynxis commented 10 months ago

Hi @schlagmichdoch, we're still using the keyble. However the keyble wasn't 100% complete. We're not parsing some answer but it is good enough and is used by our hackerspace door at the afra.

lynxis commented 10 months ago

Which firmware version are you using? I need more time to take a look into your issue. So far I remember, there was one state in which the lock rarely ran on which I could only get it our by using the official App on an android.

lynxis commented 10 months ago 
grep -v transi

yours: 

/opt/keyblepy/venv/bin/python3 /opt/keyblepy/keyble.py --device 00:00:00:00:00:00 --user-id 3 --user-key abcdefabcdefabcdefabcdefabcdefab --open --verbose
2023-10-19 16:30:52,047 DEBUG    messages               Encoding: '2' '3' '5029532017888092525'
2023-10-19 16:30:52,145 DEBUG    lowerlayer             Connecting to BLE
2023-10-19 16:30:57,876 DEBUG    lowerlayer             Sending message to BLE
2023-10-19 16:30:57,882 DEBUG    lowerlayer             OnSend: No fragment, try generating fragments
2023-10-19 16:30:57,883 DEBUG    messages               Before pad len pdu 11
2023-10-19 16:30:57,885 DEBUG    messages               After pad len pdu 16
2023-10-19 16:30:57,885 DEBUG    lowerlayer             OnSend: Encoded 1 fragments
2023-10-19 16:30:57,886 DEBUG    lowerlayer             send_fragment 1 0
2023-10-19 16:30:57,955 INFO     lowerlayer             Received on 421 data : b'\x80\x03\x03\xc3$b\x00\xf0mK\xe9\x00\x10\x17\x00\x00'
2023-10-19 16:30:57,969 INFO     lowerlayer             Received message type 0x3
2023-10-19 16:30:57,970 INFO     lowerlayer             Received decoded message <messages.ConnectionInfoMessage object at 0x75a83450> <- 0303c3246200f06d4be90010170000
2023-10-19 16:30:57,971 INFO     fsm                    Receive message <messages.ConnectionInfoMessage object at 0x75a83450>
2023-10-19 16:30:57,972 INFO     fsm                    Receive ConnectionInfoMessage
2023-10-19 16:30:57,980 INFO     fsm                    Exchanged nonce reached
2023-10-19 16:30:57,985 DEBUG    lowerlayer             Sending message to BLE
2023-10-19 16:30:57,991 DEBUG    lowerlayer             OnSend: No fragment, try generating fragments
2023-10-19 16:30:57,991 DEBUG    messages               Before pad len pdu 16
2023-10-19 16:30:57,992 DEBUG    messages               After pad len pdu 16
2023-10-19 16:30:57,993 DEBUG    lowerlayer             OnSend: Encoded 1 fragments
2023-10-19 16:30:57,993 DEBUG    lowerlayer             send_fragment 1 0
2023-10-19 16:30:58,099 INFO     lowerlayer             Received on 421 data : b'\x80\x01\x81\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'
2023-10-19 16:30:58,108 INFO     lowerlayer             Received message type 0x1
2023-10-19 16:30:58,108 INFO     lowerlayer             Received decoded message <messages.AnswerWithoutSecurity object at 0x76742470> <- 018100000000000000000000000000
2023-10-19 16:30:58,109 INFO     fsm                    Receive message <messages.AnswerWithoutSecurity object at 0x76742470>
2023-10-19 16:30:58,823 INFO     fsm                    Receive error from lower layer Exception occured Device disconnected

ours:

2023-09-24 22:31:43,690 DEBUG    messages               Encoding: '2' '1' 'XXXXXXXXXXXXXXXXXXXX'
2023-09-24 22:31:43,748 DEBUG    lowerlayer             Connecting to BLE
2023-09-24 22:31:49,630 DEBUG    lowerlayer             Sending message to BLE
2023-09-24 22:31:49,698 DEBUG    lowerlayer             OnSend: No fragment, try generating fragments
2023-09-24 22:31:49,709 DEBUG    messages               Before pad len pdu 11
2023-09-24 22:31:49,730 DEBUG    messages               After pad len pdu 16
2023-09-24 22:31:49,737 DEBUG    lowerlayer             OnSend: Encoded 1 fragments
2023-09-24 22:31:49,743 DEBUG    lowerlayer             send_fragment 1 0
2023-09-24 22:31:49,917 INFO     lowerlayer             Received on 421 data : b'\x80\x03\xXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX'
2023-09-24 22:31:49,994 INFO     lowerlayer             Received message type 0x3
2023-09-24 22:31:49,999 INFO     lowerlayer             Received decoded message <messages.ConnectionInfoMessage object at 0xb624ded0> <- 030XXXXXXXXXXXXXXXXXXXXXXXXXXX
2023-09-24 22:31:50,005 INFO     fsm                    Receive message <messages.ConnectionInfoMessage object at 0xb624ded0>
2023-09-24 22:31:50,019 INFO     fsm                    Receive ConnectionInfoMessage
2023-09-24 22:31:50,062 INFO     fsm                    Exchanged nonce reached
2023-09-24 22:31:50,106 DEBUG    lowerlayer             Sending message to BLE
2023-09-24 22:31:50,154 DEBUG    lowerlayer             OnSend: No fragment, try generating fragments
2023-09-24 22:31:50,159 DEBUG    messages               Before pad len pdu 16
2023-09-24 22:31:50,166 DEBUG    messages               After pad len pdu 16
2023-09-24 22:31:50,171 DEBUG    lowerlayer             OnSend: Encoded 1 fragments
2023-09-24 22:31:50,176 DEBUG    lowerlayer             send_fragment 1 0
2023-09-24 22:31:50,357 INFO     lowerlayer             Received on 421 data : b'\x80\x83\xed\xXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX'
2023-09-24 22:31:50,431 INFO     lowerlayer             Received message type 0x83
2023-09-24 22:31:50,439 INFO     lowerlayer             Received decoded message <messages.StatusInfoMessage object at 0xb6265230> <- 83edXXXXXXXXXXXXXXXXXXXXXXXXXX
2023-09-24 22:31:50,442 INFO     fsm                    Receive message <messages.StatusInfoMessage object at 0xb6265230>
2023-09-24 22:31:50,457 INFO     fsm                    Receive error from lower layer Exception occured isinstance() arg 2 must be a type or tuple of types

(No idea if I need to replace data with XXX).

Your keyble answers with AnswerWithoutSecurity instead with a StatusInfoMessage. So I would say your keyble doesn't like your request. Maybe your key is wrong, maybe the keyble thinks the lock is already open.

schlagmichdoch commented 10 months ago

Thanks very much for your quick answer!

Pretty sure the current credentials should work.

How did you generate your user credentials though? Normally we would send the qr-code data to the lock and receive a id-key pair. When we try to use keyble.py --register --qrdata XXXXX it fails as the script is looking for a userid and userkey

https://github.com/lynxis/keyblepy/blob/2a4e02d2be8111687b4bcc40e5777431bb6f836e/keyble.py#L60-L63

schlagmichdoch commented 10 months ago

and is used by our hackerspace door at the afra.

Awesome! Glad to hear this is indeed working! :)

So far I remember, there was one state in which the lock rarely ran on which I could only get it our by using the official App on an android.

What have you done in the app to get out of this state?

However the keyble wasn't 100% complete.

Would be glad to contribute!

Which firmware version are you using?

OS: Raspberry Pi OS (bookworm) Firmware: Not sure. I will tell you as soon as I have checked.

lynxis commented 10 months ago

I found a couple more commits which I never pushed into the repo. Please check it again. (In particular https://github.com/lynxis/keyblepy/commit/5c5d4336420fa1e821e9c6a57c110001f55393fd)

What have you done in the app to get out of this state?

Just open the app. it was gone.

lynxis commented 10 months ago

How did you generate your user credentials though? Normally we would send the qr-code data to the lock and receive a id-key pair. When we try to use keyble.py --register --qrdata XXXXX it fails as the script is looking for a userid and userkey

I can't remember. I did most of the stuff in 2019 and 2020. The lock doesn't generate the userkey, you have to generate one. So you generate a userkey and select a userid (e.g. 1) and then use the data from the qrcode to sign the pair request which consist of the userkey and the userid.

schlagmichdoch commented 10 months ago

I found a couple more commits which I never pushed into the repo.

That's great news, thanks! We will test it tomorrow. I'll keep you updated!

(In particular 5c5d433)

That means the open command should have worked already though. We will try to register new credentials first and test the open/lock/unlock commands after

schlagmichdoch commented 10 months ago

Which firmware version are you using?

keyble.py --disvover: {'bootloader': 16, 'application': 23}

vcgencmd version:

Aug 10 2023 15:35:01 
Copyright (c) 2012 Broadcom
version 03dc77429335caee083e22ddc8eec09c07f12a7a (clean) (release) (start)

We will test it tomorrow. I'll keep you updated!

So we tested the open command again which resulted in the same log as above. If the credentials are indeed not valid anymore that would make sense but we would need a way to register new user credentials.

We tried to issue new credentials by using the following command:

keyble.py --register --user-id 9 --user-key 112233445566778899aabbccddeeff --qr-data AABBCCDDEEFF --verbose
These are the logs: ``` 2023-10-21 15:34:45,145 INFO fsm Starting to pair 2023-10-21 15:34:45,149 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 15:34:45,150 DEBUG transitions.core Initiating transition from state disconnected to state connected... 2023-10-21 15:34:45,150 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 15:34:45,150 DEBUG transitions.core Executed callback before transition. 2023-10-21 15:34:45,151 DEBUG transitions.core Exiting state disconnected. Processing callbacks... 2023-10-21 15:34:45,151 INFO transitions.core Finished processing state disconnected exit callbacks. 2023-10-21 15:34:45,152 DEBUG transitions.core Entering state connected. Processing callbacks... 2023-10-21 15:34:45,152 DEBUG messages Encoding: '2' '4' 'xxx' 2023-10-21 15:34:45,152 INFO transitions.core Executed callback 'on_enter_connected' 2023-10-21 15:34:45,153 INFO transitions.core Finished processing state connected enter callbacks. 2023-10-21 15:34:45,153 DEBUG transitions.core Executed callback after transition. 2023-10-21 15:34:45,153 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 15:34:45,249 DEBUG lowerlayer Connecting to BLE 2023-10-21 15:34:48,436 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 15:34:48,437 DEBUG transitions.core Initiating transition from state disconnected to state connected... 2023-10-21 15:34:48,437 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 15:34:48,438 DEBUG transitions.core Executed callback before transition. 2023-10-21 15:34:48,438 DEBUG transitions.core Exiting state disconnected. Processing callbacks... 2023-10-21 15:34:48,438 INFO transitions.core Finished processing state disconnected exit callbacks. 2023-10-21 15:34:48,441 DEBUG transitions.core Entering state connected. Processing callbacks... 2023-10-21 15:34:48,441 INFO transitions.core Executed callback 'on_enter_connected' 2023-10-21 15:34:48,442 INFO transitions.core Finished processing state connected enter callbacks. 2023-10-21 15:34:48,443 DEBUG transitions.core Executed callback after transition. 2023-10-21 15:34:48,443 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 15:34:49,445 DEBUG lowerlayer Sending message to BLE 2023-10-21 15:34:49,447 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 15:34:49,447 DEBUG transitions.core Initiating transition from state connected to state send... 2023-10-21 15:34:49,448 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 15:34:49,449 DEBUG transitions.core Executed callback before transition. 2023-10-21 15:34:49,450 DEBUG transitions.core Exiting state connected. Processing callbacks... 2023-10-21 15:34:49,451 INFO transitions.core Finished processing state connected exit callbacks. 2023-10-21 15:34:49,452 DEBUG transitions.core Entering state send. Processing callbacks... 2023-10-21 15:34:49,452 DEBUG lowerlayer OnSend: No fragment, try generating fragments 2023-10-21 15:34:49,454 DEBUG messages Before pad len pdu 11 2023-10-21 15:34:49,454 DEBUG messages After pad len pdu 16 2023-10-21 15:34:49,455 DEBUG lowerlayer OnSend: Encoded 1 fragments 2023-10-21 15:34:49,456 DEBUG lowerlayer send_fragment 1 0 2023-10-21 15:34:49,557 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 15:34:49,557 DEBUG transitions.core Initiating transition from state send to state wait_answer... 2023-10-21 15:34:49,557 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 15:34:49,558 DEBUG transitions.core Executed callback before transition. 2023-10-21 15:34:49,558 DEBUG transitions.core Exiting state send. Processing callbacks... 2023-10-21 15:34:49,558 INFO transitions.core Finished processing state send exit callbacks. 2023-10-21 15:34:49,560 DEBUG transitions.core Entering state wait_answer. Processing callbacks... 2023-10-21 15:34:49,560 INFO transitions.core Executed callback 'on_enter_wait_answer' 2023-10-21 15:34:49,561 INFO transitions.core Finished processing state wait_answer enter callbacks. 2023-10-21 15:34:49,561 DEBUG transitions.core Executed callback after transition. 2023-10-21 15:34:49,561 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 15:34:49,562 INFO transitions.core Executed callback 'on_enter_send' 2023-10-21 15:34:49,562 INFO transitions.core Finished processing state send enter callbacks. 2023-10-21 15:34:49,562 DEBUG transitions.core Executed callback after transition. 2023-10-21 15:34:49,563 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 15:34:49,563 INFO lowerlayer Received on 421 data : b'\x80\x03\x04N]\xac\xe3\x16\x922\xa0\x00\x10\x17\x00\x00' 2023-10-21 15:34:49,564 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 15:34:49,564 DEBUG transitions.core Initiating transition from state wait_answer to state connected... 2023-10-21 15:34:49,564 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 15:34:49,565 DEBUG transitions.core Executed callback before transition. 2023-10-21 15:34:49,565 DEBUG transitions.core Exiting state wait_answer. Processing callbacks... 2023-10-21 15:34:49,566 INFO transitions.core Finished processing state wait_answer exit callbacks. 2023-10-21 15:34:49,567 DEBUG transitions.core Entering state connected. Processing callbacks... 2023-10-21 15:34:49,568 INFO transitions.core Executed callback 'on_enter_connected' 2023-10-21 15:34:49,568 INFO transitions.core Finished processing state connected enter callbacks. 2023-10-21 15:34:49,568 DEBUG transitions.core Executed callback after transition. 2023-10-21 15:34:49,569 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 15:34:49,569 INFO lowerlayer Received message type 0x3 2023-10-21 15:34:49,569 INFO lowerlayer Received decoded message <- 03044e5dace3169232a00010170000 2023-10-21 15:34:49,570 INFO fsm Receive message 2023-10-21 15:34:49,570 INFO fsm Receive ConnectionInfoMessage 2023-10-21 15:34:49,571 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 15:34:49,571 DEBUG transitions.core Initiating transition from state connected to state exchanged_nonce... 2023-10-21 15:34:49,572 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 15:34:49,572 DEBUG transitions.core Executed callback before transition. 2023-10-21 15:34:49,572 DEBUG transitions.core Exiting state connected. Processing callbacks... 2023-10-21 15:34:49,572 INFO transitions.core Finished processing state connected exit callbacks. 2023-10-21 15:34:49,573 DEBUG transitions.core Entering state exchanged_nonce. Processing callbacks... 2023-10-21 15:34:49,573 INFO fsm Exchanged nonce reached 2023-10-21 15:34:49,574 INFO transitions.core Executed callback 'on_enter_exchanged_nonce' 2023-10-21 15:34:49,574 INFO fsm userkey: b'xxxxx' 2023-10-21 15:34:49,574 INFO transitions.core Finished processing state exchanged_nonce enter callbacks. 2023-10-21 15:34:49,577 DEBUG transitions.core Executed callback after transition. 2023-10-21 15:34:49,578 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 15:34:50,580 DEBUG lowerlayer Sending message to BLE 2023-10-21 15:34:50,580 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 15:34:50,580 DEBUG transitions.core Initiating transition from state connected to state send... 2023-10-21 15:34:50,581 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 15:34:50,581 DEBUG transitions.core Executed callback before transition. 2023-10-21 15:34:50,582 DEBUG transitions.core Exiting state connected. Processing callbacks... 2023-10-21 15:34:50,582 INFO transitions.core Finished processing state connected exit callbacks. 2023-10-21 15:34:50,582 DEBUG transitions.core Entering state send. Processing callbacks... 2023-10-21 15:34:50,583 DEBUG lowerlayer OnSend: No fragment, try generating fragments 2023-10-21 15:34:50,583 DEBUG messages Before pad len pdu 16 2023-10-21 15:34:50,583 DEBUG messages After pad len pdu 16 2023-10-21 15:34:50,584 DEBUG messages Before pad len pdu 16 2023-10-21 15:34:50,584 DEBUG messages After pad len pdu 16 2023-10-21 15:34:50,584 DEBUG lowerlayer OnSend: Encoded 2 fragments 2023-10-21 15:34:50,585 DEBUG lowerlayer send_fragment 2 0 2023-10-21 15:34:50,585 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 15:34:50,585 DEBUG transitions.core Initiating transition from state send to state wait_ack... 2023-10-21 15:34:50,585 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 15:34:50,586 DEBUG transitions.core Executed callback before transition. 2023-10-21 15:34:50,586 DEBUG transitions.core Exiting state send. Processing callbacks... 2023-10-21 15:34:50,586 INFO transitions.core Finished processing state send exit callbacks. 2023-10-21 15:34:50,587 DEBUG transitions.core Entering state wait_ack. Processing callbacks... 2023-10-21 15:34:50,587 INFO transitions.core Executed callback 'on_enter_wait_ack' 2023-10-21 15:34:50,588 INFO transitions.core Finished processing state wait_ack enter callbacks. 2023-10-21 15:34:50,588 DEBUG transitions.core Executed callback after transition. 2023-10-21 15:34:50,588 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 15:34:50,678 INFO lowerlayer Received on 421 data : b'\x80\x00\x81\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' 2023-10-21 15:34:50,678 INFO lowerlayer Received correct FragmentAck 2023-10-21 15:34:50,678 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 15:34:50,679 DEBUG transitions.core Initiating transition from state wait_ack to state send... 2023-10-21 15:34:50,679 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 15:34:50,679 DEBUG transitions.core Executed callback before transition. 2023-10-21 15:34:50,679 DEBUG transitions.core Exiting state wait_ack. Processing callbacks... 2023-10-21 15:34:50,680 INFO transitions.core Finished processing state wait_ack exit callbacks. 2023-10-21 15:34:50,680 DEBUG transitions.core Entering state send. Processing callbacks... 2023-10-21 15:34:50,681 DEBUG lowerlayer send_fragment 2 1 2023-10-21 15:34:50,681 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 15:34:50,681 DEBUG transitions.core Initiating transition from state send to state wait_answer... 2023-10-21 15:34:50,682 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 15:34:50,682 DEBUG transitions.core Executed callback before transition. 2023-10-21 15:34:50,682 DEBUG transitions.core Exiting state send. Processing callbacks... 2023-10-21 15:34:50,682 INFO transitions.core Finished processing state send exit callbacks. 2023-10-21 15:34:50,683 DEBUG transitions.core Entering state wait_answer. Processing callbacks... 2023-10-21 15:34:50,683 INFO transitions.core Executed callback 'on_enter_wait_answer' 2023-10-21 15:34:50,684 INFO transitions.core Finished processing state wait_answer enter callbacks. 2023-10-21 15:34:50,684 DEBUG transitions.core Executed callback after transition. 2023-10-21 15:34:50,684 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 15:34:50,684 INFO transitions.core Executed callback 'on_enter_send' 2023-10-21 15:34:50,684 INFO transitions.core Finished processing state send enter callbacks. 2023-10-21 15:34:50,685 DEBUG transitions.core Executed callback after transition. 2023-10-21 15:34:50,685 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 15:34:50,775 INFO transitions.core Executed callback 'on_enter_send' 2023-10-21 15:34:50,775 INFO transitions.core Finished processing state send enter callbacks. 2023-10-21 15:34:50,776 DEBUG transitions.core Executed callback after transition. 2023-10-21 15:34:50,776 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 15:34:51,019 INFO lowerlayer Received on 421 data : b'\x80\x81\x8a\xf5\xb1\xab>\xf8r\xb8\x00\x01?\xb3me' 2023-10-21 15:34:51,020 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 15:34:51,020 DEBUG transitions.core Initiating transition from state wait_answer to state connected... 2023-10-21 15:34:51,021 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 15:34:51,021 DEBUG transitions.core Executed callback before transition. 2023-10-21 15:34:51,021 DEBUG transitions.core Exiting state wait_answer. Processing callbacks... 2023-10-21 15:34:51,022 INFO transitions.core Finished processing state wait_answer exit callbacks. 2023-10-21 15:34:51,023 DEBUG transitions.core Entering state connected. Processing callbacks... 2023-10-21 15:34:51,023 INFO transitions.core Executed callback 'on_enter_connected' 2023-10-21 15:34:51,024 INFO transitions.core Finished processing state connected enter callbacks. 2023-10-21 15:34:51,024 DEBUG transitions.core Executed callback after transition. 2023-10-21 15:34:51,024 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 15:34:51,025 INFO lowerlayer Received message type 0x81 2023-10-21 15:34:51,025 INFO lowerlayer Receive exception Wrong msgtype 2023-10-21 15:34:51,026 INFO fsm Receive message bytearray(b'\x81\x8a\xf5\xb1\xab>\xf8r\xb8\x00\x01?\xb3me') 2023-10-21 15:34:51,026 INFO fsm Receive error from lower layer Exception occured isinstance() arg 2 must be a type, a tuple of types, or a union ```

After that the new user is not listed in the user management in the Equiva Lock app so sadly it did not work

Apparently, your script does not like the received msgtype 0x81 which is AnswerWithSecurity as of messages.py: https://github.com/lynxis/keyblepy/blob/d19d490dc289db00582ce8dc2e727d13fd0561e0/messages.py#L441-L452

Could you please check whether your lock returns the same msgtype? Are we doing sth wrong?

Also, I saw that the message type should be correct: https://github.com/oyooyo/keyble/blob/933c452cd483f9301065c3c4007aa204faa745dc/keyble.js#L347

Update: I just found out the maximum number of devices for one lock is 8.. We will try again.

Update 2: We reset the lock and now the register command results in a message type `AnswerWithoutSecurity`.
New Logs ``` 2023-10-21 17:20:20,928 INFO fsm Starting to pair 2023-10-21 17:20:20,932 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 17:20:20,932 DEBUG transitions.core Initiating transition from state disconnected to state connected... 2023-10-21 17:20:20,933 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 17:20:20,933 DEBUG transitions.core Executed callback before transition. 2023-10-21 17:20:20,933 DEBUG transitions.core Exiting state disconnected. Processing callbacks... 2023-10-21 17:20:20,934 INFO transitions.core Finished processing state disconnected exit callbacks. 2023-10-21 17:20:20,934 DEBUG transitions.core Entering state connected. Processing callbacks... 2023-10-21 17:20:20,935 DEBUG messages Encoding: '2' '2' '15290994579444231806' 2023-10-21 17:20:20,935 INFO transitions.core Executed callback 'on_enter_connected' 2023-10-21 17:20:20,935 INFO transitions.core Finished processing state connected enter callbacks. 2023-10-21 17:20:20,936 DEBUG transitions.core Executed callback after transition. 2023-10-21 17:20:20,936 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 17:20:21,032 DEBUG lowerlayer Connecting to BLE 2023-10-21 17:20:24,454 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 17:20:24,455 DEBUG transitions.core Initiating transition from state disconnected to state connected... 2023-10-21 17:20:24,455 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 17:20:24,460 DEBUG transitions.core Executed callback before transition. 2023-10-21 17:20:24,461 DEBUG transitions.core Exiting state disconnected. Processing callbacks... 2023-10-21 17:20:24,461 INFO transitions.core Finished processing state disconnected exit callbacks. 2023-10-21 17:20:24,463 DEBUG transitions.core Entering state connected. Processing callbacks... 2023-10-21 17:20:24,464 INFO transitions.core Executed callback 'on_enter_connected' 2023-10-21 17:20:24,465 INFO transitions.core Finished processing state connected enter callbacks. 2023-10-21 17:20:24,465 DEBUG transitions.core Executed callback after transition. 2023-10-21 17:20:24,466 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 17:20:25,468 DEBUG lowerlayer Sending message to BLE 2023-10-21 17:20:25,469 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 17:20:25,469 DEBUG transitions.core Initiating transition from state connected to state send... 2023-10-21 17:20:25,470 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 17:20:25,470 DEBUG transitions.core Executed callback before transition. 2023-10-21 17:20:25,471 DEBUG transitions.core Exiting state connected. Processing callbacks... 2023-10-21 17:20:25,472 INFO transitions.core Finished processing state connected exit callbacks. 2023-10-21 17:20:25,472 DEBUG transitions.core Entering state send. Processing callbacks... 2023-10-21 17:20:25,473 DEBUG lowerlayer OnSend: No fragment, try generating fragments 2023-10-21 17:20:25,473 DEBUG messages Before pad len pdu 11 2023-10-21 17:20:25,474 DEBUG messages After pad len pdu 16 2023-10-21 17:20:25,474 DEBUG lowerlayer OnSend: Encoded 1 fragments 2023-10-21 17:20:25,475 DEBUG lowerlayer send_fragment 1 0 2023-10-21 17:20:25,575 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 17:20:25,576 DEBUG transitions.core Initiating transition from state send to state wait_answer... 2023-10-21 17:20:25,576 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 17:20:25,576 DEBUG transitions.core Executed callback before transition. 2023-10-21 17:20:25,577 DEBUG transitions.core Exiting state send. Processing callbacks... 2023-10-21 17:20:25,577 INFO transitions.core Finished processing state send exit callbacks. 2023-10-21 17:20:25,578 DEBUG transitions.core Entering state wait_answer. Processing callbacks... 2023-10-21 17:20:25,579 INFO transitions.core Executed callback 'on_enter_wait_answer' 2023-10-21 17:20:25,579 INFO transitions.core Finished processing state wait_answer enter callbacks. 2023-10-21 17:20:25,580 DEBUG transitions.core Executed callback after transition. 2023-10-21 17:20:25,580 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 17:20:25,580 INFO transitions.core Executed callback 'on_enter_send' 2023-10-21 17:20:25,581 INFO transitions.core Finished processing state send enter callbacks. 2023-10-21 17:20:25,581 DEBUG transitions.core Executed callback after transition. 2023-10-21 17:20:25,581 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 17:20:25,582 INFO lowerlayer Received on 421 data : b'\x80\x03\xff\xf8%)6\xed6W\xa4\x00\x10\x17\x00\x00' 2023-10-21 17:20:25,583 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 17:20:25,583 DEBUG transitions.core Initiating transition from state wait_answer to state connected... 2023-10-21 17:20:25,584 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 17:20:25,584 DEBUG transitions.core Executed callback before transition. 2023-10-21 17:20:25,584 DEBUG transitions.core Exiting state wait_answer. Processing callbacks... 2023-10-21 17:20:25,585 INFO transitions.core Finished processing state wait_answer exit callbacks. 2023-10-21 17:20:25,586 DEBUG transitions.core Entering state connected. Processing callbacks... 2023-10-21 17:20:25,587 INFO transitions.core Executed callback 'on_enter_connected' 2023-10-21 17:20:25,587 INFO transitions.core Finished processing state connected enter callbacks. 2023-10-21 17:20:25,588 DEBUG transitions.core Executed callback after transition. 2023-10-21 17:20:25,588 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 17:20:25,588 INFO lowerlayer Received message type 0x3 2023-10-21 17:20:25,589 INFO lowerlayer Received decoded message <- 03fff8252936ed3657a40010170000 2023-10-21 17:20:25,589 INFO fsm Receive message 2023-10-21 17:20:25,590 INFO fsm Receive ConnectionInfoMessage 2023-10-21 17:20:25,591 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 17:20:25,591 DEBUG transitions.core Initiating transition from state connected to state exchanged_nonce... 2023-10-21 17:20:25,591 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 17:20:25,592 DEBUG transitions.core Executed callback before transition. 2023-10-21 17:20:25,592 DEBUG transitions.core Exiting state connected. Processing callbacks... 2023-10-21 17:20:25,593 INFO transitions.core Finished processing state connected exit callbacks. 2023-10-21 17:20:25,593 DEBUG transitions.core Entering state exchanged_nonce. Processing callbacks... 2023-10-21 17:20:25,593 INFO fsm Exchanged nonce reached 2023-10-21 17:20:25,594 INFO transitions.core Executed callback 'on_enter_exchanged_nonce' 2023-10-21 17:20:25,594 INFO transitions.core Finished processing state exchanged_nonce enter callbacks. 2023-10-21 17:20:25,595 INFO fsm userkey: b'\xf3(\xa3\xa37\xf6\xb8\xa0\x90u\x8cm\xc0\xcd\xd4\x03' 2023-10-21 17:20:25,595 DEBUG transitions.core Executed callback after transition. 2023-10-21 17:20:25,596 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 17:20:26,599 DEBUG lowerlayer Sending message to BLE 2023-10-21 17:20:26,600 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 17:20:26,601 DEBUG transitions.core Initiating transition from state connected to state send... 2023-10-21 17:20:26,601 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 17:20:26,602 DEBUG transitions.core Executed callback before transition. 2023-10-21 17:20:26,603 DEBUG transitions.core Exiting state connected. Processing callbacks... 2023-10-21 17:20:26,603 INFO transitions.core Finished processing state connected exit callbacks. 2023-10-21 17:20:26,604 DEBUG transitions.core Entering state send. Processing callbacks... 2023-10-21 17:20:26,605 DEBUG lowerlayer OnSend: No fragment, try generating fragments 2023-10-21 17:20:26,606 DEBUG messages Before pad len pdu 16 2023-10-21 17:20:26,606 DEBUG messages After pad len pdu 16 2023-10-21 17:20:26,607 DEBUG messages Before pad len pdu 16 2023-10-21 17:20:26,607 DEBUG messages After pad len pdu 16 2023-10-21 17:20:26,608 DEBUG messages Before pad len pdu 16 2023-10-21 17:20:26,608 DEBUG messages After pad len pdu 16 2023-10-21 17:20:26,608 DEBUG lowerlayer OnSend: Encoded 3 fragments 2023-10-21 17:20:26,609 DEBUG lowerlayer send_fragment 3 0 2023-10-21 17:20:26,609 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 17:20:26,610 DEBUG transitions.core Initiating transition from state send to state wait_ack... 2023-10-21 17:20:26,610 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 17:20:26,610 DEBUG transitions.core Executed callback before transition. 2023-10-21 17:20:26,612 DEBUG transitions.core Exiting state send. Processing callbacks... 2023-10-21 17:20:26,612 INFO transitions.core Finished processing state send exit callbacks. 2023-10-21 17:20:26,614 DEBUG transitions.core Entering state wait_ack. Processing callbacks... 2023-10-21 17:20:26,615 INFO transitions.core Executed callback 'on_enter_wait_ack' 2023-10-21 17:20:26,615 INFO transitions.core Finished processing state wait_ack enter callbacks. 2023-10-21 17:20:26,616 DEBUG transitions.core Executed callback after transition. 2023-10-21 17:20:26,616 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 17:20:26,697 INFO lowerlayer Received on 421 data : b'\x80\x00\x82\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' 2023-10-21 17:20:26,697 INFO lowerlayer Received correct FragmentAck 2023-10-21 17:20:26,698 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 17:20:26,698 DEBUG transitions.core Initiating transition from state wait_ack to state send... 2023-10-21 17:20:26,699 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 17:20:26,700 DEBUG transitions.core Executed callback before transition. 2023-10-21 17:20:26,700 DEBUG transitions.core Exiting state wait_ack. Processing callbacks... 2023-10-21 17:20:26,701 INFO transitions.core Finished processing state wait_ack exit callbacks. 2023-10-21 17:20:26,702 DEBUG transitions.core Entering state send. Processing callbacks... 2023-10-21 17:20:26,702 DEBUG lowerlayer send_fragment 3 1 2023-10-21 17:20:26,702 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 17:20:26,703 DEBUG transitions.core Initiating transition from state send to state wait_ack... 2023-10-21 17:20:26,703 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 17:20:26,704 DEBUG transitions.core Executed callback before transition. 2023-10-21 17:20:26,704 DEBUG transitions.core Exiting state send. Processing callbacks... 2023-10-21 17:20:26,705 INFO transitions.core Finished processing state send exit callbacks. 2023-10-21 17:20:26,707 DEBUG transitions.core Entering state wait_ack. Processing callbacks... 2023-10-21 17:20:26,707 INFO transitions.core Executed callback 'on_enter_wait_ack' 2023-10-21 17:20:26,708 INFO transitions.core Finished processing state wait_ack enter callbacks. 2023-10-21 17:20:26,708 DEBUG transitions.core Executed callback after transition. 2023-10-21 17:20:26,708 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 17:20:26,710 INFO transitions.core Executed callback 'on_enter_send' 2023-10-21 17:20:26,710 INFO transitions.core Finished processing state send enter callbacks. 2023-10-21 17:20:26,711 DEBUG transitions.core Executed callback after transition. 2023-10-21 17:20:26,711 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 17:20:26,794 INFO lowerlayer Received on 421 data : b'\x80\x00\x01\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' 2023-10-21 17:20:26,794 INFO lowerlayer Received correct FragmentAck 2023-10-21 17:20:26,795 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 17:20:26,795 DEBUG transitions.core Initiating transition from state wait_ack to state send... 2023-10-21 17:20:26,795 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 17:20:26,796 DEBUG transitions.core Executed callback before transition. 2023-10-21 17:20:26,796 DEBUG transitions.core Exiting state wait_ack. Processing callbacks... 2023-10-21 17:20:26,797 INFO transitions.core Finished processing state wait_ack exit callbacks. 2023-10-21 17:20:26,798 DEBUG transitions.core Entering state send. Processing callbacks... 2023-10-21 17:20:26,798 DEBUG lowerlayer send_fragment 3 2 2023-10-21 17:20:26,799 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 17:20:26,799 DEBUG transitions.core Initiating transition from state send to state wait_answer... 2023-10-21 17:20:26,800 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 17:20:26,800 DEBUG transitions.core Executed callback before transition. 2023-10-21 17:20:26,800 DEBUG transitions.core Exiting state send. Processing callbacks... 2023-10-21 17:20:26,801 INFO transitions.core Finished processing state send exit callbacks. 2023-10-21 17:20:26,802 DEBUG transitions.core Entering state wait_answer. Processing callbacks... 2023-10-21 17:20:26,802 INFO transitions.core Executed callback 'on_enter_wait_answer' 2023-10-21 17:20:26,803 INFO transitions.core Finished processing state wait_answer enter callbacks. 2023-10-21 17:20:26,803 DEBUG transitions.core Executed callback after transition. 2023-10-21 17:20:26,804 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 17:20:26,804 INFO transitions.core Executed callback 'on_enter_send' 2023-10-21 17:20:26,804 INFO transitions.core Finished processing state send enter callbacks. 2023-10-21 17:20:26,805 DEBUG transitions.core Executed callback after transition. 2023-10-21 17:20:26,805 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 17:20:26,891 INFO transitions.core Executed callback 'on_enter_send' 2023-10-21 17:20:26,892 INFO transitions.core Finished processing state send enter callbacks. 2023-10-21 17:20:26,892 DEBUG transitions.core Executed callback after transition. 2023-10-21 17:20:26,892 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 17:20:26,941 INFO lowerlayer Received on 421 data : b'\x80\x01\x81\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' 2023-10-21 17:20:26,941 DEBUG transitions.core Executed machine preparation callbacks before conditions. 2023-10-21 17:20:26,942 DEBUG transitions.core Initiating transition from state wait_answer to state connected... 2023-10-21 17:20:26,942 DEBUG transitions.core Executed callbacks before conditions. 2023-10-21 17:20:26,942 DEBUG transitions.core Executed callback before transition. 2023-10-21 17:20:26,943 DEBUG transitions.core Exiting state wait_answer. Processing callbacks... 2023-10-21 17:20:26,943 INFO transitions.core Finished processing state wait_answer exit callbacks. 2023-10-21 17:20:26,945 DEBUG transitions.core Entering state connected. Processing callbacks... 2023-10-21 17:20:26,945 INFO transitions.core Executed callback 'on_enter_connected' 2023-10-21 17:20:26,945 INFO transitions.core Finished processing state connected enter callbacks. 2023-10-21 17:20:26,946 DEBUG transitions.core Executed callback after transition. 2023-10-21 17:20:26,946 DEBUG transitions.core Executed machine finalize callbacks 2023-10-21 17:20:26,947 INFO lowerlayer Received message type 0x1 2023-10-21 17:20:26,947 INFO lowerlayer Received decoded message <- 018100000000000000000000000000 2023-10-21 17:20:26,948 INFO fsm Receive message 2023-10-21 17:20:27,579 INFO fsm Receive error from lower layer Exception occured Device disconnected ```
The encryption procedure for the PairingRequestMessage differs from the procedure that you updated with the commits that you pushed yesterday. Compare: https://github.com/lynxis/keyblepy/blob/d19d490dc289db00582ce8dc2e727d13fd0561e0/fsm.py#L195-L201 with: https://github.com/lynxis/keyblepy/blob/d19d490dc289db00582ce8dc2e727d13fd0561e0/fsm.py#L271-L273 But changing it to the following did not improve it: ```python3 message = PairingRequestMessage.create( self.userid, _userkey, self.remote_nonce, self.security_counter, _cardkey) pdu = self.encrypt_message(message) self.ll.send(pdu) ```
lynxis commented 10 months ago

Yes. The pairing message a little bit different. The Open/Close/... all the regular commands are encrypted/signed using a userkey. But the pairing is special, because you don't have yet a userkey.

schlagmichdoch commented 10 months ago

That makes sense. Any idea how to go about getting new credentials?

lynxis commented 10 months ago

Not really. I've to order a second lock. Our in-production lock has

{'bootloader': 16, 'application': 23}

You shouldn't need to reset the lock to use the qrcode. It should still work even when you already set it up. (except you can't use already used user ids).

schlagmichdoch commented 10 months ago

Our in-production lock has

{'bootloader': 16, 'application': 23}

So that's the same as ours. Thanks for checking!

You shouldn't need to reset the lock to use the qrcode. It should still work even when you already set it up. (except you can't use already used user ids).

Well, since it did not work, we were not sure about the credentials and wanted to create new users as the lock had already 8 connected devices. So to be sure we reset the lock.

Not really. I've to order a second lock.

Okay, great! I guess we have to wait then.

schlagmichdoch commented 10 months ago

Not really. I've to order a second lock.

Can you anticipate when you will be able to test this? :)

lynxis commented 10 months ago

No. Not really. My order got stalled. I hope I can get the new lock this week otherwise I've to find someone who can setup a remote setup.

yunnanpl commented 7 months ago

So, my two cents, as I just was upgrading my home assistant setup, and needed to reconnect the lock. First point is, that I did not made another user registration, as I had already one made with java/node keyble (and it works).

In short, after making bluetooth work in python3 and for my user (and pairing/trusting the device) IT WORKS. So, Open, Lock and Unlock work quite nice (be sure to have a good BLE signal). (even though at the end there is some strange data handling always showing fsm Receive error from lower layer Exception occured isinstance() arg 2 must be a type, a tuple of types, or a union ).

Status and discovery have issues with timeout handling (always show timeout, even if connection went well). Discovery shows the same data as for other people ( {'bootloader': 16, 'application': 23} ) and the timeout issue. Status connects well and receives data, but maybe message decoding makes some issues as it shows device status = failed to get the StatusInfoMessage.

So, everything seems to be well documented in the readme, so timeout, decoding and status are not fully working ;)

Reading the code is a pleasure, as it is cleanly written and nicely documented. I will surely try to do some fixes, but no idea when (still, I will probably start with warnings, maybe timeout fixes, and in the far future decoding of the status).