robbertkl / homebridge-bold-ble

Homebridge plugin for Bold Smart Lock
MIT License
4 stars 1 forks source link

Skipping lock activation, it's already activated or activating #1

Open MREInc opened 7 months ago

MREInc commented 7 months ago

Describe Your Problem: When activating the lock in Homekit, the tile in homekit returns: opening..... and then nothing happens.

BoldLE running as child bridge and succesfully added to Homekit. After adding the bridge, the lock is added to homekit succesfully as well. It initially works but after unlocking, it stops working with the status on the tile in homekit: opening.....

To resolve this issue, I've tried:

Removed BoldLE plugin from Homebridge Removed BoldLE bridge and lock in Homekit Revoked access in official Bold app on iOS Reinstalled BoldLE plugin in Homebridge Reconfigured the plugin in Homebridge. Added BoldLE child bridge and bold smartlock to Homekit.

But this does not work. Only restarting the BoldLE child bridge will result in a working tile in homekit for a few moments.

Logs:

The Homebridge returns:
Skipping lock activation for device 88321, it's already activated or activating

Plugin Config:

{
            "name": "BoldBLE",
            "accessToken": "xxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxx",
            "refreshToken": "xxxxxxxxx-xxxx-xxxx-xxxxx-xxxxxxxxxxxx",
            "legacyAuthentication": false,
            "platform": "BoldBLE",
            "_bridge": {
                "username": "0E:xx:7E:xx:2D:xx",
                "port": 58073

Screenshots:

Environment:

robbertkl commented 7 months ago

Hmm, that's odd. I have a similar setup and it's been working fine since I created the plugin 9 months ago, with daily use.

I haven't used child bridges, so perhaps that's causing issues, although I'm not sure how. Would you be able to test without a child bridge?

MREInc commented 7 months ago

Sigh, it was a misconfigured Dummy Switch which caused these issues.

Because of Apple security, you cannot operate the smart lock remotely eg, when someone arrives home then activate the lock. In order to get this working, you need a dummy switch, which then triggers the smart lock.

I have 2 automations in HomeKit:

  1. When someone arrives at home, then activate dummy switch
  2. When dummy switch is triggered, open frontdoor.
gielk commented 7 months ago

I have the same issue. I'm trying to control the log directly from HomeKit, without automation, and I'm getting the same error.

gielk commented 7 months ago

I found a solution. Here's what I did: I removed it from HomeKit but left it in Homebridge, then connected Homebridge to Home Assistant. Now, I control it through Automations in Home Assistant. Apparently, trying to control the lock with Automations directly from HomeKit causes it to become unreachable and unable to unlock. This doesn't affect it when controlled through Home Assistant because Automations run independently in Home Assistant. They only send an unlock trigger or something similar. I'm not sure what the issue is in HomeKit, but this solution worked for me.

robbertkl commented 7 months ago

@MREInc Thanks for the follow-up, glad it's resolved!

robbertkl commented 7 months ago

@gielk

Apparently, trying to control the lock with Automations directly from HomeKit causes it to become unreachable and unable to unlock.

What kind of automation did you use? You mentioned in your initial message you have the issue without automation?

gielk commented 7 months ago

Yes, I was using it directly from HomeKit without automation. I had an automation set up to activate the lock when I opened the door. This way, when I left and opened the door, the lock would be activated, allowing me to close it from the outside and leave. It worked the first time, but when I tried to control the lock again from HomeKit via the app, I received the error message. So, it worked once with an automation, but afterward, it was no longer possible to control the lock from HomeKit. It's running in a child server. Restarting the child server didn't work; I had to restart the entire Homebridge. After that, I could unlock and lock using the HomeKit app, but once the automation ran once, it couldn't be controlled from the HomeKit app anymore. I hope this clarifies things. If you have any questions or would like me to help you with anything just ask.

robbertkl commented 7 months ago

Thanks for the additional info! Would you be able to test the exact same automation setup without a child bridge? I'm not using child bridges myself so I'm curious if that's causing the issue for you, or if it's the automation by itself.

MREInc commented 7 months ago

@robbertkl Bad news, not resolved.

I removed the child bridge and removed and reconnected everything in Homekit but now running without a child bridge. It got even worse. When I press the tile in the Home app, nothing happens and still the same error in the Homebridge logs. I've tested it for serveral days without a child bridge. Even restarting the bridge does not resolve the problem.

For now I've completely removed the plugin from Homebridge, removed cached accessories in Homebridge, removed the cached bridge and removed everything in Homekit/Home app and removed the integration in the official Bold app. I will wait at least 24h before adding everything in Homebridge. I've read about several other issues with iOS and Homebridge that waiting 24h will resolve some issues. Has something to do with iCloud sync between iOS devices, but this is just a rumour, not confired as a real "solution".

gielk commented 7 months ago

Here are some screenshots.

IMG_0673 IMG_0674 IMG_0675

gielk commented 7 months ago

I tried what you suggested. I attempted to run it on the main instead of a child, but unfortunately, it didn't solve the issue. The automation worked fine the first time, and there were no problems. However, the second time, the automation didn't work anymore. I waited a few minutes for it to lock again, but after that, it became unreachable and stopped working. Didn’t matter how long I waited.

gielk commented 7 months ago

Unfortunately, today it stopped. Got an error message again this morning.

[04/12/2023, 07:01:06] [BoldBLE] Skipping lock activation for device 120951, it's already activated or activating

After a restart of the child bridge, it worked again.

[04/12/2023, 08:45:17] [BoldBLE] Activated lock for device 120951, will auto-deactivate after 120s

gielk commented 4 months ago

Any updates on this matter @robbertkl ? I would appreciate getting this issue resolved. I attempted to set up a plugin to restart the child bridge periodically, but I was unsuccessful.

robbertkl commented 4 months ago

Unfortunately I haven't been able to reproduce this myself. It would be helpful if you could add some additional logging to various functions to understand what's going on when you reproduce it.

gielk commented 4 months ago

I have finally managed to restart the child bridge every 2 hours or when the lock has been in the "unlocked" or "unlocking" state for longer than 2 minutes.

I am doing this from HomeAssistant because I also use the lock here.

If anyone is interested in this and also uses HomeAssistant, I would like to share this.

gielk commented 4 months ago

Unfortunately I haven't been able to reproduce this myself. It would be helpful if you could add some additional logging to various functions to understand what's going on when you reproduce it.

What else do you need from me? Can I share a more detailed debug with you?

I am now receiving that it is unlocked, but afterwards I immediately get a message saying it is still activated when I try to unlock again after more than 2 minutes, but this is not the case at all. Maybe we can skip this check because you can always extend the unlock status even if it is already unlocked.

[28/02/2024, 11:44:33] [BoldBLE] Activated lock for device 120951, will auto-deactivate after 120s
[28/02/2024, 11:50:33] [BoldBLE] Skipping lock activation for device 120951, it's already activated or activating
robbertkl commented 4 months ago

The check is there to prevent race conditions with the internal status, and also to make sure the status gets correctly updated after the activation time (back to locked). You might be able to send a new unlock command (which has no effect) but then a new activation timer will no longer be correct.

That being said, I'm OK to disable the check to resolve the issue, if we really cannot find the cause of this. Disabling the check would be a workaround; I'd rather get to the bottom of this and track down the underlying issue causing it.

Would you be able to add some debug info to the code?

Things where additional info would be useful:

  1. Add ${lock.state} to the skip message, so we know if you lock is stuck as "activated" or "activating" (probably activated). For example change it to:
this.log.warn(`Skipping lock activation for device ${deviceId}, it's already ${lock.state}`);
  1. Add a new this.log.info line within the activation timer (search for setTimeout), to know if it gets executed. For example:
setTimeout(() => {
    this.log.info(`Setting lock to deactivated`);
    lock.state = 'deactivated';
    // ...

Would you be able to give this a try so we can get a clue what's going on?

SchmidSP commented 4 months ago

Hi, same here: I have set the parameters in index.js above.

These are the results: [09/03/2024, 17:29:13] Homebridge v1.7.0 (HAP v0.11.1) (Homebridge xxxx) is running on port 51562. [09/03/2024, 17:29:17] [BoldBLE] Discovered peripheral for device 42527 with -54 dBm RSSI [09/03/2024, 17:29:47] [BoldBLE] Activated lock for device 42527, will auto-deactivate after 5s [09/03/2024, 17:29:52] [BoldBLE] Setting lock to deactivated [09/03/2024, 17:31:57] [BoldBLE] Skipping lock activation for device 42527, it's already activating [09/03/2024, 17:31:57] [BoldBLE] Skipping lock activation for device 42527, it's already activating [09/03/2024, 17:31:57] [BoldBLE] Skipping lock activation for device 42527, it's already activating [09/03/2024, 17:31:57] [BoldBLE] Skipping lock activation for device 42527, it's already activating [09/03/2024, 17:31:57] [BoldBLE] Skipping lock activation for device 42527, it's already activating [09/03/2024, 17:31:57] [BoldBLE] Skipping lock activation for device 42527, it's already activating [09/03/2024, 17:31:58] [BoldBLE] Skipping lock activation for device 42527, it's already activating [09/03/2024, 17:31:58] [BoldBLE] Skipping lock activation for device 42527, it's already activating [09/03/2024, 17:32:08] [BoldBLE] Skipping lock activation for device 42527, it's already activating [09/03/2024, 17:32:08] [BoldBLE] Skipping lock activation for device 42527, it's already activating [09/03/2024, 17:32:08] [BoldBLE] Skipping lock activation for device 42527, it's already activating [09/03/2024, 17:32:08] [BoldBLE] Skipping lock activation for device 42527, it's already activating [09/03/2024, 17:32:08] [BoldBLE] Skipping lock activation for device 42527, it's already activating [09/03/2024, 17:32:08] [BoldBLE] Skipping lock activation for device 42527, it's already activating [09/03/2024, 17:32:08] [BoldBLE] Skipping lock activation for device 42527, it's already activating

Works only one time. Second time Skipping message an no reaction with devices in the Homebridge UI. Interesting: Homekit and Homebridge UI show the same Status (open/close). Only the Bold lock does nothing. After Homebridge restart it works again one time.

If you need more Information / Logs for debugging, just ask me. I help. Thanks!

robbertkl commented 4 months ago

@SchmidSP Thanks, that's very helpful! So actually it does set the lock to "deactivated", but it gets set to "activating" again somehow. 🤔

Could you add a few more debug lines and retry? Hopefully that will tell the full story and I can create a fix (or workaround).

  1. Add a new this.log.info to the top of the setTargetLockState function:
  private async setTargetLockState(deviceId: number, value: CharacteristicValue) {
    this.log.info(`setTargetLockState(${deviceId}, ${value})`);
    // ...
  1. Add a new this.log.info to the other places where the lock state changes:
    this.log.info('Setting lock to activating');
    lock.state = 'activating';
    // ...
    this.log.info('Setting lock to activated');
    lock.state = 'activated';
SchmidSP commented 4 months ago

Hi, sure, but can't find the correct lines. Could you help me to find them, like change this (example) to that (new example)?

Thanks!

robbertkl commented 4 months ago

Sure, the changes should again be in homebridge-bold-ble/dist/index.js. I've expanded to show a bit more lines below. You'll only have to insert the this.log.info line.

  1. Change
    async setTargetLockState(deviceId, value) {
        const lock = this.locks.get(deviceId);
        if (!lock) {

to

    async setTargetLockState(deviceId, value) {
        this.log.info(`setTargetLockState(${deviceId}, ${value})`);
        const lock = this.locks.get(deviceId);
        if (!lock) {
  1. Change
            throw new this.homebridge.hap.HapStatusError(-70412 /* NOT_ALLOWED_IN_CURRENT_STATE */);
        }
        lock.state = 'activating';
        targetState === null || targetState === void 0 ? void 0 : targetState.updateValue(this.Characteristic.LockTargetState.UNSECURED);

to

            throw new this.homebridge.hap.HapStatusError(-70412 /* NOT_ALLOWED_IN_CURRENT_STATE */);
        }
        this.log.info('Setting lock to activating');
        lock.state = 'activating';
        targetState === null || targetState === void 0 ? void 0 : targetState.updateValue(this.Characteristic.LockTargetState.UNSECURED);

and

            throw new this.homebridge.hap.HapStatusError(hapStatus);
        }
        lock.state = 'activated';
        currentState === null || currentState === void 0 ? void 0 : currentState.updateValue(this.Characteristic.LockTargetState.UNSECURED);
        setTimeout(() => {

to

            throw new this.homebridge.hap.HapStatusError(hapStatus);
        }
        this.log.info('Setting lock to activated');
        lock.state = 'activated';
        currentState === null || currentState === void 0 ? void 0 : currentState.updateValue(this.Characteristic.LockTargetState.UNSECURED);
        setTimeout(() => {
SchmidSP commented 4 months ago

Here we go: [12/03/2024, 07:12:23] [BoldBLE] Discovered peripheral for device 42527 with -57 dBm RSSI [12/03/2024, 07:13:01] [BoldBLE] setTargetLockState(42527, 0) [12/03/2024, 07:13:01] [BoldBLE] Setting lock to activating [12/03/2024, 07:13:05] [BoldBLE] Activated lock for device 42527, will auto-deactivate after 5s [12/03/2024, 07:13:05] [BoldBLE] Setting lock to activated [12/03/2024, 07:13:10] [BoldBLE] Setting lock to deactivated [12/03/2024, 07:13:26] [BoldBLE] setTargetLockState(42527, 0) [12/03/2024, 07:13:26] [BoldBLE] Setting lock to activating [12/03/2024, 07:14:01] [BoldBLE] setTargetLockState(42527, 1) [12/03/2024, 07:15:18] [BoldBLE] setTargetLockState(42527, 0) [12/03/2024, 07:15:18] [BoldBLE] Skipping lock activation for device 42527, it's already activating [12/03/2024, 07:15:58] [BoldBLE] setTargetLockState(42527, 0) [12/03/2024, 07:15:58] [BoldBLE] Skipping lock activation for device 42527, it's already activating

First try 07:12:23 working. All other activation didn't work.

After Restart Homebridge Service I can unlock the Bold Smartlock one time again: [12/03/2024, 07:18:15] [BoldBLE] Discovered peripheral for device 42527 with -59 dBm RSSI [12/03/2024, 07:18:28] [BoldBLE] setTargetLockState(42527, 0) [12/03/2024, 07:18:28] [BoldBLE] Setting lock to activating [12/03/2024, 07:18:31] [BoldBLE] Activated lock for device 42527, will auto-deactivate after 5s [12/03/2024, 07:18:31] [BoldBLE] Setting lock to activated [12/03/2024, 07:18:36] [BoldBLE] Setting lock to deactivated [12/03/2024, 07:19:06] [BoldBLE] setTargetLockState(42527, 0) [12/03/2024, 07:19:06] [BoldBLE] Setting lock to activating [12/03/2024, 07:19:09] [BoldBLE] setTargetLockState(42527, 1) [12/03/2024, 07:19:11] [BoldBLE] setTargetLockState(42527, 0) [12/03/2024, 07:19:11] [BoldBLE] Skipping lock activation for device 42527, it's already activating [12/03/2024, 07:19:13] [BoldBLE] setTargetLockState(42527, 0) [12/03/2024, 07:19:13] [BoldBLE] Skipping lock activation for device 42527, it's already activating [12/03/2024, 07:19:14] [BoldBLE] setTargetLockState(42527, 0) [12/03/2024, 07:19:14] [BoldBLE] Skipping lock activation for device 42527, it's already activating [12/03/2024, 07:19:15] [BoldBLE] setTargetLockState(42527, 0) [12/03/2024, 07:19:15] [BoldBLE] Skipping lock activation for device 42527, it's already activating

In the Bold App I can see two activations: 07:13 and 07:18 Hope it helps. Thanks.

robbertkl commented 4 months ago

Thanks a lot!

Unfortunately, it seems to be hanging in the Bluetooth code, which is going to be hard to debug. This also means it could be related to a wide number of things, e.g. Pi version, installed OS, Linux kernel, libbluetooth version. I'm still unable to reproduce this on my end.

This also makes it very unlikely that the workaround (skipping the check) will work; it will just hang on Bluetooth again. It can be seen that "Skipping lock activation" is NOT where it goes wrong, because that only happens on the 3rd attempt. However, it already fails to work on the 2nd attempt:

1st unlock attempt: (successful)

[12/03/2024, 07:13:01] [BoldBLE] setTargetLockState(42527, 0)
[12/03/2024, 07:13:01] [BoldBLE] Setting lock to activating
[12/03/2024, 07:13:05] [BoldBLE] Activated lock for device 42527, will auto-deactivate after 5s
[12/03/2024, 07:13:05] [BoldBLE] Setting lock to activated
[12/03/2024, 07:13:10] [BoldBLE] Setting lock to deactivated

2nd unlock attempt: (unsuccessful, hangs in BLE)

[12/03/2024, 07:13:26] [BoldBLE] setTargetLockState(42527, 0)
[12/03/2024, 07:13:26] [BoldBLE] Setting lock to activating

Manually setting it back to locked

[12/03/2024, 07:14:01] [BoldBLE] setTargetLockState(42527, 1)

3rd unlock attempt: (skipped)

[12/03/2024, 07:15:18] [BoldBLE] setTargetLockState(42527, 0)
[12/03/2024, 07:15:18] [BoldBLE] Skipping lock activation for device 42527, it's already activating

@SchmidSP If I could reproduce this myself, I would add a lot of this.log.info to the Bluetooth code in homebridge-bold-ble/dist/bold/ble/ble.js, to see what's the last thing it does before it hangs, and also why it's not triggering any of the timeouts I've built in. This, however, as well as trying out fixes, might get a bit time-consuming as we get closer to a fix, having to go back and forth to try things out. Would you be up for that?

SchmidSP commented 4 months ago

At the moment I have written a script as a workaround that restarts the Homebridge service after each unlock. Not so good, of course.

About the problem; Since restarting the Homebridge service helps, I think it's containable. I am happy to help with debugging on the Bluetooth side.

What can I do? Or, could you send me a customized ble.js with debug parameter? I will test it.

robbertkl commented 4 months ago

Great! I've created a debug branch here. If you could install that, I can easily make some changes for you to test. I've included the instructions to run this debug version in the README of the branch. Let me know if that works.

I've already added a bunch of additional debug info, so after installing could you test it and send me the log? Please wait for a minute between any tap / retry in HomeKit or Homebridge, to make it more clear whenever a user-initiated action starts.

SchmidSP commented 4 months ago

Ok, try to install Debug branch. Results: cd node_modules rm -Rf homebridge-bold-ble git clone -b debug https://github.com/robbertkl/homebridge-bold-ble.git cd homebridge-bold-ble npm install npm run build Cloning into 'homebridge-bold-ble'... remote: Enumerating objects: 140, done. remote: Counting objects: 100% (140/140), done. remote: Compressing objects: 100% (98/98), done. remote: Total 140 (delta 53), reused 125 (delta 38), pack-reused 0 Receiving objects: 100% (140/140), 225.30 KiB | 1.35 MiB/s, done. Resolving deltas: 100% (53/53), done. (##################) ⠏ reify:typescript: timing reifyNode:node_modules/eslint Completed in 388047ms

Stops responding. Maybe this Raspberry Pi Zero 2 W has not enough ram to compile... Restart, clean install nothing helps

I can test it (if you want) with a Raspberry Pi 4 next week?

robbertkl commented 4 months ago

Hmm, interesting, for me when testing this the npm install took quite a while, but the npm run build went relatively quick. I'm using a Raspberry Pi 3B+ on Raspbian 11. Definitely would be great if you could test it on a Pi 4! Also curious if you will even have the original issue on different hardware/software.

robbertkl commented 4 months ago

@SchmidSP Actually, perhaps we can still do it on the Zero W:

I've just pushed the compiled assets to the debug branch. I've also modified the instructions because you will no longer have to run npm run build, because the branch includes the prebuilt version.

Let me know if it works now.

gielk commented 4 months ago

I was able to install the debug version, only side note the command "hb-service restart" did not work for me, but I was of course able to do this manually.

[14/03/2024, 18:20:08] [BoldBLE] Initializing BoldBLE platform...
[14/03/2024, 18:20:08] [BoldBLE] Initializing child bridge 0E:1E:CD:17:1D:AB
[14/03/2024, 18:20:08] Loading 3 accessories...
[14/03/2024, 18:20:10] [BoldBLE] Launched child bridge with PID 10481
[14/03/2024, 18:20:11] [BoldBLE] Loaded homebridge-bold-ble v1.2.0 child bridge successfully
[14/03/2024, 18:20:11] Loaded 1 cached accessories from cachedAccessories.0E1ECD171DAB.
[14/03/2024, 18:20:11] [BoldBLE] Configuring accessory for device 120951 (Tuindeur)
[14/03/2024, 18:20:11] Publishing bridge accessory (name: BoldBLE, publishInfo: {
  username: '0E:1E:CD:17:1D:AB',
  port: 46626,
  pincode: '***-**-***',
  category: 2,
  bind: undefined,
  mdns: undefined,
  addIdentifyingMaterial: true,
  advertiser: 'bonjour-hap'
}).
[14/03/2024, 18:20:11] Registering platform 'homebridge-meural.MeuralCanvas'
[14/03/2024, 18:20:11] [BoldBLE] Refreshed API tokens
[14/03/2024, 18:20:12] [BoldBLE] BoldBle.discoverBoldPeripherals(, 30000)
[14/03/2024, 18:20:12] [BoldBLE] Updated handshake for device 120951
[14/03/2024, 18:20:12] [BoldBLE] Updated activate-command for device 120951
[14/03/2024, 18:20:12] [BoldBLE] BoldBle.discoverBoldPeripherals(120951, 30000)
[14/03/2024, 18:20:12] [BoldBLE] runWithTimeout(30000)
[14/03/2024, 18:20:12] [BoldBLE] BoldBle.waitForBluetooth()
[14/03/2024, 18:20:12] Registering platform 'homebridge-eufy-security.EufySecurity'
[14/03/2024, 18:20:12] [BoldBLE] BoldBle.getDeviceInfo()
[14/03/2024, 18:20:12] [BoldBLE] BoldBle.getDeviceInfo()
[14/03/2024, 18:20:12] [BoldBLE] Discovered peripheral for device 120951 with -81 dBm RSSI
[14/03/2024, 18:21:12] [BoldBLE] setTargetLockState(120951, 0)
[14/03/2024, 18:21:12] [BoldBLE] lock.state = activating
[14/03/2024, 18:21:12] [BoldBLE] Activating lock...
[14/03/2024, 18:21:12] [BoldBLE] BoldBle.activateLock()
[14/03/2024, 18:21:12] [BoldBLE] BoldBle.withEncryptedConnection()
[14/03/2024, 18:21:12] [BoldBLE] runWithTimeout(30000)
[14/03/2024, 18:21:12] [BoldBLE] BoldBleConnection.create(), peripheral.state=disconnected
[14/03/2024, 18:21:15] [BoldBLE] BoldBleConnection.performHandshake(), peripheral.state=connected
[14/03/2024, 18:21:15] [BoldBLE] BoldBleConnection.onPacketReceived(160, <57>, 161), peripheral.state=connected
[14/03/2024, 18:21:15] [BoldBLE] BoldBleConnection.onBytesReceived(<24>), peripheral.state=connected
[14/03/2024, 18:21:15] [BoldBLE] BoldBleConnection.onPacketReceived(161, <21>), peripheral.state=connected
[14/03/2024, 18:21:15] [BoldBLE] BoldBleConnection.onPacketReceived(162, <16>, 163), peripheral.state=connected
[14/03/2024, 18:21:15] [BoldBLE] BoldBleConnection.onBytesReceived(<12>), peripheral.state=connected
[14/03/2024, 18:21:15] [BoldBLE] BoldBleConnection.onPacketReceived(163, <9>), peripheral.state=connected
[14/03/2024, 18:21:15] [BoldBLE] BoldBleConnection.onPacketReceived(164, <46>, 165), peripheral.state=connected
[14/03/2024, 18:21:15] [BoldBLE] BoldBleConnection.onBytesReceived(<56>), peripheral.state=connected
[14/03/2024, 18:21:15] [BoldBLE] BoldBleConnection.onPacketReceived(165, <4>), peripheral.state=connected
[14/03/2024, 18:21:15] [BoldBLE] BoldBleConnection.disconnect(), peripheral.state=connected
[14/03/2024, 18:21:16] [BoldBLE] Activated lock for device 120951, will auto-deactivate after 120s
[14/03/2024, 18:21:16] [BoldBLE] lock.state = activated
[14/03/2024, 18:23:16] [BoldBLE] lock.state = deactivated
[14/03/2024, 18:23:20] [BoldBLE] setTargetLockState(120951, 0)
[14/03/2024, 18:23:20] [BoldBLE] lock.state = activating
[14/03/2024, 18:23:20] [BoldBLE] Activating lock...
[14/03/2024, 18:23:20] [BoldBLE] BoldBle.activateLock()
[14/03/2024, 18:23:20] [BoldBLE] BoldBle.withEncryptedConnection()
[14/03/2024, 18:23:20] [BoldBLE] runWithTimeout(30000)
[14/03/2024, 18:23:20] [BoldBLE] BoldBleConnection.create(), peripheral.state=disconnected
[14/03/2024, 18:25:50] [BoldBLE] setTargetLockState(120951, 1)
[14/03/2024, 18:25:52] [BoldBLE] setTargetLockState(120951, 0)
[14/03/2024, 18:25:52] [BoldBLE] Skipping lock activation for device 120951, it's already activating
SchmidSP commented 4 months ago

Here we go: [14/03/2024, 18:21:02] Loaded config.json with 0 accessories and 2 platforms. [14/03/2024, 18:21:03] Loaded 1 cached accessories from cachedAccessories. [14/03/2024, 18:21:03] --- [14/03/2024, 18:21:03] Loaded plugin: homebridge-bold-ble@1.2.0 [14/03/2024, 18:21:03] Registering platform 'homebridge-bold-ble.BoldBLE' [14/03/2024, 18:21:03] --- [14/03/2024, 18:21:03] Loading 2 platforms... [14/03/2024, 18:21:03] [BoldBLE] Initializing BoldBLE platform... [14/03/2024, 18:21:03] [BoldBLE] Configuring accessory for device 42527 (Werkstatt)

Enter this code with your HomeKit app on your iOS device to pair with Homebridge:
[14/03/2024, 18:21:03] Homebridge v1.7.0 (HAP v0.11.1) (Homebridge C848) is running on port 51562. [14/03/2024, 18:21:04] [BoldBLE] BoldBle.discoverBoldPeripherals(, 30000) [14/03/2024, 18:21:05] [BoldBLE] BoldBle.discoverBoldPeripherals(42527, 30000) [14/03/2024, 18:21:05] [BoldBLE] runWithTimeout(30000) [14/03/2024, 18:21:05] [BoldBLE] BoldBle.waitForBluetooth() [14/03/2024, 18:21:16] [BoldBLE] BoldBle.getDeviceInfo() [14/03/2024, 18:21:16] [BoldBLE] BoldBle.getDeviceInfo() [14/03/2024, 18:21:16] [BoldBLE] Discovered peripheral for device 42527 with -62 dBm RSSI [14/03/2024, 18:21:28] [BoldBLE] setTargetLockState(42527, 0) [14/03/2024, 18:21:28] [BoldBLE] lock.state = activating [14/03/2024, 18:21:28] [BoldBLE] Activating lock... [14/03/2024, 18:21:28] [BoldBLE] BoldBle.activateLock() [14/03/2024, 18:21:28] [BoldBLE] BoldBle.withEncryptedConnection() [14/03/2024, 18:21:28] [BoldBLE] runWithTimeout(30000) [14/03/2024, 18:21:28] [BoldBLE] BoldBleConnection.create(), peripheral.state=disconnected [14/03/2024, 18:21:30] [BoldBLE] BoldBleConnection.performHandshake(), peripheral.state=connected [14/03/2024, 18:21:30] [BoldBLE] BoldBleConnection.onPacketReceived(160, <57>, 161), peripheral.state=connected [14/03/2024, 18:21:31] [BoldBLE] BoldBleConnection.onBytesReceived(<24>), peripheral.state=connected [14/03/2024, 18:21:31] [BoldBLE] BoldBleConnection.onPacketReceived(161, <21>), peripheral.state=connected [14/03/2024, 18:21:31] [BoldBLE] BoldBleConnection.onPacketReceived(162, <16>, 163), peripheral.state=connected [14/03/2024, 18:21:31] [BoldBLE] BoldBleConnection.onBytesReceived(<12>), peripheral.state=connected [14/03/2024, 18:21:31] [BoldBLE] BoldBleConnection.onPacketReceived(163, <9>), peripheral.state=connected [14/03/2024, 18:21:31] [BoldBLE] BoldBleConnection.onPacketReceived(164, <46>, 165), peripheral.state=connected [14/03/2024, 18:21:31] [BoldBLE] BoldBleConnection.onBytesReceived(<100>), peripheral.state=connected [14/03/2024, 18:21:31] [BoldBLE] BoldBleConnection.onPacketReceived(165, <4>), peripheral.state=connected [14/03/2024, 18:21:31] [BoldBLE] BoldBleConnection.disconnect(), peripheral.state=connected [14/03/2024, 18:21:31] [BoldBLE] Activated lock for device 42527, will auto-deactivate after 5s [14/03/2024, 18:21:31] [BoldBLE] lock.state = activated [14/03/2024, 18:21:36] [BoldBLE] lock.state = deactivated [14/03/2024, 18:21:58] [BoldBLE] setTargetLockState(42527, 0) [14/03/2024, 18:21:58] [BoldBLE] lock.state = activating [14/03/2024, 18:21:58] [BoldBLE] Activating lock... [14/03/2024, 18:21:58] [BoldBLE] BoldBle.activateLock() [14/03/2024, 18:21:58] [BoldBLE] BoldBle.withEncryptedConnection() [14/03/2024, 18:21:58] [BoldBLE] runWithTimeout(30000) [14/03/2024, 18:21:58] [BoldBLE] BoldBleConnection.create(), peripheral.state=disconnected [14/03/2024, 18:22:28] [BoldBLE] setTargetLockState(42527, 1) [14/03/2024, 18:22:58] [BoldBLE] setTargetLockState(42527, 0) [14/03/2024, 18:22:58] [BoldBLE] Skipping lock activation for device 42527, it's already activating

gielk commented 4 months ago

@SchmidSP Almost at the same exact time! I'm no expert, but it looks like it has lost it connection to the lock.

BoldBleConnection.create(), peripheral.state=disconnected

I think that's why it also worked for me to restart the child bridge every time after the lock was unlocked. Then it was probably possible again to establish a Bluetooth connection.

SchmidSP commented 4 months ago

Yep. I also wrote a script that restarts hb service after unlock. Maybe Robert van find any idea what the bluetooth issue is.

gielk commented 3 months ago

@robbertkl Any update on this matter?

robbertkl commented 3 months ago

Hi, sorry, haven't had any time last week to take a good look. I hope to have a look later this week.

SchmidSP commented 3 months ago

Hi, tested a little bit. Maybe a quick (and dirty) solution is, after unlock disconnect the bluetooth connection and rescan for locks? If you need any further logs or basic ideas, don't hesitate to contact me ;)

gielk commented 2 months ago

Hi, tested a little bit. Maybe a quick (and dirty) solution is, after unlock disconnect the bluetooth connection and rescan for locks? If you need any further logs or basic ideas, don't hesitate to contact me ;)

What did you change? Then I could make this adjustment in advance to see if it also works for me?

SchmidSP commented 2 months ago

Hi, tested a little bit. Maybe a quick (and dirty) solution is, after unlock disconnect the bluetooth connection and rescan for locks? If you need any further logs or basic ideas, don't hesitate to contact me ;)

What did you change? Then I could make this adjustment in advance to see if it also works for me?

Hello,

I have made a workaround that I restart the homebridge and thus the Bluetooth connection after the signal to open via script. It's very messy, but since only the Bold connection is used on this Raspberry, it works. A Bluetooth disconnect and rescan would be cleaner in the plugin after the command has been sent. Unfortunately, my knowledge does not go that far. I am still hoping for Robert here.

simonrb2000 commented 1 week ago

I have just installed my Bold lock and having the same error.. did anyone find a way of restarting the bluetooth after each unlock? Does the lock work in HA? (I could use that instead)

simonrb2000 commented 5 days ago

So, I've been having the same issues as others have reported. I have had success using this plugin using the following step..

As soon as the lock is unlocked.. lock it again. For some reason.. this seems to prevent the bluetooth hanging. Since doing this I haven't had any issues.

To automate the process, I have a dummy switch that switches on when the lock unlocks and this dummy switch locks the lock again.

The lock won't actually lock, it just shows locking until the lock times out. I currently have mine set to 30secs.

I hope this is useful to some.