search

TJForc / risco-lan-bridge

risco-lan-bridge is a "bridge" between a node.js application and a Risco Panel
Other
21 stars 12 forks source link

Panel RMT command timeout, DCN 'Invalid Parameter' response, repeat until connected. #10

Closed Monofin closed 2 years ago

Monofin commented 2 years ago

I have a system here that is reproducing a failure to connect, and I think I have an idea why: Its a LightSys 2 board, old (single) IP board, similar to several other commenters here.

Summary: I think the request to disconnect command 'DCN' may be either out of sequence, or is somehow inaccurate for the LightSys single IP board. This is then leaving the (single available) socket on the far end in a timeout situation, which then prevents reconnection until the timeout has occurred.

On my system, here, I will actually get successful reconnection connection after between 2 and 20 minutes of retry, usually 20 mins.

I pulled apart the negotiation sequences: If you reset the panel (power down reset), have the cloud disabled and the panel connected directly to the system over ethernet, then power up the panel, then initiate connection, it seems to connect reliably. (I'm using homebridge here with the @gawindex plugin, which works pretty slickly and reliably - great stuff and thanks for the plugin!).

If I restart (homebridge), then the shutdown sequence is followed, ending up in a DCN - which gets a 'Invalid Parameter' response.

On restart, then the very first RMT=5678 times out with no response (though the connection is Established) - just as if the panel thought that there was another unit logged in.

Then DCN is sent which gets immediate response of 'Invalid Parameter' - which is odd, because you're trying to disconnect.

This cycle repeats, starting a new socket, then timing out, DCN, Invalid parameter, rinse and repeat till at one point, with no difference in the command sequence

(I did wonder if this could be crypt related ??)

I've seen up to five sockets on my client in TIME_WAIT, as the retry value for the connection is under the TIME_WAIT timeout - this is server side, so what if something similar is happening on the panel side??

11 has more evidence that the panel 'thinks' it's still got the Configuration Software attached.

<names sanitised>
user@server:~$ netstat |grep Security_System
tcp        0      0 server:41122    Security_System:1000 TIME_WAIT  
tcp        0      0 server:41118    Security_System:1000 TIME_WAIT  
tcp        0      0 server:41120    Security_System:1000 TIME_WAIT  
tcp        0      0 server:41116    Security_System:1000 TIME_WAIT  
user@server:~$ 

During the next connection attempt:
edwbea01@mordin:~$ netstat |grep Security_System
tcp        0      0 mordin.citadel:41170    Security_System.ci:1000 ESTABLISHED
tcp        0      0 mordin.citadel:41162    Security_System.ci:1000 TIME_WAIT  
tcp        0      0 mordin.citadel:41166    Security_System.ci:1000 TIME_WAIT  
tcp        0      0 mordin.citadel:41164    Security_System.ci:1000 TIME_WAIT  
tcp        0      0 mordin.citadel:41168    Security_System.ci:1000 TIME_WAIT

The other possibility was smoking of synchronisation issue with the crypt:

[23/11/2021, 15:52:14] [RiscoLocalAlarm] Initializing RiscoLocalAlarm platform... [23/11/2021, 15:52:14] [RiscoLocalAlarm] Initialising LightSys Panel [23/11/2021, 15:52:14] [RiscoLocalAlarm] Local GMT Timezone is : +00:00 [23/11/2021, 15:52:14] [RiscoLocalAlarm] Start Connection to Panel [23/11/2021, 15:52:14] [RiscoLocalAlarm] TCP Socket is not already created, Create It [23/11/2021, 15:52:14] [RiscoLocalAlarm] Pseudo Buffer Created for Panel Id(0001): [2,5,11,23,47,94,189,122,244,232,208,161,66,133,11,22,45,90,181,107,214,173,90,180,104,208,161,67,135,15,31,63,126,253,251,247,239,223,191,127,255,255,254,252,249,242,229,202,149,43,86,172,88,176,96,193,131,6,12,25,50,100,200,144,32,65,130,5,11,23,47,95,190,125,250,245,234,213,170,85,170,84,168,81,162,68,136,17,35,70,140,24,49,98,197,138,21,42,85,171,87,175,94,188,121,243,230,204,152,49,98,197,138,21,43,86,172,88,177,99,198,141,27,54,109,218,180,105,210,165,74,149,42,85,171,86,173,90,181,106,212,168,80,160,64,129,2,4,9,19,39,78,157,58,117,234,213,170,85,170,85,171,87,175,95,190,124,248,240,225,195,135,15,30,60,120,240,224,193,131,6,12,25,51,102,205,154,53,107,215,175,94,189,122,245,235,215,175,95,190,125,251,246,236,216,176,96,192,129,2,4,8,17,34,68,137,19,39,78,156,56,113,227,199,143,30,61,122,245,234,213,171,86,172,89,179,102,205,154,53,107,215,174,92,185,115,231,207,158,61,123,247,239,223,191] [23/11/2021, 15:52:14] [RiscoLocalAlarm] TCP Socket must be created now [23/11/2021, 15:52:14] [RiscoLocalAlarm] Initial Discovery Phase

[23/11/2021, 15:52:15] [RiscoLocalAlarm] Socket Connected. [23/11/2021, 15:52:15] [RiscoLocalAlarm] Sending Command : RMT=5678 [23/11/2021, 15:52:15] [RiscoLocalAlarm] Command CRC Value : B0F8 [23/11/2021, 15:52:15] [RiscoLocalAlarm] Command Sent. [23/11/2021, 15:52:15] [RiscoLocalAlarm] Sequence : 1 - Data Sent : RMT=5678

[23/11/2021, 15:52:20] [RiscoLocalAlarm] Command : '01 RMT=5678' Timeout!!! [23/11/2021, 15:52:20] [RiscoLocalAlarm] SendCommand receive this response : undefined [23/11/2021, 15:52:20] [RiscoLocalAlarm] Error when connecting to the control panel. [23/11/2021, 15:52:20] [RiscoLocalAlarm] TCP Socket Disconnected [23/11/2021, 15:52:20] [RiscoLocalAlarm] Sending Command : DCN [23/11/2021, 15:52:20] [RiscoLocalAlarm] Command CRC Value : A5E8 [23/11/2021, 15:52:20] [RiscoLocalAlarm] Command Sent. [23/11/2021, 15:52:20] [RiscoLocalAlarm] Sequence : 1 - Data Sent : DCN [23/11/2021, 15:52:20] [RiscoLocalAlarm] Received data Buffer : [2,48,49,78,48,53,23,53,54,51,56,3] [23/11/2021, 15:52:20] [RiscoLocalAlarm] Command CRC Value : 5638 [23/11/2021, 15:52:20] [RiscoLocalAlarm] CRC Ok [23/11/2021, 15:52:20] [RiscoLocalAlarm] Response from Panel. [23/11/2021, 15:52:20] [RiscoLocalAlarm] Expected response for Command Id : 01. [23/11/2021, 15:52:20] [RiscoLocalAlarm] Received From Panel : N05 [23/11/2021, 15:52:20] [RiscoLocalAlarm] Receipt of an error code: Invalid parameter [23/11/2021, 15:52:20] [RiscoLocalAlarm] SendCommand receive this response : N05 [23/11/2021, 15:52:20] [RiscoLocalAlarm] Socket Destroyed. [23/11/2021, 15:52:20] [RiscoLocalAlarm] Socket Disconnected.

[23/11/2021, 15:52:30] [RiscoLocalAlarm] Start Connection to Panel [23/11/2021, 15:52:30] [RiscoLocalAlarm] TCP Socket is already created, Connect It [23/11/2021, 15:52:30] [RiscoLocalAlarm] TCP Socket must be created now [23/11/2021, 15:52:30] [RiscoLocalAlarm] Socket Connected. [23/11/2021, 15:52:30] [RiscoLocalAlarm] Sending Command : RMT=5678 [23/11/2021, 15:52:30] [RiscoLocalAlarm] Command CRC Value : BF08 [23/11/2021, 15:52:30] [RiscoLocalAlarm] Command Sent. [23/11/2021, 15:52:30] [RiscoLocalAlarm] Sequence : 2 - Data Sent : RMT=5678

[23/11/2021, 15:52:35] [RiscoLocalAlarm] Command : '02 RMT=5678' Timeout!!! [23/11/2021, 15:52:35] [RiscoLocalAlarm] SendCommand receive this response : undefined [23/11/2021, 15:52:35] [RiscoLocalAlarm] Error when connecting to the control panel. [23/11/2021, 15:52:35] [RiscoLocalAlarm] TCP Socket Disconnected [23/11/2021, 15:52:35] [RiscoLocalAlarm] Sending Command : DCN [23/11/2021, 15:52:35] [RiscoLocalAlarm] Command CRC Value : A5AC [23/11/2021, 15:52:35] [RiscoLocalAlarm] Command Sent. [23/11/2021, 15:52:35] [RiscoLocalAlarm] Sequence : 2 - Data Sent : DCN [23/11/2021, 15:52:35] [RiscoLocalAlarm] Received data Buffer : [2,48,50,78,48,53,23,53,54,55,67,3] [23/11/2021, 15:52:35] [RiscoLocalAlarm] Command CRC Value : 567C [23/11/2021, 15:52:35] [RiscoLocalAlarm] CRC Ok [23/11/2021, 15:52:35] [RiscoLocalAlarm] Response from Panel. [23/11/2021, 15:52:35] [RiscoLocalAlarm] Expected response for Command Id : 02. [23/11/2021, 15:52:35] [RiscoLocalAlarm] Received From Panel : N05 [23/11/2021, 15:52:35] [RiscoLocalAlarm] Receipt of an error code: Invalid parameter [23/11/2021, 15:52:35] [RiscoLocalAlarm] SendCommand receive this response : N05 [23/11/2021, 15:52:35] [RiscoLocalAlarm] Socket Destroyed. [23/11/2021, 15:52:35] [RiscoLocalAlarm] Socket Disconnected.

Eventually it suddenly connects....!

I'm going to try a cold-cold reset: Nothing trying to connect, and a power on reset unit.

Monofin commented 2 years ago

Got it, I think. On connection to a panel, after the socket is connected, the Configuration Software waits for just under 10 seconds before sending the login RMT command. It would seem that this timing needs to be honoured whilst the panel/ip card sorts itself out somehow.

Going to try a fix with a parameterised 'hello wait time' and see if that works.

Monofin commented 2 years ago

Older LightSYS panels with single (IPC, not IPC 2) interfaces seem to require a 10 second delay between socket connect and first message. As you can't tell what the panel type/version is until after the RMT packet, it has to be applied to all connections to support older panels. (Could be parameterised at startup, but given the auto discovery is a goal, then it has to apply across the board)

12 Adds the delay to the connection for a direct TCP connection. It's unknown at this time if the proxy connection is affected by this issue.

Tested on a v3 LightSYS panel with an old IPC card.

robertboccia commented 2 years ago

Also needs testing on prosys plus which is the panel I have

Robert Boccia

From: Monofin @.> Sent: Wednesday, November 24, 2021 8:28:27 PM To: TJForc/risco-lan-bridge @.> Cc: Subscribed @.***> Subject: Re: [TJForc/risco-lan-bridge] Panel RMT command timeout, DCN 'Invalid Parameter' response, repeat until connected. (Issue #10)

Older LightSYS panels with single (IPC, not IPC 2) interfaces seem to require a 10 second delay between socket connect and first message. As you can't tell what the panel type/version is until after the RMT packet, it has to be applied to all connections to support older panels. (Could be parameterised at startup, but given the auto discovery is a goal, then it has to apply across the board)

12https://emea01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2FTJForc%2Frisco-lan-bridge%2Fpull%2F12&data=04%7C01%7C%7Cef97d0a5e1954a2b88df08d9af783606%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637733753097292878%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=oj1z9eqk0ZmUD95uOvNFeDMtXRdsLbnDdgMWSppH5no%3D&reserved=0 Adds the delay to the connection for a direct TCP connection. It's unknown at this time if the proxy connection is affected by this issue.

Tested on a v3 LightSYS panel with an old IPC card.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHubhttps://emea01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2FTJForc%2Frisco-lan-bridge%2Fissues%2F10%23issuecomment-978125484&data=04%7C01%7C%7Cef97d0a5e1954a2b88df08d9af783606%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637733753097292878%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=DZJUW%2FvRWMJfOYoQDjGLQDI1dArxZ1zQpiYnWUreeAQ%3D&reserved=0, or unsubscribehttps://emea01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fnotifications%2Funsubscribe-auth%2FAR4IWBHURBO5B226NZPNYNTUNUVEXANCNFSM5IT4O5PA&data=04%7C01%7C%7Cef97d0a5e1954a2b88df08d9af783606%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637733753097302873%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=jFPzg%2FVfhH654vHpPtBXTY3qsWHWpxyiLzFh3i4qB%2FM%3D&reserved=0.

Monofin commented 2 years ago

Hi there - I don’t have access to a ProSYS plus, but given that the Config Software does this delay regardless of the chosen panel (Wireshark reveals this) over IP, then I have high confidence on to being compatible, and necessary.

You can clone, test and install from the fork repo, if you can test it (git clone, then npm link, if you’re using npm)? It would be most helpful?

I’ve seen some other protocol traces from a ProSYS unit that isn’t necessarily show the same error conditions - this fix is specific to the timeout from RMT command that is shown if debug is enabled.

(I believe that a similar trace, but different cause is seen if the Panel does not have CS communication enabled, or the Cloud is enabled, but only when debug is not enabled.)

Hope to help! Cheers, Monofin

On 24 Nov 2021, at 19:18, Robert Boccia @.***> wrote:

 Also needs testing on prosys plus which is the panel I have

Robert Boccia

From: Monofin @.> Sent: Wednesday, November 24, 2021 8:28:27 PM To: TJForc/risco-lan-bridge @.> Cc: Subscribed @.***> Subject: Re: [TJForc/risco-lan-bridge] Panel RMT command timeout, DCN 'Invalid Parameter' response, repeat until connected. (Issue #10)

Older LightSYS panels with single (IPC, not IPC 2) interfaces seem to require a 10 second delay between socket connect and first message. As you can't tell what the panel type/version is until after the RMT packet, it has to be applied to all connections to support older panels. (Could be parameterised at startup, but given the auto discovery is a goal, then it has to apply across the board)

12https://emea01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2FTJForc%2Frisco-lan-bridge%2Fpull%2F12&data=04%7C01%7C%7Cef97d0a5e1954a2b88df08d9af783606%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637733753097292878%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=oj1z9eqk0ZmUD95uOvNFeDMtXRdsLbnDdgMWSppH5no%3D&reserved=0 Adds the delay to the connection for a direct TCP connection. It's unknown at this time if the proxy connection is affected by this issue.

Tested on a v3 LightSYS panel with an old IPC card.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHubhttps://emea01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2FTJForc%2Frisco-lan-bridge%2Fissues%2F10%23issuecomment-978125484&data=04%7C01%7C%7Cef97d0a5e1954a2b88df08d9af783606%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637733753097292878%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=DZJUW%2FvRWMJfOYoQDjGLQDI1dArxZ1zQpiYnWUreeAQ%3D&reserved=0, or unsubscribehttps://emea01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fnotifications%2Funsubscribe-auth%2FAR4IWBHURBO5B226NZPNYNTUNUVEXANCNFSM5IT4O5PA&data=04%7C01%7C%7Cef97d0a5e1954a2b88df08d9af783606%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637733753097302873%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=jFPzg%2FVfhH654vHpPtBXTY3qsWHWpxyiLzFh3i4qB%2FM%3D&reserved=0. — You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub, or unsubscribe. Triage notifications on the go with GitHub Mobile for iOS or Android.

TJForc commented 2 years ago

@Monofin, I think that your modifications having been accepted, we can close the subject.

Thank you for your contribution.