search

ronniepettersson / homebridge-remootio

Homebridge plugin for Remootio garage door openers
Apache License 2.0
8 stars 1 forks source link

Can't connect to the garage door #2

Closed DaveD-W closed 3 years ago

DaveD-W commented 3 years ago

Hi Ronnie,

Was very excited to see this and be able to add to Homekit, sadly it's not working for me though.

Adding it is fine, the sensor is installed, I'm on the right version (checked the firmware, no new versions to get either) and the API is on with logging.

On boot on homebridge it shows: [11/20/2020, 12:13:19 AM] [Remootio] [garage door] Connected Unexpected error - lastActionId is undefined

The unexpected error pops up a couple more times too (wasn't there before the plugin).

If I then try and run it through accessories in Homebridge, the logs update to show:

[11/20/2020, 12:21:23 AM] [Remootio] [garage door] setTargetStateHandler: New value: CLOSED Old value: undefined [11/20/2020, 12:21:23 AM] [Remootio] [garage door] Device is not connected

It shows as unresponsive in Apple Home

I see it periodically also try and reconnect in the logs when I'm not touching it, showing this:

[11/20/2020, 12:22:20 AM] [Remootio] [garage door] whoops! there was an error: No response for PING message in 30000 ms. Connection is broken. [11/20/2020, 12:22:21 AM] [Remootio] [garage door] Connected [11/20/2020, 12:23:08 AM] [Remootio] [garage door] setTargetStateHandler: New value: CLOSED Old value: undefined [11/20/2020, 12:23:08 AM] [Remootio] [garage door] Device is not connected

Any ideas on how to troubleshoot? It works fine via the internet setting in the Remootio App, it's a v2 Remootio unit.

Thanks, Dave.

ronniepettersson commented 3 years ago

Hi Dave,

This particular error ( lastActionId is undefined) seems to indicate that the remootio-api-client-node library has not yet fully authenticated the session, which could happen if one of the API keys is not configured properly.

Would you please turn on debugging in HomeBridge and post the resulting log output?

Thanks, Ronnie

DaveD-W commented 3 years ago

Hi Ronnie,

Debug enabled, rebooted Homebridge and got the following

[11/20/2020, 2:39:05 AM] [Remootio] [Garage Door] whoops! there was an error: No response for PING message in 30000 ms. Connection is broken. [11/20/2020, 2:39:05 AM] [Remootio] [Garage Door] Disconnected: undefined [11/20/2020, 2:39:05 AM] [Remootio] [Garage Door] Reconnecting [11/20/2020, 2:39:05 AM] [Remootio] [Garage Door] Connecting: undefined, attempt 1 [11/20/2020, 2:39:06 AM] [Remootio] [Garage Door] Connected [11/20/2020, 2:39:06 AM] [Remootio] [Garage Door] Outgoing: HELLO [11/20/2020, 2:39:06 AM] [Remootio] [Garage Door] Outgoing: AUTH [11/20/2020, 2:39:27 AM] [Remootio] [Garage Door] getTargetStateHandler: Target door state: [Closed] [11/20/2020, 2:39:27 AM] [Remootio] [Garage Door] ObstructionDetected was requested [11/20/2020, 2:39:27 AM] [Remootio] [Garage Door] getCurrentStateHandler: Current door state: [Closed] Unexpected error - lastActionId is undefined [11/20/2020, 2:39:31 AM] [Remootio] [Garage Door] setTargetStateHandler: New value: CLOSED Old value: undefined [11/20/2020, 2:39:31 AM] [Remootio] [Garage Door] Device is not connected [11/20/2020, 2:39:31 AM] [Remootio] [Garage Door] getTargetStateHandler: Target door state: [Closed] [11/20/2020, 2:39:33 AM] [Remootio] [Garage Door] getCurrentStateHandler: Current door state: [Closed] Unexpected error - lastActionId is undefined [11/20/2020, 2:39:33 AM] [Remootio] [Garage Door] getTargetStateHandler: Target door state: [Closed] [11/20/2020, 2:39:33 AM] [Remootio] [Garage Door] ObstructionDetected was requested

The not connected message is when I attempt to press the button within accessories.

When left alone, it seems to go through this cycle

[11/20/2020, 2:40:06 AM] [Remootio] [Garage Door] Outgoing: PING [11/20/2020, 2:40:06 AM] [Remootio] [Garage Door] Disconnected: undefined [11/20/2020, 2:40:06 AM] [Remootio] [Garage Door] Reconnecting [11/20/2020, 2:40:06 AM] [Remootio] [Garage Door] Connecting: undefined, attempt 1 [11/20/2020, 2:40:06 AM] [Remootio] [Garage Door] Connected [11/20/2020, 2:40:06 AM] [Remootio] [Garage Door] Outgoing: HELLO [11/20/2020, 2:40:06 AM] [Remootio] [Garage Door] Outgoing: AUTH [11/20/2020, 2:40:36 AM] [Remootio] [Garage Door] whoops! there was an error: No response for PING message in 30000 ms. Connection is broken. [11/20/2020, 2:40:36 AM] [Remootio] [Garage Door] Disconnected: undefined [11/20/2020, 2:40:36 AM] [Remootio] [Garage Door] Reconnecting [11/20/2020, 2:40:36 AM] [Remootio] [Garage Door] Connecting: undefined, attempt 1 [11/20/2020, 2:40:36 AM] [Remootio] [Garage Door] Connected [11/20/2020, 2:40:36 AM] [Remootio] [Garage Door] Outgoing: HELLO [11/20/2020, 2:40:36 AM] [Remootio] [Garage Door] Outgoing: AUTH [11/20/2020, 2:41:36 AM] [Remootio] [Garage Door] Outgoing: PING [11/20/2020, 2:41:36 AM] [Remootio] [Garage Door] Disconnected: undefined [11/20/2020, 2:41:36 AM] [Remootio] [Garage Door] Reconnecting [11/20/2020, 2:41:36 AM] [Remootio] [Garage Door] Connecting: undefined, attempt 1 [11/20/2020, 2:41:36 AM] [Remootio] [Garage Door] Connected [11/20/2020, 2:41:36 AM] [Remootio] [Garage Door] Outgoing: HELLO [11/20/2020, 2:41:36 AM] [Remootio] [Garage Door] Outgoing: AUTH

ronniepettersson commented 3 years ago

Dave, I am not seeing any incoming messages from the Remootio device. Are you sure you have the right IP address and API keys from the Remootio app? The debug output (in bold) should look something like this:

[11/19/2020, 7:43:26 AM] [Remootio] Remootio 2: Adding Remootio device to HomeKit with IP address 192.168.1.xxx. [11/19/2020, 7:43:26 AM] [Remootio] IP: 192.168.1.xxx [11/19/2020, 7:43:26 AM] [Remootio] SK: CDC6D71B8882E959A0CB8CD35E6DB9EE95BA36B33A9716A6C14A8F416D73D573 [11/19/2020, 7:43:26 AM] [Remootio] AK: 6438CDE2F2C48FF38DB34270632AAD6C476C8136390C75C799FF688EAB4B5687

[11/19/2020, 7:43:27 AM] [Remootio] [Remootio 2] Connected [11/19/2020, 7:43:27 AM] [Remootio] [Remootio 2] Outgoing: HELLO [11/19/2020, 7:43:27 AM] [Remootio] [Remootio 2] Outgoing: AUTH [11/19/2020, 7:43:28 AM] [Remootio] [Remootio 2] Incoming: SERVER_HELLO {"type":"SERVER_HELLO","apiVersion":2,"message":"This is the Remootio Websocket API","serialNumber":"2462abe6701xxxxxxxxxx","remootioVersion":"remootio-2"} [11/19/2020, 7:43:59 AM] [Remootio] [Remootio 2] Incoming: {"type":"CHALLENGE","challenge":{"sessionKey":"ojUdXR1RpeO+76izl42cc+G1vd4lprSmmmzRzcnbNT0=","initialActionId":1774569418}}

DaveD-W commented 3 years ago

Hi Ronnie,

It's all in there, this is from the config (just so you know I've saved it in the plugin.

Screenshot 2020-11-19 at 16 05 47 copy

Are there any other debug options to enable, other than just Homebridge Debug Mode ?

ronniepettersson commented 3 years ago

There is currently no other debug option that I know of.

Regardless, you should at least get a response from the device if the IP address is correct. So far, I have not seen any evidence of that. If you're using Homebridge UI, you could use the Terminal menu item and try to ping the device to confirm that Hombridge actually can reach it.

DaveD-W commented 3 years ago
Screenshot 2020-11-19 at 16 17 30

Seems to ping OK!

ronniepettersson commented 3 years ago

Can you connect with the Remootio app over wifi and see if you get anything on the debug output? I am getting the following:

[11/19/2020, 8:40:52 AM] [Remootio] [Remootio 2] Incoming: {"event":{"cnt":3,"type":"Connected","state":"closed","t100ms":3990,"data":{"keyNr":0,"keyType":"master key","via":"wifi"}}}

DaveD-W commented 3 years ago

Absolutely no different whether I'm on Wifi or Internet within the Remootio App - it didn't seem to notice a state change

Any other settings within your remootio app that might be worth me checking on mine?

ronniepettersson commented 3 years ago

I am not sure I can replicate your situation correctly. My Remootio 2 device is not properly programmed to be a Remootio 2, I came to find out. I am waiting for an update from Remootio to reprogram it. As soon as I have the proper firmware in the device, I will run the tests again and see if I can replicate your problem.

In the meanwhile, you could try to use wscat to see if you can get connected to it. Use it on the command line to see if you get a connection:

npm install wscat wscat -c ws://192.168.0.93:8080

DaveD-W commented 3 years ago

Hi Ronnie,

Sorry for the delay in coming back to you, got totally sidetracked!

WSCAT installed and that connects OK

wscat -c ws://192.168.0.93:8080 Connected (press CTRL+C to quit)

DaveD-W commented 3 years ago

more detail in the logs this time since the update you released:

[11/22/2020, 11:09:27 PM] Homebridge v1.2.3 is running on port 53167. [11/22/2020, 11:09:28 PM] [Remootio] [Garage Door] Connected [11/22/2020, 11:09:28 PM] [Remootio] [Garage Door] Outgoing: AUTH [11/22/2020, 11:09:28 PM] [Remootio] [Garage Door] Incoming: {"type":"CHALLENGE","challenge":{"sessionKey":"YssZIN7sP78DZHFjxMUTdJlhnsEDLaY8aUW+yv38s5E=","initialActionId":1594679198}} [11/22/2020, 11:09:28 PM] [Remootio] [Garage Door] Outgoing: ENCRYPTED [11/22/2020, 11:09:28 PM] [Remootio] [Garage Door] Incoming: {"response":{"type":"QUERY","id":1594679199,"success":true,"state":"closed","t100ms":232,"relayTriggered":false,"errorCode":""}} [11/22/2020, 11:09:28 PM] [Remootio] [Garage Door] Decrypted payload: QUERY [11/22/2020, 11:09:28 PM] [Remootio] [Garage Door] Authenticated [11/22/2020, 11:09:28 PM] [Remootio] [Garage Door] Outgoing: HELLO [11/22/2020, 11:09:28 PM] [Remootio] [Garage Door] Incoming: {"event":{"cnt":0,"type":"Restart","state":"open","t100ms":7}} [11/22/2020, 11:09:30 PM] [Remootio] [Garage Door] getCurrentStateHandler: Current door state: [Closed] [11/22/2020, 11:09:30 PM] [Remootio] [Garage Door] Outgoing: ENCRYPTED [11/22/2020, 11:09:30 PM] [Remootio] [Garage Door] getTargetStateHandler: Target door state: [Closed] [11/22/2020, 11:09:30 PM] [Remootio] [Garage Door] ObstructionDetected was requested [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] Disconnected: undefined [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] Reconnecting [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] Connecting: attempt 1 [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] Connected [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] Outgoing: AUTH [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] getCurrentStateHandler: Current door state: [Closed] [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] getTargetStateHandler: Target door state: [Closed] Unexpected error - lastActionId is undefined [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] ObstructionDetected was requested [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] Incoming: {"type":"CHALLENGE","challenge":{"sessionKey":"UkMYl04fyaNW6E76zbJgZZpkHK0QDrYDFEsvFlFVJ4o=","initialActionId":1405582127}} [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] Outgoing: ENCRYPTED [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] Incoming: {"response":{"type":"QUERY","id":1405582128,"success":true,"state":"closed","t100ms":50,"relayTriggered":false,"errorCode":""}} [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] Decrypted payload: QUERY [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] Authenticated [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] Outgoing: HELLO [11/22/2020, 11:09:34 PM] [Remootio] [Garage Door] Incoming: {"event":{"cnt":0,"type":"Restart","state":"open","t100ms":7}} [11/22/2020, 11:09:41 PM] [Remootio] [Garage Door] Disconnected: undefined [11/22/2020, 11:09:41 PM] [Remootio] [Garage Door] Reconnecting [11/22/2020, 11:09:41 PM] [Remootio] [Garage Door] Connecting: attempt 1 [11/22/2020, 11:09:41 PM] [Remootio] [Garage Door] Connected [11/22/2020, 11:09:41 PM] [Remootio] [Garage Door] Outgoing: AUTH [11/22/2020, 11:09:41 PM] [Remootio] [Garage Door] Incoming: {"type":"CHALLENGE","challenge":{"sessionKey":"x2v/g/hjwQWmy90tqZMsvz+HgCbO7o0mjNi1qS5HzDw=","initialActionId":108728513}} [11/22/2020, 11:09:41 PM] [Remootio] [Garage Door] Outgoing: ENCRYPTED [11/22/2020, 11:09:41 PM] [Remootio] [Garage Door] Incoming: {"response":{"type":"QUERY","id":108728514,"success":true,"state":"closed","t100ms":61,"relayTriggered":false,"errorCode":""}} [11/22/2020, 11:09:41 PM] [Remootio] [Garage Door] Decrypted payload: QUERY [11/22/2020, 11:09:41 PM] [Remootio] [Garage Door] Authenticated [11/22/2020, 11:09:41 PM] [Remootio] [Garage Door] Outgoing: HELLO [11/22/2020, 11:09:41 PM] [Remootio] [Garage Door] Incoming: {"event":{"cnt":0,"type":"Restart","state":"open","t100ms":6}} [11/22/2020, 11:10:00 PM] [Remootio] [Garage Door] setTargetStateHandler: New value: CLOSED Old value: undefined [11/22/2020, 11:10:00 PM] [Remootio] [Garage Door] Sending sendClose() [11/22/2020, 11:10:00 PM] [Remootio] [Garage Door] Outgoing: ENCRYPTED [11/22/2020, 11:10:00 PM] [Remootio] [Garage Door] getTargetStateHandler: Target door state: [Closed] [11/22/2020, 11:10:01 PM] [Remootio] [Garage Door] Disconnected: undefined [11/22/2020, 11:10:01 PM] [Remootio] [Garage Door] Reconnecting [11/22/2020, 11:10:01 PM] [Remootio] [Garage Door] Connecting: attempt 1 [11/22/2020, 11:10:01 PM] [Remootio] [Garage Door] Connected [11/22/2020, 11:10:01 PM] [Remootio] [Garage Door] Outgoing: AUTH [11/22/2020, 11:10:01 PM] [Remootio] [Garage Door] Incoming: {"type":"CHALLENGE","challenge":{"sessionKey":"LeYUrpTZxFXW5DczywMO88OTSddok19cQM0XpzdSsdQ=","initialActionId":1573330902}} [11/22/2020, 11:10:01 PM] [Remootio] [Garage Door] Outgoing: ENCRYPTED [11/22/2020, 11:10:01 PM] [Remootio] [Garage Door] Incoming: {"response":{"type":"QUERY","id":1573330903,"success":true,"state":"closed","t100ms":189,"relayTriggered":false,"errorCode":""}} [11/22/2020, 11:10:01 PM] [Remootio] [Garage Door] Decrypted payload: QUERY [11/22/2020, 11:10:01 PM] [Remootio] [Garage Door] Authenticated [11/22/2020, 11:10:01 PM] [Remootio] [Garage Door] Outgoing: HELLO [11/22/2020, 11:10:01 PM] [Remootio] [Garage Door] Incoming: {"event":{"cnt":0,"type":"Restart","state":"open","t100ms":6}} [11/22/2020, 11:10:02 PM] [Remootio] [Garage Door] getCurrentStateHandler: Current door state: [Closed] [11/22/2020, 11:10:02 PM] [Remootio] [Garage Door] Outgoing: ENCRYPTED [11/22/2020, 11:10:02 PM] [Remootio] [Garage Door] getTargetStateHandler: Target door state: [Closed] [11/22/2020, 11:10:02 PM] [Remootio] [Garage Door] ObstructionDetected was requested [11/22/2020, 11:10:08 PM] [Remootio] [Garage Door] Disconnected: undefined [11/22/2020, 11:10:08 PM] [Remootio] [Garage Door] Reconnecting [11/22/2020, 11:10:08 PM] [Remootio] [Garage Door] Connecting: attempt 1 [11/22/2020, 11:10:08 PM] [Remootio] [Garage Door] Connected [11/22/2020, 11:10:08 PM] [Remootio] [Garage Door] Outgoing: AUTH [11/22/2020, 11:10:08 PM] [Remootio] [Garage Door] Incoming: {"type":"CHALLENGE","challenge":{"sessionKey":"Kppthqe/iOgHNtmOkChi7/iXY1ijQnWCH/quayGIADU=","initialActionId":791325813}} [11/22/2020, 11:10:08 PM] [Remootio] [Garage Door] Outgoing: ENCRYPTED [11/22/2020, 11:10:08 PM] [Remootio] [Garage Door] Incoming: {"response":{"type":"QUERY","id":791325814,"success":true,"state":"closed","t100ms":63,"relayTriggered":false,"errorCode":""}} [11/22/2020, 11:10:08 PM] [Remootio] [Garage Door] Decrypted payload: QUERY [11/22/2020, 11:10:08 PM] [Remootio] [Garage Door] Authenticated [11/22/2020, 11:10:08 PM] [Remootio] [Garage Door] Outgoing: HELLO [11/22/2020, 11:10:08 PM] [Remootio] [Garage Door] Incoming: {"event":{"cnt":0,"type":"Restart","state":"open","t100ms":6}}

ronniepettersson commented 3 years ago

Dave, it appear that your Remootio device reboots every time it receives the HELLO message. That should not happen. You could try to reset the device to factory default and re-install the latest firmware. If that does not help, we should get in contact with the Remootio support team.

DaveD-W commented 3 years ago

Thanks Ronnie, I'll give that a go.

It's always quite slow to connect in the app, I just assumed that was normal.

DaveD-W commented 3 years ago

Restart did nothing. Now you've flagged up what's happening, makes sense with some of the odd behaviour in the app, for example when re-enabling the API after resetting it, it dropped out in the middle of doing that!

Messaging Remootio now, will see what suggestions they've got, hopefully a quick swap out :) - thanks for all your help so far, it'll be brilliant to be able to use this in Homebridge :)

ronniepettersson commented 3 years ago

Dave, if you are able to modify the remootio-accessory.ts file in your setup, I can give you a one-line change to remove the sendHello message, to see if it's specifically that API call that is causing your device to reboot.

Comment out line 232: from this.device.sendHello(); to // this.device.sendHello();

DaveD-W commented 3 years ago

Hi Ronnie,

I can't find that file, this is the closest I got to it:

index.d.ts index.js.map platform.js remootio-accessory.d.ts.map remootio-types.d.ts remootio-types.js.map settings.js index.d.ts.map platform.d.ts platform.js.map remootio-accessory.js remootio-types.d.ts.map settings.d.ts settings.js.map index.js platform.d.ts.map remootio-accessory.d.ts remootio-accessory.js.map remootio-types.js settings.d.ts.map

That's within the dist folder, it's a docker install of Homebridge I'm running, anywhere in particular for me to check?

Thanks, Dave.

ronniepettersson commented 3 years ago

Didn't think of it, but he typescript files are converted to javascript when I publish it..... The resulting file is /dist/remootio-accessory.js Simply comment out line 101
// this.device.sendHello();

DaveD-W commented 3 years ago

Ronnie...

Removing that line has made it work!!!

The garage door now opens and closes via Home - amazing :)

ronniepettersson commented 3 years ago

Great. The problem is still there, but this is at least a work around. I'll release an updated version with the workaround until Remootio has a fix.

DaveD-W commented 3 years ago

Do you think it's a firmware thing, rather than a hardware issue then?

Just wondering whether I need to tell them not to worry about my email :)

ronniepettersson commented 3 years ago

It is likely a firmware issue that they should investigate.

ronniepettersson commented 3 years ago

v1.2.2 temporarily fixes this issue.

DaveD-W commented 3 years ago

Thanks for all your help Ronnie, I'll reply to my email to Remootio (they didn't get back to me yet..) and tell them it's firmware, rather than hardware.

ronniepettersson commented 3 years ago

You are welcome. Happy to help.

Why don't you also create an issue on their github project remootio-api-client-node, as this is the library that is actually sending the Hello message to the device.

DaveD-W commented 3 years ago

Done! - https://github.com/remootio/remootio-api-client-node/issues/1

Feel free to stick in whatever comments you might think would be helpful to them, thanks again :)

remootio commented 3 years ago

Hello Ronnie and Dave,

Thank you for troubleshooting the issue. I can confirm that this is indeed a firmware bug which will be fixed in the Remootio firmware v2.22 soon.

DaveD-W commented 3 years ago

Thanks @remootio and @ronniepettersson - lovely bit of work :)