Esp-idf: Boot crash with DEBUG logging enabled in efuse component (IDFGH-3367)

[jeremyherbert]

Environment

• Development Kit: none
• Module or chip used: ESP32-WROVER
• IDF version: v4.2-dev-1575-ga3520970f
• Build System: CMake
• Compiler version (run xtensa-esp32-elf-gcc --version to find it):
  xtensa-esp32-elf-gcc (crosstool-NG esp-2020r1) 8.2.0
• Operating System: Linux
• Using an IDE?: Yes (CLion)
• Power Supply: External 3.3V

Problem Description

When DEBUG logging level is enabled, an abort() is triggered on startup:

The issue appears to be in the efuse component, if I comment out this everything works fine:

            ESP_LOGD(TAG, "In EFUSE_BLK%d__DATA%d_REG is used %d bits starting with %d bit",
                    (int)field[i]->efuse_block, num_reg, num_bits, start_bit);

If, rather than commenting it out I replace it with this, it still crashes:

            ESP_LOGD(TAG, "A");

I'm pretty lost at how to best debug this further.

Code to reproduce this issue

extern "C" {
    void app_main() {
        while (1) {
            vTaskDelay(1000);
        }
    }
}

Debug Logs

... (nothing usual here)
I (896) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (900) cpu_start: Pro cpu up.
I (902) cpu_start: Application information:
I (904) cpu_start: Project name:     esp32_test
I (907) cpu_start: App version:      1
I (909) cpu_start: Compile time:     May 25 2020 16:34:05
I (912) cpu_start: ELF file SHA256:  1b891882d215d037...
I (915) cpu_start: ESP-IDF:          v4.2-dev-1575-ga3520970f-dirty
I (919) cpu_start: Starting app cpu, entry point is 0x40082088
D (922) efuse: coding scheme 0
/home/jeremy/esp/esp-idf/components/freertos/queue.c:1447 (xQueueGenericReceive)- assert failed!
Re-enable cpu cache.

abort() was called at PC 0x4008f8e8 on core 0

Backtrace:0x4008bae2:0x3ffe39b0 0x4008c229:0x3ffe39e0 0x40090add:0x3ffe3a10 0x4008f8e8:0x3ffe3a90 0x40090991:0x3ffe3ad0 0x401717b9:0x3ffe3b00 0x400908b6:0x3ffe3b40 0x400febb5:0x3ffe3b90 0x400fe8c2:0x3ffe3be0 0x400ff0d1:0x3ffe3c10 0x40082234:0x3ffe3c40 0x40079926:0x3ffe3c80 |<-CORRUPTED


ELF file SHA256: 1b891882d215d037

Rebooting...

Other items if possible

Note: sdkconfig has encryption enabled, be careful.

sdkconfig.txt

[KonstantinKondrashov]

Hi @jeremyherbert!
I understand what is going on here. Thanks for your report. The solution which I will apply is to change all ESP_LOGx to ESP_EARLY_LOGx in the efuse component. We need to use ESP_EARLY_LOGx because the efuse API is used in the early startup code, before heap allocator and syscalls have been initialized.
Thanks.

[jeremyherbert]

Thanks, I suspected something like that was happening.

[KonstantinKondrashov]

@jeremyherbert. You can apply this patch 8904.zip, so as not to wait when it will be merged with the master.
Thanks.

[jeremyherbert]

great, thank you!

[reyking]

i was just loking for that today

[bastianhjaeger]

Ran into this issue today. Patch works for me.
Looking forward for the merge.

[AxelLin]

Hi @KonstantinKondrashov
Thanks, the patch works.
BTW, I'm quite surprised you have the patch 24 days ago but the fix is still not in github.
(Especially the changes is quite clean as it only replaces ESP_LOG* to ESP_EARLY_LOG*)

[AxelLin]

Hi @projectgus @KonstantinKondrashov

Above shows "projectgus pushed a commit that referenced this issue 8 days ago".
I'm wondering if something wrong, I cannot find the commit a6ac0e8 in current master tree.
I did git pull && git submodule update but nothing is pulled (still in v4.2-dev-1905-g625bd5eb1806).

[projectgus]

Hi @AxelLin ,

Sorry about this. Because of an internal problem with our CI checks, the release/v4.2 branch has pushed out some backported fixes which are not on master.

(You can see which branches a commit belongs to by viewing the commit in github, the branch list is at the bottom of the blue box.)

We accept this is not a good situation to be in, generally we don't want the "backported" release branches moving ahead of master. We're working to deploy master ASAP which will correct the situation.