PietroLubini / homebridge-ecoflow

MIT License
1 stars 1 forks source link

Bug: Adding Second Device Causes Plugin / Homebridge to Crash #11

Closed jamesbabiak closed 1 month ago

jamesbabiak commented 2 months ago

I just added a second device to my EcoFlow plugin config. The original device (Delta 2 Max) was working fine, but when I added the Delta 2, it went into a crash loop. The plugin crashed and took Homebridge down with it, similar to the issue I had when the api-e was failing, even though I had it setup the same way. I tried updating the plugin to the latest version, but that failed as well, even after setting the server to the US one. From review of the logs, the plugin connects and pulls data for both devices, but eventually gets this error:

[8/11/2024, 2:42:24 PM] [Homebridge EcoFlow] [Delta 2 Max] Acquire certificate for MQTT connection [8/11/2024, 2:42:25 PM] ErrorWithReasonCode: Connection refused: Client Identifier not valid at handleConnack (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/mqtt/src/lib/handlers/connack.ts:47:15) at handle (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/mqtt/src/lib/handlers/index.ts:49:17) at work (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/mqtt/src/lib/client.ts:765:17) at Writable.writable._write (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/mqtt/src/lib/client.ts:789:4) at writeOrBuffer (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/readable-stream/lib/internal/streams/writable.js:334:12) at _write (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/readable-stream/lib/internal/streams/writable.js:283:10) at Writable.write (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/readable-stream/lib/internal/streams/writable.js:286:10) at TLSSocket.ondata (node:internal/streams/readable:1007:22) at TLSSocket.emit (node:events:519:28) at TLSSocket.emit (node:domain:488:12) at addChunk (node:internal/streams/readable:559:12) at readableAddChunkPushByteMode (node:internal/streams/readable:510:3) at TLSSocket.Readable.push (node:internal/streams/readable:390:5) at TLSWrap.onStreamRead (node:internal/stream_base_commons:191:23) [8/11/2024, 2:42:25 PM] [Homebridge EcoFlow] [Delta 2] Connected to EcoFlow MQTT Service [8/11/2024, 2:42:25 PM] Got SIGTERM, shutting down Homebridge...

I wasn't sure if there was a limit to one device per API key, but when I tried creating a second one, to see if that would fix it, EcoFlow said I could only have 1 per account.

Just to make sure it wasn't the new device itself, I removed the old Delta 2 Max config and just left the Delta 2, restarted, and that one is working fine by itself. So it seems like either device individually works, but adding both will cause the plugin (and Homebridge) to crash. I'm not sure why it says "Connection refused" in the log above, because right before then I can see it pulling all of the data for both devices, but maybe there is some limitation on connections, etc.

Also, on a separate note, prior to updating to the latest version, the logs were pretty quiet. But now I am seeing a constant flood of log entries on the status screen for the plugin every couple of seconds, even with the device in standby mode:

[8/11/2024, 3:09:32 PM] [Homebridge EcoFlow] [Delta 2] BatteryLevel -> 100 [8/11/2024, 3:09:32 PM] [Homebridge EcoFlow] [Delta 2] Battery Level, % -> 100 [8/11/2024, 3:09:32 PM] [Homebridge EcoFlow] [Delta 2] Battery Level, % -> 100 [8/11/2024, 3:09:32 PM] [Homebridge EcoFlow] [Delta 2] Battery Level, % -> 100 [8/11/2024, 3:09:33 PM] [Homebridge EcoFlow] [Delta 2] INV: { invOutVol: 120334, acInVol: 120987 } [8/11/2024, 3:09:34 PM] [Homebridge EcoFlow] [Delta 2] BMS: { amp: 0, soc: 100, minCellVol: 3355, outputWatts: 0, maxCellVol: 3369, inputWatts: 0, f32ShowSoc: 100, cellVol: [ 3358, 3355, 3358 ], mosState: 2, cellTemp: [], actSoc: 100, sysState: 2, allErrCode: 8388672 } [8/11/2024, 3:09:34 PM] [Homebridge EcoFlow] [Delta 2] Status Low Battery -> false [8/11/2024, 3:09:34 PM] [Homebridge EcoFlow] [Delta 2] BatteryLevel -> 100 [8/11/2024, 3:09:34 PM] [Homebridge EcoFlow] [Delta 2] Battery Level, % -> 100 [8/11/2024, 3:09:34 PM] [Homebridge EcoFlow] [Delta 2] Battery Level, % -> 100 [8/11/2024, 3:09:34 PM] [Homebridge EcoFlow] [Delta 2] Battery Level, % -> 100 [8/11/2024, 3:09:36 PM] [Homebridge EcoFlow] [Delta 2] INV: { acInVol: 121358 } [8/11/2024, 3:09:36 PM] [Homebridge EcoFlow] [Delta 2] BMS: { .....

I'm concerned this could fill up the log files very quickly.

Please let me know if you need anything else in order to troubleshoot. Thanks!

PietroLubini commented 2 months ago
PietroLubini commented 2 months ago

[8/11/2024, 2:42:24 PM] [Homebridge EcoFlow] [Delta 2 Max] Acquire certificate for MQTT connection [8/11/2024, 2:42:25 PM] ErrorWithReasonCode: Connection refused: Client Identifier not valid

If you have 2 devices for the same account (accessKey and secretKey are the same), plugin will try to create two connection to MQTT Server with the same parameters (username, password, clientId). I assume this is reason of the failure. I will extend plugin by sharing mqtt connection for devices with the same accessKey and secretKey

PietroLubini commented 2 months ago

I've published version 1.3.0-beta where i've added support for multiple devices:

@jamesbabiak. can you try it? And let me know whether your issue was fixed and both devices for the same account are added successfully?

jamesbabiak commented 2 months ago

I just upgraded and tested it out. Some bad news, good news, then more bad news.

I added my Delta 2 Max back into the plugin settings, as I only had the Delta 2 left from before. Restarted Homebridge and noticed it immediately started failing again, which once again caused Homebridge to shutdown and restart as well.

Here are the relevant error logs from the crash loop:

[8/17/2024, 8:25:40 AM] TypeError: Cannot read properties of null (reading 'bms_bmsStatus') at Delta2Accessory.processQuotaMessage (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/accessories/batteries/batteryAccessory.ts:46:32) at Object.next (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/apis/containers/mqttDevice.ts:41:49) at ConsumerObserver.next (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/rxjs/src/internal/Subscriber.ts:161:25) at SafeSubscriber.Subscriber._next (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/rxjs/src/internal/Subscriber.ts:119:22) at SafeSubscriber.Subscriber.next (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/rxjs/src/internal/Subscriber.ts:75:12) at /usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/rxjs/src/internal/Subject.ts:68:20 at Object.errorContext (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/rxjs/src/internal/util/errorContext.ts:29:5) at Subject.next (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/rxjs/src/internal/Subject.ts:61:5) at MqttDevice.processReceivedMessage (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/apis/containers/mqttDevice.ts:25:27) at /usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/apis/ecoFlowMqttApiManager.ts:123:38 at Array.forEach () at EcoFlowMqttApiManager.processReceivedMessage (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/apis/ecoFlowMqttApiManager.ts:123:13) at MqttClient. (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/apis/ecoFlowMqttApiManager.ts:84:16) at MqttClient.emit (node:events:519:28) at MqttClient.emit (node:domain:488:12) at handlePublish (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/mqtt/src/lib/handlers/publish.ts:172:11) at handle (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/mqtt/src/lib/handlers/index.ts:31:17) at work (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/mqtt/src/lib/client.ts:773:17) at Writable.writable._write (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/mqtt/src/lib/client.ts:797:4) at writeOrBuffer (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/readable-stream/lib/internal/streams/writable.js:334:12) at _write (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/readable-stream/lib/internal/streams/writable.js:283:10) at Writable.write (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/node_modules/readable-stream/lib/internal/streams/writable.js:286:10) at TLSSocket.ondata (node:internal/streams/readable:1007:22) at TLSSocket.emit (node:events:519:28) at TLSSocket.emit (node:domain:488:12) at addChunk (node:internal/streams/readable:559:12) at readableAddChunkPushByteMode (node:internal/streams/readable:510:3) at TLSSocket.Readable.push (node:internal/streams/readable:390:5) at TLSWrap.onStreamRead (node:internal/stream_base_commons:191:23)

Then, just as I was about to remove the second device again, I noticed things seemed to stabilize. No more errors or restarts. I checked the accessories and was able to confirm that both devices were showing up.

Unfortunately, just as I was about to let you know that, after a few hiccups, it seemed to be working, I saw it start to crash again, albeit a little differently this time.

Relevant logs:

[8/17/2024, 8:29:17 AM] [Homebridge EcoFlow] [Delta 2] Request is failed: TypeError: fetch failed at node:internal/deps/undici/undici:13178:13 at processTicksAndRejections (node:internal/process/task_queues:95:5) at EcoFlowHttpApiManager.execute (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/apis/ecoFlowHttpApiManager.ts:98:24) at EcoFlowHttpApiManager.acquireCertificate (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/apis/ecoFlowHttpApiManager.ts:61:22) at EcoFlowMqttApiManager.acquireCertificate (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/apis/ecoFlowMqttApiManager.ts:131:29) at EcoFlowMqttApiManager.connect (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/apis/ecoFlowMqttApiManager.ts:66:23) at EcoFlowMqttApiManager.subscribeOnTopic (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/apis/ecoFlowMqttApiManager.ts:95:20) at Delta2Accessory.initMqtt (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/accessories/ecoFlowAccessory.ts:139:8) at Delta2Accessory.connectMqtt (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/accessories/ecoFlowAccessory.ts:128:5) at Delta2Accessory.initialize (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/accessories/ecoFlowAccessory.ts:45:5) at EcoFlowHomebridgePlatform.initialize (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/platform.ts:176:7) { [cause]: ConnectTimeoutError: Connect Timeout Error at onConnectTimeout (node:internal/deps/undici/undici:2331:28) at node:internal/deps/undici/undici:2283:50 at Immediate._onImmediate (node:internal/deps/undici/undici:2315:13) at processImmediate (node:internal/timers:483:21) { code: 'UND_ERR_CONNECT_TIMEOUT' } } [8/17/2024, 8:29:27 AM] [Homebridge EcoFlow] [Delta 2] Request is failed: TypeError: fetch failed at node:internal/deps/undici/undici:13178:13 at processTicksAndRejections (node:internal/process/task_queues:95:5) at EcoFlowHttpApiManager.execute (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/apis/ecoFlowHttpApiManager.ts:98:24) at EcoFlowHttpApiManager.getAllQuotas (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/apis/ecoFlowHttpApiManager.ts:46:22) at Delta2Accessory.initializeDefaultValues (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/accessories/ecoFlowAccessory.ts:164:21) at EcoFlowHomebridgePlatform.initialize (/usr/lib/node_modules/@pietrolubini/homebridge-ecoflow/src/platform.ts:177:7) { [cause]: ConnectTimeoutError: Connect Timeout Error at onConnectTimeout (node:internal/deps/undici/undici:2331:28) at node:internal/deps/undici/undici:2283:50 at Immediate._onImmediate (node:internal/deps/undici/undici:2315:13) at processImmediate (node:internal/timers:483:21) { code: 'UND_ERR_CONNECT_TIMEOUT' } }

After removing the second device again, it stopped crashing and seems to be OK.

So unfortunately, while it did seem, at least temporarily, to successfully connect and work with 2 different devices, that was only for a minute or so before it crashed again.

One other weird issue I found was that, after removing the 2nd device, it was still showing up in my HomeBridge accessories. I reviewed the logs and it didn't mention the other one, but it was still listed. I checked the config file and confirmed only the single Delta2 was listed. I tried restarting HomeBridge a couple times, but the second orphaned device remained. I downgraded to the previous 1.2.1 version, restarted, and that seemed to purge the old record. Not sure if that was just a bug in the new version or some weird one-off situation, but I figured I would mention it.

Let me know if you need anything else. Thanks!

PietroLubini commented 2 months ago

@jamesbabiak , thanks for testing. I have several comments:

Can you turn on Debug mode in homebridge for debug messages be shown as well?

This error should not force homebridge to restart. Nevertheless, can you post your config with anonymized secrets? Something like this

"devices": [
{
    "name": "Name1",
    "model": "Delta 2",
    "serialNumber": "sn1",
    "location": "US",
    "accessKey": "accessKey1",
    "secretKey": "secretKey1",
},
{
    "name": "Name2",
    "model": "Delta 2 Max",
    "serialNumber": "sn2",
    "location": "US",
    "accessKey": "accessKey1",
    "secretKey": "secretKey1"
}
],

I am particularly interested in whether you have the same accessKey and secretKey for both devices.

Can you turn on Debug mode and post the whole log for Ecoflow plugin particularly? image

This feature is by design. Despite on fact that your removed device from configuration, the accessory is still in homebridge's cache. This is useful when you have some automations for that device in HomeKit and your want to disable it for a while and later return back. In this case you don't need to update those automations, but if a device is removed from homebridge, next time it is created, you will have to update all conditions where it is stated. If you really want to remove device, you can do it in homebridge -> Settings -> Manage Cached Accessories -> Remove Single Cached Accessory