SC Failed from Install - Release 1.5.0

[dman66]

Describe the bug Another test with 2 instances of OSDPCTL talking to each other over RS-485.

My configuration had an SCBK from running 1.4.0 and everything worked fine. If I start from INSTALL_MODE it fails with timeouts (CP) and invalid SOM errors (PD).

Expected behavior Negotiate SCBK without constant failures and retries.

Observed behavior CP Log: OSDP: INFO : CP : CP setup complete OSDP: ERROR: PD[0]: CP : Failed to verify PD cryptogram OSDP: WARN : PD[0]: CP : SC Failed. Retry with SCBK-D OSDP: WARN : PD[0]: CP : SC ACtive with SCBK-D. Set SCBK OSDP: ERROR: PD[0]: CP : Response timeout for CMD(75) OSDP: ERROR: PD[0]: CP : Failed to verify PD cryptogram OSDP: WARN : PD[0]: CP : SC Failed. Retry with SCBK-D OSDP: WARN : PD[0]: CP : SC ACtive with SCBK-D. Set SCBK OSDP: ERROR: PD[0]: CP : Response timeout for CMD(75) OSDP: ERROR: PD[0]: CP : Failed to verify PD cryptogram OSDP: WARN : PD[0]: CP : SC Failed. Retry with SCBK-D OSDP: WARN : PD[0]: CP : SC ACtive with SCBK-D. Set SCBK OSDP: ERROR: PD[0]: CP : Response timeout for CMD(75)

PD Log: OSDP: WARN : PD[0]: PD : SCBK not provided. PD is in INSTALL_MODE OSDP: INFO : PD[0]: PD : PD setup complete OSDP: DEBUG: PD[0]: PD : CMD: 61 REPLY: 45 OSDP: DEBUG: PD[0]: PD : CMD: 62 REPLY: 46 OSDP: DEBUG: PD[0]: PD : CMD: 76 REPLY: 76 OSDP: DEBUG: PD[0]: PD : CMD: 76 REPLY: 76 OSDP: DEBUG: PD[0]: PD : CMD: 77 REPLY: 78 OSDP: WARN : PD[0]: PD : SC Active with SCBK-D OSDP: ERROR: PD[0]: PHY: Invalid SOM 0xb6 OSDP: ERROR: PD[0]: PD : CMD receive error/timeout - err:-1 OSDP: DEBUG: PD[0]: PD : CMD: 61 REPLY: 45 OSDP: DEBUG: PD[0]: PD : CMD: 62 REPLY: 46 OSDP: DEBUG: PD[0]: PD : CMD: 76 REPLY: 76 OSDP: DEBUG: PD[0]: PD : CMD: 76 REPLY: 76 OSDP: DEBUG: PD[0]: PD : CMD: 77 REPLY: 78 OSDP: WARN : PD[0]: PD : SC Active with SCBK-D OSDP: ERROR: PD[0]: PHY: Invalid SOM 0x70 OSDP: ERROR: PD[0]: PD : CMD receive error/timeout - err:-1 OSDP: DEBUG: PD[0]: PD : CMD: 61 REPLY: 45 OSDP: DEBUG: PD[0]: PD : CMD: 62 REPLY: 46 OSDP: DEBUG: PD[0]: PD : CMD: 76 REPLY: 76 OSDP: DEBUG: PD[0]: PD : CMD: 76 REPLY: 76 OSDP: DEBUG: PD[0]: PD : CMD: 77 REPLY: 78 OSDP: WARN : PD[0]: PD : SC Active with SCBK-D OSDP: ERROR: PD[0]: PHY: Invalid SOM 0xa3 OSDP: ERROR: PD[0]: PD : CMD receive error/timeout - err:-1

Attached traces of 1.4.0 and 1.5.0 from INSTALL_MODE.

Additional context Stock 1.5.0 build with 369f3e8 picked up for the Command slab allocation failed issue.

Tried master, but it doesn't currently build ... want to stick with a release. OSDP Trace.pdf

[sidcha]

@dman66, looking into this issue made me discover another issue in master but what you are experiencing appears to be a different issue.

I am unable to reproduce this issue locally. I did a clean build on a branch with v1.5.0 + 369f3e8. So my tree looked like this:

c3ceba4 (HEAD -> tmp) libosdp: Fix slab_free() assertion bug in release builds
e58dbcc (tag: v1.5.0) Release v1.5.0

Can you post your CP and PD osdpctl config file? Also, pastbin full logs (from boot to failure) with packet trace enabled (cmake -DCONFIG_OSDP_PACKET_TRACE=on) and log level set to 7 (DEBUG).

[sidcha]

Also what errors are you facing with build on most recent master? I'm able to build everything just fine (CI builds too).

[dman66]

Regarding 'master' - "git clone https://github.com/goToMain/libosdp --recurse-submodules"

build git:(master) make -- Failed to find sphinx-build executable (missing: SPHINX_EXECUTABLE) -- Could NOT find Doxygen (missing: DOXYGEN_EXECUTABLE) -- Found PythonInterp: /usr/local/opt/python@3.8/bin/python3 (found suitable version "3.8.11", minimum required is "3") -- Could NOT find PythonLibs (missing: PYTHON_LIBRARIES PYTHON_INCLUDE_DIRS) (Required is at least version "3") -- Configuring done -- Generating done -- Build files have been written to: /Users/XXXX/Code/OSDP/libosdp/build Consolidate compiler generated dependencies of target utils [ 37%] Built target utils Consolidate compiler generated dependencies of target osdpstatic [ 38%] Building C object src/CMakeFiles/osdpstatic.dir/osdp_common.c.o [ 40%] Building C object src/CMakeFiles/osdpstatic.dir/osdp_phy.c.o [ 42%] Building C object src/CMakeFiles/osdpstatic.dir/osdp_pd.c.o [ 44%] Building C object src/CMakeFiles/osdpstatic.dir/osdp_sc.c.o [ 46%] Building C object src/CMakeFiles/osdpstatic.dir/osdp_cp.c.o [ 48%] Linking C static library ../lib/libosdpstatic.a [ 50%] Built target osdpstatic Consolidate compiler generated dependencies of target osdp [ 51%] Building C object src/CMakeFiles/osdp.dir/osdp_common.c.o [ 53%] Building C object src/CMakeFiles/osdp.dir/osdp_phy.c.o [ 55%] Building C object src/CMakeFiles/osdp.dir/osdp_pd.c.o [ 57%] Building C object src/CMakeFiles/osdp.dir/osdp_sc.c.o [ 59%] Building C object src/CMakeFiles/osdp.dir/osdp_cp.c.o [ 61%] Linking C shared library ../lib/libosdp.dylib [ 70%] Built target osdp Consolidate compiler generated dependencies of target osdpctl [ 72%] Building C object osdpctl/CMakeFiles/osdpctl.dir/config.c.o [ 74%] Building C object osdpctl/CMakeFiles/osdpctl.dir/cmd_start.c.o /Users/XXXX/Code/OSDP/libosdp/osdpctl/cmd_start.c:290:9: error: no member named 'scbk' in 'osdp_pd_info_t' info->scbk = NULL;

/Users/XXXX/Code/OSDP/libosdp/osdpctl/cmd_start.c:307:13: error: no member named 'scbk' in 'osdp_pd_info_t'
                info_arr->scbk = scbk;
                ~~~~~~~~  ^
/Users/XXXX/Code/OSDP/libosdp/osdpctl/cmd_start.c:308:37: error: too few arguments to function call, expected 2, have 1
                c->pd_ctx = osdp_pd_setup(info_arr);
                            ~~~~~~~~~~~~~         ^
/usr/local/include/osdp.h:684:9: note: 'osdp_pd_setup' declared here
osdp_t *osdp_pd_setup(osdp_pd_info_t * info, uint8_t *scbk);
        ^
3 errors generated.

[dman66]

uart-cp.cfg

[GLOBAL]

mode = CP num_pd = 1 log_level = 7 conn_topology = chain master_key = 000102030405060708090a0b0c0d0e0f

[PD-0]

channel_type = uart channel_device = /dev/tty.usbserial-AG0JKDEH channel_speed = 9600

address = 0

uart-pd.cfg

[GLOBAL]

mode = PD num_pd = 1 log_level = 7

[PD]

channel_type = uart channel_device = /dev/tty.usbserial-AG0JKQNV channel_speed = 9600

address = 1

address = 0

key_store = /tmp/pd-0.key

; PD ID information vendor_code = 153 model = 1 version = 1 serial_number = 1234 firmware_version = 4321

capabilities = [ (3,2,0), (4,1,1), (5,1,1), (6,1,1), (8,1,0), (9,1,0) ]

[dman66]

CP Log : https://pastebin.com/wKxvhMeP PD Log : https://pastebin.com/1ZqKvqj5

[dman66]

Never mind the issue with master - had an old version (1.5.0) of osdp.h in /usr/local that was being picked up...

[dman66]

CP/PD Logs from master:

https://pastebin.com/ssCwVLvF https://pastebin.com/xeFx4XNf

[sidcha]

On master please apply this patch. I think this should fix your issue.

diff --git a/src/osdp_pd.c b/src/osdp_pd.c
index 620abf6..1485008 100644
--- a/src/osdp_pd.c
+++ b/src/osdp_pd.c
@@ -990,6 +988,10 @@ static int pd_receive_and_process_command(struct osdp_pd *pd)

        err = pd_decode_packet(pd, &len);

+       if (err == OSDP_PD_ERR_NO_DATA) {
+               return err;
+       }
+
        /* We are done with the packet (error or not). Remove processed bytes */
        remaining = pd->rx_buf_len - len;
        if (remaining) {

[dman66]

It gets further ... but it SC fails ... but it isn't restarting over and over again.

PD Log: https://pastebin.com/7WUxbMAe CP Log: https://pastebin.com/wbwJYXzJ

[sidcha]

Now you are hitting the bug I fixed earlier in this thread :)

You need to pull latest master to get 3ce12eb875f3e39716ac211860c1e0a6c0c598d0

[dman66]

My bad, skimmed right past that commit ... seems to be working well.

Now on to my further testing with the real target CP.