Merge pull request #174 from icanos/feature/0.7.0

Release 0.7.0

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)

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;
+    const added = {
-    this.deviceIdsBySerial[device.serialNumber] = device.id;
+      ...this.plejdDevices[device.id],
-    if (!this.deviceIdsByRoom[device.roomId]) {
+      ...device,
-      this.deviceIdsByRoom[device.roomId] = [];
+    };
+
+    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];
       }
-    this.deviceIdsByRoom[device.roomId].push(device.id);
+      logger.verbose(
+        `Added to room #${added.roomId}: ${JSON.stringify(this.deviceIdsByRoom[added.roomId])}`,
+      );
+    }
+
+    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;
+    const added = {
-  }
+      ...this.sceneDevices[scene.id],
-
+      ...scene,
-  setApiSite(siteDetails) {
+    };
-    this.apiSite = siteDetails;
+    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;

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
 

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,9 +118,10 @@ class MqttClient extends EventEmitter {
     });
 
     this.client.on('message', (topic, message) => {
+      try {
         if (startTopics.includes(topic)) {
           logger.info('Home Assistant has started. lets do discovery.');
-        this.emit('connected');
+          this.emit(MqttClient.EVENTS.connected);
         } else {
           const decodedTopic = decodeTopic(topic);
           if (decodedTopic) {
@@ -138,7 +144,6 @@ class MqttClient extends EventEmitter {
               );
               device = this.deviceRegistry.getScene(decodedTopic.id);
             }
-
             const deviceName = device ? device.name : '';
 
             switch (decodedTopic.command) {
@@ -148,7 +153,7 @@ class MqttClient extends EventEmitter {
                 );
 
                 if (device) {
-                this.emit('stateChanged', device, command);
+                  this.emit(MqttClient.EVENTS.stateChanged, device, command);
                 } else {
                   logger.warn(
                     `Device for topic ${topic} not found! Can happen if HA calls previously existing devices.`,
@@ -175,6 +180,9 @@ class MqttClient extends EventEmitter {
             );
           }
         }
+      } 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');

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 PlejdDeviceCommunication = require('./PlejdDeviceCommunication');
-const PlejdBLEHandler = require('./PlejdBLEHandler');
 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.plejdDeviceCommunication = new PlejdDeviceCommunication(this.deviceRegistry);
-    this.sceneManager = new SceneManager(this.deviceRegistry, this.plejdBLEHandler);
+    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();
 
-    ['SIGINT', 'SIGHUP', 'SIGTERM'].forEach((signal) => {
+    this.processCleanupFunc = () => {
-      process.on(signal, () => {
+      this.cleanup();
+      this.processCleanupFunc = () => {};
       this.mqttClient.disconnect(() => process.exit(0));
-      });
+    };
+
+    ['SIGINT', 'SIGHUP', 'SIGTERM'].forEach((signal) => {
+      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) => {
+    this.plejdDeviceCommunication.on(
+      PlejdDeviceCommunication.EVENTS.stateChanged,
+      (deviceId, command) => {
         try {
           this.mqttClient.updateState(deviceId, command);
         } catch (err) {
-        logger.error('Error in PlejdService.stateChanged callback in main.js', 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.plejdDeviceCommunication.init();
-      await this.plejdBLEHandler.init();
-    } catch (err) {
-      logger.error('Failed init() of BLE. Starting reconnect loop.');
-      await this.plejdBLEHandler.startReconnectPeriodicallyLoop();
-    }
     logger.info('Main init done');
   }
 }

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 = [];
+  requestCurrentPlejdTimeRef = null;
-  writeQueueRef = 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.bus = dbus.systemBus();
-    this.on('writeSuccess', () => this.onWriteSuccess());
+  }
+
+  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}`);
+      if (plejd.device) {
-      // Todo: Connect should probably be done here
+        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._startPing();
-      this.startWriteQueue();
 
       // 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) {
+  async _authenticate() {
-    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() {
     logger.info('authenticate()');
 
     try {
@@ -554,21 +474,62 @@ class PlejBLEHandler extends EventEmitter {
   }
 
   async startReconnectPeriodicallyLoop() {
-    logger.verbose('startReconnectPeriodicallyLoop');
+    logger.info('Starting reconnect loop...');
-    if (this.reconnectInProgress) {
+    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);
+    if (this.emergencyReconnectTimeout) {
-    clearTimeout(this.writeQueueRef);
+      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) {
+  async _write(payload) {
-    if (!data || !this.plejdService || !this.characteristics.data) {
+    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')}`);
+      logger.verbose(
-      const encryptedData = this._encryptDecrypt(this.cryptoKey, this.plejdService.addr, data);
+        `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();
+      await this._onWriteSuccess();
-      return true;
     } catch (err) {
+      await this._onWriteFailed(err);
       if (err.message === 'In Progress') {
         logger.debug("Write failed due to 'In progress' ", err);
-      } else {
+        throw new Error("Write failed due to 'In progress'");
-        logger.debug('Write failed ', err);
       }
-      await this.onWriteFailed(err);
+      logger.debug('Write failed ', err);
-      return false;
+      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 = this._createHexPayload(
-    const payload = Buffer.from(
+      this.connectedDevice.id,
-      `${this.connectedDevice.id.toString(16).padStart(2, '0')}0102${BLE_CMD_TIME_UPDATE.toString(
+      BLE_CMD_TIME_UPDATE,
-        16,
+      '',
-      ).padStart(4, '0')}`,
+      BLE_REQUEST_RESPONSE,
-      'hex',
     );
-    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) {
+      this._write(payload);
-        const queueItem = this.writeQueue.pop();
+    } catch (error) {
-        const deviceName = this.deviceRegistry.getDeviceName(queueItem.deviceId);
+      logger.warn('Failed requesting time update from Plejd');
-        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.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 encryptedData = value.value;
-    const decoded = this._encryptDecrypt(this.cryptoKey, this.plejdService.addr, data);
+    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, {
+      command = COMMANDS.DIM;
-        state,
+      data = { state, dim };
-        brightness: dim,
+      this.emit(PlejBLEHandler.EVENTS.commandReceived, deviceId, command, data);
-      });
-
-      this.plejdDevices[deviceId] = {
-        state,
-        dim,
-      };
-      logger.silly(`All states: ${JSON.stringify(this.plejdDevices, null, 2)}`);
     } else if (cmd === BLE_CMD_STATE_CHANGE) {
       logger.debug(`${deviceName} (${deviceId}) got state update. S: ${state}`);
-      this.emit('stateChanged', deviceId, {
+      command = state ? COMMANDS.TURN_ON : COMMANDS.TURN_OFF;
-        state,
+      this.emit(PlejBLEHandler.EVENTS.commandReceived, deviceId, command, data);
-      });
-      this.plejdDevices[deviceId] = {
-        state,
-        dim: 0,
-      };
-      logger.silly(`All states: ${JSON.stringify(this.plejdDevices, null, 2)}`);
     } 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);
+            const payload = this._createPayload(
-            // E.g: 00 0110 001b 38df2360 00
+              this.connectedDevice.id,
-            // 00: set?, 0110: don't respond, 001b: time command, 38df236000: the time
+              BLE_CMD_TIME_UPDATE,
-            payload.write('000110001b', 0, 'hex');
+              10,
-            payload.writeInt32LE(Math.trunc(newLocalTimestamp), 5);
+              (pl) => pl.writeInt32LE(Math.trunc(newLocalTimestamp), 5),
-            payload.write('00', 9, 'hex');
+            );
-            this.writeQueue.unshift({
+            try {
-              deviceId: this.connectedDevice.id,
+              this.write(payload);
-              log: 'SetTime',
+            } catch (err) {
-              shouldRetry: true,
+              logger.error(
-              payload,
+                '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();

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;

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 ....`

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 = {};

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/",

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 };