search

msp1974 / visonic_proxy

1 stars 0 forks source link

Messages from integration can get sent without getting the ACK first #9

Open msp1974 opened 2 months ago

msp1974 commented 2 months ago

When creating requests in response to a b0 51 message, they seem to get sent to Alarm in quick succession without handling the ACK first. Need to look at why this is. Causes a timeout waiting for ACK.

2024-08-02 01:34:38.513 INFO     Alarm->Visonic P58004-6749 VIS-BBA 0d b0 03 51 07 ff 08 ff 02 19 24 50 43 19 0a
2024-08-02 01:34:38.547 INFO     Alarm->HA P50330-6749 VIS-BBA 0d b0 03 51 07 ff 08 ff 02 19 24 50 43 19 0a
2024-08-02 01:34:38.547 INFO     Visonic->Alarm P58004-6749 VIS-ACK 0d 02 43 ba 0a
2024-08-02 01:34:38.548 INFO     HA->Alarm P58004-6750 VIS-BBA 0d b0 01 19 01 05 43 eb 0a
2024-08-02 01:34:41.219 INFO     HA->Alarm P58004-6751 VIS-BBA 0d b0 01 24 01 05 43 e0 0a
2024-08-02 01:34:44.895 INFO     -------------------------------------------------------------------------------------------
2024-08-02 01:34:44.896 INFO     CONNECTIONS: Alarm: ['P58004'], Visonic: ['P58004'], HA: ['P50330']
2024-08-02 01:34:44.896 INFO     MODES: Disconnected Mode: False, Stealth Mode: False
2024-08-02 01:34:44.896 INFO     -------------------------------------------------------------------------------------------
2024-08-02 01:34:46.221 WARNING  Timeout waiting for ACK from Alarm for msg id 6751
2024-08-02 01:34:46.222 INFO     Alarm->HA P50330-6750 VIS-ACK 0d 02 43 ba 0a
2024-08-02 01:34:46.222 INFO     Alarm->Visonic P58004-6751 VIS-BBA 0d b0 03 19 0d ff 01 03 08 00 00 00 00 00 00 00 00 53 43 83 0a
2024-08-02 01:34:46.252 INFO     Alarm->HA P50330-6751 VIS-BBA 0d b0 03 19 0d ff 01 03 08 00 00 00 00 00 00 00 00 53 43 83 0a
2024-08-02 01:34:46.253 INFO     Visonic->Alarm P58004-6750 VIS-BBA 0d b0 01 24 01 05 43 e0 0a
2024-08-02 01:34:46.271 INFO     Visonic->Alarm P58004-6751 VIS-ACK 0d 02 43 ba 0a
2024-08-02 01:34:46.271 INFO     Alarm->Visonic P58004-6752 VIS-ACK 0d 02 43 ba 0a
2024-08-02 01:34:46.276 INFO     Alarm->Visonic P58004-6753 VIS-BBA 0d b0 03 24 1a ff 08 ff 15 02 00 00 00 00 00 00 00 27 22 01 02 08 18 14 06 01 00 81 00 00 54 43 4e 0a
2024-08-02 01:34:46.309 INFO     Alarm->HA P50330-6753 VIS-BBA 0d b0 03 24 1a ff 08 ff 15 02 00 00 00 00 00 00 00 27 22 01 02 08 18 14 06 01 00 81 00 00 54 43 4e 0a

2024-08-02 02:15:38.631 INFO     ConnectionManager->Alarm P34281-7474 VIS-BBA 0d b0 01 6a 00 43 a0 0a
2024-08-02 02:15:38.663 INFO     ConnectionManager->HA P39498-0000 VIS-BBA 0d e0 01 00 01 00 43 d9 0a
2024-08-02 02:15:38.665 INFO     HA->Alarm P34281-7475 VIS-ACK 0d 02 fd 0a
2024-08-02 02:15:39.446 INFO     ConnectionManager->Alarm P34281-7475 VIS-ACK 0d 02 43 ba 0a
2024-08-02 02:15:39.446 INFO     Alarm->HA P39498-7475 VIS-BBA 0d b0 03 51 08 ff 08 ff 03 18 24 4b 02 43 1b 0a
2024-08-02 02:15:39.448 INFO     HA->Alarm P34281-7476 VIS-BBA 0d b0 01 18 01 05 43 ec 0a
2024-08-02 02:15:40.768 INFO     -------------------------------------------------------------------------------------------
2024-08-02 02:15:40.769 INFO     CONNECTIONS: Alarm: ['P34281'], Visonic: [], HA: ['P39498']
2024-08-02 02:15:40.769 INFO     MODES: Disconnected Mode: True, Stealth Mode: False
2024-08-02 02:15:40.769 INFO     -------------------------------------------------------------------------------------------
2024-08-02 02:15:44.456 WARNING  Timeout waiting for ACK from Alarm for msg id 7476
2024-08-02 02:15:44.456 INFO     HA->Alarm P34281-7476 VIS-BBA 0d b0 01 24 01 05 43 e0 0a
2024-08-02 02:15:44.577 INFO     HA->Alarm P34281-7477 VIS-BBA 0d b0 01 4b 01 05 43 b9 0a
2024-08-02 02:15:48.638 INFO     Connecting Visonic Client P34281
2024-08-02 02:15:48.639 INFO     Initiating connection to Visonic on behalf of P34281
2024-08-02 02:15:48.671 INFO     Connected to Visonic server on port 5001 for P34281
2024-08-02 02:15:49.579 WARNING  Timeout waiting for ACK from Alarm for msg id 7477
2024-08-02 02:15:49.580 INFO     Alarm->HA P39498-7476 VIS-ACK 0d 02 43 ba 0a
2024-08-02 02:15:49.580 INFO     ConnectionManager->Alarm P34281-7477 VIS-ACK 0d 02 43 ba 0a
2024-08-02 02:15:49.580 INFO     Alarm->HA P39498-7477 VIS-BBA 0d b0 03 18 0d ff 01 03 08 00 00 00 00 00 00 00 00 07 43 d0 0a
2024-08-02 02:15:49.580 INFO     ConnectionManager->HA P39498-0000 VIS-BBA 0d e0 01 01 01 03 43 d5 0a
2024-08-02 02:15:49.580 INFO     ConnectionManager->Alarm P34281-7478 VIS-BBA 0d b0 01 17 0b 01 ff 08 ff 05 51 51 51 0f 24 00 43 b3 0a
2024-08-02 02:15:50.772 INFO     -------------------------------------------------------------------------------------------
2024-08-02 02:15:50.772 INFO     CONNECTIONS: Alarm: ['P34281'], Visonic: ['P34281'], HA: ['P39498']
2024-08-02 02:15:50.772 INFO     MODES: Disconnected Mode: False, Stealth Mode: False
2024-08-02 02:15:50.772 INFO     -------------------------------------------------------------------------------------------
2024-08-02 02:15:54.589 WARNING  Timeout waiting for ACK from Alarm for msg id 7478
2024-08-02 02:15:54.589 INFO     Alarm->Visonic P34281-7479 VIS-ACK 0d 02 43 ba 0a
2024-08-02 02:15:54.589 INFO     Alarm->Visonic P34281-7478 VIS-BBA 0d b0 03 51 08 ff 08 ff 03 18 24 4b 0a 43 13 0a
2024-08-02 02:15:54.657 INFO     Alarm->HA P39498-7478 VIS-BBA 0d b0 03 51 08 ff 08 ff 03 18 24 4b 0a 43 13 0a
2024-08-02 02:15:54.657 INFO     Alarm->Visonic P34281-7480 VIS-BBA 0d b0 03 24 1a ff 08 ff 15 02 00 00 00 00 00 00 00 2b 0f 02 02 08 18 14 06 01 00 81 00 00 0b 43 a5 0a
msp1974 commented 2 months ago

NTS: CM ACK'd the b0 51 request as the integration doesn't. Did Alarm not like the ACK and was waiting for a different one which is why it didn't ACK the next request before timeout. See second log 2024-08-02 02:15:39.446

msp1974 commented 2 months ago

NTS: Implemented a dodgy fix in flow manager to send data receive event and then wait 0.01s before releasing queue to ensure the ACK is on the send queue before releasing, ensuring ACK gets sent next.

This needs improving as uses a blocking tactic to do, rather than good logic and flow!

Interestingly, this also seems to have fixed the Comms Failure trouble - time will tell!