Fix BLE notification read disconnect logging

src/ble.ts

@@ -1210,7 +1210,8 @@ export class BLEConnection {
       if (this.connections.get(normalizedMac) !== peripheral) {
         return
       }
-      if (expected) {
+      const established = this.characteristics.has(normalizedMac)
+      if (expected || !established) {
         this.logger.debug(`${mac} disconnected`)
       } else {
         this.logger.warn(`Unexpected disconnect from ${mac}`)
@@ -1315,6 +1316,24 @@ export class BLEConnection {
     }
   }
 
+  private async readNotification(normalizedMac: string, chars: any): Promise<Buffer> {
+    return withTimeout(
+      new Promise<Buffer>((resolve, reject) => {
+        (chars.notify).read((error: Error, data: Buffer) => {
+          if (error) {
+            reject(error)
+          } else {
+            this.markExpectedDisconnect(normalizedMac)
+            this.scheduleDisconnect(normalizedMac)
+            resolve(data)
+          }
+        })
+      }),
+      BLE_COMMAND_TIMEOUT,
+      'Read operation timed out',
+    )
+  }
+
   /**
    * Read data from device
    */
@@ -1338,20 +1357,7 @@ export class BLEConnection {
     this.logger.debug(`Reading from ${mac}`)
 
     try {
-      return await withTimeout(
-        new Promise<Buffer>((resolve, reject) => {
-          (chars!.notify).read((error: Error, data: Buffer) => {
-            if (error) {
-              reject(error)
-            } else {
-              this.scheduleDisconnect(normalizedMac)
-              resolve(data)
-            }
-          })
-        }),
-        BLE_COMMAND_TIMEOUT,
-        'Read operation timed out',
-      )
+      return await this.readNotification(normalizedMac, chars)
     } catch (err: any) {
       // If error is characteristic-related, clear cache and retry once
       if (CHARACTERISTIC_REGEX.test(err?.message || '')) {
@@ -1362,20 +1368,7 @@ export class BLEConnection {
           throw err
         }
         // Retry once
-        return await withTimeout(
-          new Promise<Buffer>((resolve, reject) => {
-            (chars!.notify).read((error: Error, data: Buffer) => {
-              if (error) {
-                reject(error)
-              } else {
-                this.scheduleDisconnect(normalizedMac)
-                resolve(data)
-              }
-            })
-          }),
-          BLE_COMMAND_TIMEOUT,
-          'Read operation timed out',
-        )
+        return await this.readNotification(normalizedMac, chars)
       } else {
         throw err
       }

test/apis/ble-disconnect.test.ts

@@ -1,3 +1,4 @@
+import { Buffer } from 'node:buffer'
 import { EventEmitter } from 'node:events'
 
 import { describe, expect, it, vi } from 'vitest'
@@ -23,8 +24,16 @@ function createPeripheral() {
     }),
     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() },
+        {
+          uuid: BLE_WRITE_CHARACTERISTIC_UUID,
+          write: vi.fn((_data: Buffer, _withoutResponse: boolean, cb: (error?: Error) => void) => cb()),
+        },
+        {
+          uuid: BLE_NOTIFY_CHARACTERISTIC_UUID,
+          subscribe: (cb: any) => cb(),
+          on: vi.fn(),
+          read: (cb: (error: Error | null, data: Buffer) => void) => cb(null, Buffer.from([0x01])),
+        },
       ])
     },
   })
@@ -89,4 +98,78 @@ describe('bLEConnection disconnects', () => {
     expect(internal.expectedDisconnects.size).toBe(0)
     expect(internal.connections.size).toBe(0)
   })
+
+  it('does not warn when the device disconnects after a successful read', async () => {
+    const { connection, logger, peripheral } = setup()
+    await connection.read('AA:BB:CC:DD:EE:FF')
+    peripheral.emit('disconnect')
+    expect(logger.warn).not.toHaveBeenCalled()
+  })
+
+  it('marks the disconnect expected before a successful read resolves', async () => {
+    const { connection, logger, peripheral, internal } = setup()
+    let markedDuringRead = false
+    const discover = peripheral.discoverSomeServicesAndCharacteristics
+    peripheral.discoverSomeServicesAndCharacteristics = (
+      services: string[],
+      characteristics: string[],
+      callback: (error: Error | null, services: any[], characteristics: any[]) => void,
+    ) => {
+      discover(services, characteristics, (error: Error | null, foundServices: any[], foundCharacteristics: any[]) => {
+        const notify = foundCharacteristics.find((c: any) => c.uuid === BLE_NOTIFY_CHARACTERISTIC_UUID)
+        const read = notify.read
+        notify.read = (cb: (error: Error | null, data: Buffer) => void) => {
+          read((readError: Error | null, data: Buffer) => {
+            cb(readError, data)
+            markedDuringRead = internal.expectedDisconnects.has('aa:bb:cc:dd:ee:ff')
+          })
+        }
+        callback(error, foundServices, foundCharacteristics)
+      })
+    }
+
+    await connection.read('AA:BB:CC:DD:EE:FF')
+
+    expect(markedDuringRead).toBe(true)
+    expect(logger.warn).not.toHaveBeenCalled()
+  })
+
+  it('does not warn when the device disconnects before characteristics are discovered', async () => {
+    const { connection, logger, peripheral, internal } = setup()
+    let finishDiscovery: ((error: Error, services: any[], characteristics: any[]) => void) | undefined
+    peripheral.discoverSomeServicesAndCharacteristics = (
+      _services: string[],
+      _characteristics: string[],
+      callback: (error: Error, services: any[], characteristics: any[]) => void,
+    ) => {
+      finishDiscovery = callback
+    }
+
+    const connect = connection.connect('AA:BB:CC:DD:EE:FF').catch((error: Error) => error)
+    await vi.waitFor(() => expect(internal.connections.size).toBe(1))
+    peripheral.emit('disconnect')
+
+    expect(logger.warn).not.toHaveBeenCalled()
+
+    finishDiscovery?.(new Error('Characteristic discovery failed'), [], [])
+    const error = await connect
+    expect(error).toBeInstanceOf(Error)
+  })
+
+  it('warns when the device disconnects after a write-only command', async () => {
+    const { connection, logger, peripheral } = setup()
+    await connection.sendCommand('AA:BB:CC:DD:EE:FF', Buffer.from([0x57, 0x01]), { expectResponse: false, validateResponse: false })
+    peripheral.emit('disconnect')
+    expect(logger.warn).toHaveBeenCalledWith(expect.stringContaining('Unexpected disconnect'))
+  })
+
+  it('warns when the device disconnects before answering a command', async () => {
+    const { connection, logger, peripheral, internal } = setup()
+    const command = connection.sendCommand('AA:BB:CC:DD:EE:FF', Buffer.from([0x57, 0x01])).catch(error => error)
+    await vi.waitFor(() => expect(internal.notificationFutures.size).toBe(1))
+    peripheral.emit('disconnect')
+    expect(logger.warn).toHaveBeenCalledWith(expect.stringContaining('Unexpected disconnect'))
+    const error = await command
+    expect(error.message).toContain('disconnected')
+  })
 })