Cant receive DMX : timer is not running (esp-idf v5.0.2)

[bensuffolk]

I have upgraded my project from esp-idf v4.4.4 upgraded to v5.0.2 so that I could use some new networking featrues I require. IN doing so I have changed from esp_dmx V2.0.2 to V3.0.3-beta as I needed compatability with esp-idf V5 and above.

However when I run a loop to recieve DMX I get repeated errors about the timer not running:

They look to be running about DMX_TIMEOUT_TICK interval. If I actually connect a DMX source then I get the same error message repeated for what looks like every byte received. This is quickly followed by the watch dog timer error and the ESP halts.

I'm building with PlatformIO under VSCode, its my own custom PCB with an ESP-32-WROVER

[env:esp-wrover-kit]
platform = espressif32
board = esp-wrover-kit
framework = espidf

build_type = debug
board_upload.flash_size = 16MB
board_upload.maximum_ram_size = 532480
board_upload.maximum_size = 16777216

board_build.partitions = partitions.csv

monitor_filters = esp32_exception_decoder
monitor_speed = 115200
monitor_rts = 0
monitor_dtr = 0

PACKAGES: 
 - framework-espidf @ 3.50002.230601 (5.0.2) 
 - tool-cmake @ 3.16.4 
 - tool-esptoolpy @ 1.40501.0 (4.5.1) 
 - tool-mkfatfs @ 2.0.1 
 - tool-mklittlefs @ 1.203.210628 (2.3) 
 - tool-mkspiffs @ 2.230.0 (2.30) 
 - tool-ninja @ 1.9.0 
 - toolchain-esp32ulp @ 1.23500.220830 (2.35.0) 
 - toolchain-xtensa-esp32 @ 11.2.0+2022r1

I have built a small test project to make sure there is nothing else in my main project code thats causing an issue. Pretty much a direct copy of the sample code from the documentation.

#include "esp_dmx.h"
#include "stddef.h"
#include "log.h"

#define DMX_RX_UART DMX_NUM_1
#define DMX_IN_TX 5
#define DMX_IN_RX 19
#define DMX_IN_RTS 18


extern "C" void app_main()
{
 LOG_I("Starting Main");
 
 uint8_t rx_buffer[DMX_PACKET_SIZE];

 dmx_set_pin(DMX_RX_UART, DMX_IN_TX, DMX_IN_RX, DMX_IN_RTS);
 dmx_driver_install(DMX_RX_UART, DMX_DEFAULT_INTR_FLAGS);

 dmx_packet_t packet;

 LOG_I("Installed Driver");

 while(1) {
  if (dmx_receive(DMX_RX_UART, &packet, DMX_TIMEOUT_TICK)) {

   // Check that no errors occurred.
   if (packet.err == ESP_OK) {
    dmx_read(DMX_RX_UART, rx_buffer, packet.size);
   } else {
    LOG_I("An error occurred receiving DMX!");
   }

  } else {
   LOG_I("Timed out waiting for DMX.");
  }

 }
}

I (29) boot: ESP-IDF 5.0.2 2nd stage bootloader
I (29) boot: compile time 07:55:20
I (29) boot: chip revision: v3.0
I (32) boot.esp32: SPI Speed      : 40MHz
I (37) boot.esp32: SPI Mode       : DIO
I (41) boot.esp32: SPI Flash Size : 16MB
I (46) boot: Enabling RNG early entropy source...
I (51) boot: Partition Table:
I (55) boot: ## Label            Usage          Type ST Offset   Length
I (62) boot:  0 nvs              WiFi data        01 02 00009000 00015000
I (70) boot:  1 otadata          OTA data         01 00 0001e000 00002000
I (77) boot:  2 ota_0            OTA app          00 10 00020000 005f0000
I (85) boot:  3 ota_1            OTA app          00 11 00610000 005f0000
I (92) boot:  4 spiffs           Unknown data     01 82 00c00000 00400000
I (100) boot: End of partition table
I (104) esp_image: segment 0: paddr=00020020 vaddr=3f400020 size=0a244h ( 41540) map
I (127) esp_image: segment 1: paddr=0002a26c vaddr=3ffb0000 size=01efch (  7932) load
I (131) esp_image: segment 2: paddr=0002c170 vaddr=40080000 size=03ea8h ( 16040) load
I (140) esp_image: segment 3: paddr=00030020 vaddr=400d0020 size=18eb4h (102068) map
I (179) esp_image: segment 4: paddr=00048edc vaddr=40083ea8 size=08ac8h ( 35528) load
I (200) boot: Loaded app from partition at offset 0x20000
I (200) boot: Disabling RNG early entropy source...
I (211) cpu_start: Pro cpu up.
I (211) cpu_start: Starting app cpu, entry point is 0x40081c60
I (0) cpu_start: App cpu up.
I (226) cpu_start: Pro cpu start user code
I (226) cpu_start: cpu freq: 160000000 Hz
I (226) cpu_start: Application information:
I (230) cpu_start: Project name:     test
I (235) cpu_start: App version:      1
I (240) cpu_start: Compile time:     Jun 16 2023 07:54:49
I (246) cpu_start: ELF file SHA256:  299e75ec48a7c4c6...
I (252) cpu_start: ESP-IDF:          5.0.2
I (256) cpu_start: Min chip rev:     v0.0
I (261) cpu_start: Max chip rev:     v3.99 
I (266) cpu_start: Chip rev:         v3.0
I (271) heap_init: Initializing. RAM available for dynamic allocation:
I (278) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (284) heap_init: At 3FFB2808 len 0002D7F8 (181 KiB): DRAM
I (290) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (297) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (303) heap_init: At 4008C970 len 00013690 (77 KiB): IRAM
I (311) spi_flash: detected chip: generic
I (314) spi_flash: flash io: dio
I (319) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (329) main.cpp: Line 13: app_main(): Starting Main
I (339) main.cpp: Line 22: app_main(): Installed Driver
E (1589) gptimer: gptimer_stop(389): timer is not running
I (1589) main.cpp: Line 35: app_main(): Timed out waiting for DMX.
E (2839) gptimer: gptimer_stop(389): timer is not running
I (2839) main.cpp: Line 35: app_main(): Timed out waiting for DMX.
E (4089) gptimer: gptimer_stop(389): timer is not running
I (4089) main.cpp: Line 35: app_main(): Timed out waiting for DMX.
E (5339) gptimer: gptimer_stop(389): timer is not running
I (5339) main.cpp: Line 35: app_main(): Timed out waiting for DMX.
E (6589) gptimer: gptimer_stop(389): timer is not running
I (6589) main.cpp: Line 35: app_main(): Timed out waiting for DMX.
E (7839) gptimer: gptimer_stop(389): timer is not running

[someweisguy]

Thanks for reaching out and thank you for your patience on this. I'll try to recreate this issue. I'm guessing it has something to do with the v5.0.2 changes because I believe I am still running v5.0.0!

[someweisguy]

Indeed, it appears that this is a v5.0.0 vs. v5.0.2 issue. I was able to replicate the problem. The GPTimer is a hardware timer that is used for various purposes including sending and receiving DMX and RDM packets. In IDF v5.0.0, it appears we were able to call the function to stop the GPTimer even if the timer wasn't running. In v5.0.2, a log message is now generated when stopping an already stopped timer.

I have implemented a fix which adds a timer_is_running flag to the DMX driver. Before stopping the timer, the flag is checked. This fix appears to be working. I will hopefully have a patch soon!

[someweisguy]

This is fixed in the dev branch. Let me know if you have any other issues!

[bensuffolk]

Many thanks for a quick investigation and fix.

I shall download the dev branch and test.