Exception when several commands arrive in a short time

[sebbo2002]

trafficstars

• [x] Before submitting a problem please check the troubleshooting section https://docs.openmqttgateway.com/upload/troubleshoot.html

Describe the bug If several ble_write_address commands are sent in a too short time interval, I get an exception and the command is not executed.

To Reproduce Steps to reproduce the behavior:

1. Publish two (or more) write commands directly after each other. Example:

{"ble_write_address":"DD:A2:6E:62:B8:2F","ble_write_service":"cba20d00-224d-11e6-9fb8-0002a5d5c51b","ble_write_char":"cba20002-224d-11e6-9fb8-0002a5d5c51b","ble_write_value":"570F450105FF00","value_type":"HEX","mac_type":1,"ttl":5,"immediate":true}

{"ble_write_address":"EC:B9:3A:06:BF:96","ble_write_service":"cba20d00-224d-11e6-9fb8-0002a5d5c51b","ble_write_char":"cba20002-224d-11e6-9fb8-0002a5d5c51b","ble_write_value":"570F450105FF00","value_type":"HEX","mac_type":1,"ttl":5,"immediate":true}

2. See exception

16:51:25.610 -> N: [ MQTT->OMG ]: {"ble_write_address":"DD:A2:6E:62:B8:2F","ble_write_service":"cba20d00-224d-11e6-9fb8-0002a5d5c51b","ble_write_char":"cba20002-224d-11e6-9fb8-0002a5d5c51b","ble_write_value":"570F450105FF00","value_type":"HEX","mac_type":1,"ttl":5,"immediate":true}
16:51:25.610 -> N: Send on /BTtoMQTT msg {"bleconnect":true,"interval":55555,"activescan":true,"scanbcnct":10,"onlysensors":false,"hasspresence":false,"presenceTopic":"presence/","presenceUseBeaconUuid":false,"minrssi":-100,"extDecoderEnable":false,"extDecoderTopic":"undecoded","filterConnectable":false,"pubadvdata":false,"pubBeaconUuidForTopic":false,"ignoreWBlist":false}
16:51:25.658 -> N: BLE Connect begin
16:51:25.658 -> N: [ MQTT->OMG ]: {"ble_write_address":"EC:B9:3A:06:BF:96","ble_write_service":"cba20d00-224d-11e6-9fb8-0002a5d5c51b","ble_write_char":"cba20002-224d-11e6-9fb8-0002a5d5c51b","ble_write_value":"570F450105FF00","value_type":"HEX","mac_type":1,"ttl":5,"immediate":true}
16:51:25.658 -> N: Send on /BTtoMQTT msg {"bleconnect":true,"interval":55555,"activescan":true,"scanbcnct":10,"onlysensors":false,"hasspresence":false,"presenceTopic":"presence/","presenceUseBeaconUuid":false,"minrssi":-100,"extDecoderEnable":false,"extDecoderTopic":"undecoded","filterConnectable":false,"pubadvdata":false,"pubBeaconUuidForTopic":false,"ignoreWBlist":false}
16:51:26.041 -> Guru Meditation Error: Core  1 panic'ed (LoadProhibited). Exception was unhandled.
16:51:26.041 -> Core 1 register dump:
16:51:26.041 -> PC      : 0x400fdf2f  PS      : 0x00060730  A0      : 0x800f6a2e  A1      : 0x3ffeae90  
16:51:26.041 -> A2      : 0x00000000  A3      : 0x3ffc43e8  A4      : 0x00060720  A5      : 0x00000001  
16:51:26.041 -> A6      : 0x00060d20  A7      : 0x00000000  A8      : 0x800f607e  A9      : 0x3ffeae80  
16:51:26.080 -> A10     : 0x3ffc43dc  A11     : 0x00000000  A12     : 0x00000038  A13     : 0x3ffc4414  
16:51:26.080 -> A14     : 0x0000200d  A15     : 0x00000003  SAR     : 0x00000018  EXCCAUSE: 0x0000001c  
16:51:26.080 -> EXCVADDR: 0x00000000  LBEG    : 0x4000c46c  LEND    : 0x4000c477  LCOUNT  : 0x00000000  
16:51:26.080 -> 
16:51:26.080 -> ELF file SHA256: 0000000000000000
16:51:26.080 -> 
16:51:26.080 -> Backtrace: 0x400fdf2f:0x3ffeae90 0x400f6a2b:0x3ffeaeb0 0x400effcf:0x3ffeaf10 0x400f0036:0x3ffeaf40 0x400d47ce:0x3ffeaf80 0x400dd657:0x3ffeafd0 0x400d629d:0x3ffeb030 0x400d71d2:0x3ffeb0a0 0x400d754e:0x3ffeb110 0x40090dba:0x3ffeb150
16:51:26.113 -> 
16:51:26.113 -> Rebooting...
16:51:26.754 -> N: 
16:51:26.754 -> ************* WELCOME TO OpenMQTTGateway **************

Expected behavior Since both write requests have the immediate flag set, I would expect both requests to be written to a queue, the scan to be interrupted, and then both requests to be processed in sequence.

Environment:

• OpenMQTTGateway version used
  • I use the dev build that was provided in #1412, as this version has decoding support for Switchbot Curtains. I have not tested the current / stable release, as I assume this test build is otherwise up to date.
• ~~Library version related to the problem you have (if you have troubles with RF provide the version of RCSwitch library)~~
• ~~For IR and RF clarify if you tested with the basic examples given with these libraries~~

Additional context

• I used the web installer to upload OpenMQTTGateway (environment esp32dev-ble)

---

• [x] You should not have a compilation error if you use the versions of the libraries linked into the libraries folder, this badges show you the state of the compilation

• [x] If you are not sure this is a bug or an enhancement post your question to the forum below

[1technophile]

Thanks for pointing this.

With immediate:false the BT action will go to a queue and be processed at the next connect time. You can play with the time between connects to reduce the time. This will work but is not ideal as other actions are processed within this connect function, retrieving battery level of MiFloras or sensors values of some connectable sensors (LYWSD03MMC, MHO_C401 with stock firmware). If you don't have those it may be interesting to try this.

In the meantime I will check how this mechanism can be improved.

[sebbo2002]

My current workaround is that I have a fixed delay between both curtains of 10 seconds via the home automation. I also experimented with immediate: false first, but I prefer that at least one of the curtains moves immediately.

In the meantime I will check how this mechanism can be improved.

Thank you 🙏🏼

[DigiH]

More details with the same sending of two successive WRITE commands, with decoded backtrace

N: [ MQTT->OMG ]: {"ble_write_address":"AA:AA:AA:DD:EE:FF","mac_type":0,"ble_write_service":"ff02","ble_write_char":"fffb","ble_write_value":"00ff000000000100","value_type":"HEX","ttl":10,"immediate":true}
N: Send on /BTtoMQTT msg {"bleconnect":false,"interval":20000,"adaptivescan":false,"intervalacts":180000,"intervalcnct":3600000,"scanduration":10000,"onlysensors":false,"randommacs":false,"hasspresence":false,"presenceTopic":"presence/","presenceUseBeaconUuid":false,"minrssi":-100,"extDecoderEnable":false,"extDecoderTopic":"undecoded","filterConnectable":false,"pubadvdata":true,"pubBeaconUuidForTopic":false,"ignoreWBlist":false,"presenceawaytimer":120000,"btqblck":5,"btqsum":63,"btqsnd":41,"btqavg":1.536585}
N: BLE Connect begin
N: [ MQTT->OMG ]: {"ble_write_address":"BB:BB:BB:DD:EE:FF","mac_type":0,"ble_write_service":"ff02","ble_write_char":"fffb","ble_write_value":"00ff000000000100","value_type":"HEX","ttl":10,"immediate":true}
N: Send on /BTtoMQTT msg {"bleconnect":false,"interval":20000,"adaptivescan":false,"intervalacts":180000,"intervalcnct":3600000,"scanduration":10000,"onlysensors":false,"randommacs":false,"hasspresence":false,"presenceTopic":"presence/","presenceUseBeaconUuid":false,"minrssi":-100,"extDecoderEnable":false,"extDecoderTopic":"undecoded","filterConnectable":false,"pubadvdata":true,"pubBeaconUuidForTopic":false,"ignoreWBlist":false,"presenceawaytimer":120000,"btqblck":5,"btqsum":63,"btqsnd":41,"btqavg":1.536585}
E: Connect to: aa:aa:aa:dd:ee:ff failed
Guru Meditation Error: Core  1 panic'ed (LoadProhibited). Exception was unhandled.

Core  1 register dump:
PC      : 0x400d73c6  PS      : 0x00060d30  A0      : 0x800d9cc6  A1      : 0x3ffeb970  
A2      : 0x3ffe33f0  A3      : 0x3ffe87f8  A4      : 0x00000012  A5      : 0x3ffdc740  
A6      : 0x3ffc58f8  A7      : 0x3ffe87f8  A8      : 0x800d75f6  A9      : 0x3ffeb950  
A10     : 0x3ffeb97c  A11     : 0x3ffc53fc  A12     : 0x3ffe87f8  A13     : 0x3ffc775c  
A14     : 0x3ffe9c04  A15     : 0x3ffc4718  SAR     : 0x0000001b  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x0000002d  LBEG    : 0x40090968  LEND    : 0x4009097e  LCOUNT  : 0x00000000  

Backtrace: 0x400d73c3:0x3ffeb970 0x400d9cc3:0x3ffeb9d0

  #0  0x400d73c3:0x3ffeb970 in BLEconnect() at main/ZgatewayBT.ino:737 (discriminator 1)
  #1  0x400d9cc3:0x3ffeb9d0 in immediateBTAction(void*) at main/ZgatewayBT.ino:1237

ELF file SHA256: de46383a51952943
Rebooting...

[h2zero]

This looks to be caused by the bleconnect loop still iterating when the command arrives which then swaps the queue when immediate is used. A semaphore or other blocking mechanism my be required.

[github-actions[bot]]

This issue is stale because it has been open for 30 days with no activity.

[sebbo2002]

This bug is still present in the current version 1.6.0... #unstale

[github-actions[bot]]

This issue is stale because it has been open for 90 days with no activity.

[DigiH]

Bump