vanackej / risco-mqtt-local

Provide Risco alarm system integration to Home assistant using local TCP communication (no cloud required) and MQTT
MIT License
24 stars 11 forks source link

Restart needed on cloud disconnect #57

Open pergolafabio opened 1 year ago

pergolafabio commented 1 year ago

Describe the bug Hi @vanackej , using the addon with cloud proxy method... Yesteday i had a small internet interrupt, but after internet was restored, the addon was not able to connect to cloud anymore, i had to restart the addon to make it functional... It possible on this type of event as in screenshot, that the service can be restarted? I had watchdog enabled, but that doesnt help, since addon keeps on running

Thnx in advance

Configuration

Logs

I only have a screenshot: Screenshot_20230227-064843

pergolafabio commented 11 months ago

You indeed receive other errors then me, I dont see my entries going to unavailable, the only "errors" I see are the timeouts, but they are normal as in this post:

https://github.com/vanackej/risco-mqtt-local/issues/57#issuecomment-1779086178

pergolafabio commented 11 months ago

How did you configure the proxy? Did you change your panel to connect to the addon? Or did you create an pre routing on your router to forward outgoing traffic to the addon?

bugzke commented 11 months ago

Cloud IP on my panel is set to the local IP of my HA instance where the add-on runs. My router isn't fancy enough :-)

markxroberts commented 11 months ago

It looks as though you're seeing cloud socket timeouts. The cloud socket timeout is 2 minutes. The cloud socket seems to be closing but from the logs provided it's possible this is sooner than 2 minutes. Can you send a debug log, please? The system will also go offline when no clock signal is received for 60 seconds.

bugzke commented 11 months ago

This is what I got from the debug log. Is there any way to see/ older log entries? Where is the file stored?

Connection went down on 8:58:33, noticed it right away because of an automation alert I set, this is what I got (but perhaps useful entry from right before is missing):

11/18/2023, 8:58:33 PM [info] [Panel => MQTT] Panel not communicating properly.  Panel offline
11/18/2023, 8:58:33 PM [info] [RML] Proxy server not communicating.
11/18/2023, 8:58:33 PM [verbose] [Panel => MQTT] Published proxy connection status offline
11/18/2023, 8:58:33 PM [info] [RML] TCP Socket disconnected
11/18/2023, 8:58:33 PM [info] [MQTT => Panel] Socket listeners removed
11/18/2023, 8:58:33 PM [info] [RML] Error received CommsError, Socket Disconnected
11/18/2023, 8:58:33 PM [info] [Panel => MQTT] Panel not communicating properly.  Panel offline
11/18/2023, 8:58:33 PM [info] [RML] Proxy server not communicating.
11/18/2023, 8:58:33 PM [verbose] [Panel => MQTT] Published proxy connection status offline
11/18/2023, 8:58:33 PM [info] [RML] TCP Socket disconnected
11/18/2023, 8:58:33 PM [info] [MQTT => Panel] Socket listeners removed
11/18/2023, 8:58:33 PM [info] [RML] Error received CommsError, Socket Disconnected
11/18/2023, 8:58:33 PM [info] [Panel => MQTT] Panel not communicating properly.  Panel offline
11/18/2023, 8:58:33 PM [info] [RML] Proxy server not communicating.
11/18/2023, 8:58:33 PM [verbose] [Panel => MQTT] Published proxy connection status offline
11/18/2023, 8:58:33 PM [info] [RML] TCP Socket disconnected
11/18/2023, 8:58:33 PM [info] [MQTT => Panel] Socket listeners removed
11/18/2023, 8:58:33 PM [info] [RML] Error received CommsError, Socket Disconnected
11/18/2023, 8:58:33 PM [info] [Panel => MQTT] Panel not communicating properly.  Panel offline
11/18/2023, 8:58:33 PM [info] [RML] Proxy server not communicating.
11/18/2023, 8:58:33 PM [verbose] [Panel => MQTT] Published proxy connection status offline
11/18/2023, 8:58:33 PM [info] [RML] TCP Socket disconnected
11/18/2023, 8:58:33 PM [info] [MQTT => Panel] Socket listeners removed
11/18/2023, 8:58:33 PM [info] [RML] Error received CommsError, Socket Disconnected
11/18/2023, 8:58:33 PM [info] [Panel => MQTT] Panel not communicating properly.  Panel offline
11/18/2023, 8:58:33 PM [info] [RML] Proxy server not communicating.
11/18/2023, 8:58:33 PM [verbose] [Panel => MQTT] Published proxy connection status offline
11/18/2023, 8:58:33 PM [info] [RML] TCP Socket disconnected
11/18/2023, 8:58:33 PM [info] [MQTT => Panel] Socket listeners removed
11/18/2023, 8:58:33 PM [info] Automatic reconnection will be attempted in 10000 ms
11/18/2023, 8:58:33 PM [verbose] [Panel => MQTT] Published alarm offline
11/18/2023, 8:58:33 PM [info] [RML] Proxy server not communicating.
11/18/2023, 8:58:33 PM [verbose] [Panel => MQTT] Published proxy connection status offline
11/18/2023, 8:58:38 PM [debug] Socket Destroyed.
11/18/2023, 8:58:43 PM [verbose] Start Connection to Panel
11/18/2023, 8:58:43 PM [debug] A TCP Socket already exists, clearing its listeners before creating a new one
11/18/2023, 8:58:43 PM [info] [RML] Error received CommsError, New socket being connected
11/18/2023, 8:58:43 PM [info] [Panel => MQTT] Panel not communicating properly.  Panel offline
11/18/2023, 8:58:43 PM [info] [RML] Proxy server not communicating.
11/18/2023, 8:58:43 PM [verbose] [Panel => MQTT] Published proxy connection status offline
11/18/2023, 8:58:43 PM [info] [RML] TCP Socket disconnected, new socket being connected.  Ensure old listeners removed.
11/18/2023, 8:58:43 PM [info] [RML] Error received CommsError, New socket being connected
11/18/2023, 8:58:43 PM [info] [Panel => MQTT] Panel not communicating properly.  Panel offline
11/18/2023, 8:58:43 PM [info] [RML] Proxy server not communicating.
11/18/2023, 8:58:43 PM [verbose] [Panel => MQTT] Published proxy connection status offline
11/18/2023, 8:58:43 PM [info] [RML] TCP Socket disconnected, new socket being connected.  Ensure old listeners removed.
11/18/2023, 8:58:43 PM [info] [RML] Error received CommsError, New socket being connected
11/18/2023, 8:58:43 PM [info] [Panel => MQTT] Panel not communicating properly.  Panel offline
11/18/2023, 8:58:43 PM [info] [RML] Proxy server not communicating.
11/18/2023, 8:58:43 PM [verbose] [Panel => MQTT] Published proxy connection status offline
11/18/2023, 8:58:43 PM [info] [RML] TCP Socket disconnected, new socket being connected.  Ensure old listeners removed.
11/18/2023, 8:58:43 PM [info] [RML] Error received CommsError, New socket being connected
11/18/2023, 8:58:43 PM [info] [Panel => MQTT] Panel not communicating properly.  Panel offline
11/18/2023, 8:58:43 PM [info] [RML] Proxy server not communicating.
11/18/2023, 8:58:43 PM [verbose] [Panel => MQTT] Published proxy connection status offline
11/18/2023, 8:58:43 PM [info] [RML] TCP Socket disconnected, new socket being connected.  Ensure old listeners removed.
11/18/2023, 8:58:43 PM [info] [RML] Error received CommsError, New socket being connected
11/18/2023, 8:58:43 PM [info] [Panel => MQTT] Panel not communicating properly.  Panel offline
11/18/2023, 8:58:43 PM [info] [RML] Proxy server not communicating.
11/18/2023, 8:58:43 PM [verbose] [Panel => MQTT] Published proxy connection status offline
11/18/2023, 8:58:43 PM [info] [RML] TCP Socket disconnected, new socket being connected.  Ensure old listeners removed.
11/18/2023, 8:58:43 PM [info] [RML] Error received CommsError, New socket being connected
11/18/2023, 8:58:43 PM [info] [Panel => MQTT] Panel not communicating properly.  Panel offline
11/18/2023, 8:58:43 PM [info] [RML] Proxy server not communicating.
11/18/2023, 8:58:43 PM [verbose] [Panel => MQTT] Published proxy connection status offline
11/18/2023, 8:58:43 PM [info] [RML] TCP Socket disconnected, new socket being connected.  Ensure old listeners removed.
11/18/2023, 8:58:43 PM [debug] Pseudo Buffer Created for Panel Id(1)
11/18/2023, 8:58:43 PM [debug] TCP Socket created
11/18/2023, 8:58:43 PM [info] Listening on IP :: and Port 33000
11/18/2023, 8:58:43 PM [info] Waiting for panel incoming connection... This can take up to 1 or 2 minutes
11/18/2023, 8:58:43 PM [debug] RiscoCloud Socket: connect
11/18/2023, 8:58:43 PM [info] RiscoCloud Socket: ready
11/18/2023, 8:58:54 PM [info] Incoming connection from panel received
11/18/2023, 8:58:54 PM [debug] RiscoCloud Socket: connect
11/18/2023, 8:58:54 PM [info] RiscoCloud Socket: ready
11/18/2023, 8:58:54 PM [info] Setting a timer for panel connection in 30000 ms
11/18/2023, 8:58:54 PM [debug] [Panel => Cloud] Forwarding panel packet to cloud: [2,19,55,49,4,121,0,10,0,11,0,0,21,128,0,16,3,0,0,4,4,88,32,35,17,24,0,0,7,0,0,0,0,0,0,1,7,0,0,0,0,0,0,0,16,3,7,0,0,0,0,0,0,0,4,7,0,0,0,0,0,0,0,5,12,0,0,0,0,0,0,0,0,0,0,0,0,7,11,0,0,0,0,0,0,0,0,0,0,0,8,7,0,0,0,0,0,0,0,9,11,0,0,0,0,0,0,0,0,0,0,0,11,4,0,0,0,0,12,4,16,3,0,0,0,13,4,15,0,0,0,23,53,48,69,50,3]
11/18/2023, 8:58:54 PM [debug] [Cloud => Panel] Forwarding Cloud data Buffer to panel: [2,19,55,49,0,16,2,0,10,253,23,54,54,55,66,3]
11/18/2023, 8:58:54 PM [debug] [Panel => Cloud] Forwarding panel packet to cloud: [2,19,55,49,4,121,0,10,0,11,0,0,21,128,0,16,3,0,0,4,4,88,32,35,17,24,0,0,7,0,0,0,0,0,0,1,7,0,0,0,0,0,0,0,16,3,7,0,0,0,0,0,0,0,4,7,0,0,0,0,0,0,0,5,12,0,0,0,0,0,0,0,0,0,0,0,0,7,11,0,0,0,0,0,0,0,0,0,0,0,8,7,0,0,0,0,0,0,0,9,11,0,0,0,0,0,0,0,0,0,0,0,11,4,0,0,0,0,12,4,16,3,0,0,0,13,4,15,0,0,0,23,53,48,69,50,3]
11/18/2023, 8:58:54 PM [debug] [Cloud => Panel] Forwarding Cloud data Buffer to panel: [2,19,55,49,0,16,2,0,10,253,23,54,54,55,66,3]
11/18/2023, 8:58:54 PM [debug] [Panel => Cloud] Forwarding panel packet to cloud: [2,19,55,50,4,81,0,16,3,0,51,48,48,53,48,49,53,50,50,48,48,32,32,32,32,32,66,66,66,66,66,66,32,32,32,32,32,32,32,32,32,32,0,0,23,23,69,76,5,40,1,255,255,255,255,255,255,50,16,2,49,0,0,0,0,6,255,32,239,8,0,0,16,2,15,49,57,50,46,49,54,56,46,48,48,48,46,49,48,48,1,23,53,69,53,69,3]
11/18/2023, 8:58:54 PM [debug] [Cloud => Panel] Forwarding Cloud data Buffer to panel: [2,19,55,50,0,9,0,16,3,0,84,88,32,35,17,24,16,3,23,50,48,51,50,3,2,19,48,48,4,16,3,0,10,0,255,23,51,48,49,65,3]
11/18/2023, 8:58:54 PM [debug] [Panel => Cloud] Forwarding panel packet to cloud: [2,19,48,48,4,121,0,10,0,11,0,0,21,128,0,16,3,0,0,16,3,88,88,32,35,17,24,0,0,7,0,0,0,0,0,0,1,7,0,0,0,0,0,0,0,16,3,7,0,0,0,0,0,0,0,4,7,0,0,0,0,0,0,0,5,12,0,0,0,0,0,0,0,0,0,0,0,0,7,11,0,0,0,0,0,0,0,0,0,0,0,8,7,0,0,0,0,0,0,0,9,11,0,0,0,0,0,0,0,0,0,0,0,11,4,0,0,0,0,12,4,16,3,0,0,0,13,4,15,0,0,0,23,67,48,53,55,3]
11/18/2023, 8:58:54 PM [debug] [Cloud => Panel] Forwarding Cloud data Buffer to panel: [2,19,48,48,0,16,2,0,10,0,23,68,48,54,65,3,2,19,48,48,0,9,0,16,3,0,84,88,32,35,17,24,16,3,23,69,48,55,54,3]
11/18/2023, 8:58:57 PM [debug] [Cloud => Panel] Forwarding Cloud data Buffer to panel: [2,19,48,48,0,5,0,4,0,120,0,0,23,48,69,54,48,3]
11/18/2023, 8:58:57 PM [debug] [Panel => Cloud] Forwarding panel packet to cloud: [2,19,55,51,0,214,0,5,0,16,2,16,16,0,4,0,80,111,111,114,116,32,103,97,114,97,103,101,32,32,32,32,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,1,68,101,117,114,32,98,101,114,103,105,110,103,32,32,32,32,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,16,2,68,101,117,114,32,103,97,114,97,103,101,32,32,32,32,32,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,16,3,76,105,118,105,110,103,32,97,99,104,116,101,114,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,23,57,67,69,56,3]
11/18/2023, 8:58:57 PM [debug] [Panel => Cloud] Forwarding panel packet to cloud: [2,19,55,52,0,214,0,5,0,16,2,16,16,4,4,4,76,105,118,105,110,103,32,122,105,106,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,5,75,101,117,107,101,110,32,114,97,97,109,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,6,86,111,111,114,100,101,117,114,32,32,32,32,32,32,32,32,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,8,83,108,107,32,49,32,114,97,97,109,32,76,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,23,55,65,52,50,3]
11/18/2023, 8:58:57 PM [debug] [Panel => Cloud] Forwarding panel packet to cloud: [2,19,55,53,0,214,0,5,0,16,2,16,16,8,4,10,82,97,97,109,32,98,97,100,107,97,109,101,114,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,12,83,108,107,32,51,32,114,97,97,109,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,13,87,99,32,114,97,97,109,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,15,83,108,107,32,50,32,114,97,97,109,32,76,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,23,55,69,57,53,3]
11/18/2023, 8:58:57 PM [debug] [Panel => Cloud] Forwarding panel packet to cloud: [2,19,55,54,4,214,0,5,0,16,2,16,16,12,4,16,16,68,101,116,46,32,108,105,118,105,110,103,32,32,32,32,32,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,17,68,101,116,46,32,103,97,114,97,103,101,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,22,66,105,110,110,101,110,115,105,114,101,110,101,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,23,66,117,105,116,101,110,115,105,114,101,110,101,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,1,23,65,66,50,69,3]
11/18/2023, 8:58:57 PM [debug] [Cloud => Panel] Forwarding Cloud data Buffer to panel: [2,19,55,54,0,16,2,0,5,0,23,51,53,55,68,3]
11/18/2023, 8:58:57 PM [debug] [Panel => Cloud] Forwarding panel packet to cloud: [2,19,55,55,4,56,0,5,0,4,1,0,1,0,68,86,69,32,83,101,114,118,105,99,101,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,23,48,56,54,50,3]
11/18/2023, 8:58:58 PM [debug] [Cloud => Panel] Forwarding Cloud data Buffer to panel: [2,19,55,55,0,16,2,0,5,0,23,70,53,54,68,3]
11/18/2023, 8:58:58 PM [debug] [Panel => Cloud] Forwarding panel packet to cloud: [2,19,55,56,0,222,0,5,0,1,6,0,4,0,71,114,97,110,100,32,77,97,115,116,101,114,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,8,24,104,170,1,1,75,114,105,115,116,101,108,32,32,32,32,32,32,32,32,32,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,16,3,115,21,170,1,16,2,77,73,67,72,65,69,76,32,72,65,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,16,3,1,131,170,1,16,3,83,71,87,32,32,32,32,32,32,32,32,32,32,32,32,32,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,16,3,70,39,170,1,23,55,55,69,69,3]
11/18/2023, 8:58:58 PM [debug] [Panel => Cloud] Forwarding panel packet to cloud: [2,19,55,57,4,114,0,5,0,1,6,4,16,2,30,73,110,115,116,97,108,108,97,116,101,117,114,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,9,120,105,170,1,31,79,110,100,101,114,73,110,115,116,97,108,108,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,10,25,69,170,1,23,48,65,50,54,3]
11/18/2023, 8:58:58 PM [debug] [Cloud => Panel] Forwarding Cloud data Buffer to panel: [2,19,55,57,0,16,2,0,5,0,23,51,53,56,50,3]
11/18/2023, 8:58:58 PM [debug] [Panel => Cloud] Forwarding panel packet to cloud: [2,19,56,48,4,6,0,5,0,16,3,0,0,0,23,69,54,48,49,3]
11/18/2023, 8:58:58 PM [debug] [Cloud => Panel] Forwarding Cloud data Buffer to panel: [2,19,56,48,0,16,2,0,5,0,23,55,53,53,66,3]
11/18/2023, 8:58:59 PM [error] RiscoCloud Socket: closed
11/18/2023, 8:59:01 PM [debug] [Panel => Cloud] Forwarding panel packet to cloud: [2,19,56,49,4,121,0,10,0,11,0,0,21,128,0,16,3,0,0,16,3,5,89,32,35,17,24,0,0,7,0,0,0,0,0,0,1,7,0,0,0,0,0,0,0,16,3,7,0,0,0,0,0,0,0,4,7,0,0,0,0,0,0,0,5,12,0,0,0,0,0,0,0,0,0,0,0,0,7,11,0,0,0,0,0,0,0,0,0,0,0,8,7,0,0,0,0,0,0,0,9,11,0,0,0,0,0,0,0,0,0,0,0,11,4,0,0,0,0,12,4,16,3,0,0,0,13,4,15,0,0,0,23,50,56,69,65,3]
11/18/2023, 8:59:01 PM [debug] [Cloud => Panel] Forwarding Cloud data Buffer to panel: [2,19,56,49,0,16,2,0,10,0,23,66,54,55,66,3,2,19,56,49,0,9,0,16,3,0,1,89,32,35,17,24,16,3,23,69,52,65,66,3]
pergolafabio commented 11 months ago

On the addon page itself at the top there is a download button to download full log .. You can also do it from ssh container with docker commands, to download log to a file

bugzke commented 11 months ago

From the HA interface I only can get the limited log, even when using the "download full log" button. But found the complete log by accessing the add-on via Portainer.

In attachment hopefully something useful! risco-log.txt

markxroberts commented 11 months ago

Thanks for additional information. This is really hard to debug. The panel connection is probably still working at the start, but the cloud socket just closes.

11/19/2023, 2:23:09 AM [verbose] Command[4] Received data: CLOCK=19/11/2023 02:23, crcOk: true
11/19/2023, 2:23:09 AM [debug] Command[4] Command response from Panel
11/19/2023, 2:23:09 AM [debug] Command[4] Emitting expected command response
11/19/2023, 2:23:09 AM [debug] Command[4] Data type: Clock
11/19/2023, 2:23:09 AM [verbose] [Panel => MQTT] Published alarm online
11/19/2023, 2:23:09 AM [verbose] [Panel => MQTT] Published proxy connection status online
11/19/2023, 2:23:09 AM [debug] Command[4] command response : CLOCK=19/11/2023 02:23
11/19/2023, 2:23:15 AM [info] [RML] Error received SocketError, RiscoCloud socket closed

This is processed through the underlying risco-lan-bridge library, which initiates an automatic reconnection.

11/19/2023, 2:23:15 AM [debug] Command[5] crcOK : true, Computed CRC : F91A, Message CRC: F91A
11/19/2023, 2:23:15 AM [verbose] Command[5] Received data: ACK, crcOk: true

Panel connection is OK at this point, but because a disconnection signal is then sent, the whole thing goes down. There's then a reinitiation of the connection

11/19/2023, 2:23:25 AM [debug] TCP Socket created

The panel socket is then separately disconnected

11/19/2023, 2:23:39 AM [error] Panel Socket Closed.

Everything then takes another 2 minutes to reinitiate.

11/19/2023, 2:26:26 AM [verbose] System initialization completed.
bugzke commented 11 months ago

Would it make sense to test the add-on in direct mode and see what happens? Or is it the same as the core HA integration? (no disconnects when using the integration)

markxroberts commented 11 months ago

The core integration is completely reworked in Python, so it may be worth trying the direct mode. The other thing you could do is to try @vanackej's integration and see whether you get the same errors with that. I have made quite a few changes to the libraries, so it's possible that some of my changes have caused the problem.

bugzke commented 11 months ago

Switched to direct mode yesterday, no disconnects so far. Will monitor further, and will also test proxy mode with the original add-on.

bugzke commented 11 months ago

Issue also present in proxy mode on the original addon. Direct mode on both versions is ok.

markxroberts commented 11 months ago

Have you tried setting panelConnectionDelay and cloudConnectionDelay options? The defaults are 30 seconds and 5 seconds. It may perhaps be worth making cloud connection delay a bit longer. I've looked at this a few times and wondered whether some of the problem relates to the socket trying to reconnect before it has properly disconnected.

bugzke commented 11 months ago

I tried cloudConnectionDelay with default as well as on 10 seconds, with no difference. Will try playing a bit around with these values and see if it gets better or worse.

bugzke commented 11 months ago

Might be on to something!

current settings: "cloudConnectionDelay": 3000, "panelConnectionDelay": 10000,

no disconnects for the last 12 hours...

pergolafabio commented 11 months ago

Cool! Do you see any other errors like me that I posted on my last reply? For me everything is stable , I just see those errors...

Gonna try your config too.. if those error disappear, maybe they can be set as default on future release

bugzke commented 11 months ago

I've noticed an error about an hour ago, but only visible in the logs, no impact on my entities.

11/24/2023, 7:57:44 AM [info] [RML] Error received SocketError, Cloud socket timeout 11/24/2023, 7:57:44 AM [info] [RML] Error not processed. 11/24/2023, 7:57:44 AM [error] RiscoCloud Socket Timeout.

pergolafabio commented 11 months ago

Yeah, i see those too, no impact tough, how frequent do you see those?

I only have this below, no panelconnectiondelay, dont think its needed? But gonna try now your settings

"cloudConnectionDelay": 10000,


11/23/2023, 10:24:50 PM [info] [RML] Error received SocketError, Cloud socket timeout
11/23/2023, 10:24:50 PM [info] [RML] Panel or cloud not communicating properly.
11/23/2023, 10:24:50 PM [info] [RML] Error not processed.
11/23/2023, 10:24:50 PM [error] RiscoCloud Socket Timeout.
11/23/2023, 10:30:50 PM [info] [RML] Error received SocketError, Cloud socket timeout
11/23/2023, 10:30:50 PM [info] [RML] Panel or cloud not communicating properly.
11/23/2023, 10:30:50 PM [info] [RML] Error not processed.
11/23/2023, 10:30:50 PM [error] RiscoCloud Socket Timeout.
11/23/2023, 10:36:50 PM [info] [RML] Error received SocketError, Cloud socket timeout
11/23/2023, 10:36:50 PM [info] [RML] Panel or cloud not communicating properly.
11/23/2023, 10:36:50 PM [info] [RML] Error not processed.
11/23/2023, 10:36:50 PM [error] RiscoCloud Socket Timeout.
11/23/2023, 11:09:17 PM [info] [RML] Error received SocketError, Cloud socket timeout
11/23/2023, 11:09:17 PM [info] [RML] Panel or cloud not communicating properly.
11/23/2023, 11:09:17 PM [info] [RML] Error not processed.
11/23/2023, 11:09:17 PM [error] RiscoCloud Socket Timeout.
11/23/2023, 11:43:17 PM [info] [RML] Error received SocketError, Cloud socket timeout
11/23/2023, 11:43:17 PM [info] [RML] Panel or cloud not communicating properly.
11/23/2023, 11:43:17 PM [info] [RML] Error not processed.
11/23/2023, 11:43:17 PM [error] RiscoCloud Socket Timeout.
11/24/2023, 12:39:16 AM [info] [RML] Error received SocketError, Cloud socket timeout
11/24/2023, 12:39:16 AM [info] [RML] Panel or cloud not communicating properly.
11/24/2023, 12:39:16 AM [info] [RML] Error not processed.
11/24/2023, 12:39:16 AM [error] RiscoCloud Socket Timeout.
11/24/2023, 12:45:16 AM [info] [RML] Error received SocketError, Cloud socket timeout
11/24/2023, 12:45:16 AM [info] [RML] Panel or cloud not communicating properly.
11/24/2023, 12:45:16 AM [info] [RML] Error not processed.
bugzke commented 11 months ago

Nooo, alarm just disconnected 😞 But it took a lot longer than before, so I'll try some more tweaking with the values

pergolafabio commented 11 months ago

you tried this one?

"cloudConnectionDelay": 10000,

bugzke commented 11 months ago

Yes, that value gives daily multiple disconnects. Only noticable improvement is lowering the value below the defaults.

pergolafabio commented 11 months ago

Still getting below, but it doesnt impact, but seem the connectiondelay setting 3000 or 10000 doesnt make any difference

11/24/2023, 10:15:17 AM [info] [RML] Error received SocketError, Cloud socket timeout
11/24/2023, 10:15:17 AM [info] [RML] Panel or cloud not communicating properly.
11/24/2023, 10:15:17 AM [info] [RML] Error not processed.
11/24/2023, 10:15:17 AM [error] RiscoCloud Socket Timeout.
11/24/2023, 10:19:17 AM [info] [RML] Error received SocketError, Cloud socket timeout
11/24/2023, 10:19:17 AM [info] [RML] Panel or cloud not communicating properly.
11/24/2023, 10:19:17 AM [info] [RML] Error not processed.
11/24/2023, 10:19:17 AM [error] RiscoCloud Socket Timeout.
11/24/2023, 10:41:17 AM [info] [RML] Error received SocketError, Cloud socket timeout
11/24/2023, 10:41:17 AM [info] [RML] Panel or cloud not communicating properly.
11/24/2023, 10:41:17 AM [info] [RML] Error not processed.
11/24/2023, 10:41:17 AM [error] RiscoCloud Socket Timeout.
markxroberts commented 10 months ago

Timeouts are ok as the connection doesn’t close. I think it likely that different setups will need different values as everyone’s connections are different. It might perhaps be helpful to offer the values that work for each of your setups, and to describe the setup too.

bugzke commented 10 months ago

Still looking for the perfect value. CloudConnectionDelay doesn't seem to have a real impact, PanelConnectionDelay does. Went from 6 daily disconnects to 2 by lowering the value. Not been able to completely eliminate the disconnects yet.

I have a Risco LightSys/RP432, Firmware: 5.28

Fixed IP set on the panel. Cloud enabled to be able to use the proxy. Not actually using RiscoCloud itself (didn't pay the subscription), only need for the proxy is avoiding issues because of the 1-connection TCP module (NTP and follow-me don't function when connected directly to Home Assistant).

pergolafabio commented 10 months ago

What doesn't work with follow me when direct connected??

bugzke commented 10 months ago

Text messages don't get sent. As soon as the integration is stopped or I shut down HA the entire queue of messages is sent. So seems direct connection (the integration or direct mode on the add-on) blocks all other outgoing communication like SMS or NTP.

That's the only reason I'm trying to use proxy now.

pergolafabio commented 10 months ago

Ah, thats strange that SmS doesn't work either, good to know, then i stick with the proxy

bugzke commented 10 months ago

@markxroberts unfortunately I'm not able to eliminate all the disconnects. Even brought the panelConnectionDelay back to 0, but still having about 2 disconnects per day. Which is a lot better than with the default values, but still not solved. Any ideas what else I can try? Other settings that might have an effect on this?

markxroberts commented 10 months ago

I don't have any immediate suggestions. Can you post the latest log with the disconnects, please, and I'll try to find some time to look at this.

bugzke commented 10 months ago

_addon_1318033d_risco-mqtt-local-addon_logs (3).txt

In attachment log from 12/5/2023, 9:18:00 PM -> 12/5/2023, 9:36:55 PM Two disconnects occured during that period: the first at 21:20:33 and a second one at 21:35:33

markxroberts commented 10 months ago

Each of your disconnects is preceded by a socket timeout, so it may help to change the timeout. I've made a couple more configurable options. The default socket timeout is 120000 ms (2 mins). The second option is to 'keepAlive' the connection. I don't know what this will do as we've never tried it before! The default is off. For your configuration file the options are (in the panel section):

bugzke commented 10 months ago

Very nice, will test asap!

bugzke commented 10 months ago

Unfortunately didn't help. I gave up and bought a new IP module that allows multi sockets. Works like a charm now. Thanks for your effort in trying to find a solution!

markxroberts commented 10 months ago

No problem. This sounds sensible. There are quite a lot of factors with the cloud socket that make it difficult to debug.

pergolafabio commented 10 months ago

Tok bad I can't change to a multi socket, my board is just too old, I have to replace everything...