Homebridge doesn't start after Update Node/NPM

[koerby]

Hi, my homebridge doesn't start after Update NPM & Node for some Plugins.

The issue come from Bachome....

After remove plugin, my homebridge run normaly.

Sep 05 10:02:56 homebridge homebridge[20330]: [5.9.2021, 10:02:56] [homebridge-bachome] This plugin slows down Homebridge. The read handler for the characteristic 'On' was slow to respond! See https://git.io/JtMGR for more info.

[koerby]

Sep 05 11:14:48 homebridge homebridge[31320]: (node:31320) 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(). To terminate the node process on unhandled promise rejection, use the CLI flag --unhandled-rejections=strict (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 119) Sep 05 11:14:48 homebridge homebridge[31320]: (node:31320) UnhandledPromiseRejectionWarning: Error: BacnetAbort - Reason:1 Sep 05 11:14:48 homebridge homebridge[31320]: at processAbort (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:99:30) Sep 05 11:14:48 homebridge homebridge[31320]: at handlePdu (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:313:9) Sep 05 11:14:48 homebridge homebridge[31320]: at handleNpdu (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:342:5) Sep 05 11:14:48 homebridge homebridge[31320]: at self.receiveData (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:353:7) Sep 05 11:14:48 homebridge homebridge[31320]: at Socket. (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/transport.js:13:25) Sep 05 11:14:48 homebridge homebridge[31320]: at Socket.emit (events.js:400:28) Sep 05 11:14:48 homebridge homebridge[31320]: at UDP.onMessage (dgram.js:941:8)

[Apsysikal]

I'm looking into this issue. For the time being, according to the homebridge documentation, you cloud put the bachome plugin into its own child bridge to prevent slowing down other plugins.

[koerby]

Hey, i create a new instance for bachome plugin, but the bridge doesn't start...

Okt 05 19:47:35 homebridge homebridge[16511]: [5.10.2021, 19:47:35] Error: BacnetAbort - Reason:1 Okt 05 19:47:35 homebridge homebridge[16511]: at processAbort (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:99:30) Okt 05 19:47:35 homebridge homebridge[16511]: at handlePdu (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:313:9) Okt 05 19:47:35 homebridge homebridge[16511]: at handleNpdu (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:342:5) Okt 05 19:47:35 homebridge homebridge[16511]: at self.receiveData (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:353: Okt 05 19:47:35 homebridge homebridge[16511]: at Socket. (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/transport.js Okt 05 19:47:35 homebridge homebridge[16511]: at Socket.emit (node:events:390:28) Okt 05 19:47:35 homebridge homebridge[16511]: at UDP.onMessage (node:dgram:931:8) Okt 05 19:47:35 homebridge homebridge[16511]: [5.10.2021, 19:47:35] Got SIGTERM, shutting down Homebridge...

Any Idea?

[Apsysikal]

It seems that the error is from the BACnet library. Which is not so good, as the library isn't actively maintained. I'm refactoring some code according error handling for the next update. I'll have to get back to you on this.

[koerby]

Hi. something new about an update?

[Apsysikal]

I have the code mostly ready and it's currently working on my machine. If i have time over new year I'll push out an update. Sorry I didn't have time the past half year.

[Apsysikal]

Update 1.4.0 is out now. Can you check, if this fixes the issue with your node version? The current version of the plugin is aimed at node versions >=16.10.0 and homebridge versions >=1.3.4

[koerby]

Hi, thank you for your work, but i my homebridge doesn't start after update.

Dez 08 20:12:12 homebridge homebridge[16978]: [8.12.2021, 20:12:12] Homebridge v1.3.8 (HAP v0.9.7) (Homebridge-Bachome) is running on port 51844. Dez 08 20:12:14 homebridge homebridge[16978]: [8.12.2021, 20:12:14] Error: BacnetAbort - Reason:1 Dez 08 20:12:14 homebridge homebridge[16978]: at processAbort (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:99:30) Dez 08 20:12:14 homebridge homebridge[16978]: at handlePdu (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:313:9) Dez 08 20:12:14 homebridge homebridge[16978]: at handleNpdu (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:342:5) Dez 08 20:12:14 homebridge homebridge[16978]: at self.receiveData (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:353:7) Dez 08 20:12:14 homebridge homebridge[16978]: at Socket. (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/transport.js:13:25) Dez 08 20:12:14 homebridge homebridge[16978]: at Socket.emit (node:events:390:28) Dez 08 20:12:14 homebridge homebridge[16978]: at UDP.onMessage (node:dgram:939:8) Dez 08 20:12:14 homebridge homebridge[16978]: [8.12.2021, 20:12:14] [BAChome Dynamic Platform] BacnetAbort - Reason:1 Dez 08 20:12:14 homebridge systemd[1]: homebridge-bachome.service: Main process exited, code=exited, status=1/FAILURE Dez 08 20:12:14 homebridge systemd[1]: homebridge-bachome.service: Unit entered failed state. Dez 08 20:12:14 homebridge systemd[1]: homebridge-bachome.service: Failed with result 'exit-code'.

node version : 16.13.1 homebridge version : 1.3.8

[koerby]

Ok, there is no issue when i only use one thermostat. If i tried a second one, my homebridge doesn't start.

[12/8/2021, 9:03:32 PM] [homebridge-bachome] This plugin slows down Homebridge. The read handler for the characteristic 'Target Heating Cooling State' was slow to respond! See https://git.io/JtMGR for more info. [12/8/2021, 9:03:32 PM] [homebridge-bachome] This plugin slows down Homebridge. The read handler for the characteristic 'Current Temperature' was slow to respond! See https://git.io/JtMGR for more info. [12/8/2021, 9:03:32 PM] [homebridge-bachome] This plugin slows down Homebridge. The read handler for the characteristic 'Target Temperature' was slow to respond! See https://git.io/JtMGR for more info. [12/8/2021, 9:03:32 PM] Error: ERR_TIMEOUT at Timeout._onTimeout (/homebridge/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:75:16) at listOnTimeout (node:internal/timers:557:17) at processTimers (node:internal/timers:500:7) [12/8/2021, 9:03:32 PM] [BAChome Dynamic Platform] ERR_TIMEOUT [12/8/2021, 9:03:32 PM] [HB Supervisor] Homebridge Process Ended. Code: 1, Signal: null [12/8/2021, 9:03:37 PM] [HB Supervisor] Restarting Homebridge...

[Apsysikal]

Hi, thank you for your work, but i my homebridge doesn't start after update.

Dez 08 20:12:12 homebridge homebridge[16978]: [8.12.2021, 20:12:12] Homebridge v1.3.8 (HAP v0.9.7) (Homebridge-Bachome) is running on port 51844. Dez 08 20:12:14 homebridge homebridge[16978]: [8.12.2021, 20:12:14] Error: BacnetAbort - Reason:1 Dez 08 20:12:14 homebridge homebridge[16978]: at processAbort (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:99:30) Dez 08 20:12:14 homebridge homebridge[16978]: at handlePdu (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:313:9) Dez 08 20:12:14 homebridge homebridge[16978]: at handleNpdu (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:342:5) Dez 08 20:12:14 homebridge homebridge[16978]: at self.receiveData (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:353:7) Dez 08 20:12:14 homebridge homebridge[16978]: at Socket. (/usr/local/lib/node_modules/homebridge-bachome/node_modules/bacstack/lib/transport.js:13:25) Dez 08 20:12:14 homebridge homebridge[16978]: at Socket.emit (node:events:390:28) Dez 08 20:12:14 homebridge homebridge[16978]: at UDP.onMessage (node:dgram:939:8) Dez 08 20:12:14 homebridge homebridge[16978]: [8.12.2021, 20:12:14] [BAChome Dynamic Platform] BacnetAbort - Reason:1 Dez 08 20:12:14 homebridge systemd[1]: homebridge-bachome.service: Main process exited, code=exited, status=1/FAILURE Dez 08 20:12:14 homebridge systemd[1]: homebridge-bachome.service: Unit entered failed state. Dez 08 20:12:14 homebridge systemd[1]: homebridge-bachome.service: Failed with result 'exit-code'.

node version : 16.13.1 homebridge version : 1.3.8

Is this happening when using multiple thermostats?

[Apsysikal]

Ok, there is no issue when i only use one thermostat. If i tried a second one, my homebridge doesn't start.

[12/8/2021, 9:03:32 PM] [homebridge-bachome] This plugin slows down Homebridge. The read handler for the characteristic 'Target Heating Cooling State' was slow to respond! See https://git.io/JtMGR for more info. [12/8/2021, 9:03:32 PM] [homebridge-bachome] This plugin slows down Homebridge. The read handler for the characteristic 'Current Temperature' was slow to respond! See https://git.io/JtMGR for more info. [12/8/2021, 9:03:32 PM] [homebridge-bachome] This plugin slows down Homebridge. The read handler for the characteristic 'Target Temperature' was slow to respond! See https://git.io/JtMGR for more info. [12/8/2021, 9:03:32 PM] Error: ERR_TIMEOUT at Timeout._onTimeout (/homebridge/node_modules/homebridge-bachome/node_modules/bacstack/lib/client.js:75:16) at listOnTimeout (node:internal/timers:557:17) at processTimers (node:internal/timers:500:7) [12/8/2021, 9:03:32 PM] [BAChome Dynamic Platform] ERR_TIMEOUT [12/8/2021, 9:03:32 PM] [HB Supervisor] Homebridge Process Ended. Code: 1, Signal: null [12/8/2021, 9:03:37 PM] [HB Supervisor] Restarting Homebridge...

This error seems from a BACnet device not responding. I can fix the warning, but if the device isn't responding, it won't fix your problem of the device not working. Would you mind sharing your config? Once with two thermostats and with only one.

[koerby]

Hey, here is my config, before the update it works.

  {
        "name": "BAChome Dynamic Platform",
        "switch": [
            {
                "name": "Presence",
                "manufacturer": "Koerby",
                "model": "Koerby's switch",
                "serial": "B-H-R-PSC",
                "ipAddress": "192.168.1.105",
                "stateObject": "BV:82"
            },
            {
                "name": "Gong",
                "manufacturer": "Koerby",
                "model": "Koerby's switch",
                "serial": "B-H-OA-GONG",
                "ipAddress": "192.168.1.105",
                "stateObject": "BV:63"
            }
        ],
        "thermostat": [
            {
                "name": "UT Thermostat",
                "manufacturer": "Koerby",
                "model": "Koerby's thermostat",
                "serial": "B-H-R-F1-R2",
                "ipAddress": "192.168.1.201",
                "currentHeatingCoolingState": "AI:75",
                "targetHeatingCoolingState": "AV:384",
                "currentTemperature": "AI:48",
                "targetTemperature": "AV:251"
            },
            {
                "name": "Kitchen Thermostat",
                "manufacturer": "Koerby",
                "model": "Koerby's thermostat",
                "serial": "B-H-R-F1-R3",
                "ipAddress": "192.168.1.201",
                "currentHeatingCoolingState": "AI:76",
                "targetHeatingCoolingState": "AV:386",
                "currentTemperature": "AI:49",
                "targetTemperature": "AV:262"
            },
            {
                "name": "Living Room Thermostat",
                "manufacturer": "Koerby",
                "model": "Koerby's thermostat",
                "serial": "B-H-R-F1-R4",
                "ipAddress": "192.168.1.201",
                "currentHeatingCoolingState": "AI:73",
                "targetHeatingCoolingState": "AV:380",
                "currentTemperature": "AI:53",
                "targetTemperature": "AV:273"
            },
            {
                "name": "Office Thermostat",
                "manufacturer": "Koerby",
                "model": "Koerby's thermostat",
                "serial": "B-H-R-F1-R5",
                "ipAddress": "192.168.1.201",
                "currentHeatingCoolingState": "AI:77",
                "targetHeatingCoolingState": "AV:388",
                "currentTemperature": "AI:54",
                "targetTemperature": "AV:284"
            },
            {
                "name": "Floor 1 Thermostat",
                "manufacturer": "Koerby",
                "model": "Koerby's thermostat",
                "serial": "B-H-R-F1-R6",
                "ipAddress": "192.168.1.201",
                "currentHeatingCoolingState": "AI:78",
                "targetHeatingCoolingState": "AV:390",
                "currentTemperature": "AI:55",
                "targetTemperature": "AV:295"
            },
            {
                "name": "Toilet Thermostat",
                "manufacturer": "Koerby",
                "model": "Koerby's thermostat",
                "serial": "B-H-R-F1-R7",
                "ipAddress": "192.168.1.201",
                "currentHeatingCoolingState": "AI:79",
                "targetHeatingCoolingState": "AV:392",
                "currentTemperature": "AI:56",
                "targetTemperature": "AV:306"
            },
            {
                "name": "Bathroom Thermostat",
                "manufacturer": "Koerby",
                "model": "Koerby's thermostat",
                "serial": "B-H-R-F2-R1",
                "ipAddress": "192.168.1.201",
                "currentHeatingCoolingState": "AI:74",
                "targetHeatingCoolingState": "AV:382",
                "currentTemperature": "AI:60",
                "targetTemperature": "AV:317"
            },
            {
                "name": "Bedroom Thermostat",
                "manufacturer": "Koerby",
                "model": "Koerby's thermostat",
                "serial": "B-H-R-F2-R3",
                "ipAddress": "192.168.1.201",
                "currentHeatingCoolingState": "AI:80",
                "targetHeatingCoolingState": "AV:394",
                "currentTemperature": "AI:62",
                "targetTemperature": "AV:328"
            },
            {
                "name": "Dressing Thermostat",
                "manufacturer": "Koerby",
                "model": "Koerby's thermostat",
                "serial": "B-H-R-F2-R4",
                "ipAddress": "192.168.1.201",
                "currentHeatingCoolingState": "AI:81",
                "targetHeatingCoolingState": "AV:396",
                "currentTemperature": "AI:63",
                "targetTemperature": "AV:339"
            },
            {
                "name": "Child 2 Thermostat",
                "manufacturer": "Koerby",
                "model": "Koerby's thermostat",
                "serial": "B-H-R-F2-R5",
                "ipAddress": "192.168.1.201",
                "currentHeatingCoolingState": "AI:82",
                "targetHeatingCoolingState": "AV:398",
                "currentTemperature": "AI:64",
                "targetTemperature": "AV:350"
            },
            {
                "name": "Child 1 Thermostat",
                "manufacturer": "Koerby",
                "model": "Koerby's thermostat",
                "serial": "B-H-R-F2-R6",
                "ipAddress": "192.168.1.201",
                "currentHeatingCoolingState": "AI:83",
                "targetHeatingCoolingState": "AV:400",
                "currentTemperature": "AI:65",
                "targetTemperature": "AV:361"
            },
            {
                "name": "Floor 2 Thermostat",
                "manufacturer": "Koerby",
                "model": "Koerby's thermostat",
                "serial": "B-H-R-F2-R7",
                "ipAddress": "192.168.1.201",
                "currentHeatingCoolingState": "AI:84",
                "targetHeatingCoolingState": "AV:402",
                "currentTemperature": "AI:66",
                "targetTemperature": "AV:372"
            }
        ],
        "platform": "bachome"
    }

and all objects are respondig.

[koerby]

Hi, i test it with every thermostat, everytime when i add a second thermostat my homebridge doesn't start. I checked all objects AI / AV and all objecst are rechable. Any ideas?

[Apsysikal]

Thank you lots for investing time into testing so thoroughly. To be frank, I don't have any idea why this is happening. I'll have to invest some time into modelling your environment on a controller and then test it on a live device. I'll get back to you when I had time to do that. Sorry for the inconvenience.

[koerby]

I think it has something to do with node update?! Before i updated it works with this config.

[Apsysikal]

I've added error catching for the thermostat module. It should now log the error, but without crashing the app. The new version is 1.4.2. Can you check your logs after updating. Maybe check, if all devices don't respond.

[koerby]

At first -> Thank your for your work!

Homebridge starts, but only the first thermostat works. I test all thermostats alone and it works, so all objects are respond. i checked it also with yabe (bacnet browser).

[koerby]

I don't know, but it looks like the Adapter trys to get all objects at the same time.

I changed the ip of my bacnet controller, changed the device id... nothing works... After a long time all values are ok in my homekite / homebridge, but in the log there is always a error timeout i can also change the setpoint for all of my thermostats and it works fine, but the it shows alwas the error...

Log: Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:13 homebridge homebridge[20292]: [14.12.2021, 09:22:13] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:35 homebridge homebridge[20292]: [14.12.2021, 09:22:35] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:35 homebridge homebridge[20292]: [14.12.2021, 09:22:35] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:35 homebridge homebridge[20292]: [14.12.2021, 09:22:35] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:35 homebridge homebridge[20292]: [14.12.2021, 09:22:35] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:35 homebridge homebridge[20292]: [14.12.2021, 09:22:35] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:35 homebridge homebridge[20292]: [14.12.2021, 09:22:35] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT Dez 14 09:22:35 homebridge homebridge[20292]: [14.12.2021, 09:22:35] [BAChome Dynamic Platform] An error occured: Error: ERR_TIMEOUT

[Apsysikal]

Ok, that's a bummer. I never had this issue, but I can understand, that some devices may get "overloaded" when too many requests are sent/received at the same time. I'll go ahead and close the issue, since it is a different problem now. I'll open a new one as a reminder to add "rate limiting" and maybe even a "slow mode". I think it could be especially useful when one device hosts multiple accessories.