diff --git a/plejd/CHANGELOG.md b/plejd/CHANGELOG.md index e15b399..25091da 100644 --- a/plejd/CHANGELOG.md +++ b/plejd/CHANGELOG.md @@ -1,5 +1,19 @@ # Changelog hassio-plejd Home Assistant Plejd addon +## [0.7.0](https://github.com/icanos/hassio-plejd/tree/0.7.0) (2021-03-23) + +[Full Changelog](https://github.com/icanos/hassio-plejd/compare/0.6.2...0.7.0) + +**Closed issues:** + +- \[plejd-ble\] Unable to connect. Software caused connection abort [\#173](https://github.com/icanos/hassio-plejd/issues/173) +- All logs seam to be OK but it´s not working anyway [\#171](https://github.com/icanos/hassio-plejd/issues/171) +- Include rooms as lights does not work in 0.6.1 [\#169](https://github.com/icanos/hassio-plejd/issues/169) + +**Merged pull requests:** + +- Feature/restructure ble [\#167](https://github.com/icanos/hassio-plejd/pull/167) ([SweVictor](https://github.com/SweVictor)) + ### [0.6.2](https://github.com/icanos/hassio-plejd/tree/0.6.2) (2021-02-27) [Full Changelog](https://github.com/icanos/hassio-plejd/compare/0.6.1...0.6.2) diff --git a/plejd/DeviceRegistry.js b/plejd/DeviceRegistry.js index 39cb342..c03d969 100644 --- a/plejd/DeviceRegistry.js +++ b/plejd/DeviceRegistry.js @@ -1,3 +1,6 @@ +const Logger = require('./Logger'); + +const logger = Logger.getLogger('device-registry'); class DeviceRegistry { apiSite; cryptoKey = null; @@ -19,20 +22,70 @@ class DeviceRegistry { } addPlejdDevice(device) { - this.plejdDevices[device.id] = device; - this.deviceIdsBySerial[device.serialNumber] = device.id; - if (!this.deviceIdsByRoom[device.roomId]) { - this.deviceIdsByRoom[device.roomId] = []; + const added = { + ...this.plejdDevices[device.id], + ...device, + }; + + this.plejdDevices = { + ...this.plejdDevices, + [added.id]: added, + }; + + this.deviceIdsBySerial[added.serialNumber] = added.id; + + logger.verbose( + `Added/updated device: ${JSON.stringify(added)}. ${ + Object.keys(this.plejdDevices).length + } plejd devices in total.`, + ); + + if (added.roomId) { + const room = this.deviceIdsByRoom[added.roomId] || []; + if (!room.includes(added.roomId)) { + this.deviceIdsByRoom[added.roomId] = [...room, added.roomId]; + } + logger.verbose( + `Added to room #${added.roomId}: ${JSON.stringify(this.deviceIdsByRoom[added.roomId])}`, + ); } - this.deviceIdsByRoom[device.roomId].push(device.id); + + return added; + } + + addRoomDevice(device) { + const added = { + ...this.roomDevices[device.id], + ...device, + }; + this.roomDevices = { + ...this.roomDevices, + [added.id]: added, + }; + + logger.verbose( + `Added/updated room device: ${JSON.stringify(added)}. ${ + Object.keys(this.roomDevices).length + } room devices total.`, + ); + return added; } addScene(scene) { - this.sceneDevices[scene.id] = scene; - } - - setApiSite(siteDetails) { - this.apiSite = siteDetails; + const added = { + ...this.sceneDevices[scene.id], + ...scene, + }; + this.sceneDevices = { + ...this.sceneDevices, + [added.id]: added, + }; + logger.verbose( + `Added/updated scene: ${JSON.stringify(added)}. ${ + Object.keys(this.sceneDevices).length + } scenes in total.`, + ); + return added; } clearPlejdDevices() { @@ -41,10 +94,6 @@ class DeviceRegistry { this.deviceIdsBySerial = {}; } - addRoomDevice(device) { - this.roomDevices[device.id] = device; - } - clearRoomDevices() { this.roomDevices = {}; } @@ -62,7 +111,7 @@ class DeviceRegistry { } getDeviceBySerialNumber(serialNumber) { - return this.plejdDevices[this.deviceIdsBySerial[serialNumber]]; + return this.getDevice(this.deviceIdsBySerial[serialNumber]); } getDeviceName(deviceId) { @@ -76,6 +125,34 @@ class DeviceRegistry { getSceneName(sceneId) { return (this.sceneDevices[sceneId] || {}).name; } + + getState(deviceId) { + const device = this.getDevice(deviceId) || {}; + if (device.dimmable) { + return { + state: device.state, + dim: device.dim, + }; + } + return { + state: device.state, + }; + } + + setApiSite(siteDetails) { + this.apiSite = siteDetails; + } + + setState(deviceId, state, dim) { + const device = this.getDevice(deviceId) || this.addPlejdDevice({ id: deviceId }); + device.state = state; + if (dim && device.dimmable) { + device.dim = dim; + } + if (Logger.shouldLog('silly')) { + logger.silly(`Updated state: ${JSON.stringify(device)}`); + } + } } module.exports = DeviceRegistry; diff --git a/plejd/Dockerfile b/plejd/Dockerfile index 9f558a9..cb32527 100644 --- a/plejd/Dockerfile +++ b/plejd/Dockerfile @@ -7,19 +7,9 @@ ENV LANG C.UTF-8 SHELL ["/bin/bash", "-o", "pipefail", "-c"] # Copy data for add-on +COPY ./*.js /plejd/ COPY ./config.json /plejd/ -COPY ./Configuration.js /plejd/ -COPY ./DeviceRegistry.js /plejd/ -COPY ./Logger.js /plejd/ -COPY ./main.js /plejd/ -COPY ./MqttClient.js /plejd/ COPY ./package.json /plejd/ -COPY ./PlejdAddon.js /plejd/ -COPY ./PlejdApi.js /plejd/ -COPY ./PlejdBLEHandler.js /plejd/ -COPY ./Scene.js /plejd/ -COPY ./SceneManager.js /plejd/ -COPY ./SceneStep.js /plejd/ ARG BUILD_ARCH diff --git a/plejd/MqttClient.js b/plejd/MqttClient.js index 5c89ee9..0369010 100644 --- a/plejd/MqttClient.js +++ b/plejd/MqttClient.js @@ -70,6 +70,11 @@ const getSwitchPayload = (device) => ({ class MqttClient extends EventEmitter { deviceRegistry; + static EVENTS = { + connected: 'connected', + stateChanged: 'stateChanged', + }; + constructor(deviceRegistry) { super(); @@ -94,10 +99,10 @@ class MqttClient extends EventEmitter { this.client.subscribe(startTopics, (err) => { if (err) { - logger.error('Unable to subscribe to status topics'); + logger.error('Unable to subscribe to status topics', err); } - this.emit('connected'); + this.emit(MqttClient.EVENTS.connected); }); this.client.subscribe(getSubscribePath(), (err) => { @@ -113,67 +118,70 @@ class MqttClient extends EventEmitter { }); this.client.on('message', (topic, message) => { - if (startTopics.includes(topic)) { - logger.info('Home Assistant has started. lets do discovery.'); - this.emit('connected'); - } else { - const decodedTopic = decodeTopic(topic); - if (decodedTopic) { - let device = this.deviceRegistry.getDevice(decodedTopic.id); - - const messageString = message.toString(); - const isJsonMessage = messageString.startsWith('{'); - const command = isJsonMessage ? JSON.parse(messageString) : messageString; - - if ( - !isJsonMessage - && messageString === 'ON' - && this.deviceRegistry.getScene(decodedTopic.id) - ) { - // Guess that id that got state command without dim value belongs to Scene, not Device - // This guess could very well be wrong depending on the installation... - logger.warn( - `Device id ${decodedTopic.id} belongs to both scene and device, guessing Scene is what should be set to ON.` - + 'OFF commands still sent to device.', - ); - device = this.deviceRegistry.getScene(decodedTopic.id); - } - - const deviceName = device ? device.name : ''; - - switch (decodedTopic.command) { - case 'set': - logger.verbose( - `Got mqtt SET command for ${decodedTopic.type}, ${deviceName} (${decodedTopic.id}): ${messageString}`, - ); - - if (device) { - this.emit('stateChanged', device, command); - } else { - logger.warn( - `Device for topic ${topic} not found! Can happen if HA calls previously existing devices.`, - ); - } - break; - case 'state': - case 'config': - case 'availability': - logger.verbose( - `Sent mqtt ${decodedTopic.command} command for ${ - decodedTopic.type - }, ${deviceName} (${decodedTopic.id}). ${ - decodedTopic.command === 'availability' ? messageString : '' - }`, - ); - break; - default: - logger.verbose(`Warning: Unknown command ${decodedTopic.command} in decoded topic`); - } + try { + if (startTopics.includes(topic)) { + logger.info('Home Assistant has started. lets do discovery.'); + this.emit(MqttClient.EVENTS.connected); } else { - logger.verbose( - `Warning: Got unrecognized mqtt command on '${topic}': ${message.toString()}`, - ); + const decodedTopic = decodeTopic(topic); + if (decodedTopic) { + let device = this.deviceRegistry.getDevice(decodedTopic.id); + + const messageString = message.toString(); + const isJsonMessage = messageString.startsWith('{'); + const command = isJsonMessage ? JSON.parse(messageString) : messageString; + + if ( + !isJsonMessage + && messageString === 'ON' + && this.deviceRegistry.getScene(decodedTopic.id) + ) { + // Guess that id that got state command without dim value belongs to Scene, not Device + // This guess could very well be wrong depending on the installation... + logger.warn( + `Device id ${decodedTopic.id} belongs to both scene and device, guessing Scene is what should be set to ON. ` + + 'OFF commands still sent to device.', + ); + device = this.deviceRegistry.getScene(decodedTopic.id); + } + const deviceName = device ? device.name : ''; + + switch (decodedTopic.command) { + case 'set': + logger.verbose( + `Got mqtt SET command for ${decodedTopic.type}, ${deviceName} (${decodedTopic.id}): ${messageString}`, + ); + + if (device) { + this.emit(MqttClient.EVENTS.stateChanged, device, command); + } else { + logger.warn( + `Device for topic ${topic} not found! Can happen if HA calls previously existing devices.`, + ); + } + break; + case 'state': + case 'config': + case 'availability': + logger.verbose( + `Sent mqtt ${decodedTopic.command} command for ${ + decodedTopic.type + }, ${deviceName} (${decodedTopic.id}). ${ + decodedTopic.command === 'availability' ? messageString : '' + }`, + ); + break; + default: + logger.verbose(`Warning: Unknown command ${decodedTopic.command} in decoded topic`); + } + } else { + logger.verbose( + `Warning: Got unrecognized mqtt command on '${topic}': ${message.toString()}`, + ); + } } + } catch (err) { + logger.error(`Error processing mqtt message on topic ${topic}`, err); } }); } @@ -182,6 +190,10 @@ class MqttClient extends EventEmitter { this.client.reconnect(); } + cleanup() { + this.client.removeAllListeners(); + } + disconnect(callback) { this.deviceRegistry.allDevices.forEach((device) => { this.client.publish(getAvailabilityTopic(device), 'offline'); diff --git a/plejd/PlejdAddon.js b/plejd/PlejdAddon.js index 9f2a18a..eb39c50 100644 --- a/plejd/PlejdAddon.js +++ b/plejd/PlejdAddon.js @@ -3,8 +3,7 @@ const EventEmitter = require('events'); const Configuration = require('./Configuration'); const Logger = require('./Logger'); const PlejdApi = require('./PlejdApi'); -// const PlejdBLE = require('./PlejdBLE'); -const PlejdBLEHandler = require('./PlejdBLEHandler'); +const PlejdDeviceCommunication = require('./PlejdDeviceCommunication'); const MqttClient = require('./MqttClient'); const SceneManager = require('./SceneManager'); const DeviceRegistry = require('./DeviceRegistry'); @@ -16,8 +15,9 @@ class PlejdAddon extends EventEmitter { config; deviceRegistry; plejdApi; - plejdBLEHandler; + plejdDeviceCommunication; mqttClient; + processCleanupFunc; sceneManager; constructor() { @@ -27,24 +27,35 @@ class PlejdAddon extends EventEmitter { this.deviceRegistry = new DeviceRegistry(); this.plejdApi = new PlejdApi(this.deviceRegistry); - this.plejdBLEHandler = new PlejdBLEHandler(this.deviceRegistry); - this.sceneManager = new SceneManager(this.deviceRegistry, this.plejdBLEHandler); + this.plejdDeviceCommunication = new PlejdDeviceCommunication(this.deviceRegistry); + this.sceneManager = new SceneManager(this.deviceRegistry, this.plejdDeviceCommunication); this.mqttClient = new MqttClient(this.deviceRegistry); } + cleanup() { + this.mqttClient.cleanup(); + this.mqttClient.removeAllListeners(); + this.plejdDeviceCommunication.cleanup(); + this.plejdDeviceCommunication.removeAllListeners(); + } + async init() { logger.info('Main Plejd addon init()...'); await this.plejdApi.init(); this.sceneManager.init(); + this.processCleanupFunc = () => { + this.cleanup(); + this.processCleanupFunc = () => {}; + this.mqttClient.disconnect(() => process.exit(0)); + }; + ['SIGINT', 'SIGHUP', 'SIGTERM'].forEach((signal) => { - process.on(signal, () => { - this.mqttClient.disconnect(() => process.exit(0)); - }); + process.on(signal, this.processCleanupFunc); }); - this.mqttClient.on('connected', () => { + this.mqttClient.on(MqttClient.EVENTS.connected, () => { try { logger.verbose('connected to mqtt.'); this.mqttClient.sendDiscoveryToHomeAssistant(); @@ -54,7 +65,7 @@ class PlejdAddon extends EventEmitter { }); // subscribe to changes from HA - this.mqttClient.on('stateChanged', (device, command) => { + this.mqttClient.on(MqttClient.EVENTS.stateChanged, (device, command) => { try { const deviceId = device.id; @@ -88,47 +99,38 @@ class PlejdAddon extends EventEmitter { } if (state === 'ON') { - this.plejdBLEHandler.turnOn(deviceId, commandObj); + this.plejdDeviceCommunication.turnOn(deviceId, commandObj); } else { - this.plejdBLEHandler.turnOff(deviceId, commandObj); + this.plejdDeviceCommunication.turnOff(deviceId, commandObj); } } catch (err) { - logger.error('Error in MqttClient.stateChanged callback in main.js', err); + logger.error('Error in MqttClient.stateChanged callback', err); } }); this.mqttClient.init(); - this.plejdBLEHandler.on('connected', () => { - logger.info('Bluetooth connected. Plejd BLE up and running!'); - }); - this.plejdBLEHandler.on('reconnecting', () => { - logger.info('Bluetooth reconnecting...'); - }); - // subscribe to changes from Plejd - this.plejdBLEHandler.on('stateChanged', (deviceId, command) => { - try { - this.mqttClient.updateState(deviceId, command); - } catch (err) { - logger.error('Error in PlejdService.stateChanged callback in main.js', err); - } - }); + this.plejdDeviceCommunication.on( + PlejdDeviceCommunication.EVENTS.stateChanged, + (deviceId, command) => { + try { + this.mqttClient.updateState(deviceId, command); + } catch (err) { + logger.error('Error in PlejdService.stateChanged callback', err); + } + }, + ); - this.plejdBLEHandler.on('sceneTriggered', (deviceId, sceneId) => { + this.plejdDeviceCommunication.on(PlejdDeviceCommunication.EVENTS.sceneTriggered, (sceneId) => { try { this.mqttClient.sceneTriggered(sceneId); } catch (err) { - logger.error('Error in PlejdService.sceneTriggered callback in main.js', err); + logger.error('Error in PlejdService.sceneTriggered callback', err); } }); - try { - await this.plejdBLEHandler.init(); - } catch (err) { - logger.error('Failed init() of BLE. Starting reconnect loop.'); - await this.plejdBLEHandler.startReconnectPeriodicallyLoop(); - } + await this.plejdDeviceCommunication.init(); logger.info('Main init done'); } } diff --git a/plejd/PlejdBLEHandler.js b/plejd/PlejdBLEHandler.js index bef0441..9256324 100644 --- a/plejd/PlejdBLEHandler.js +++ b/plejd/PlejdBLEHandler.js @@ -2,10 +2,12 @@ const dbus = require('dbus-next'); const crypto = require('crypto'); const xor = require('buffer-xor'); const EventEmitter = require('events'); -const Logger = require('./Logger'); const Configuration = require('./Configuration'); +const constants = require('./constants'); +const Logger = require('./Logger'); +const { COMMANDS } = constants; const logger = Logger.getLogger('plejd-ble'); // UUIDs @@ -23,6 +25,9 @@ const BLE_CMD_SCENE_TRIG = 0x0021; const BLE_CMD_TIME_UPDATE = 0x001b; const BLE_BROADCAST_DEVICE_ID = 0x01; +const BLE_REQUEST_NO_RESPONSE = 0x0110; +const BLE_REQUEST_RESPONSE = 0x0102; +// const BLE_REQUEST_READ_VALUE = 0x0103; const BLUEZ_SERVICE_NAME = 'org.bluez'; const DBUS_OM_INTERFACE = 'org.freedesktop.DBus.ObjectManager'; @@ -33,9 +38,6 @@ const BLUEZ_DEVICE_ID = 'org.bluez.Device1'; const GATT_SERVICE_ID = 'org.bluez.GattService1'; const GATT_CHRC_ID = 'org.bluez.GattCharacteristic1'; -const MAX_TRANSITION_STEPS_PER_SECOND = 5; // Could be made a setting -const MAX_RETRY_COUNT = 5; // Could be made a setting - const delay = (timeout) => new Promise((resolve) => setTimeout(resolve, timeout)); class PlejBLEHandler extends EventEmitter { @@ -43,24 +45,28 @@ class PlejBLEHandler extends EventEmitter { adapterProperties; config; bleDevices = []; - bleDeviceTransitionTimers = {}; bus = null; connectedDevice = null; consecutiveWriteFails; - deviceRegistry; + consecutiveReconnectAttempts = 0; discoveryTimeout = null; plejdService = null; - plejdDevices = {}; pingRef = null; - writeQueue = []; - writeQueueRef = null; + requestCurrentPlejdTimeRef = null; reconnectInProgress = false; + emergencyReconnectTimeout = null; // Refer to BLE-states.md regarding the internal BLE/bluez state machine of Bluetooth states // These states refer to the state machine of this file static STATES = ['MAIN_INIT', 'GET_ADAPTER_PROXY']; - static EVENTS = ['connected', 'reconnecting', 'sceneTriggered', 'stateChanged']; + static EVENTS = { + connected: 'connected', + reconnecting: 'reconnecting', + commandReceived: 'commandReceived', + writeFailed: 'writeFailed', + writeSuccess: 'writeSuccess', + }; constructor(deviceRegistry) { super(); @@ -79,14 +85,37 @@ class PlejBLEHandler extends EventEmitter { ping: null, }; - this.on('writeFailed', (error) => this.onWriteFailed(error)); - this.on('writeSuccess', () => this.onWriteSuccess()); + this.bus = dbus.systemBus(); + } + + cleanup() { + logger.verbose('cleanup() - Clearing ping interval and clock update timer'); + clearInterval(this.pingRef); + clearTimeout(this.requestCurrentPlejdTimeRef); + + logger.verbose('Removing listeners to write events, bus events and objectManager...'); + + this.removeAllListeners(PlejBLEHandler.EVENTS.writeFailed); + this.removeAllListeners(PlejBLEHandler.EVENTS.writeSuccess); + + if (this.bus) { + this.bus.removeAllListeners('error'); + this.bus.removeAllListeners('connect'); + } + if (this.characteristics.lastDataProperties) { + this.characteristics.lastDataProperties.removeAllListeners('PropertiesChanged'); + } + if (this.objectManager) { + this.objectManager.removeAllListeners('InterfacesAdded'); + } } async init() { logger.info('init()'); - this.bus = dbus.systemBus(); + this.on(PlejBLEHandler.EVENTS.writeFailed, (error) => this._onWriteFailed(error)); + this.on(PlejBLEHandler.EVENTS.writeSuccess, () => this._onWriteSuccess()); + this.bus.on('error', (err) => { // Uncaught error events will show UnhandledPromiseRejection logs logger.verbose(`dbus-next error event: ${err.message}`); @@ -123,6 +152,32 @@ class PlejBLEHandler extends EventEmitter { logger.info('BLE init done, waiting for devices.'); } + async sendCommand(command, deviceId, data) { + let payload; + let brightnessVal; + switch (command) { + case COMMANDS.TURN_ON: + payload = this._createHexPayload(deviceId, BLE_CMD_STATE_CHANGE, '01'); + break; + case COMMANDS.TURN_OFF: + payload = this._createHexPayload(deviceId, BLE_CMD_STATE_CHANGE, '00'); + break; + case COMMANDS.DIM: + // eslint-disable-next-line no-bitwise + brightnessVal = (data << 8) | data; + payload = this._createHexPayload( + deviceId, + BLE_CMD_DIM2_CHANGE, + `01${brightnessVal.toString(16).padStart(4, '0')}`, + ); + break; + default: + logger.error(`Unknown command ${command}`); + throw new Error(`Unknown command ${command}`); + } + await this._write(payload); + } + async _initDiscoveredPlejdDevice(path) { logger.debug(`initDiscoveredPlejdDevice(). Got ${path} device`); @@ -143,9 +198,14 @@ class PlejBLEHandler extends EventEmitter { fixedPlejdPath = fixedPlejdPath.replace(/_/g, ''); plejd.device = this.deviceRegistry.getDeviceBySerialNumber(fixedPlejdPath); - logger.debug(`Discovered ${plejd.path} with rssi ${plejd.rssi}, name ${plejd.device.name}`); - // Todo: Connect should probably be done here - this.bleDevices.push(plejd); + if (plejd.device) { + logger.debug( + `Discovered ${plejd.path} with rssi ${plejd.rssi} dBm, name ${plejd.device.name}`, + ); + this.bleDevices.push(plejd); + } else { + logger.warn(`Device registry does not contain device with serial ${fixedPlejdPath}`); + } } catch (err) { logger.error(`Failed inspecting ${path}. `, err); } @@ -217,7 +277,6 @@ class PlejBLEHandler extends EventEmitter { } logger.info(`BLE Connected to ${this.connectedDevice.name}`); - this.emit('connected'); // Connected and authenticated, request current time and start ping if (this.config.updatePlejdClock) { @@ -225,8 +284,7 @@ class PlejBLEHandler extends EventEmitter { } else { logger.info('Plejd clock updates disabled in configuration.'); } - this.startPing(); - this.startWriteQueue(); + this._startPing(); // After we've authenticated, we need to hook up the event listener // for changes to lastData. @@ -234,8 +292,13 @@ class PlejBLEHandler extends EventEmitter { iface, properties, // invalidated (third param), - ) => this.onLastDataUpdated(iface, properties)); + ) => this._onLastDataUpdated(iface, properties)); this.characteristics.lastData.StartNotify(); + this.consecutiveReconnectAttempts = 0; + this.emit(PlejBLEHandler.EVENTS.connected); + + clearTimeout(this.emergencyReconnectTimeout); + this.emergencyReconnectTimeout = null; } catch (err) { // This method is run on a timer, so errors can't e re-thrown. // Start reconnect loop if errors occur here @@ -246,6 +309,7 @@ class PlejBLEHandler extends EventEmitter { async _getInterface() { const bluez = await this.bus.getProxyObject(BLUEZ_SERVICE_NAME, '/'); + this.objectManager = await bluez.getInterface(DBUS_OM_INTERFACE); // We need to find the ble interface which implements the Adapter1 interface @@ -285,18 +349,21 @@ class PlejBLEHandler extends EventEmitter { } async _powerCycleAdapter() { + logger.verbose('Power cycling BLE adapter'); await this._powerOffAdapter(); await this._powerOnAdapter(); } async _powerOnAdapter() { + logger.verbose('Powering on BLE adapter and waiting 5 seconds'); await this.adapterProperties.Set(BLUEZ_ADAPTER_ID, 'Powered', new dbus.Variant('b', 1)); - await delay(1000); + await delay(5000); } async _powerOffAdapter() { + logger.verbose('Powering off BLE adapter and waiting 30 seconds'); await this.adapterProperties.Set(BLUEZ_ADAPTER_ID, 'Powered', new dbus.Variant('b', 0)); - await delay(1000); + await delay(30000); } async _cleanExistingConnections(managedObjects) { @@ -339,7 +406,7 @@ class PlejBLEHandler extends EventEmitter { async _startGetPlejdDevice() { logger.verbose('Setting up interfacesAdded subscription and discovery filter'); - this.objectManager.on('InterfacesAdded', (path, interfaces) => this.onInterfacesAdded(path, interfaces)); + this.objectManager.on('InterfacesAdded', (path, interfaces) => this._onInterfacesAdded(path, interfaces)); this.adapter.SetDiscoveryFilter({ UUIDs: new dbus.Variant('as', [PLEJD_SERVICE]), @@ -372,15 +439,14 @@ class PlejBLEHandler extends EventEmitter { ); } - async onInterfacesAdded(path, interfaces) { + async _onInterfacesAdded(path, interfaces) { logger.silly(`Interface added ${path}, inspecting...`); - // const [adapter, dev, service, characteristic] = path.split('/').slice(3); const interfaceKeys = Object.keys(interfaces); if (interfaceKeys.indexOf(BLUEZ_DEVICE_ID) > -1) { if (interfaces[BLUEZ_DEVICE_ID].UUIDs.value.indexOf(PLEJD_SERVICE) > -1) { logger.debug(`Found Plejd service on ${path}`); - + this.objectManager.removeAllListeners('InterfacesAdded'); await this._initDiscoveredPlejdDevice(path); } else { logger.error('Uh oh, no Plejd device!'); @@ -390,153 +456,7 @@ class PlejBLEHandler extends EventEmitter { } } - turnOn(deviceId, command) { - const deviceName = this.deviceRegistry.getDeviceName(deviceId); - logger.info( - `Plejd got turn on command for ${deviceName} (${deviceId}), brightness ${command.brightness}${ - command.transition ? `, transition: ${command.transition}` : '' - }`, - ); - this._transitionTo(deviceId, command.brightness, command.transition, deviceName); - } - - turnOff(deviceId, command) { - const deviceName = this.deviceRegistry.getDeviceName(deviceId); - logger.info( - `Plejd got turn off command for ${deviceName} (${deviceId})${ - command.transition ? `, transition: ${command.transition}` : '' - }`, - ); - this._transitionTo(deviceId, 0, command.transition, deviceName); - } - - _clearDeviceTransitionTimer(deviceId) { - if (this.bleDeviceTransitionTimers[deviceId]) { - clearInterval(this.bleDeviceTransitionTimers[deviceId]); - } - } - - _transitionTo(deviceId, targetBrightness, transition, deviceName) { - const initialBrightness = this.plejdDevices[deviceId] - ? this.plejdDevices[deviceId].state && this.plejdDevices[deviceId].dim - : null; - this._clearDeviceTransitionTimer(deviceId); - - const isDimmable = this.deviceRegistry.getDevice(deviceId).dimmable; - - if ( - transition > 1 - && isDimmable - && (initialBrightness || initialBrightness === 0) - && (targetBrightness || targetBrightness === 0) - && targetBrightness !== initialBrightness - ) { - // Transition time set, known initial and target brightness - // Calculate transition interval time based on delta brightness and max steps per second - // During transition, measure actual transition interval time and adjust stepping continously - // If transition <= 1 second, Plejd will do a better job - // than we can in transitioning so transitioning will be skipped - - const deltaBrightness = targetBrightness - initialBrightness; - const transitionSteps = Math.min( - Math.abs(deltaBrightness), - MAX_TRANSITION_STEPS_PER_SECOND * transition, - ); - const transitionInterval = (transition * 1000) / transitionSteps; - - logger.debug( - `transitioning from ${initialBrightness} to ${targetBrightness} ${ - transition ? `in ${transition} seconds` : '' - }.`, - ); - logger.verbose( - `delta brightness ${deltaBrightness}, steps ${transitionSteps}, interval ${transitionInterval} ms`, - ); - - const dtStart = new Date(); - - let nSteps = 0; - - this.bleDeviceTransitionTimers[deviceId] = setInterval(() => { - const tElapsedMs = new Date().getTime() - dtStart.getTime(); - let tElapsed = tElapsedMs / 1000; - - if (tElapsed > transition || tElapsed < 0) { - tElapsed = transition; - } - - let newBrightness = Math.round( - initialBrightness + (deltaBrightness * tElapsed) / transition, - ); - - if (tElapsed === transition) { - nSteps++; - this._clearDeviceTransitionTimer(deviceId); - newBrightness = targetBrightness; - logger.debug( - `Queueing finalize ${deviceName} (${deviceId}) transition from ${initialBrightness} to ${targetBrightness} in ${tElapsedMs}ms. Done steps ${nSteps}. Average interval ${ - tElapsedMs / (nSteps || 1) - } ms.`, - ); - this._setBrightness(deviceId, newBrightness, true, deviceName); - } else { - nSteps++; - logger.verbose( - `Queueing dim transition for ${deviceName} (${deviceId}) to ${newBrightness}. Total queue length ${this.writeQueue.length}`, - ); - this._setBrightness(deviceId, newBrightness, false, deviceName); - } - }, transitionInterval); - } else { - if (transition && isDimmable) { - logger.debug( - `Could not transition light change. Either initial value is unknown or change is too small. Requested from ${initialBrightness} to ${targetBrightness}`, - ); - } - this._setBrightness(deviceId, targetBrightness, true, deviceName); - } - } - - _setBrightness(deviceId, brightness, shouldRetry, deviceName) { - let payload = null; - let log = ''; - - if (!brightness && brightness !== 0) { - logger.debug( - `Queueing turn on ${deviceName} (${deviceId}). No brightness specified, setting DIM to previous.`, - ); - payload = Buffer.from(`${deviceId.toString(16).padStart(2, '0')}0110009701`, 'hex'); - log = 'ON'; - } else if (brightness <= 0) { - logger.debug(`Queueing turn off ${deviceId}`); - payload = Buffer.from(`${deviceId.toString(16).padStart(2, '0')}0110009700`, 'hex'); - log = 'OFF'; - } else { - if (brightness > 255) { - // eslint-disable-next-line no-param-reassign - brightness = 255; - } - - logger.debug(`Queueing ${deviceId} set brightness to ${brightness}`); - // eslint-disable-next-line no-bitwise - const brightnessVal = (brightness << 8) | brightness; - payload = Buffer.from( - `${deviceId.toString(16).padStart(2, '0')}0110009801${brightnessVal - .toString(16) - .padStart(4, '0')}`, - 'hex', - ); - log = `DIM ${brightness}`; - } - this.writeQueue.unshift({ - deviceId, - log, - shouldRetry, - payload, - }); - } - - async authenticate() { + async _authenticate() { logger.info('authenticate()'); try { @@ -554,21 +474,62 @@ class PlejBLEHandler extends EventEmitter { } async startReconnectPeriodicallyLoop() { - logger.verbose('startReconnectPeriodicallyLoop'); - if (this.reconnectInProgress) { + logger.info('Starting reconnect loop...'); + clearTimeout(this.emergencyReconnectTimeout); + this.emergencyReconnectTimeout = null; + await this._startReconnectPeriodicallyLoopInternal(); + } + + async _startReconnectPeriodicallyLoopInternal() { + logger.verbose('Starting internal reconnect loop...'); + + if (this.reconnectInProgress && !this.emergencyReconnectTimeout) { logger.debug('Reconnect already in progress. Skipping this call.'); return; } - clearInterval(this.pingRef); - clearTimeout(this.writeQueueRef); + if (this.emergencyReconnectTimeout) { + logger.warn( + 'Restarting reconnect loop due to emergency reconnect timer elapsed. This should very rarely happen!', + ); + } + this.reconnectInProgress = true; /* eslint-disable no-await-in-loop */ // eslint-disable-next-line no-constant-condition while (true) { try { + logger.verbose('Reconnect: Clean up, emit reconnect event, wait 5s and the re-init...'); + this.cleanup(); + + this.consecutiveReconnectAttempts++; + + if (this.consecutiveReconnectAttempts % 100 === 0) { + logger.error('Failed reconnecting 100 times. Creating a new dbus instance...'); + this.bus = dbus.systemBus(); + } + + if (this.consecutiveReconnectAttempts % 10 === 0) { + logger.warn( + `Tried reconnecting ${this.consecutiveReconnectAttempts} times. Will power cycle the BLE adapter now...`, + ); + await this._powerCycleAdapter(); + } else { + logger.verbose( + `Reconnect attempt ${this.consecutiveReconnectAttempts} in a row. Will power cycle every 10th time.`, + ); + } + + this.emit(PlejBLEHandler.EVENTS.reconnecting); + + // Emergency 2 minute timer if reconnect silently fails somewhere + clearTimeout(this.emergencyReconnectTimeout); + this.emergencyReconnectTimeout = setTimeout( + () => this._startReconnectPeriodicallyLoopInternal(), + 120 * 1000, + ); + await delay(5000); - this.emit('reconnecting'); logger.info('Reconnecting BLE...'); await this.init(); break; @@ -581,45 +542,46 @@ class PlejBLEHandler extends EventEmitter { this.reconnectInProgress = false; } - async write(data) { - if (!data || !this.plejdService || !this.characteristics.data) { + async _write(payload) { + if (!payload || !this.plejdService || !this.characteristics.data) { logger.debug('data, plejdService or characteristics not available. Cannot write()'); - return false; + throw new Error('data, plejdService or characteristics not available. Cannot write()'); } try { - logger.verbose(`Sending ${data.length} byte(s) of data to Plejd. ${data.toString('hex')}`); - const encryptedData = this._encryptDecrypt(this.cryptoKey, this.plejdService.addr, data); + logger.verbose( + `Sending ${payload.length} byte(s) of data to Plejd. ${payload.toString('hex')}`, + ); + const encryptedData = this._encryptDecrypt(this.cryptoKey, this.plejdService.addr, payload); await this.characteristics.data.WriteValue([...encryptedData], {}); - await this.onWriteSuccess(); - return true; + await this._onWriteSuccess(); } catch (err) { + await this._onWriteFailed(err); if (err.message === 'In Progress') { logger.debug("Write failed due to 'In progress' ", err); - } else { - logger.debug('Write failed ', err); + throw new Error("Write failed due to 'In progress'"); } - await this.onWriteFailed(err); - return false; + logger.debug('Write failed ', err); + throw new Error(`Write failed due to ${err.message}`); } } - startPing() { + _startPing() { logger.info('startPing()'); clearInterval(this.pingRef); this.pingRef = setInterval(async () => { logger.silly('ping'); - await this.ping(); + await this._ping(); }, 3000); } // eslint-disable-next-line class-methods-use-this - onWriteSuccess() { + _onWriteSuccess() { this.consecutiveWriteFails = 0; } - async onWriteFailed(error) { + async _onWriteFailed(error) { this.consecutiveWriteFails++; logger.debug(`onWriteFailed #${this.consecutiveWriteFails} in a row.`, error); logger.verbose(`Error message: ${error.message}`); @@ -635,7 +597,6 @@ class PlejBLEHandler extends EventEmitter { logger.error("'Method \"WriteValue\" doesn't exist'. Plejd device is probably disconnected."); errorIndicatesDisconnected = true; } - logger.verbose(`Made it ${errorIndicatesDisconnected} || ${this.consecutiveWriteFails >= 5}`); if (errorIndicatesDisconnected || this.consecutiveWriteFails >= 5) { logger.warn( @@ -645,7 +606,7 @@ class PlejBLEHandler extends EventEmitter { } } - async ping() { + async _ping() { logger.silly('ping()'); const ping = crypto.randomBytes(1); @@ -656,88 +617,45 @@ class PlejBLEHandler extends EventEmitter { pong = await this.characteristics.ping.ReadValue({}); } catch (err) { logger.verbose(`Error pinging Plejd, calling onWriteFailed... ${err.message}`); - await this.onWriteFailed(err); + await this._onWriteFailed(err); return; } // eslint-disable-next-line no-bitwise if (((ping[0] + 1) & 0xff) !== pong[0]) { logger.verbose('Plejd ping failed, pong contains wrong data. Calling onWriteFailed...'); - await this.onWriteFailed(new Error(`plejd ping failed ${ping[0]} - ${pong[0]}`)); + await this._onWriteFailed(new Error(`plejd ping failed ${ping[0]} - ${pong[0]}`)); return; } logger.silly(`pong: ${pong[0]}`); - await this.onWriteSuccess(); + await this._onWriteSuccess(); } async _requestCurrentPlejdTime() { - logger.info('Requesting current Plejd clock time...'); + if (!this.connectedDevice) { + logger.warn('Cannot request current Plejd time, not connected.'); + return; + } + logger.info('Requesting current Plejd time...'); - // Eg: 0b0102001b: 0b: id, 0102: read, 001b: time - const payload = Buffer.from( - `${this.connectedDevice.id.toString(16).padStart(2, '0')}0102${BLE_CMD_TIME_UPDATE.toString( - 16, - ).padStart(4, '0')}`, - 'hex', + const payload = this._createHexPayload( + this.connectedDevice.id, + BLE_CMD_TIME_UPDATE, + '', + BLE_REQUEST_RESPONSE, ); - this.writeQueue.unshift({ - deviceId: this.connectedDevice.id, - log: 'RequestTime', - shouldRetry: true, - payload, - }); - setTimeout(() => this._requestCurrentPlejdTime(), 1000 * 3600); // Once per hour - } - - startWriteQueue() { - logger.info('startWriteQueue()'); - clearTimeout(this.writeQueueRef); - - this.writeQueueRef = setTimeout(() => this.runWriteQueue(), this.config.writeQueueWaitTime); - } - - async runWriteQueue() { try { - while (this.writeQueue.length > 0) { - const queueItem = this.writeQueue.pop(); - const deviceName = this.deviceRegistry.getDeviceName(queueItem.deviceId); - logger.debug( - `Write queue: Processing ${deviceName} (${queueItem.deviceId}). Command ${queueItem.log}. Total queue length: ${this.writeQueue.length}`, - ); - - if (this.writeQueue.some((item) => item.deviceId === queueItem.deviceId)) { - logger.verbose( - `Skipping ${deviceName} (${queueItem.deviceId}) ` - + `${queueItem.log} due to more recent command in queue.`, - ); - // Skip commands if new ones exist for the same deviceId - // still process all messages in order - } else { - // eslint-disable-next-line no-await-in-loop - const success = await this.write(queueItem.payload); - if (!success && queueItem.shouldRetry) { - queueItem.retryCount = (queueItem.retryCount || 0) + 1; - logger.debug(`Will retry command, count failed so far ${queueItem.retryCount}`); - if (queueItem.retryCount <= MAX_RETRY_COUNT) { - this.writeQueue.push(queueItem); // Add back to top of queue to be processed next; - } else { - logger.error( - `Write queue: Exceeed max retry count (${MAX_RETRY_COUNT}) for ${deviceName} (${queueItem.deviceId}). Command ${queueItem.log} failed.`, - ); - break; - } - if (queueItem.retryCount > 1) { - break; // First retry directly, consecutive after writeQueueWaitTime ms - } - } - } - } - } catch (e) { - logger.error('Error in writeQueue loop, values probably not written to Plejd', e); + this._write(payload); + } catch (error) { + logger.warn('Failed requesting time update from Plejd'); } - this.writeQueueRef = setTimeout(() => this.runWriteQueue(), this.config.writeQueueWaitTime); + clearTimeout(this.requestCurrentPlejdTimeRef); + this.requestCurrentPlejdTimeRef = setTimeout( + () => this._requestCurrentPlejdTime(), + 1000 * 3600, + ); // Once per hour } async _processPlejdService(path, characteristics) { @@ -845,13 +763,13 @@ class PlejBLEHandler extends EventEmitter { logger.info('Connected device is a Plejd device with the right characteristics.'); this.connectedDevice = device.device; - await this.authenticate(); + await this._authenticate(); return this.connectedDevice; } // eslint-disable-next-line no-unused-vars - async onLastDataUpdated(iface, properties) { + async _onLastDataUpdated(iface, properties) { if (iface !== GATT_CHRC_ID) { return; } @@ -866,8 +784,8 @@ class PlejBLEHandler extends EventEmitter { return; } - const data = value.value; - const decoded = this._encryptDecrypt(this.cryptoKey, this.plejdService.addr, data); + const encryptedData = value.value; + const decoded = this._encryptDecrypt(this.cryptoKey, this.plejdService.addr, encryptedData); if (decoded.length < 5) { if (Logger.shouldLog('debug')) { @@ -901,29 +819,18 @@ class PlejBLEHandler extends EventEmitter { ); } + let command; + let data = {}; if (cmd === BLE_CMD_DIM_CHANGE || cmd === BLE_CMD_DIM2_CHANGE) { logger.debug(`${deviceName} (${deviceId}) got state+dim update. S: ${state}, D: ${dim}`); - this.emit('stateChanged', deviceId, { - state, - brightness: dim, - }); - - this.plejdDevices[deviceId] = { - state, - dim, - }; - logger.silly(`All states: ${JSON.stringify(this.plejdDevices, null, 2)}`); + command = COMMANDS.DIM; + data = { state, dim }; + this.emit(PlejBLEHandler.EVENTS.commandReceived, deviceId, command, data); } else if (cmd === BLE_CMD_STATE_CHANGE) { logger.debug(`${deviceName} (${deviceId}) got state update. S: ${state}`); - this.emit('stateChanged', deviceId, { - state, - }); - this.plejdDevices[deviceId] = { - state, - dim: 0, - }; - logger.silly(`All states: ${JSON.stringify(this.plejdDevices, null, 2)}`); + command = state ? COMMANDS.TURN_ON : COMMANDS.TURN_OFF; + this.emit(PlejBLEHandler.EVENTS.commandReceived, deviceId, command, data); } else if (cmd === BLE_CMD_SCENE_TRIG) { const sceneId = state; const sceneName = this.deviceRegistry.getSceneName(sceneId); @@ -932,11 +839,13 @@ class PlejBLEHandler extends EventEmitter { `${sceneName} (${sceneId}) scene triggered (device id ${deviceId}). Name can be misleading if there is a device with the same numeric id.`, ); - this.emit('sceneTriggered', deviceId, sceneId); + command = COMMANDS.TRIGGER_SCENE; + data = { sceneId }; + this.emit(PlejBLEHandler.EVENTS.commandReceived, deviceId, command, data); } else if (cmd === BLE_CMD_TIME_UPDATE) { const now = new Date(); // Guess Plejd timezone based on HA time zone - const offsetSecondsGuess = now.getTimezoneOffset() * 60; + const offsetSecondsGuess = now.getTimezoneOffset() * 60 + 250; // Todo: 4 min off // Plejd reports local unix timestamp adjust to local time zone const plejdTimestampUTC = (decoded.readInt32LE(5) + offsetSecondsGuess) * 1000; @@ -955,20 +864,22 @@ class PlejBLEHandler extends EventEmitter { `Plejd clock time off by more than 1 minute. Reported time: ${plejdTime.toString()}, diff ${diffSeconds} seconds. Time will be set hourly.`, ); if (this.connectedDevice && deviceId === this.connectedDevice.id) { + // Requested time sync by us const newLocalTimestamp = now.getTime() / 1000 - offsetSecondsGuess; logger.info(`Setting time to ${now.toString()}`); - const payload = Buffer.alloc(10); - // E.g: 00 0110 001b 38df2360 00 - // 00: set?, 0110: don't respond, 001b: time command, 38df236000: the time - payload.write('000110001b', 0, 'hex'); - payload.writeInt32LE(Math.trunc(newLocalTimestamp), 5); - payload.write('00', 9, 'hex'); - this.writeQueue.unshift({ - deviceId: this.connectedDevice.id, - log: 'SetTime', - shouldRetry: true, - payload, - }); + const payload = this._createPayload( + this.connectedDevice.id, + BLE_CMD_TIME_UPDATE, + 10, + (pl) => pl.writeInt32LE(Math.trunc(newLocalTimestamp), 5), + ); + try { + this.write(payload); + } catch (err) { + logger.error( + 'Failed writing new time to Plejd. Will try again in one hour or at restart.', + ); + } } } else if (deviceId !== BLE_BROADCAST_DEVICE_ID) { logger.info('Got time response. Plejd clock time in sync with Home Assistant time'); @@ -983,6 +894,37 @@ class PlejBLEHandler extends EventEmitter { } } + _createHexPayload( + deviceId, + command, + hexDataString, + requestResponseCommand = BLE_REQUEST_NO_RESPONSE, + ) { + return this._createPayload( + deviceId, + command, + 5 + Math.ceil(hexDataString.length / 2), + (payload) => payload.write(hexDataString, 5, 'hex'), + requestResponseCommand, + ); + } + + // eslint-disable-next-line class-methods-use-this + _createPayload( + deviceId, + command, + bufferLength, + payloadBufferAddDataFunc, + requestResponseCommand = BLE_REQUEST_NO_RESPONSE, + ) { + const payload = Buffer.alloc(bufferLength); + payload.writeUInt8(deviceId); + payload.writeUInt16BE(requestResponseCommand, 1); + payload.writeUInt16BE(command, 3); + payloadBufferAddDataFunc(payload); + return payload; + } + // eslint-disable-next-line class-methods-use-this _createChallengeResponse(key, challenge) { const intermediate = crypto.createHash('sha256').update(xor(key, challenge)).digest(); diff --git a/plejd/PlejdDeviceCommunication.js b/plejd/PlejdDeviceCommunication.js new file mode 100644 index 0000000..e64c8cd --- /dev/null +++ b/plejd/PlejdDeviceCommunication.js @@ -0,0 +1,304 @@ +const EventEmitter = require('events'); +const Configuration = require('./Configuration'); +const constants = require('./constants'); +const Logger = require('./Logger'); +const PlejBLEHandler = require('./PlejdBLEHandler'); + +const { COMMANDS } = constants; +const logger = Logger.getLogger('device-comm'); + +const MAX_TRANSITION_STEPS_PER_SECOND = 5; // Could be made a setting +const MAX_RETRY_COUNT = 10; // Could be made a setting + +class PlejdDeviceCommunication extends EventEmitter { + bleConnected; + bleDeviceTransitionTimers = {}; + plejdBleHandler; + config; + deviceRegistry; + writeQueue = []; + writeQueueRef = null; + + static EVENTS = { + sceneTriggered: 'sceneTriggered', + stateChanged: 'stateChanged', + }; + + constructor(deviceRegistry) { + super(); + logger.info('Starting Plejd communication handler.'); + + this.plejdBleHandler = new PlejBLEHandler(deviceRegistry); + this.config = Configuration.getOptions(); + this.deviceRegistry = deviceRegistry; + } + + cleanup() { + Object.values(this.bleDeviceTransitionTimers).forEach((t) => clearTimeout(t)); + this.plejdBleHandler.cleanup(); + this.plejdBleHandler.removeAllListeners(PlejBLEHandler.EVENTS.commandReceived); + this.plejdBleHandler.removeAllListeners(PlejBLEHandler.EVENTS.connected); + this.plejdBleHandler.removeAllListeners(PlejBLEHandler.EVENTS.reconnecting); + } + + async init() { + try { + this.cleanup(); + this.bleConnected = false; + // eslint-disable-next-line max-len + this.plejdBleHandler.on(PlejBLEHandler.EVENTS.commandReceived, (deviceId, command, data) => this._bleCommandReceived(deviceId, command, data)); + + this.plejdBleHandler.on(PlejBLEHandler.EVENTS.connected, () => { + logger.info('Bluetooth connected. Plejd BLE up and running!'); + logger.verbose(`Starting writeQueue loop. Write queue length: ${this.writeQueue.length}`); + this.bleConnected = true; + this._startWriteQueue(); + }); + this.plejdBleHandler.on(PlejBLEHandler.EVENTS.reconnecting, () => { + logger.info('Bluetooth reconnecting...'); + logger.verbose( + `Stopping writeQueue loop until connection is established. Write queue length: ${this.writeQueue.length}`, + ); + this.bleConnected = false; + clearTimeout(this.writeQueueRef); + }); + + await this.plejdBleHandler.init(); + } catch (err) { + logger.error('Failed init() of BLE. Starting reconnect loop.'); + await this.plejdBleHandler.startReconnectPeriodicallyLoop(); + } + } + + turnOn(deviceId, command) { + const deviceName = this.deviceRegistry.getDeviceName(deviceId); + logger.info( + `Plejd got turn on command for ${deviceName} (${deviceId}), brightness ${command.brightness}${ + command.transition ? `, transition: ${command.transition}` : '' + }`, + ); + this._transitionTo(deviceId, command.brightness, command.transition, deviceName); + } + + turnOff(deviceId, command) { + const deviceName = this.deviceRegistry.getDeviceName(deviceId); + logger.info( + `Plejd got turn off command for ${deviceName} (${deviceId})${ + command.transition ? `, transition: ${command.transition}` : '' + }`, + ); + this._transitionTo(deviceId, 0, command.transition, deviceName); + } + + _bleCommandReceived(deviceId, command, data) { + try { + if (command === COMMANDS.DIM) { + this.deviceRegistry.setState(deviceId, data.state, data.dim); + this.emit(PlejdDeviceCommunication.EVENTS.stateChanged, deviceId, { + state: data.state, + brightness: data.dim, + }); + } else if (command === COMMANDS.TURN_ON) { + this.deviceRegistry.setState(deviceId, 1); + this.emit(PlejdDeviceCommunication.EVENTS.stateChanged, deviceId, { + state: 1, + }); + } else if (command === COMMANDS.TURN_OFF) { + this.deviceRegistry.setState(deviceId, 0); + this.emit(PlejdDeviceCommunication.EVENTS.stateChanged, deviceId, { + state: 0, + }); + } else if (command === COMMANDS.TRIGGER_SCENE) { + this.emit(PlejdDeviceCommunication.EVENTS.sceneTriggered, data.sceneId); + } else { + logger.warn(`Unknown ble command ${command}`); + } + } catch (error) { + logger.error('Error processing ble command', error); + } + } + + _clearDeviceTransitionTimer(deviceId) { + if (this.bleDeviceTransitionTimers[deviceId]) { + clearInterval(this.bleDeviceTransitionTimers[deviceId]); + } + } + + _transitionTo(deviceId, targetBrightness, transition, deviceName) { + const device = this.deviceRegistry.getDevice(deviceId); + const initialBrightness = device ? device.state && device.dim : null; + this._clearDeviceTransitionTimer(deviceId); + + const isDimmable = this.deviceRegistry.getDevice(deviceId).dimmable; + + if ( + transition > 1 + && isDimmable + && (initialBrightness || initialBrightness === 0) + && (targetBrightness || targetBrightness === 0) + && targetBrightness !== initialBrightness + ) { + // Transition time set, known initial and target brightness + // Calculate transition interval time based on delta brightness and max steps per second + // During transition, measure actual transition interval time and adjust stepping continously + // If transition <= 1 second, Plejd will do a better job + // than we can in transitioning so transitioning will be skipped + + const deltaBrightness = targetBrightness - initialBrightness; + const transitionSteps = Math.min( + Math.abs(deltaBrightness), + MAX_TRANSITION_STEPS_PER_SECOND * transition, + ); + const transitionInterval = (transition * 1000) / transitionSteps; + + logger.debug( + `transitioning from ${initialBrightness} to ${targetBrightness} ${ + transition ? `in ${transition} seconds` : '' + }.`, + ); + logger.verbose( + `delta brightness ${deltaBrightness}, steps ${transitionSteps}, interval ${transitionInterval} ms`, + ); + + const dtStart = new Date(); + + let nSteps = 0; + + this.bleDeviceTransitionTimers[deviceId] = setInterval(() => { + const tElapsedMs = new Date().getTime() - dtStart.getTime(); + let tElapsed = tElapsedMs / 1000; + + if (tElapsed > transition || tElapsed < 0) { + tElapsed = transition; + } + + let newBrightness = Math.round( + initialBrightness + (deltaBrightness * tElapsed) / transition, + ); + + if (tElapsed === transition) { + nSteps++; + this._clearDeviceTransitionTimer(deviceId); + newBrightness = targetBrightness; + logger.debug( + `Queueing finalize ${deviceName} (${deviceId}) transition from ${initialBrightness} to ${targetBrightness} in ${tElapsedMs}ms. Done steps ${nSteps}. Average interval ${ + tElapsedMs / (nSteps || 1) + } ms.`, + ); + this._setBrightness(deviceId, newBrightness, true, deviceName); + } else { + nSteps++; + logger.verbose( + `Queueing dim transition for ${deviceName} (${deviceId}) to ${newBrightness}. Total queue length ${this.writeQueue.length}`, + ); + this._setBrightness(deviceId, newBrightness, false, deviceName); + } + }, transitionInterval); + } else { + if (transition && isDimmable) { + logger.debug( + `Could not transition light change. Either initial value is unknown or change is too small. Requested from ${initialBrightness} to ${targetBrightness}`, + ); + } + this._setBrightness(deviceId, targetBrightness, true, deviceName); + } + } + + _setBrightness(deviceId, brightness, shouldRetry, deviceName) { + if (!brightness && brightness !== 0) { + logger.debug( + `Queueing turn on ${deviceName} (${deviceId}). No brightness specified, setting DIM to previous.`, + ); + this._appendCommandToWriteQueue(deviceId, COMMANDS.TURN_ON, null, shouldRetry); + } else if (brightness <= 0) { + logger.debug(`Queueing turn off ${deviceId}`); + this._appendCommandToWriteQueue(deviceId, COMMANDS.TURN_OFF, null, shouldRetry); + } else { + if (brightness > 255) { + // eslint-disable-next-line no-param-reassign + brightness = 255; + } + + logger.debug(`Queueing ${deviceId} set brightness to ${brightness}`); + // eslint-disable-next-line no-bitwise + this._appendCommandToWriteQueue(deviceId, COMMANDS.DIM, brightness, shouldRetry); + } + } + + _appendCommandToWriteQueue(deviceId, command, data, shouldRetry) { + this.writeQueue.unshift({ + deviceId, + command, + data, + shouldRetry, + }); + } + + _startWriteQueue() { + logger.info('startWriteQueue()'); + clearTimeout(this.writeQueueRef); + + this.writeQueueRef = setTimeout(() => this._runWriteQueue(), this.config.writeQueueWaitTime); + } + + async _runWriteQueue() { + try { + while (this.writeQueue.length > 0) { + if (!this.bleConnected) { + logger.warn('BLE not connected, stopping write queue until connection is up again.'); + return; + } + const queueItem = this.writeQueue.pop(); + const deviceName = this.deviceRegistry.getDeviceName(queueItem.deviceId); + logger.debug( + `Write queue: Processing ${deviceName} (${queueItem.deviceId}). Command ${ + queueItem.command + }${queueItem.data ? ` ${queueItem.data}` : ''}. Total queue length: ${ + this.writeQueue.length + }`, + ); + + if (this.writeQueue.some((item) => item.deviceId === queueItem.deviceId)) { + logger.verbose( + `Skipping ${deviceName} (${queueItem.deviceId}) ` + + `${queueItem.command} due to more recent command in queue.`, + ); + // Skip commands if new ones exist for the same deviceId + // still process all messages in order + } else { + /* eslint-disable no-await-in-loop */ + try { + await this.plejdBleHandler.sendCommand( + queueItem.command, + queueItem.deviceId, + queueItem.data, + ); + } catch (err) { + if (queueItem.shouldRetry) { + queueItem.retryCount = (queueItem.retryCount || 0) + 1; + logger.debug(`Will retry command, count failed so far ${queueItem.retryCount}`); + if (queueItem.retryCount <= MAX_RETRY_COUNT) { + this.writeQueue.push(queueItem); // Add back to top of queue to be processed next; + } else { + logger.error( + `Write queue: Exceeed max retry count (${MAX_RETRY_COUNT}) for ${deviceName} (${queueItem.deviceId}). Command ${queueItem.command} failed.`, + ); + break; + } + if (queueItem.retryCount > 1) { + break; // First retry directly, consecutive after writeQueueWaitTime ms + } + } + } + /* eslint-enable no-await-in-loop */ + } + } + } catch (e) { + logger.error('Error in writeQueue loop, values probably not written to Plejd', e); + } + + this.writeQueueRef = setTimeout(() => this._runWriteQueue(), this.config.writeQueueWaitTime); + } +} + +module.exports = PlejdDeviceCommunication; diff --git a/plejd/README.md b/plejd/README.md index 3a16cf0..5c91796 100644 --- a/plejd/README.md +++ b/plejd/README.md @@ -147,6 +147,8 @@ If you're having issues to get the addon working, there are a few things you can - Start `bluetoothctl` interactive command - Write `list` and make sure it finds the Bluetooth device. If no device is found you need to fix this first! - Look in Plejd addon log and make sure there is no `unable to find a bluetooth adapter` line +- Make sure signal strength is "good enough". The BLE adapter needs to be reasonably close to a Plejd device. Look at the RSSI reading in the debug logs. In some cases an RSSI of -80 dBm works well, in other cases a higher value such as -40 dBm is required to work. +- You should get verbose/debug logs similar to: `Found Plejd service on ...` => `Discovered ... with RSSI ...` => `Inspecting ...` => `Connecting ...` => `Connected` => `Connected device is a Plejd device ...` => `BLE Connected to ...` => `Bluetooth connected. Plejd BLE up and running!`. After this sequence (which could fail multiple times before finally succeeding) you should get quite frequent `Raw event received ...` from the Plejd mesh. When updating state you should see in the logs `Sending 8 byte(s) of data to Plejd ...`. - Listen to `#` in the MQTT integration and watch Plejd mqtt messages come in - Initial device discovery messages originate from the Plejd API, so if you set up that correctly you should get new devices in HA - Plejd log will show something like `discovered light (DIM-01) named ....` diff --git a/plejd/SceneManager.js b/plejd/SceneManager.js index a30e58b..e5047cc 100644 --- a/plejd/SceneManager.js +++ b/plejd/SceneManager.js @@ -1,16 +1,13 @@ -const EventEmitter = require('events'); const Logger = require('./Logger'); const Scene = require('./Scene'); const logger = Logger.getLogger('scene-manager'); -class SceneManager extends EventEmitter { +class SceneManager { deviceRegistry; plejdBle; scenes; constructor(deviceRegistry, plejdBle) { - super(); - this.deviceRegistry = deviceRegistry; this.plejdBle = plejdBle; this.scenes = {}; diff --git a/plejd/config.json b/plejd/config.json index eeeff6c..e0a2043 100644 --- a/plejd/config.json +++ b/plejd/config.json @@ -1,6 +1,6 @@ { "name": "Plejd", - "version": "0.6.2", + "version": "0.7.0", "slug": "plejd", "description": "Adds support for the Swedish home automation devices from Plejd.", "url": "https://github.com/icanos/hassio-plejd/", diff --git a/plejd/constants.js b/plejd/constants.js new file mode 100644 index 0000000..0b69b3a --- /dev/null +++ b/plejd/constants.js @@ -0,0 +1,8 @@ +const COMMANDS = { + TURN_ON: 'Turn on', + TURN_OFF: 'Turn off', + DIM: 'Dim', + TRIGGER_SCENE: 'Trigger scene', +}; + +module.exports = { COMMANDS };