dBus Error?

[sookis]

I have ran this plugin without any issues. But after the latest releases i cant get it to work. This is the log:

Log [s6-init] making user provided files available at /var/run/s6/etc...exited 0. [s6-init] ensuring user provided files have correct perms...exited 0. [fix-attrs.d] applying ownership & permissions fixes... [fix-attrs.d] done. [cont-init.d] executing container initialization scripts... [cont-init.d] 00-banner.sh: executing...

Hass.io Add-on: Plejd Adds support for the Swedish home automation devices from Plejd.

Add-on version: 0.3.4 You are running the latest version of this add-on. parse error: Expected string key before ':' at line 1, column 4 [13:52:19] ERROR: Unknown HTTP error occured System: (armv7 / raspberrypi3) Home Assistant version: 0.105.2 Supervisor version: 199

Please, share the above information when looking for help or support in, e.g., GitHub, forums or the Discord chat.

[cont-init.d] 00-banner.sh: exited 0. [cont-init.d] 01-log-level.sh: executing... [cont-init.d] 01-log-level.sh: exited 0. [cont-init.d] done. [services.d] starting services [services.d] done. [13:52:20] INFO: Starting the Plejd service... [13:52:20] INFO: Verified permissions on startup script [13:52:20] INFO: Executing startup script [13:52:22] INFO: Wrote plejd.json [13:52:22] INFO: Running add-on starting Plejd add-on v. 0.3.4 plejd-api: login() plejd-api: logging into Sörnacksta 47A plejd-api: got session token response plejd-api: getCryptoKey() plejd-api: got sites response wireEvents() init() plejd-ble: disconnecting /org/bluez/hci0/dev_C6_AD_A9_BA_05_61 plejd-mqtt: connected to mqtt. plejd-mqtt: discovered light named Spottar badrum with PID 21. plejd-mqtt: discovered light named Astrour with PID 11. plejd-mqtt: discovered light named Spottar utanför sovrum with PID 15. plejd-mqtt: discovered light named Spottar tvättstuga with PID 17. plejd-mqtt: discovered light named Spottar hall with PID 18. plejd-mqtt: discovered light named Spottar matrum with PID 13. plejd-mqtt: discovered light named Spottar trall with PID 19. (node:291) UnhandledPromiseRejectionWarning: DBusError: Does Not Exist at _methodReturnHandlers.(anonymous function) (/plejd/node_modules/dbus-next/lib/bus.js:339:27) at handleMessage (/plejd/node_modules/dbus-next/lib/bus.js:98:11) at EventEmitter.MessageBus.conn.on (/plejd/node_modules/dbus-next/lib/bus.js:147:9) at EventEmitter.emit (events.js:198:13) at /plejd/node_modules/dbus-next/lib/connection.js:112:14 at Socket. (/plejd/nodemodules/dbus-next/lib/message.js:55:9) at Socket.emit (events.js:198:13) at emitReadable (_stream_readable.js:554:12) at process._tickCallback (internal/process/next_tick.js:63:19) (node:291) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 1) (node:291) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.

[jzee]

@icanos - I believe I found a good reproduction for the problem:

My system's been running stable on 0.3.4 up until today when I tried to toy a bit with automating it. In particular, switching all lights off simultaneously.

Since a lot of lights are plejd-controlled, this seems to cause a lot of parallel requests to the plugin, which seems to cause it to struggle to execute all service calls as expected: Of the 5 plejd lights to be turned off, only 1 actually receive the service call, the rest stays on.

Here's are the relevant log parts:

1. Startup

   Home Assistant version: 0.105.2 Supervisor version: 199 [cont-init.d] 00-banner.sh: exited 0. [cont-init.d] 01-log-level.sh: executing... [cont-init.d] 01-log-level.sh: exited 0. [cont-init.d] done. [services.d] starting services [services.d] done. [15:36:17] INFO: Starting the Plejd service... [15:36:17] INFO: Verified permissions on startup script [15:36:17] INFO: Executing startup script [15:36:19] INFO: Wrote plejd.json [15:36:19] INFO: Running add-on starting Plejd add-on v. 0.3.4 plejd-api: login() plejd-api: logging into XXXXX plejd-api: got session token response plejd-api: getCryptoKey() plejd-api: got sites response wireEvents() init() plejd-ble: disconnecting /org/bluez/hci0/dev_XX plejd-mqtt: connected to mqtt. plejd-mqtt: discovered light named AA with PID 11. plejd-mqtt: discovered light named BB with PID 22. plejd-mqtt: discovered light named CC with PID 20. plejd-mqtt: discovered light named DD with PID 13. plejd-mqtt: discovered switch named EE with PID 19. plejd-mqtt: discovered light named FF with PID 14. plejd-mqtt: discovered light named GG with PID 17. plejd-ble: connecting to /org/bluez/hci0/dev_YY onDeviceConnected() trying 10 characteristics authenticate() startPing()

2. Turning on the 5 lights via HA, manually

   plejd-ble: sending 6 byte(s) of data to Plejd plejd-ble: sending 6 byte(s) of data to Plejd plejd-ble: sending 6 byte(s) of data to Plejd plejd-ble: sending 6 byte(s) of data to Plejd plejd-ble: sending 6 byte(s) of data to Plejd

3. starting the automation to turn off all 5 lights (and others)

   plejd-ble: sending 6 byte(s) of data to Plejd plejd-ble: sending 6 byte(s) of data to Plejd plejd-ble: write failed DBusError: In Progress plejd-ble: sending 6 byte(s) of data to Plejd plejd-ble: write failed DBusError: In Progress plejd-ble: sending 6 byte(s) of data to Plejd plejd-ble: write failed DBusError: In Progress plejd-ble: sending 6 byte(s) of data to Plejd plejd-ble: write failed DBusError: In Progress init() init() init() init() plejd-ble: disconnecting /org/bluez/hci0/dev_YY plejd-ble: disconnecting /org/bluez/hci0/dev_YY plejd-ble: disconnecting /org/bluez/hci0/dev_YY plejd-ble: disconnecting /org/bluez/hci0/dev_YY (node:290) UnhandledPromiseRejectionWarning: DBusError: Does Not Exist at _methodReturnHandlers.(anonymous function) (/plejd/node_modules/dbus-next/lib/bus.js:339:27) at handleMessage (/plejd/node_modules/dbus-next/lib/bus.js:98:11) at EventEmitter.MessageBus.conn.on (/plejd/node_modules/dbus-next/lib/bus.js:147:9) at EventEmitter.emit (events.js:198:13) at /plejd/node_modules/dbus-next/lib/connection.js:112:14 at Socket. (/plejd/nodemodules/dbus-next/lib/message.js:55:9) at Socket.emit (events.js:198:13) at emitReadable (_stream_readable.js:554:12) at process._tickCallback (internal/process/next_tick.js:63:19) (node:290) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 1) (node:290) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. (node:290) UnhandledPromiseRejectionWarning: DBusError: Does Not Exist at _methodReturnHandlers.(anonymous function) (/plejd/node_modules/dbus-next/lib/bus.js:339:27) at handleMessage (/plejd/node_modules/dbus-next/lib/bus.js:98:11) at EventEmitter.MessageBus.conn.on (/plejd/node_modules/dbus-next/lib/bus.js:147:9) at EventEmitter.emit (events.js:198:13) at /plejd/node_modules/dbus-next/lib/connection.js:112:14 at Socket. (/plejd/nodemodules/dbus-next/lib/message.js:55:9) at Socket.emit (events.js:198:13) at emitReadable (_stream_readable.js:554:12) at process._tickCallback (internal/process/next_tick.js:63:19) (node:290) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 2) (node:290) UnhandledPromiseRejectionWarning: DBusError: Does Not Exist at _methodReturnHandlers.(anonymous function) (/plejd/node_modules/dbus-next/lib/bus.js:339:27) at handleMessage (/plejd/node_modules/dbus-next/lib/bus.js:98:11) at EventEmitter.MessageBus.conn.on (/plejd/node_modules/dbus-next/lib/bus.js:147:9) at EventEmitter.emit (events.js:198:13) at /plejd/node_modules/dbus-next/lib/connection.js:112:14 at Socket. (/plejd/nodemodules/dbus-next/lib/message.js:55:9) at Socket.emit (events.js:198:13) at emitReadable (_stream_readable.js:554:12) at process._tickCallback (internal/process/next_tick.js:63:19) (node:290) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 3) plejd-ble: connecting to /org/bluez/hci0/dev_XX onDeviceConnected() trying 10 characteristics authenticate() startPing()

This is 100% reproducible and it smells like a queueing problem somewhere. Note that after this happens, all lights respond normally to on/off commands. But I can never turn off more than one light at a time.

Hope that helps with fault-finding. if you have a good pointer on how to create a good debugging setup for the add-on, I'd be more than happy to help out with some debugging

[icanos]

This seems like a queueing issue and something I'll address in the upcoming version

[axlthorell]

Any update on this issue? I'm getting the same error when trying to run an automation that turns on or off multiple plejd devices at once.

[icanos]

Resolved in #64