search

athombv / homey-apps-sdk-issues

This issue tracker is for Homey Developers using the Apps SDK.
21 stars 4 forks source link

[BUG] homey.ble.find(...) ignores timeout parameter #312

Open redoz opened 1 year ago

redoz commented 1 year ago

Edit: I've spent a few hours digging into this, and it seems like the timeout specified isn't respected:

2023-08-05T15:19:51.423Z [log] [ManagerDrivers] [Driver:aranet4] [Device:87ed2320-4fca-4b83-abaf-59cd3c483a48] Attempting to find Aranet with id: c239e6b1510f (timeout: 15000ms)
2023-08-05T15:19:56.449Z [err] [ManagerDrivers] [Driver:aranet4] [Device:87ed2320-4fca-4b83-abaf-59cd3c483a48] An unexpected error occured Error: Peripheral Not Found: c239e6b1510f
    at Remote Process
    at HomeyClient.emit (/node_modules/@athombv/homey-apps-sdk-v3/lib/HomeyClient.js:44:23)
    at ManagerBLE.find (/node_modules/@athombv/homey-apps-sdk-v3/manager/ble.js:104:47)
    at Aranet4Device.readDataFromDevice (/app/drivers/aranet4/device.js:90:54)
    at Aranet4Device.refresh (/app/drivers/aranet4/device.js:62:45)
    at Aranet4Device.onInit (/app/drivers/aranet4/device.js:43:20)
    at Aranet4Device._onInit (/node_modules/@athombv/homey-apps-sdk-v3/lib/Device.js:148:18)
    at /node_modules/@athombv/homey-apps-sdk-v3/lib/Driver.js:180:34
    at processTicksAndRejections (node:internal/process/task_queues:96:5) {
  statusCode: 404
}
2023-08-05T15:19:56.449Z [log] [ManagerDrivers] [Driver:aranet4] [Device:87ed2320-4fca-4b83-abaf-59cd3c483a48] Aranet4 has been initialized
2023-08-05T15:20:01.452Z [log] [ManagerDrivers] [Driver:aranet4] [Device:87ed2320-4fca-4b83-abaf-59cd3c483a48] Attempting to find Aranet with id: c239e6b1510f (timeout: 15000ms)
2023-08-05T15:20:06.480Z [err] [ManagerDrivers] [Driver:aranet4] [Device:87ed2320-4fca-4b83-abaf-59cd3c483a48] An unexpected error occured Error: Peripheral Not Found: c239e6b1510f
    at Remote Process
    at HomeyClient.emit (/node_modules/@athombv/homey-apps-sdk-v3/lib/HomeyClient.js:44:23)
    at ManagerBLE.find (/node_modules/@athombv/homey-apps-sdk-v3/manager/ble.js:104:47)
    at Aranet4Device.readDataFromDevice (/app/drivers/aranet4/device.js:90:54)
    at Aranet4Device.refresh (/app/drivers/aranet4/device.js:62:45)
    at /app/drivers/aranet4/device.js:84:59
    at Timeout._onTimeout (/node_modules/@athombv/homey-apps-sdk-v3/lib/Homey.js:219:7)
    at listOnTimeout (node:internal/timers:559:17)
    at processTimers (node:internal/timers:502:7) {
  statusCode: 404
}

The timeout trips after 5 seconds, even though I passed in a timeout of 15000 milliseconds. 

this.log("Attempting to find Aranet with id: " + this.getStore().peripheralUuid + " (timeout: " + BLE_FIND_TIMEOUT + "ms)");      
var advertisement = await this.homey.ble.find(this.getStore().peripheralUuid, BLE_FIND_TIMEOUT);

Running on Homey Pro (early 2023) version: 10.0.1-rc.1

redoz commented 9 months ago

Can anyone at Athom say anything about this? Is this expected behavior?

robertklep commented 9 months ago

Looking at the actual implementation:

  if (event === 'find') {
    return this.onAppEventFind(data);
  }
  ...
  async onAppEventFind({ peripheralUuid }) {
    await this.discover();

    const peripheral = await this.getPeripheral({ peripheralUuid });
    return peripheral.toAppJSON();
  }
  ...
  async discover() {
    if (!this.__discoverPromise) {
      this.__discoverPromise = Promise.resolve().then(async () => {
        await Bluez.startDiscovery();
        await HomeyUtil.wait(TIMES.ONE_SECOND * 5);
        await Bluez.stopDiscovery();
      });
      this.__discoverPromise
        .catch((err) => this.error(`Error Discovering: ${err.message}`))
        .finally(() => {
          delete this.__discoverPromise;
        });
    }

    await this.__discoverPromise;
  }

Which to me looks like a timeout argument on .find() is just discarded.

redoz commented 9 months ago

Looking at the actual implementation:

  if (event === 'find') {
    return this.onAppEventFind(data);
  }
  ...
  async onAppEventFind({ peripheralUuid }) {
    await this.discover();

    const peripheral = await this.getPeripheral({ peripheralUuid });
    return peripheral.toAppJSON();
  }
  ...
  async discover() {
    if (!this.__discoverPromise) {
      this.__discoverPromise = Promise.resolve().then(async () => {
        await Bluez.startDiscovery();
        await HomeyUtil.wait(TIMES.ONE_SECOND * 5);
        await Bluez.stopDiscovery();
      });
      this.__discoverPromise
        .catch((err) => this.error(`Error Discovering: ${err.message}`))
        .finally(() => {
          delete this.__discoverPromise;
        });
    }

    await this.__discoverPromise;
  }

Which to me looks like a timeout argument on .find() is just discarded.

That was more or less my suspicion as well, thank you!

@robertklep do you work for Athom, or is this source somehow available so I could've found this answer myself?

robertklep commented 9 months ago

No, I don't work for Athom 😅 If you jailbreak your Homey you can find the file ManagerBLE.mjs in /var/lib/docker/overlay2/b8abd68bb4b398dba93cdb5da5da6e32d260bb76d3594d00daf768414f11fb84/diff/app/lib/

redoz commented 9 months ago

Well in that case I owe you a drink of choice, thank you!

Now if only we could get Athom's attention so they could actually fix this 🙄