diff --git a/src/ble.ts b/src/ble.ts index dbba48af..3c334355 100644 --- a/src/ble.ts +++ b/src/ble.ts @@ -497,7 +497,8 @@ export class BLEConnection { // Expected disconnect tracking private expectedDisconnects: Set = new Set() /** - * Mark the next disconnect for this MAC as expected + * Mark the next disconnect started by the device as expected (for example after a command that + * restarts it), so it is not logged as unexpected */ markExpectedDisconnect(mac: string): void { this.expectedDisconnects.add(normalizeMAC(mac)) @@ -925,20 +926,16 @@ export class BLEConnection { this.connections.set(normalizedMac, peripheral) this.clearDisconnectTimer(normalizedMac) + this.expectedDisconnects.delete(normalizedMac) + this.watchForDisconnect(normalizedMac, mac, peripheral) this.logger.info(`Connected to ${mac}`) // Discover characteristics (may throw) try { await this.discoverCharacteristics(normalizedMac, peripheral) } catch (error) { - // Clean up partial connection if characteristic discovery fails - this.connections.delete(normalizedMac) - this.characteristics.delete(normalizedMac) - - // Best effort disconnect to avoid leaked active BLE links - await new Promise((resolve) => { - peripheral.disconnect(() => resolve()) - }) + // Clean up the partial connection, and disconnect to avoid leaking an active BLE link + await this.disconnect(normalizedMac) throw error } @@ -986,44 +983,76 @@ export class BLEConnection { } /** - * Disconnect from a device + * Forget the connection state for a device: characteristics, encryption session, notification + * handlers and any pending reply. */ - async disconnect(mac: string): Promise { - const normalizedMac = normalizeMAC(mac) - const peripheral = this.connections.get(normalizedMac) + private dropConnectionState(normalizedMac: string, reason: string): void { + this.connections.delete(normalizedMac) + this.characteristics.delete(normalizedMac) this.clearDisconnectTimer(normalizedMac) // Reset encryption state (IV, cipher, mode) for this device this.clearEncryption(normalizedMac) this.notificationHandlers.delete(normalizedMac) - - const wasExpected = this.expectedDisconnects.has(normalizedMac) - if (wasExpected) { - this.expectedDisconnects.delete(normalizedMac) + const pending = this.notificationFutures.get(normalizedMac) + if (pending) { + clearTimeout(pending.timer) + this.notificationFutures.delete(normalizedMac) + pending.reject(new Error(reason)) } + } - if (!peripheral) { - if (!wasExpected) { - this.logger.warn(`Unexpected disconnect: peripheral not found for ${mac}`) + /** + * Watch for the device dropping the link (out of range, powered off, rebooted). Without this the + * stale peripheral stays in `connections` and the next command is sent over a dead link. + */ + private watchForDisconnect(normalizedMac: string, mac: string, peripheral: any): void { + if (typeof peripheral?.once !== 'function') { + return + } + peripheral.once('disconnect', () => { + const expected = this.expectedDisconnects.delete(normalizedMac) + if (this.connections.get(normalizedMac) !== peripheral) { + return + } + if (expected) { + this.logger.debug(`${mac} disconnected`) } else { - this.logger.info(`Expected disconnect: peripheral not found for ${mac}`) + this.logger.warn(`Unexpected disconnect from ${mac}`) } + this.dropConnectionState(normalizedMac, `${mac} disconnected while waiting for a reply`) + }) + } + + /** + * Disconnect from a device. Disconnects started here (idle timeout, disconnectAll, a failed + * connection) are expected and logged at debug level; only a disconnect the device starts is + * reported as unexpected. + */ + async disconnect(mac: string): Promise { + const normalizedMac = normalizeMAC(mac) + const peripheral = this.connections.get(normalizedMac) + this.dropConnectionState(normalizedMac, `Disconnected from ${mac} while waiting for a reply`) + + if (!peripheral) { + this.expectedDisconnects.delete(normalizedMac) + this.logger.debug(`Not connected to ${mac}`) return } + // Consumed by the 'disconnect' listener from watchForDisconnect + this.expectedDisconnects.add(normalizedMac) await new Promise((resolve) => { peripheral.disconnect(() => { - this.connections.delete(normalizedMac) - this.characteristics.delete(normalizedMac) - if (wasExpected) { - this.logger.info(`Expected disconnect from ${mac}`) - } else { - this.logger.warn(`Unexpected disconnect from ${mac}`) - } + this.logger.debug(`Disconnected from ${mac}`) resolve() }) }) + if (typeof peripheral.once !== 'function') { + this.expectedDisconnects.delete(normalizedMac) + } } + /** * Write data to device */ diff --git a/test/apis/ble-disconnect.test.ts b/test/apis/ble-disconnect.test.ts new file mode 100644 index 00000000..63541f5b --- /dev/null +++ b/test/apis/ble-disconnect.test.ts @@ -0,0 +1,92 @@ +import { EventEmitter } from 'node:events' + +import { describe, expect, it, vi } from 'vitest' + +import { BLEConnection } from '../../src/ble.js' +import { BLE_NOTIFY_CHARACTERISTIC_UUID, BLE_WRITE_CHARACTERISTIC_UUID } from '../../src/settings.js' + +// Every disconnect BLEConnection started itself (the idle timer, disconnectAll) was logged as +// "Unexpected disconnect", while a disconnect started by the device left a stale connection behind. +// https://github.com/OpenWonderLabs/node-switchbot/pull/348 + +function createPeripheral() { + const peripheral: any = new EventEmitter() + Object.assign(peripheral, { + id: 'mock-id', + address: 'aa:bb:cc:dd:ee:ff', + connect: (callback: (error?: Error) => void) => callback(), + disconnect: vi.fn((callback: () => void) => { + setImmediate(() => { + peripheral.emit('disconnect') + callback() + }) + }), + discoverSomeServicesAndCharacteristics: (_s: string[], _c: string[], callback: (error: Error | null, services: any[], chars: any[]) => void) => { + callback(null, [], [ + { uuid: BLE_WRITE_CHARACTERISTIC_UUID, write: vi.fn() }, + { uuid: BLE_NOTIFY_CHARACTERISTIC_UUID, subscribe: (cb: any) => cb(), on: vi.fn() }, + ]) + }, + }) + return peripheral +} + +function setup() { + const peripheral = createPeripheral() + const logger = { debug: vi.fn(), info: vi.fn(), warn: vi.fn(), error: vi.fn() } + const connection = new BLEConnection({ noble: { peripherals: [peripheral] }, logger: logger as any }) + return { peripheral, logger, connection, internal: connection as any } +} + +describe('bLEConnection disconnects', () => { + it('does not warn for a disconnect it starts', async () => { + const { connection, logger, internal } = setup() + await connection.connect('AA:BB:CC:DD:EE:FF') + await connection.disconnect('AA:BB:CC:DD:EE:FF') + await new Promise(resolve => setImmediate(resolve)) + expect(logger.warn).not.toHaveBeenCalled() + expect(internal.connections.size).toBe(0) + expect(internal.expectedDisconnects.size).toBe(0) + }) + + it('does not warn for disconnectAll', async () => { + const { connection, logger } = setup() + await connection.connect('AA:BB:CC:DD:EE:FF') + await connection.disconnectAll() + expect(logger.warn).not.toHaveBeenCalled() + }) + + it('does not warn when asked to disconnect a device that is not connected', async () => { + const { connection, logger } = setup() + await connection.disconnect('AA:BB:CC:DD:EE:FF') + expect(logger.warn).not.toHaveBeenCalled() + }) + + it('warns and drops the connection when the device disconnects', async () => { + const { connection, logger, peripheral, internal } = setup() + await connection.connect('AA:BB:CC:DD:EE:FF') + peripheral.emit('disconnect') + expect(logger.warn).toHaveBeenCalledWith(expect.stringContaining('Unexpected disconnect')) + expect(internal.connections.size).toBe(0) + expect(internal.characteristics.size).toBe(0) + }) + + it('reconnects after the device disconnects instead of reusing the dead link', async () => { + const { connection, peripheral } = setup() + const connect = vi.spyOn(peripheral, 'connect') + await connection.connect('AA:BB:CC:DD:EE:FF') + peripheral.emit('disconnect') + await connection.connect('AA:BB:CC:DD:EE:FF') + expect(connect).toHaveBeenCalledTimes(2) + }) + + it('does not warn for a device disconnect marked as expected', async () => { + const { connection, logger, peripheral, internal } = setup() + await connection.connect('AA:BB:CC:DD:EE:FF') + connection.markExpectedDisconnect('AA:BB:CC:DD:EE:FF') + peripheral.emit('disconnect') + expect(logger.warn).not.toHaveBeenCalled() + expect(internal.expectedDisconnects.size).toBe(0) + expect(internal.connections.size).toBe(0) + }) +})