paulw11 / homebridge-elkm1

Homebridge plugin for the Elk M1 alarm panel
MIT License
7 stars 6 forks source link

No longer working with homebridge Version 1.1.3? #10

Closed zylantha closed 3 years ago

zylantha commented 4 years ago

I had this working previously, but I've just updated homebridge to 1.1.3 and it's now failing to start, reporting an error relating to unhandled promise rejections. Has anybody else noticed that this is no longer working with homebridge 1.1.3?

(node:75382) UnhandledPromiseRejectionWarning: Timout occured before Text Description (sd) was received. (Usenode --trace-warnings ...to show where the warning was created) (node:75382) 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: 1) (node:75382) [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.

I have had to experiment to figure out which module is causing the issue, and it's only once I delete the homebridge-elkm1 configuration that this error message goes away, and homebridge starts up properly (otherwise it just hangs and never fully initialises).

paulw11 commented 4 years ago

I am running the current version with Homebridge 1.1.6 without any issues.

Can you provide some more information on your environment? What version of Node do you have?

zylantha commented 4 years ago

Node is reporting v14.4.0 (I think I had to upgrade this at the same time as the upgrade to 1.1.3).

Am running homebridge in a SmartOS zone (Illumos - OpenSolaris), base-64 20.2.0.

paulw11 commented 4 years ago

OK, I have 12.18.2; I will update and test later. However, this is only a warning, so this shouldn't prevent your Homebridge from running. You should be aware that there are issues with Homebridge - https://github.com/homebridge/homebridge/issues/2670 I had to manually change one of the dependencies before I could get Homebridge to start, even after rolling back to 1.1.2

zylantha commented 4 years ago

Yes it looks like a warning, but Homebridge then stalls and doesn't finish initialising (homebridge-ui works but reports that homebridge is not running).

It's only once I removed the configuration entry for homebridge-elkm1 that it would finally start up properly, so while I'm now running again on 1.1.3 (and now 1.1.6), I've lost all my integration with my m1g :(

paulw11 commented 4 years ago

The installation instructions suggest node.js 12.x for Homebridge

zylantha commented 4 years ago

OK I have downgraded to node.js v12.18.0 but I still get the same error, and a hang on startup when elkm1 is configured:

(node:5230) UnhandledPromiseRejectionWarning: Timout occured before Text Description (sd) was received. (node:5230) 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: 1) (node:5230) [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.

zylantha commented 4 years ago

I've also checked & corrected my configuration (one zone was set to the incorrect type, and another zone was set as "temperature" (which it is) even though this is not supported in homebridge-elkm1, so I've removed that zone) but this hasn't helped. I've also tried deleting all of the garage doors and all but one zone, and this also didn't help.

paulw11 commented 4 years ago

The problem is occurring in the elkmon module that my code uses. I would start by checking that all of your zones etc have text descriptions while I investigate further.

zylantha commented 4 years ago

I'm in the process of spinning up a new zone solely to run homebridge-elkm1 (in a completely separate homebridge instance), because I get the impression that it will be better that way. There were lots of pauses and errors being thrown when I was trying to issue commands to the m1 (prior to it stopping working), I suspect because it exposes so many devices it just needs to run in its own instance.

In doing this I'll be able to gradually upgrade each component in the same way (and be able to roll back) to try to isolate the exact upgrade / moment that's causing the issue.

zylantha commented 4 years ago

OK I now have a new zone set up running nothing but homebridge-elkm1 (+ homebridge-config-ui-x), but still has the same issue of hanging on startup with the same error - at least now I can try selectively downgrading other components until it works again.

All zones have text descriptions recorded according to elkrp2

paulw11 commented 4 years ago

I know where I need to implement a fix, it just might take me a couple of days to find time to do it.

paulw11 commented 4 years ago

I have uploaded version 1.1.7, which adds the required catch statement. This should prevent the warning you are seeing, but I can't guarantee that it will fix your problem, since that seems to be an issue with actually getting the data from your M1 panel (You are getting a timeout). Are you sure your M1 is on the network and responding?

zylantha commented 4 years ago

Thanks, but I'm now getting a different error (and it's still not starting):

(node:98381) UnhandledPromiseRejectionWarning: ReferenceError: assert is not defined at /opt/local/lib/node_modules/homebridge-elkm1/index.js:153:25 at runMicrotasks (<anonymous>) at processTicksAndRejections (internal/process/task_queues.js:97:5) (node:98381) 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: 1) (node:98381) [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.

My M1 is definitely on the network, I can control it with ElkRP2 as well as eK Pro on my phone.

paulw11 commented 4 years ago

This is as I suspected; A timeout is occurring when trying to retrieve the config from your M1. I have uploaded version 1.1.8 but I don't think it will make your M1 work in homebridge. This is the real problem; We need to understand why you are getting a timeout. Can you ping your M1 from the device running Homebridge? Can you telnet to it on port 2101?

zylantha commented 4 years ago

Yes I can telnet to port 2101, and it connects. I don't know the protocol it's using but I get stuff like - 1BSD00194Bike Shed 0099

and a bunch of other long strings. Maybe I can try an ethernet module reboot, it was working originally using essentially the same config I'm using, so I'm at a bit of a loss to explain why it's suddenly stopped - which happened when I did that upgrade, but that could be coincidence (since I'm in the process of doing some other M1 upgrades / changes at the moment as well).

I'm also getting another new error coming from 1.1.8 -

[9/10/2020, 8:59:54 AM] [ElkM1] Initializing ElkM1 platform... [9/10/2020, 8:59:54 AM] [ElkM1] Connection is not secure [9/10/2020, 8:59:54 AM] [ElkM1] Connecting to M1 [9/10/2020, 8:59:54 AM] [ElkM1] ***Connected*** [9/10/2020, 8:59:56 AM] [Config] Homebridge Config UI X v4.27.1 is listening on :: port 8080 [9/10/2020, 9:00:09 AM] [ElkM1] Error retrieving data from M1 panel [9/10/2020, 9:00:09 AM] [ElkM1] Timout occured before Text Description (sd) was received. (node:88515) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'forEach' of undefined at /opt/local/lib/node_modules/homebridge/src/server.ts:417:21 at /opt/local/lib/node_modules/homebridge/node_modules/hap-nodejs/src/lib/util/once.ts:10:18 at /opt/local/lib/node_modules/homebridge-elkm1/index.js:154:25 at runMicrotasks (<anonymous>) at processTicksAndRejections (internal/process/task_queues.js:97:5) (node:88515) 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: 1) (node:88515) [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.

paulw11 commented 4 years ago

I have updated to fix the crash on discovery failure, but it still won't address your underlying problem. What changes have you made to your M1? The error message says it is getting a timeout waiting for a response to the SD command which gets the description of an item in the M1 config.

zylantha commented 4 years ago

Thanks, this latest version now allows homebridge to start up at least, but you are correct - it still shows the error [9/11/2020, 12:30:59 AM] [ElkM1] Timout occured before Text Description (sd) was received.

The changes I made have been to add a new keypad (ELK-M1KAM) and associated door control outputs and zones, however the keypad was already in the system when I first installed homebridge-elkm1 only a few weeks ago.

Can we show more detailed output in the error message on which specific M1 config item it was trying to retrieve when it received the timeout?

paulw11 commented 4 years ago

Unfortunately that is difficult, because the timeout occurs in the elkmon module, not in my code. I have added some additional debug logging that will at least show how far through the startup process you are getting before the failure. You will need to enable "DEBUG" in the home bridge settings before you will see the messages