Rebooting after transmit, xQueueGenericSend exception

ianmtaylor1 commented 1 year ago

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

Describe the bug Occasionally when transmitting, especially when transmitting two signals in quick succession, the board will unexpectedly reboot and print the following error to the serial console:

assert failed: xQueueGenericSend queue.c:832 (pxQueue->pcHead != ((void *)0) || pxQueue->u.xSemaphore.xMutexHolder == ((void *)0) || pxQueue->u.xSemaphore.xMutexHolder == xTaskGetCurrentTaskHandle())

Backtrace: 0x40083add:0x3ffb2100 0x4008d9d5:0x3ffb2120 0x400935c1:0x3ffb2140 0x4008e48a:0x3ffb2270 0x401aa235:0x3ffb22b0 0x401a80e3:0x3ffb22d0 0x400f00df:0x3ffb22f0 0x400f023e:0x3ffb2310 0x400f036b:0x3ffb2330 0x400de20b:0x3ffb2360 0x400de365:0x3ffb23c0 0x400e45a2:0x3ffb23e0 0x400e4667:0x3ffb2750 0x401c0e07:0x3ffb2770 0x400e7459:0x3ffb2790 0x400e5f2a:0x3ffb27d0 0x40125e85:0x3ffb2810

To Reproduce

Send a series of these messages to the MQTT broker in quick succession:

Topic: rfbridge/OpenMQTTGateway/commands/MQTTto433
Payload: either
- {"value":1135923,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
- {"value":1135932,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}

Expected behavior The Etekcity RF outlet these commands control turns on and off and the ESP32 board does not crash.

Screenshots Full serial output during crash:

N: Send on /433toMQTT msg {"value":1135923,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
N: Switching to RTL_433 Receiver: 433.92Mhz
N: [ MQTT->OMG ]: {"value":1135932,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
N: RF Protocol:1
N: RF Pulse Lgth: 185
N: Bits nb: 24
N: CC1101 TX Power: 12
N: Transmit mhz: 433.92
N: MQTTtoRF OK
N: Send on /433toMQTT msg {"value":1135932,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
N: Switching to RTL_433 Receiver: 433.92Mhz
N: Send on /RTL_433toMQTT/Ambientweather-F007TH/1/161 msg {"model":"Ambientweather-F007TH","id":161,"channel":1,"battery_ok":1,"temperature_C":12.38889,"humidity":17,"mic":"CRC","protocol":"Ambient Weather F007TH, TFA 30.3208.02, SwitchDocLabs F016TH temperature sensor","rssi":-64,"duration":206000}
N: [ MQTT->OMG ]: {"value":1135923,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
N: RF Protocol:1
N: RF Pulse Lgth: 185
N: Bits nb: 24
N: CC1101 TX Power: 12
N: Transmit mhz: 433.92
N: MQTTtoRF OK
N: Send on /433toMQTT msg {"value":1135923,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
N: Switching to RTL_433 Receiver: 433.92Mhz
N: [ MQTT->OMG ]: {"value":1135932,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
N: RF Protocol:1
N: RF Pulse Lgth: 185
N: Bits nb: 24
N: CC1101 TX Power: 12
N: Transmit mhz: 433.92
N: MQTTtoRF OK
N: Send on /433toMQTT msg {"value":1135932,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
N: Switching to RTL_433 Receiver: 433.92Mhz
rtl_433_ESP(7): Average RSSI Signal -74 dbm, adjusted RSSI Threshold -65, samples 50000
N: [ MQTT->OMG ]: {"value":1135923,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
N: RF Protocol:1
N: RF Pulse Lgth: 185
N: Bits nb: 24
N: CC1101 TX Power: 12
N: Transmit mhz: 433.92
N: MQTTtoRF OK
N: Send on /433toMQTT msg {"value":1135923,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
N: Switching to RTL_433 Receiver: 433.92Mhz
N: [ MQTT->OMG ]: {"value":1135932,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
N: RF Protocol:1
N: RF Pulse Lgth: 185
N: Bits nb: 24
N: CC1101 TX Power: 12
N: Transmit mhz: 433.92
N: MQTTtoRF OK
N: Send on /433toMQTT msg {"value":1135932,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
N: Switching to RTL_433 Receiver: 433.92Mhz
N: Send on /SYStoMQTT msg {"uptime":130,"version":"version_tag","discovery":true,"ohdiscovery":false,"env":"taylovich-iot-433","freemem":87244,"mqttport":"8883","mqttsecure":true,"minfreemem":61744,"tempc":45.55556,"freestack":4636,"rssi":-58,"SSID":"taylovich-iot","BSSID":"3E:98:B5:28:58:FE","ip":"10.185.9.217","mac":"B0:B2:1C:A7:41:B8","actRec":3,"mhz":433.92,"RTLRssiThresh":-65,"RTLRssi":-71,"RTLAVGRssi":-74,"RTLCnt":8,"modules":["WebUI","RF","RF2","RTL_433"]}
N: Send on /WebUItoMQTT msg {"displayMetric":true,"webUISecure":true,"displayQueue":1}
N: [ MQTT->OMG ]: {"value":1135923,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
N: RF Protocol:1
N: RF Pulse Lgth: 185
N: Bits nb: 24
N: CC1101 TX Power: 12
N: Transmit mhz: 433.92
N: MQTTtoRF OK
N: Send on /433toMQTT msg {"value":1135923,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
N: Switching to RTL_433 Receiver: 433.92Mhz
N: [ MQTT->OMG ]: {"value":1135932,"protocol":1,"length":24,"delay":185,"mhz":433.92,"repeat":5,"cc1101_pa":7}
N: RF Protocol:1
N: RF Pulse Lgth: 185
N: Bits nb: 24

assert failed: xQueueGenericSend queue.c:832 (pxQueue->pcHead != ((void *)0) || pxQueue->u.xSemaphore.xMutexHolder == ((void *)0) || pxQueue->u.xSemaphore.xMutexHolder == xTaskGetCurrentTaskHandle())

Backtrace: 0x40083add:0x3ffb2100 0x4008d9d5:0x3ffb2120 0x400935c1:0x3ffb2140 0x4008e48a:0x3ffb2270 0x401aa235:0x3ffb22b0 0x401a80e3:0x3ffb22d0 0x400f00df:0x3ffb22f0 0x400f023e:0x3ffb2310 0x400f036b:0x3ffb2330 0x400de20b:0x3ffb2360 0x400de365:0x3ffb23c0 0x400e45a2:0x3ffb23e0 0x400e4667:0x3ffb2750 0x401c0e07:0x3ffb2770 0x400e7459:0x3ffb2790 0x400e5f2a:0x3ffb27d0 0x40125e85:0x3ffb2810

ELF file SHA256: b32d8a4e68cc53bb

Rebooting...
ets Jul 29 2019 12:21:46

rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:1184
load:0x40078000,len:13192
load:0x40080400,len:3028
entry 0x400805e4
N: 
************* WELCOME TO OpenMQTTGateway **************
N: OpenMQTTGateway Version: version_tag
E (9407) wifi:Association refused temporarily, comeback time 1024 mSec
N: WiFi ok with manual config credentials
[  6311][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND
N: No WebUI config to load
N: OpenMQTTGateway URL: http://10.185.9.217/
N: ZwebUI setup done
N: RF_EMITTER_GPIO: 12 
N: RF_RECEIVER_GPIO: 27 
N: C1101 spi Connection OK
N: RF_EMITTER_GPIO: 12 
N: RF_RECEIVER_GPIO: 27 
N: ZgatewayRTL_433 setup done 
N: Switching to RTL_433 Receiver: 433.92Mhz
N: OpenMQTTGateway modules: ["WebUI","RF","RF2","RTL_433"]
N: ************** Setup OpenMQTTGateway end **************

Environment (please complete the following information):

OMG version 1.6.0, installed to board from VSCode and PlatformIO.
ESP32-WROOM-32 development board with CC1101 transceiver.
Custom configuration in my_env.ini:
```
[platformio]
default_envs = myenv-433
```

[env:myenv-433] extends = env:esp32dev-multi_receiver build_flags = ${env:esp32dev-multi_receiver.build_flags} '-UZgatewayPilight' ; Replicate workaround in https://github.com/1technophile/OpenMQTTGateway/pull/1785 '-DESPWifiManualSetup=true' '-Dwifi_ssid=""' '-Dwifi_password=""' '-DBase_Topic="rfbridge/"' '-Ddiscovery_Topic="OMGdiscovery"' '-DMQTT_SERVER=""' '-DMQTT_PORT="8883"' '-DMQTT_SECURE_DEFAULT=true' '-DMQTT_USER=""' '-DMQTT_PASS=""' '-DGateway_Name="OpenMQTTGateway"'



**Additional context**

I thought it might have been a power supply issue, however, it happens whether connected to my PC USB port or dedicated USB power supply. I tried adjusting the transmission power (hence "cc1101_pa":7) however that didn't seem to do anything based on the serial output.

**Thanks in advance for any help!**

* 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 
[![Build Status](https://github.com/1technophile/OpenMQTTGateway/workflows/Build/badge.svg?branch=master)](https://github.com/1technophile/OpenMQTTGateway/actions)
* If you are not sure this is a bug or an enhancement post your question to the forum below
[![Community forum](https://img.shields.io/badge/community-forum-brightgreen.svg)](https://community.openmqttgateway.com)

1technophile commented 1 year ago

Hello,

How much time do you leave between the commands?

ianmtaylor1 commented 1 year ago

Hi,

I'll see the crash if I send about 1 message every second.

ianmtaylor1 commented 1 year ago

Hello,

I hope I'm not bugging you or stepping on your toes. I did a little more investigating of this issue and found a potential fix, I'm wondering if this makes sense to you.

I think that it has to do with the placement of the call to disableActiveReceiver() inside the function MQTTtoRF() (currently line 271 in ZgatewayRF.ino) and that this function should be called before ELECHOUSE_cc1101.setPA().

The setPA function causes an SPI signal to be sent to the CC1101 board. If that board is still receiving, this could interfere with a message that is currently being received. The crash didn't have to do with sending messages too quickly, but with sending a message while a message is being received. This is just more likely to happen when you are sending several messages quickly.

After changing that section of the code to the following:

#    ifdef ZradioCC1101 // set Receive off and Transmitt on
      disableActiveReceiver(); // <---- THIS MOVED

      int txPower = RFdata["txpower"] | RF_CC1101_TXPOWER;
      ELECHOUSE_cc1101.setPA((int)txPower);
      Log.notice(F("CC1101 TX Power: %d" CR), txPower);

      float trMhz = RFdata["mhz"] | CC1101_FREQUENCY;
      if (validFrequency((int)trMhz)) {
        ELECHOUSE_cc1101.SetTx(trMhz);
        Log.notice(F("Transmit mhz: %F" CR), trMhz);
      }
#    endif

I can no longer reproduce the crash.

I'm not familiar with the internals of these functions, so I don't know if this is 100% correct or if there was any reason disableActiveReceiver() was being called inside the if(validFrequency((int)trMhz)) conditional. Does this make sense to you? If so, I'm happy to make a pull request if you would like.

1technophile commented 1 year ago

Hello,

No problem, this is a collaborative project. Quality comments are always welcome :-) @northernman54 may have a better answer than me on this

NorthernMan54 commented 1 year ago

@ianmtaylor1 That change makes sense looking at the logic. Pls submit a PR

ianmtaylor1 commented 1 year ago

Thanks for your time!

1technophile / OpenMQTTGateway

Rebooting after transmit, xQueueGenericSend exception #1800