LMIC failed and stopped: components/ttn-esp32/src/lmic/radio.c:1166

[vrees]

Hi,
I am using my self created Lora Board using ESP32-S3 Microcontroller, HopeRF board RFM95W with SX1276 / 868 MHz and the latest master branch version of ttn-esp32.
Hardware: https://oshwlab.com/vrees/esp32loraboard-2023-12-29-pro

The code sends data every minute via LoraWan and then goes to deep sleep. This works fine several times. But after an unspecified number of wake-ups of DeepSleep suddenly the following error / assertion is raised. That could be after 10 Minutes or after 50 minutes.

As log shows the error occurs in ttn.resumeAfterDeepSleep().

Any idea what's wrong?

15:55:52.046 > I (29) boot: ESP-IDF 5.1.1 2nd stage bootloader
15:55:52.046 > I (29) boot: compile time Mar 26 2024 07:53:49
15:55:52.046 > I (29) boot: Multicore bootloader
15:55:52.046 > I (32) boot: chip revision: v0.2
15:55:52.046 > I (36) boot.esp32s3: Boot SPI Speed : 80MHz
15:55:52.090 > I (40) boot.esp32s3: SPI Mode : DIO
15:55:52.090 > I (45) boot.esp32s3: SPI Flash Size : 8MB
15:55:52.090 > I (50) boot: Enabling RNG early entropy source...
15:55:52.090 > I (55) boot: Partition Table:
15:55:52.090 > I (59) boot: ## Label Usage Type ST Offset Length
15:55:52.090 > I (66) boot: 0 nvs WiFi data 01 02 00009000 00006000
15:55:52.090 > I (74) boot: 1 phy_init RF data 01 01 0000f000 00001000
15:55:52.090 > I (81) boot: 2 factory factory app 00 00 00010000 00100000
15:55:52.137 > I (89) boot: End of partition table
15:55:52.137 > I (93) esp_image: segment 0: paddr=00010020 vaddr=3c030020 size=0ead8h ( 60120) map
15:55:52.137 > I (112) esp_image: segment 1: paddr=0001eb00 vaddr=3fc94d00 size=01518h ( 5400) load
15:55:52.137 > I (113) esp_image: segment 2: paddr=00020020 vaddr=42000020 size=29054h (168020) map
15:55:52.190 > I (148) esp_image: segment 3: paddr=0004907c vaddr=3fc96218 size=01650h ( 5712) load
15:55:52.191 > I (150) esp_image: segment 4: paddr=0004a6d4 vaddr=40374000 size=10cc4h ( 68804) load
15:55:52.191 > I (169) esp_image: segment 5: paddr=0005b3a0 vaddr=50000000 size=00178h ( 376)
15:55:52.191 > I (170) esp_image: segment 6: paddr=0005b520 vaddr=600fe000 size=00070h ( 112)
15:55:52.191 > I (181) boot: Loaded app from partition at offset 0x10000
15:55:52.191 > I (181) boot: Disabling RNG early entropy source...
15:55:52.235 > I (197) cpu_start: Multicore app
15:55:52.235 > I (197) cpu_start: Pro cpu up.
15:55:52.235 > I (198) cpu_start: Starting app cpu, entry point is 0x40376df0
15:55:52.235 > I (0) cpu_start: App cpu up.
15:55:52.235 > I (216) cpu_start: Pro cpu start user code
15:55:52.235 > I (216) cpu_start: cpu freq: 160000000 Hz
15:55:52.235 > I (216) cpu_start: Application information:
15:55:52.235 > I (219) cpu_start: Project name: Esp32LoraBoard2
15:55:52.235 > I (225) cpu_start: App version: c660bb5-dirty
15:55:52.278 > I (230) cpu_start: Compile time: Mar 26 2024 07:53:25
15:55:52.278 > I (236) cpu_start: ELF file SHA256: acf4e9ce927a8188...
15:55:52.278 > I (242) cpu_start: ESP-IDF: 5.1.1
15:55:52.278 > I (247) cpu_start: Min chip rev: v0.0
15:55:52.278 > I (251) cpu_start: Max chip rev: v0.99
15:55:52.278 > I (256) cpu_start: Chip rev: v0.2
15:55:52.278 > I (261) heap_init: Initializing. RAM available for dynamic allocation:
15:55:52.278 > I (268) heap_init: At 3FC98678 len 00051098 (324 KiB): DRAM
15:55:52.321 > I (274) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
15:55:52.321 > I (281) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
15:55:52.321 > I (287) heap_init: At 600FE070 len 00001F78 (7 KiB): RTCRAM
15:55:52.321 > I (295) spi_flash: detected chip: gd
15:55:52.321 > I (298) spi_flash: flash io: dio
15:55:52.321 > I (302) sleep: Configure to isolate all GPIO pins in sleep state
15:55:52.321 > I (309) sleep: Enable automatic switching of GPIO sleep configuration
15:55:52.358 > I (316) app_start: Starting scheduler on CPU0
15:55:52.358 > I (321) app_start: Starting scheduler on CPU1
15:55:52.358 > I (321) main_task: Started on CPU0
15:55:52.358 > I (331) main_task: Calling app_main()
15:55:52.358 > Start app on ESP32LoraBoard
15:55:52.874 > wakeup(). Boot number: 36
15:55:52.874 > Wakeup caused by timer
15:55:52.874 > Enabling Peripheral Power
15:55:52.874 > Init IO ports
15:55:52.874 > I (841) gpio: GPIO[16]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
15:55:52.874 > I (841) gpio: GPIO[18]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
15:55:52.874 > I (851) gpio: GPIO[3]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
15:55:52.874 > I (861) gpio: GPIO[6]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
15:55:52.917 > I (871) gpio: GPIO[7]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
15:55:52.917 > I (881) gpio: GPIO[8]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
15:55:52.917 > I (891) gpio: GPIO[9]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
15:55:52.917 > I (901) gpio: GPIO[10]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
15:55:52.917 > I (911) gpio: GPIO[15]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
15:55:52.963 > MAC-Adress: xx xx xx xx xx xx
15:55:52.963 > I (931) ttn_prov: DevEUI, AppEUI/JoinEUI and AppKey saved in NVS storage
15:55:55.058 > Water Level is LOW 0
15:55:55.058 > Try to resume from DeepSleep...
15:55:55.058 > I (3041) gpio: GPIO[13]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
15:55:55.101 > I (3051) gpio: GPIO[14]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
15:55:55.101 > I (3061) gpio: GPIO[36]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:1
15:55:55.101 > I (3071) gpio: GPIO[37]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:1
15:55:55.101 > I (3081) ttn_hal: IO initialized
15:55:55.101 > I (3081) ttn_hal: SPI initialized
15:55:55.101 > I (3091) ttn_hal: Timer initialized
15:55:55.101 > E (3101) ttn_hal: LMIC failed and stopped: components/ttn-esp32/src/lmic/radio.c:1166

main.cpp:

extern "C" void app_main(void)
{
  printf("Start app on ESP32LoraBoard\n");
  vTaskDelay(500 / portTICK_PERIOD_MS); // Take some time to open up the Serial Monitor

  wakeupAndInit();

  initEsp32Resources();

 // Configure the SX127x pins
  ttn.configurePins(TTN_SPI_HOST, TTN_PIN_NSS, TTN_PIN_RXTX, TTN_PIN_RST, TTN_PIN_DIO0, TTN_PIN_DIO1);

  showMacAddress();
  ttn.provisionWithMAC(appEui, appKey);

  // Register callback for received messages
  ttn.onMessage(messageReceived);

  initAdc();

  vTaskDelay(2000 / portTICK_PERIOD_MS);
  readSensorValues();

  printf("Try to resume from DeepSleep...\n");
  if (ttn.resumeAfterDeepSleep())
  {
      printf("Resumed from deep sleep.\n");
  }
  else
  {
      printf("Joining...\n");
      if (ttn.join())
      {
          printf("Joined.\n");
      }
      else
      {
          printf("Join failed. Goodbye\n");
          return;
      }
 }

  // send data and deep sleep afterwards
  xTaskCreate(sendMessages, "send_messages", 1024 * 4, (void *)0, 3, nullptr);
}

#define TTN_SPI_HOST      SPI2_HOST
#define TTN_SPI_DMA_CHAN  1
#define TTN_PIN_SPI_SCLK  21
#define TTN_PIN_SPI_MOSI  47
#define TTN_PIN_SPI_MISO  48
#define TTN_PIN_NSS       14 // also called CS
#define TTN_PIN_RXTX      TTN_NOT_CONNECTED
#define TTN_PIN_RST       13
#define TTN_PIN_DIO0      37
#define TTN_PIN_DIO1      36
#define TTN_PIN_DIO2      35`

void wakeupAndInit()
{
  // Increment boot number and print it every reboot
  ++bootCount;
  sensor_values.bootCount = bootCount;
  sensor_values.execTooLongCount = execTooLongCount;
  printf("wakeup(). Boot number: %d\n", bootCount);

  // Print the wakeup reason for ESP32
  printWakeupReason();

  // define output level before port config to ensure unwanted glitch
  enablePeripheralPower();
  initIoPorts();
}


void initIoPorts()
{
    printf("Init IO ports\n");
    // Configure all output pins
    gpio_config_t io_conf;
    // disable interrupt
    io_conf.intr_type = GPIO_INTR_DISABLE;
    // set as output mode
    io_conf.mode = GPIO_MODE_OUTPUT;
    // bit mask of the pins that you want to set
    io_conf.pin_bit_mask = GPIO_OUTPUT_PIN_SEL;
    // disable pull-down mode
    io_conf.pull_down_en = 0;
    // disable pull-up mode
    io_conf.pull_up_en = 0;
    // configure GPIO with the given settings
    gpio_config(&io_conf);

    // Configure all input pins
    io_conf.intr_type = GPIO_INTR_DISABLE;
    io_conf.mode = GPIO_MODE_INPUT;
    io_conf.pin_bit_mask = GPIO_INPUT_PIN_SEL;
    io_conf.pull_down_en = 0;
    io_conf.pull_up_en = 0;
    gpio_config(&io_conf);
}

void initEsp32Resources()
{
esp_err_t err;
// Initialize the GPIO ISR handler service
err = gpio_install_isr_service(ESP_INTR_FLAG_IRAM);
ESP_ERROR_CHECK(err);

// Initialize the NVS (non-volatile storage) for saving and restoring the keys
err = nvs_flash_init();
ESP_ERROR_CHECK(err);

// Initialize SPI bus
spi_bus_config_t spi_bus_config;
memset(&spi_bus_config, 0, sizeof(spi_bus_config_t));
spi_bus_config.miso_io_num = TTN_PIN_SPI_MISO;
spi_bus_config.mosi_io_num = TTN_PIN_SPI_MOSI;
spi_bus_config.sclk_io_num = TTN_PIN_SPI_SCLK;
spi_bus_config.quadwp_io_num = -1;
spi_bus_config.quadhd_io_num = -1;
spi_bus_config.max_transfer_sz = 0;
err = spi_bus_initialize(TTN_SPI_HOST, &spi_bus_config, SPI_DMA_CH_AUTO);
ESP_ERROR_CHECK(err);

}

[manuelbl]

This error has always been related to SPI communication. It's the first SPI interaction after start.

So far it was either a wrong pin configuration or an invalid SPI mode. The first one certainly doesn't apply in your case. The latter one is possible. An invalid SPI mode can work sometimes.

I propose you analyze the timing the SPI signals and the voltage levels of the SPI pins (incl. NSS) and verify that they are correct. You can also try another SPI mode (see https://github.com/manuelbl/ttn-esp32/blob/master/src/hal/hal_esp32.c#L218).

[vrees]

As a workaround I set 'CONFIG_ESP_INT_WDT_CHECK_CPU1=y'.
So in case resumeAfterDeepSleep() blocks due to corrupt SPI communication and a task watchdog timeout occurred it resets the CPU. The first time after reset a ttn.join() gets executed once instead of ttn.resumeAfterDeepSleep().