IDF v4.1: CS crashes during init of status LEDs

[atanisoft]

IDF v4.1: CS crashes during init of status LEDs

[atanisoft]

Sounds like this is a regression in IDF v4.1 that Espressif needs to look into?

There is likely a change in the IDF RMT ISR that is exposing this but with the DCC code not using the IDF API to write data to the RMT it likely would be rejected as an issue. I'll dig into this further and see what can be done to mitigate the race condition properly.

[atanisoft]

This looks related to an issue I'm trying to resolve with NeoPixelBus which is used by the status leds. If you can try disabling CONFIG_STATUS_LED it should fix it while I resolve the issue with NeoPixelBus.

[atanisoft]

@TrainzLuvr can you test status LED with ead408a ? I've done a small bit of testing locally and it looks like it works.

[TrainzLuvr]

The LEDs are back but I don't know about stability.

It crashed and rebooted at least once, after I force-reloaded the main UI page:

22:58:41.652 -> [WS 192.168.x.x/51] Connected
22:58:41.746 -> Incoming connection from 192.168.x.x, fd 52.
22:58:42.875 -> [WS 192.168.x.x/51] Disconnected
22:58:42.922 -> Incoming connection from 192.168.x.x, fd 51.
22:58:42.922 -> Incoming connection from 192.168.x.x, fd 52.
22:58:42.922 -> Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled.
22:58:42.970 -> Core 0 register dump:
22:58:42.970 -> PC : 0x40157d06 PS : 0x00060730 A0 : 0x80159ae7 A1 : 0x3ffda510
22:58:42.970 -> A2 : 0x0000009e A3 : 0x0000059b A4 : 0x3ffd9758 A5 : 0x00000000
22:58:42.970 -> A6 : 0x3ffd9768 A7 : 0x00000000 A8 : 0x8014b611 A9 : 0x3ffda4f0
22:58:42.970 -> A10 : 0x00000000 A11 : 0x3ffb3e68 A12 : 0x800883eb A13 : 0x00000000
22:58:42.970 -> A14 : 0x00000003 A15 : 0x00060023 SAR : 0x00000019 EXCCAUSE: 0x0000001c
22:58:42.970 -> EXCVADDR: 0x0000009e LBEG : 0x4000c2e0 LEND : 0x4000c2f6 LCOUNT : 0xffffffff
22:58:43.018 ->
22:58:43.018 -> ELF file SHA256: 3bc37063189aed11
22:58:43.018 ->
22:58:43.018 -> Backtrace: 0x40157d03:0x3ffda510 0x40159ae4:0x3ffda530 0x40148719:0x3ffda550
22:58:43.018 ->
22:58:43.018 -> Rebooting...
22:58:43.018 -> ets Jun 8 2016 00:22:57

I think if I keep CTRL+R or CTRL+F5 to reload it would crash again after a few times. Also, 2nd LED from the left turned red at one point, then CS crashed and rebooted.

[atanisoft]

Can you run this through IDF.py monitor so that it decodes the backtraces?

As for the led, that is likely due to a small delay in the data line when the rmt reloads the buffer. I have a couple ideas of how to fix it so I'll do some testing tomorrow and push an update.

[TrainzLuvr]

Another crash, after editing one loco in my roster and turning track on and off:

23:07:29.346 -> Incoming connection from 192.168.x.x, fd 53.
23:07:29.440 -> abort() was called at PC 0x400d6977 on core 0
23:07:29.440 ->
23:07:29.440 -> ELF file SHA256: 3bc37063189aed11
23:07:29.440 ->
23:07:29.440 -> Backtrace: 0x40086f24:0x3ffd4b90 0x4008734d:0x3ffd4bb0 0x400d6977:0x3ffd4bd0 0x401968e9:0x3ffd4bf0 0x40196dcd:0x3ffd4c10 0x40196f4c:0x3ffd4c30 0x40197455:0x3ffd4c70 0x401974a3:0x3ffd4c90 0x400da581:0x3ffd4cb0 0x400e2581:0x3ffd4cd0 0x400e2717:0x3ffd4d00 0x400e2593:0x3ffd4d30 0x400e29be:0x3ffd4d60 0x400e58b5:0x3ffd5010 0x400e5b1e:0x3ffd52e0 0x400ebf29:0x3ffd5330 0x401a7e8b:0x3ffd53f0 0x40115e23:0x3ffd5410 0x4011a579:0x3ffd5460 0x4011a385:0x3ffd5490 0x401a8b15:0x3ffd54c0 0x4012596f:0x3ffd54e0
23:07:29.487 ->
23:07:29.487 -> Rebooting...
23:07:29.487 -> ets Jun 8 2016 00:22:57

[TrainzLuvr]

Connecting from idf.py monitor then CTRL+C and then running idf.py monitor again causes it to reboot.

[atanisoft]

IDF.py monitor toggles the DTR/RTS lines on connect so a restart is expected unfortunately.

The abort() looks memory related but to know for sure we will need the decode of the backtrace.

[TrainzLuvr]

How do we get the decode of the backtrace?

[atanisoft]

How do we get the decode of the backtrace?

idf.py monitor should be doing that for you, but if you are not using that you can download decoder.py and run it as: decoder.py -p ESP32 -t ~/.espressif/tools/xtensa-espre32-elf/esp-2020r2-8.2.0/xtensa-esp32-elf -e build/ESP32CommandStation.elf {file containing stacktrace}

[TrainzLuvr]

Well the last abort() crash was obtained via idf.py monitor, yet there was no decode of the backtrace so that's why I'm asking.

[atanisoft]

17:08:48.848 -> [Status] Initializing LEDs (color-mode:RGB, protocol:RMT(6)-APA106, pin: 22, brightness: 128)
17:08:50.641 -> Guru Meditation Error: Core 0 panic'ed (Interrupt wdt timeout on CPU0)
17:08:50.641 -> Core 0 register dump:

This stems from the RailCom UART ISR and Status LED RMT ISR competing for ISR time cycles resulting in effectively a deadlock. I'd suggest disable either the status led or RailCom while I rework the RailCom UART ISR so it doesn't block.

Well the last abort() crash was obtained via idf.py monitor, yet there was no decode of the backtrace so that's why I'm asking.

Were you running idf.py monitor from the CS code directory (where sdkconfig and build directory are present)? In any case, the above usage of decoder.py should be able to decode it.

[TrainzLuvr]

Yes, I was in the code top folder.

Should the Railcom and Status LED be competing for ISR cycles like this - sounds like a problem with ISR then?

[atanisoft]

Should the Railcom and Status LED be competing for ISR cycles like this - sounds like a problem with ISR then?

Normally no they should not be competing at all. But there is a race condition that wasn't occurring in IDF v4.0 that is now showing up in IDF v4.1+ relating to the amount of data being sent to the RMT.

I've partially resolved the race condition as part of ead408a but it has the side effect of the LED blinking red after the first 64 bits have been transmitted to the LEDs. I've fixed that blink locally but it brings back the ISR WDT failure.

[TrainzLuvr]

Sounds like this is a regression in IDF v4.1 that Espressif needs to look into?

[atanisoft]

Fixed the RailCom side here: 5baf527
Added note about IDF v4.1 issues in 4751f60.

In short, IDF v4.1 while being "stable" it has a few issues which break it's usability for all modules and as such is not recommended.

[atanisoft]

Filed espressif/esp-idf#5992 to track the RMT truncation.