rsgmodelworks
commented
1 week ago Previous investigations indicated a COMSET/COM sequence in the real world often causes the ACU and the PD to get out of sync as to what speed they are using. The net result is that you're likely to se a glitch before it stabilizes. I think that explains what you saw. Keeping this open to mark reviewing log output if nothing else.
Communication log:
Library sends ID request
Credentials File A: open-osdp-creds-a.dat Loading parameters from osdp-saved-parameters.json Saved parameters loaded. Opening /dev/ttyUSB0, fd=0. Command IDENT (0) submitted. DEBUG: enqueue_command: top, cmd->command 3eb Command identify received. process_command: command is 0 process_command_from_queue: processing command 1003. process_command: command is 1003 Identify requested osdp_ID, L=1 V=00 CLEAR=0
---OSDP ACU Frame:0000 DestAddr=00(hex) Timestamp:20220628-122920 (Sec/Nanosec: 1656419360 688828141) SOM ADDR=00 LEN_LSB=09 LEN_MSB=00 CTRL=04 CRC=66c0 Raw input: (L=9./0x0009) 53 00 09 00-04 61 00 c0-66 Pkt 0000 Msg osdp_ID A:00 Lth:9. S:00 Check:CRC(66c0) Command dump_status received. process_command: command is 1001
RESPONSE IS: 2022/06/28 14:29:20 Handling command Id report request 2022/06/28 14:29:20 --- Sending response for OsdpResponsePdId - 53-80-14-00-04-45-00-06-8e-01-01-7f-00-00-00-01-0a-05-d3-4d
Library sends comset:
osdp_parse_message status was 3. last-cmd 61 parsed-cmd 00 last-check 6166c0 current-check 0000 Command conform_2_2_1 received. process_command: command is 1018
---OSDP ACU Frame:0001 DestAddr=00(hex) Timestamp:20220628-122920 (Sec/Nanosec: 1656419360 715983020) SOM ADDR=7f LEN_LSB=0d LEN_MSB=00 CTRL=05 CRC=800f Raw input: (L=13./0x000d) 53 7f 0d 00-05 6e 00 80-25 00 00 0f-80 Pkt 0001 Msg osdp_COMSET A:7f Lth:13. S:01 Check:CRC(800f) COMSET will use New Address 00 New Speed 9600. Opening /dev/ttyUSB0, fd=0.
RESPONSE IS: 2022/06/28 14:29:20 Handling command COMSET request 2022/06/28 14:29:20 Setting new PD address: 0 leaving baudrate at: 9600 2022/06/28 14:29:20 --- Sending response for OsdpResponseComSet - 53-ff-0d-00-05-54-00-80-25-00-00-b5-cd
Then POLL request
2022/06/28 14:29:20 ======== SQN IS 2 2022/06/28 14:29:20 Packet finished - 53-00-08-00-06-60-89-cc
and response with: (osdp_RAW)
2022/06/28 14:29:20 Handling Osdp Poll command 2022/06/28 14:29:20 --- Sending response for osdp raw - 53-80-10-00-06-50-00-01-1a-00-80-80-3d-c0-89-9f
And here is the error:
osdp_parse_message status was 3. last-cmd 6e parsed-cmd 5a last-check 6e800f current-check 0000
---OSDP ACU Frame:0002 DestAddr=00(hex) Timestamp:20220628-122920 (Sec/Nanosec: 1656419360 850462570) SOM ADDR=00 LEN_LSB=08 LEN_MSB=00 CTRL=06 CRC=cc89 Raw input: (L=8./0x0008) 53 00 08 00-06 60 89 cc Pkt 0002 Msg osdp_POLL A:00 Lth:8. S:02 Check:CRC(cc89)
---OSDP Frame:0003 A=00(hex) Timestamp:20220628-122920 (Sec/Nanosec: 1656419360 850652478) ACU-Polls 1 PD-Acks 0 PD-NAKs 0 CkSumErr 0 osdp_parse_message status was 3. last-cmd 60 parsed-cmd 5a last-check 60cc89 current-check 0000
---OSDP PD Frame:0003 A=00(hex) Timestamp:20220628-122920 (Sec/Nanosec: 1656419360 864390598) Sequence restarted. Resettinng ACU to sequence 0. Bad CRC: Got 53ff Expected dddf SOM ADDR=80 LEN_LSB=14 LEN_MSB=00 CTRL=04 CRC=53ff Raw input: (L=20./0x0014) 53 80 14 00-04 45 00 06-8e 01 01 00-80 25 00 00 b5 cd ff 53 Pkt 0003 Msg osdp_PDID A:00 Lth:20. S:00 Check:CRC(53ff) Message input parsing failed, status 16
Library tells that CRC is wrong, but the problem is that data presented above is not what was sent:
53-80-10-00-06-50-00-01-1a-00-80-80-3d-c0-89-9f
but library received:
Raw input: (L=20./0x0014) 53 80 14 00-04 45 00 06-8e 01 01 00-80 25 00 00 b5 cd ff 53
Which is data that was sent before with osdp_PDID (at least part of it), please check above (--- Sending response for OsdpResponsePdId - 53-80-14-00-04-45-00-06-8e-01-01-7f-00-00-00-01-0a-05-d3-4d)
I suspect that after COMSET there has been some kind of reset in library, but the reset was not properly done. But it is also possible that I have missed something.