search

manuelbl / ttn-esp32

The Things Network device library for ESP32 (ESP-IDF) and SX127x based devices
MIT License
301 stars 64 forks source link

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

Open vrees opened 3 months ago

vrees commented 3 months ago

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 commented 3 months ago

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 commented 2 months ago

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().