goToMain / libosdp

Implementation of IEC 60839-11-5 OSDP (Open Supervised Device Protocol); provides a C library with support for C++, Rust and Python3
https://libosdp.sidcha.dev
Apache License 2.0
134 stars 71 forks source link

Issues trying to use OSDP with an InnerRange Inception #70

Closed vk2tds closed 2 years ago

vk2tds commented 2 years ago

I am attempting to use LibOSDP with an InnerRange Exception alarm system. I have compiled the library, with some changes onto the STM32 using the Arduino ecosystem.

The exact code I am running lives in the following repositories:

The PD is configured in Install Mode (PD is in INSTALL_MODE)

The PD that I am creating has the ID number of 1. There is an existing device that has the ID number of 0. The full debug log can be found at the following link: (https://pastebin.com/6FgGWAar). Looking at the appropriate lines, it appears that a SC session is created, and then things stop working. Alas, I am not familiar enough with the internal workings of the protocol to know what should be going on.

OSDP: DEBUG: PD[1]: PD: CMD: CHLNG(76) REPLY: CCRYPT(76)
OSDP: DEBUG: PD[1]: PD: CMD: SCRYPT(77) REPLY: RMAC_I(78)
OSDP: WARN : PD[1]: PD: SC Active with SCBK-D
OSDP: DEBUG: PD[1]: PD: CMD: ID(61) REPLY: PDID(45)
OSDP: INFO : PD[1]: PD: PD SC session timeout!
OSDP: ERROR: PD[1]: PHY: seq-repeat/reply-resend not supported!
OSDP: ERROR: PD[1]: PHY: seq-repeat/reply-resend not supported!
OSDP: ERROR: PD[1]: PD: CMD receive error/timeout - err:-1

The pastebin was created using the following PD_CAP

      .function_code = OSDP_PD_CAP_COMMUNICATION_SECURITY,
      .compliance_level = 0, // Try 1 later
      // more doc/libosdp/secure-channel.rst
      .num_items = 0
    },

NOTE: I also tried with compliance_level=1. The capture can be found at https://pastebin.com/0guBD9zy

Any hints in getting this working would be appreciated. Thanks.

sidcha commented 2 years ago

From the logs, the CP sent you a CMD_MFG:

OSDP: PD[1]: Received [1f] =>
    0000  ff 53 01 1e 00 0d 02 17  80 af 0b 8a 7d 2d d9 82  |.S..........}-..|
    0010  c7 df e0 2a 7c d4 b2 66  ce 32 38 ac d9 a7 fd     |...*|..f.28.... |
OSDP: CMD: MFG(80) [5] =>
    0000  80 00 11 b9 10                                    |.....           |

For which your PD replied with:

OSDP: PD[1]: Sent [f] =>
    0000  ff 53 81 0e 00 0d 02 16  40 19 69 28 fb 69 a2     |.S......@.i(.i. |

Both those are valid OSDP packets. After this, the CP did not send anything for at least OSDP_PD_SC_TIMEOUT_MS (which causes the secure channel session to timeout with the message "OSDP: INFO : PD[1]: PD: PD SC session timeout!").

After this, things get interesting, your PD thinks it sees the next command but that's just the last command sitting in your rx buffer without being removed plus the new command. (notice that the first 31 bytes are identical to CMD_MFG)

OSDP: PD[1]: Received [3f] =>
    0000  ff 53 01 1e 00 0d 02 17  80 af 0b 8a 7d 2d d9 82  |.S..........}-..|
    0010  c7 df e0 2a 7c d4 b2 66  ce 32 38 ac d9 a7 fd ff  |...*|..f.28.....|
    0020  53 01 1e 00 0d 02 17 80  af 0b 8a 7d 2d d9 82 c7  |S..........}-...|
    0030  df e0 2a 7c d4 b2 66 ce  32 38 ac d9 a7 fd ff     |..*|..f.28..... |

This caused LibOSDP PD to think that the CP is resending the same packet twice and that produces this error:

OSDP: ERROR: PD[1]: PHY: seq-repeat/reply-resend not supported!

Looks like you are causing this issue with your downstream changes. Can you remove any changes you made to pd_decode_packet() and report what errors you are seeing? In essence, what was the issue you faced that prompted you to patch pd_decode_packet()? -- that fix is not right and is causing this problem for you.

nit:

OSDP: PD: Setup complete - @PROJECT_NAME@-@PROJECT_VERSION@ @GIT_BRANCH@ (@GIT_TAG@)

You need to run ./configure which will produce the osdp_config.h which you need to include in your project. Looks like you are including osdp_config.h.in

vk2tds commented 2 years ago

Thank you so much for the comments. Once I found what I was looking for, I found an issue with my pd_command_handler, which had an incorrect syntax on the switch statement, which although it compiled, did not operate correctly at all. I had left out all the case statements, which improved things significantly.

I have removed all the changes to osdp_pd.c, and that has also improved things. I am still getting SC Session Timeout errors but it does not appear that I am getting those sequence errors. Here is the link to the log, but the highlights are below. https://pastebin.com/u1w7wVZG

I am just wondering if the MFG(80) reply should be something else. I have tried ACK and that doesn't seem to help. Thanks

OSDP: DEBUG: PD[1]: PD: CMD: CAP(62) REPLY: PDCAP(46) OSDP: DEBUG: PD[1]: PD: CMD: ID(61) REPLY: PDID(45) OSDP: DEBUG: PD[1]: PD: CMD: MFG(80) REPLY: NAK(41) OSDP: DEBUG: PD[1]: PD: CMD: CAP(62) REPLY: PDCAP(46) OSDP: DEBUG: PD[1]: PD: CMD: CHLNG(76) REPLY: CCRYPT(76) OSDP: DEBUG: PD[1]: PD: CMD: SCRYPT(77) REPLY: RMAC_I(78) OSDP: WARN : PD[1]: PD: SC Active with SCBK-D OSDP: DEBUG: PD[1]: PD: CMD: ID(61) REPLY: PDID(45) OSDP: DEBUG: PD[1]: PD: CMD: MFG(80) REPLY: NAK(41) OSDP: DEBUG: PD[1]: PD: CMD: BUZ(6a) REPLY: ACK(40) OSDP: DEBUG: PD[1]: PD: CMD: MFG(80) REPLY: NAK(41) OSDP: DEBUG: PD[1]: PD: CMD: MFG(80) REPLY: NAK(41) OSDP: DEBUG: PD[1]: PD: CMD: MFG(80) REPLY: NAK(41) OSDP: INFO : PD[1]: PD: PD SC session timeout!

sidcha commented 2 years ago

... and that has also improved things ...

Can you describe a bit more about what you improved? I am still trying to understand this.

I am still getting SC Session Timeout errors but it does not appear that I am getting those sequence errors.

From the logs, your PD did timeout the secure channel and deactivated the SC. The next command from the CP came in secure channel as the CP doesn't know that the PD has discarded it yet. The PD should reply with a NACK for this so the CP can restart the secure channel -- which is not happening. I'll post a fix for that.

I am just wondering if the MFG(80) reply should be something else. I have tried ACK and that doesn't seem to help. Thanks

Quite possible. CP could be expecting a REPLY_MFGREP too; you have to ask the vendor about its structure. You can populate the reply data in the command PD handler and it will be sent to the CP for you (see the tests to see how this can be done).

sidcha commented 2 years ago

That should fix the sequence mismatch issue (your SC would still timeout as that is due to the CP's inaction). Please redo your tests with this fix and let me know if that works for you.

vk2tds commented 2 years ago

Once again, thanks for this. Previously, I had simplified the info_pd structure removing audible output and a few other items. This made the results 'better' along with all your other comments. I have been unwell and can't remember many of the details. The patch has definitely helped.

I have since managed to determine that the Inner Range Inception has a detailed logging mode, and the ability to record more information. Below is a synopsis of the recorded data. I tried to remove all the repeated data, and make it understandable. In general, the sequence errors are now gone.

I started about 09:09:10 or so. Things I am seeing from this:

I have uploaded the packet logs to PasteBin, but I think you are right. It seems to be related to the MFG code. I will reach out to the vendor and see what I can find out. I will let you know as soon as I find anything. Once again, thanks.

EDIT: Just wondering what would cause the PD to timeout? Is that because the CP should be sending one of its normal heartbeat messages, and this message is not being received? I have just messaged the vendor and we will see what they come up with

https://pastebin.com/bRLfdHKq

05  2021-10-23  09:09:17.724    mono-service        0   OsdpManager: ProcessMessage - Reader 1 sent a NAK - OSDP_NAK_UNABLE_TO_PROCESS message
[REPEATED]
02  2021-10-23  09:09:25.561    mono-service        0   OsdpManager: ProcessMessage - Reader 1 sent incorrect sequence num (0 instead of 3)
02  2021-10-23  09:09:25.563    mono-service        0   OsdpManager: Error processing received message
05  2021-10-23  09:09:42.075    mono-service        0   OsdpManager: ProcessMessage - Reader 1 sent a NAK - OSDP_NAK_UNABLE_TO_PROCESS message
[REPEATED]
02  2021-10-23  09:09:49.865    mono-service        0   OsdpManager: ProcessMessage - Reader 1 sent incorrect sequence num (0 instead of 2)
02  2021-10-23  09:09:49.869    mono-service        0   OsdpManager: Error processing received message
05  2021-10-23  09:09:58.002    mono-service        0   OsdpManager: ProcessMessage - Reader 1 sent a NAK - OSDP_NAK_UNABLE_TO_PROCESS message
05  2021-10-23  09:10:00.503    mono-service        0   OsdpManager: ProcessMessage - Reader 1 sent a NAK - OSDP_NAK_UNABLE_TO_PROCESS message
05  2021-10-23  09:10:00.649    mono-service        0   OsdpManager: ProcessMessage - Reader 1 sent a NAK - OSDP_NAK_UNKNOWN_CMD message
02  2021-10-23  09:10:01.346    mono-service        0   OsdpManager: ProcessMessage - Reader 1 sent a NAK - Crypt Required message
sidcha commented 2 years ago

what would cause the PD to timeout?

The CP has to keep polling the PD to keep the current secure channel session active. Currently this timeout is defined in libOSDP by OSDP_PD_SC_TIMEOUT_MS to be 800 ms. From the log message that you posted, it appears that the CP is causing a SC timeout at equal intervals. Perhaps the CP was designed that way (in which case, the CP is okay with loosing the SC and restarting it); if not you need to report it to the vendor.

Plus,

OsdpManager: Error processing received message

Looks worry-some. Can you do something to figure out which message caused the CP to print this? One approach is to log these messages with timestamps (for instance, mincom has an option to do this) on the PD and compare it with the timestamps on the CP logs.

vk2tds commented 2 years ago

Hi. You are NOT going to believe this. I THINK I have found what is going on.

From the alarms datasheet:

Inception also features an RS-485 OSDP reader bus, meaning that up
to 8 Inner Range SIFER smart card readers, or 8 Wiegand readers via
OSDP <> Wiegand converters, can be connected directly to the
controller to provide card access for both in and out directions for all
doors

This sounds all nice and logical. They want you to use their hardware on the device. So, I made contact with the vendor. Their response was as follows

The Inception does not support any 3rd Party OSDP readers, so only SIFER readers can be used on the RS485 Reader port – this is the same for both the controller itself, as well as any connected SLAMs. The only option available for using 3rd Party OSDP readers may be via the OSDP<>Wiegand converter connecting into the Weigand port of a SLAM.

Essentially, they have implemented an OSDP port that by designs only operates with a superset of the OSDP (0x40 MFG) protocol, and will not operate with third party devices.

I think what is happening is that the OSDP software on the alarm is getting confused by an actual OSDP device on the bus, crashing and restarting.

My next step is to look at writing a protocol decoder for OSDP. I have one of the manufacturers WIEGAND to OSDP converters. Assuming that I capture the entire transaction, including initial enrolment, I should be able to decode the entire transmission. This would allow me to see the MFG 0x40 packets and their responses. Once I decode these, I might be able to implement enough to talk OSDP to this device.

Once again, thanks for your help. I will keep you updated.

sidcha commented 2 years ago

The Inception does not support any 3rd Party OSDP readers, so only SIFER readers can be used on the RS485 Reader port

This doesn't make any sense to me at all :). If the idea is to have vendor locked devices, then why take the trouble of implementing OSPD - a protocol meant to promote interoperability - in the first place? For their sake, I hope this response is from a tech support engineer who doesn't know what he is taking about.

My next step is to look at writing a protocol decoder for OSDP.

This is a nice idea; but you may have some trouble due to secure channel but that can be overcome easily.

vk2tds commented 2 years ago

To be honest, I have a feeling that they want to leverage OSDP, but have commercial lock in. This is for their 'lower end' product. Their more expensive one does more explicitly support OSDP. Anyway, I have followed up and will report anything I get back.

I have started with the decoder, and am making progress. As the PD is not locked down, it appears to do a key exchange on power up, meaning that I can capture CMD_CHLNG/REPLY_CCRYPT/CMD_SCRYPT/REPLY_RMAC_I. I am now working through the libosdp code to see how to decode packets. I am getting there with that, but I think it will be a task for another day.

EDIT: Out of interest, is there a good source for how encryption/decryption works once CMD_CHLNG/REPLY_CCRYPT/CMD_SCRYPT/REPLY_RMAC_I has been done? Thanks