espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.58k stars 7.27k forks source link

assertion in xQueueGenericReceive when doing Lora with Interrupts. (IDFGH-4680) #6492

Closed rfx77 closed 3 years ago

rfx77 commented 3 years ago

I do Lora with interrupt-receive. in the main loop i update a oled display. when i do not use a delay (to reproduce error) i get this stacktrace every minute or so when i use a delay it is not often but still happens.

/home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/queue.c:1446 (xQueueGenericReceive)- assert failed!
abort() was called at PC 0x4008abfb on core 1

Backtrace: 0x4008e724:0x3ffbe660 0x4008e951:0x3ffbe680 0x4008abfb:0x3ffbe6a0 0x400d5901:0x3ffbe6e0 0x400d2930:0x3ffbe700 0x400d309d:0x3ffbe730 0x400d30d0:0x3ffbe750 0x400d370d:0x3ffbe770 0x400810ea:0x3ffbe790 0x40081139:0x3ffbe7b0 0x4008758d:0x3ffbe7d0 0x4000bfed:0x3ffb1e30 0x4008c005:0x3ffb1e40 0x4008b4d4:0x3ffb1e60 0x400d4d42:0x3ffb1e90 0x400d515b:0x3ffb1ec0 0x400d2581:0x3ffb1ee0 0x400d25d5:0x3ffb1f00 0x400d2741:0x3ffb1f20 0x400d1958:0x3ffb1f40 0x400d1cf8:0x3ffb1f60 0x400d1da1:0x3ffb1f90 0x400d65ed:0x3ffb1fb0 0x4008aed5:0x3ffb1fd0
  #0  0x4008e724:0x3ffbe660 in invoke_abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/panic.c:707
  #1  0x4008e951:0x3ffbe680 in abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/panic.c:707
  #2  0x4008abfb:0x3ffbe6a0 in xQueueGenericReceive at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/queue.c:1996
  #3  0x400d5901:0x3ffbe6e0 in spiTransaction at C:\users\rauscherf\.platformio\packages\framework-arduinoespressif32\cores\esp32/esp32-hal-spi.c:283
  #4  0x400d2930:0x3ffbe700 in SPIClass::beginTransaction(SPISettings) at C:\users\rauscherf\.platformio\packages\framework-arduinoespressif32\libraries\SPI\src/SPI.cpp:270
  #5  0x400d309d:0x3ffbe730 in LoRaClass::singleTransfer(unsigned char, unsigned char) at C:\users\rauscherf\Documents\Arduino\libraries\LoRa\src/LoRa.cpp:391 (discriminator 4)
  #6  0x400d30d0:0x3ffbe750 in LoRaClass::readRegister(unsigned char) at C:\users\rauscherf\Documents\Arduino\libraries\LoRa\src/LoRa.cpp:391 (discriminator 4)
  #7  0x400d370d:0x3ffbe770 in LoRaClass::handleDio0Rise() at C:\users\rauscherf\Documents\Arduino\libraries\LoRa\src/LoRa.cpp:391 (discriminator 4)
  #8  0x400810ea:0x3ffbe790 in LoRaClass::onDio0Rise() at C:\users\rauscherf\Documents\Arduino\libraries\LoRa\src/LoRa.cpp:391 (discriminator 4)
  #9  0x40081139:0x3ffbe7b0 in __onPinInterrupt at C:\users\rauscherf\.platformio\packages\framework-arduinoespressif32\cores\esp32/esp32-hal-gpio.c:274
  #10 0x4008758d:0x3ffbe7d0 in _xt_lowint1 at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/xtensa_vectors.S:1154
  #11 0x4000bfed:0x3ffb1e30 in ?? ??:0
  #12 0x4008c005:0x3ffb1e40 in vTaskExitCritical at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/tasks.c:3507
  #13 0x4008b4d4:0x3ffb1e60 in xEventGroupWaitBits at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/event_groups.c:338
  #14 0x400d4d42:0x3ffb1e90 in i2cProcQueue at C:\users\rauscherf\.platformio\packages\framework-arduinoespressif32\cores\esp32/esp32-hal-i2c.c:1279
  #15 0x400d515b:0x3ffb1ec0 in i2cWrite at C:\users\rauscherf\.platformio\packages\framework-arduinoespressif32\cores\esp32/esp32-hal-i2c.c:1621
  #16 0x400d2581:0x3ffb1ee0 in TwoWire::writeTransmission(unsigned short, unsigned char*, unsigned short, bool) at C:\users\rauscherf\.platformio\packages\framework-arduinoespressif32\libraries\Wire\src/Wire.cpp:368
  #17 0x400d25d5:0x3ffb1f00 in TwoWire::endTransmission(bool) at C:\users\rauscherf\.platformio\packages\framework-arduinoespressif32\libraries\Wire\src/Wire.cpp:368
  #18 0x400d2741:0x3ffb1f20 in TwoWire::endTransmission() at C:\users\rauscherf\.platformio\packages\framework-arduinoespressif32\libraries\Wire\src/Wire.cpp:368
  #19 0x400d1958:0x3ffb1f40 in Adafruit_SSD1306::display() at src/Adafruit_SSD1306.cpp:519 (discriminator 2)
  #20 0x400d1cf8:0x3ffb1f60 in task_loop(void*) at src/GPSMain.cpp:90
  #21 0x400d1da1:0x3ffb1f90 in loop() at src/GPSMain.cpp:90
  #22 0x400d65ed:0x3ffb1fb0 in loopTask(void*) at C:\users\rauscherf\.platformio\packages\framework-arduinoespressif32\cores\esp32/main.cpp:19
  #23 0x4008aed5:0x3ffb1fd0 in vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c:355 (discriminator 1)

Rebooting...

With no delay the issue is reproduceable because it happens every minute or so. (see last line of code)

here is my code:


#include <Arduino.h>
#include <TinyGPS++.h>
#include "axp20x.h"
#include <SPI.h>
#include <LoRa.h>
#include <Wire.h>  
#include "Adafruit_GFX.h"
#include "Adafruit_SSD1306.h"
#define SCREEN_WIDTH 128 // OLED display width, in pixels
#define SCREEN_HEIGHT 32

AXP20X_Class axp;

#define OLED_RESET 4

Adafruit_SSD1306 display(OLED_RESET);

#define SS      18   // GPIO18 -- SX1278's CS
#define RST     14   // GPIO14 -- SX1278's RESET
#define DI0     26   // GPIO26 -- SX1278's IRQ(Interrupt Request)
#define BAND  433125000

byte msgCount = 0;            // count of outgoing messages
byte localAddress = 0xBA;     // address of this device
byte destination = 0xFF;      // destination to send to
long lastSendTime = 0;        // last send time
int interval = 2000;          // interval between sends

int counter = 0;

void doRcv(int len);

void setup()
{
  Serial.begin(115200);

  Wire.begin(21, 22);
  if (!axp.begin(Wire, AXP192_SLAVE_ADDRESS)) {
    Serial.println("AXP192 Begin PASS");
  } else {
    Serial.println("AXP192 Begin FAIL");
  }

  display.begin(SSD1306_SWITCHCAPVCC, 0x3C, 0, 22, 21, 800000);
  display.clearDisplay();

  axp.setPowerOutPut(AXP192_LDO2, AXP202_ON);

  LoRa.setPins(SS,RST,DI0);
  if (!LoRa.begin(BAND)) {
    Serial.println("Starting LoRa failed!");
    while (1);
  }
//  LoRa.onReceive(onReceive);
//  LoRa.enableCrc();
  LoRa.setSyncWord(0xAA);
  LoRa.setTxPower(0);
  LoRa.setSpreadingFactor(12);
  LoRa.setSignalBandwidth(125E3);
  LoRa.setCodingRate4(8);
  //LoRa.setGain(1);

  LoRa.onReceive(doRcv);
  LoRa.receive();

  Serial.println("init ok");
}

long last1 = millis();
long last2 = last1;
long d_pt = 100;
long d_ms = 60000;
String lastvolt[4];
long curr = 0;

const char* circle = "-\\|/";
int pos = 0;

char buffer[1024];

void doRcv(int len) {
  int recipient = LoRa.read();
  byte sender = LoRa.read();
  byte incomingMsgId = LoRa.read();
  byte incomingLength = LoRa.read();

  String incoming = "";

  while (LoRa.available()) {
    incoming += (char)LoRa.read();
  }

  lastvolt[0] = lastvolt[1];
  lastvolt[1] = lastvolt[2];
  lastvolt[2] = lastvolt[3];
  lastvolt[3] = incoming;

  int rssi = LoRa.packetRssi();
  float snr =  LoRa.packetSnr();
  sprintf(buffer, "%d %4.1f: %s", rssi, snr, incoming.c_str());
  Serial.println(buffer);

}

void loop() {

  curr = millis();

  display.clearDisplay();
  display.setTextColor(WHITE);

  display.setTextSize(1);

  display.setCursor(0,0);
  display.print(lastvolt[0].substring(0,20));
  display.setCursor(0,0);
  display.print(String(circle[pos]));
  display.setCursor(0,8);
  display.println(lastvolt[1].substring(0,20));
  display.setCursor(0,16);
  display.println(lastvolt[2].substring(0,20));
  display.setCursor(0,24);
  display.println(lastvolt[3].substring(0,20));

  display.display();

  pos++;
  if (pos > 3) pos =0;
  last2 = curr;

  //delay(100);    // Comment out this delay to reproduce the problem
}

My Board is a T-Beam with Lora. I use PlatformIO

Originally posted by @rfx77 in https://github.com/espressif/arduino-esp32/issues/4580#issuecomment-771850378

rfx77 commented 3 years ago

Here is the same problem: https://github.com/sandeepmistry/arduino-LoRa/issues/224#issuecomment-771884658

igrr commented 3 years ago

@rfx77 What happens is, SPIClass::beginTransaction function is invoked from an interrupt handler (you can see __onPinInterrupt in the call stack). However this function doesn't support being called from an interrupt — it acquires a mutex using xSemaphoreTake function (hidden in SPI_MUTEX_LOCK macro): https://github.com/espressif/arduino-esp32/blob/4b385690bc4171b75b398e57fb1a3be33c5980f4/cores/esp32/esp32-hal-spi.c#L714-L719 I don't know whether Arduino SPI API requires that beginTransaction works from ISRs. If yes, then this needs to be fixed in arduino-esp32 project, where SPIClass is implemented. I'm going to close this ticket as it doesn't seem to be an issue in ESP-IDF.

chegewara commented 3 years ago

Probably you are doing some reading from LoRa in ISR function. I am recommending to use this library: https://github.com/StuartsProjects/SX12XX-LoRa

rfx77 commented 3 years ago

When i put the reading out of the ISR and do a polling in a seperate Tasks i get this error sometimes:

assertion in freertos "tasks.c:1438" when the delay(1) is called (see below) (with vTaskDelay )

This is my recieving-loop:

void receiveTask(void*) {
  int ps = 0;
  while (true)  {

    ps = LoRa.parsePacket();
    if(ps) {
      doRcv(ps);
    }
    delay(1);
  }

}

I only do polling now without an ISR

igrr commented 3 years ago

@rfx77 Please decode the backtrace reported by the panic handler, it will help understand the cause of this assertion.