[closed] moving to cmake/IDF V4.0 is causing problems

[mzimmers]

Hi all -

As a precursor to using the Eclipse IDE for ESP32 development, I changed my IDF to v4.0 and started using cmake.

Now, when I flash my program, something odd happens to the console output:

Code: Select all

 (32) boot: ESP-IDF v4.0-beta2-70-g0a03a55c1 2nd stage bootloader
I (32) boot: compile time 15:25:22
I (41) boot: Enabling RNG early entropy source...
I (41) boot: SPI Speed      : 40MHz
I (41) boot: SPI Mode       : DIO
I (45) boot: SPI Flash Size : 4MB
I (50) boot: Partition Table:
I (53) boot: ## Label            Usage          Type ST Offset   Length
I (60) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (68) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (75) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (83) boot:  3 factory          factory app      00 00 00010000 00130000
I (90) boot:  4 ota_0            OTA app          00 10 00140000 00130000
I (98) boot:  5 ota_1            OTA app          00 11 00270000 00130000
I (105) boot: End of partition table
I (110) boot: Defaulting to factory image
I (114) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x3f5e8 (259560) map
I (223) esp_image: segment 1: paddr=0x0004f610 vaddr=0x3ffbdb60 size=0x00a00 (  2560) load
I (224) esp_image: segment 2: paddr=0x00050018 vaddr=0x400d0018 size=0xd15bc (857532) map
I (559) esp_image: segment 3: paddr=0x001215dc vaddr=0x3ffbe560 size=0x02c6c ( 11372) load
I (564) esp_image: segment 4: paddr=0x00124250 vaddr=0x40080000 size=0x00400 (  1024) load
I (566) esp_image: segment 5: paddr=0x00124658 vaddr=0x40080400 size=0x12e8c ( 77452) load
I (608) esp_image: segment 6: paddr=0x001374ec vaddr=0x400c0000 size=0x00064 (   100) load
I (620) boot: Loaded app from partition at offset 0x10000
I (620) boot: Disabling RNG early entropy source...
I (621) cpu_start: Pro cpu up.
I (624) cpu_start: Application information:
I (629) cpu_start: Project name:     wifibutton
I (634) cpu_start: App version:      V0.1-24-g54a0f12-dirty
I (640) cpu_start: Compile time:     Nov  5 2019 15:25:21
I (646) cpu_start: ELF file SHA256:  3859215f0b0e8b24...
I (652) cpu_start: ESP-IDF:          v4.0-beta2-70-g0a03a55c1
I (659) cpu_start: Starting app cpu, entry point is 0x4008148c
I (0) cpu_start: App cpu up.
I (669) heap_init: Initializing. RAM available for dynamic allocation:
I (676) heap_init: At 3FFAE6E0 len 0000F480 (61 KiB): DRAM
I (682) heap_init: At 3FFDA5C8 len 00005A38 (22 KiB): DRAM
I (688) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (695) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (703) heap_init: At 4009328C len 0000CD74 (51 KiB): IRAM
I (707) cpu_start: Pro cpu start user code
î½@é°ÿî¼8=ÿïûÿäž)
                 N

This is very repeatable. It also doesn't appear that my program is running, though without the console messages, it's hard to know what's going on. Any ideas what might be happening?

[ESP_Angus]

Hi mzimmers,

I've seen similar results (UART baud rate changes to some invalid value) when the Wi-Fi was initialized with a wrong/mismatched libphy version. Is it possible this is happening, are any submodules out of date? The last log lines indicate app_main() is about to be run, what does your project's app_main() function do?

You mentioned that switching to cmake is a factor for this. If you build the same project with the same IDF version and make, does it work OK?

Angus

[mzimmers]

Hi Angus -

I'll take a closer look in the morning, but I think I lost some of the necessary make files for using make in my (admittedly hasty) conversion. I can look into the WiFi possibility. Which component contains libphy -- LwIP?

Thanks...

[ESP_Angus]

I can look into the WiFi possibility. Which component contains libphy -- LwIP?

It's part of the esp_wifi component. "git submodule update --init --recursive" should rule it out.

You'll also see build warnings if the build system detects some modules are out of date.

[mzimmers]

I did the submodule update command with the same results, so I guess it's not a submodule problem.

I'm having problems re-creating the msys build environment, but I'll keep working on that.

[mzimmers]

Here's where I am now:

- did a git checkout of IDF v3.3, and rebuilt...app runs fine.
- did a git checkout of IDF v4.0, and rebuilt...get this:

Code: Select all

2 2nd stage bootloader
I (31) boot: compile time 14:52:24
I (39) boot: Enabling RNG early entropy source...
I (39) boot: SPI Speed      : 40MHz
I (39) boot: SPI Mode       : DIO
I (43) boot: SPI Flash Size : 4MB
I (47) boot: Partition Table:
I (50) boot: ## Label            Usage          Type ST Offset   Length
I (57) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (65) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (72) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (80) boot:  3 factory          factory app      00 00 00010000 00130000
I (87) boot:  4 ota_0            OTA app          00 10 00140000 00130000
I (95) boot:  5 ota_1            OTA app          00 11 00270000 00130000
I (102) boot: End of partition table
I (107) boot: Defaulting to factory image
I (111) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x3f6fc (259836) map
I (220) esp_image: segment 1: paddr=0x0004f724 vaddr=0x3ffbdb60 size=0x008ec (  2284) load
I (221) esp_image: segment 2: paddr=0x00050018 vaddr=0x400d0018 size=0xd14c4 (857284) map
I (556) esp_image: segment 3: paddr=0x001214e4 vaddr=0x3ffbe44c size=0x02d94 ( 11668) load
I (561) esp_image: segment 4: paddr=0x00124280 vaddr=0x40080000 size=0x00400 (  1024) load
I (563) esp_image: segment 5: paddr=0x00124688 vaddr=0x40080400 size=0x12ef4 ( 77556) load
I (605) esp_image: segment 6: paddr=0x00137584 vaddr=0x400c0000 size=0x00064 (   100) load
I (617) boot: Loaded app from partition at offset 0x10000
I (617) boot: Disabling RNG early entropy source...
I (618) cpu_start: Pro cpu up.
I (621) cpu_start: Application information:
I (626) cpu_start: Project name:     wifibutton
I (631) cpu_start: App version:      V0.1-24-g54a0f12-dirty
I (637) cpu_start: Compile time:     Nov  6 2019 14:52:24
I (644) cpu_start: ELF file SHA256:  54c17f2f1a25d1e2...
I (650) cpu_start: ESP-IDF:          v4.0-beta2
I (655) cpu_start: Starting app cpu, entry point is 0x400814ec
I (646) cpu_start: App cpu up.
I (665) heap_init: Initializing. RAM available for dynamic allocation:
I (672) heap_init: At 3FFAE6E0 len 0000F480 (61 KiB): DRAM
I (678) heap_init: At 3FFDA5D8 len 00005A28 (22 KiB): DRAM
I (684) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (691) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (699) heap_init: At 400932F4 len 0000CD0C (51 KiB): IRAM
I (703) cpu_start: Pro cpu start user code
I (749) spi_fl8ÿî½@xŸ—˜”éoÿA
                            »ï¼@

This now repeats indefinitely, which is a change from how it was working before.

I did have to make a few code changes for V4.0:

- needed to change this path: #include "esp32/rom/crc.h"
- needed to change initialization of a struct:

Code: Select all

// this initialization works for esp-idf v4.0.
const ledc_timer_config_t LED_TIMER_CONFIG = {  LEDC_HIGH_SPEED_MODE,
                                                LEDC_TIMER_10_BIT,
                                                LED_TIMER,
                                                5000,
                                                LEDC_AUTO_CLK};
// this initialization works for esp-idf v3.3.
//const ledc_timer_config_t LED_TIMER_CONFIG = {  LEDC_HIGH_SPEED_MODE,
//                                                {LEDC_TIMER_10_BIT},
//                                                LED_TIMER,
//                                                5000};

- added this to a switch statement: __attribute__((fallthrough));

And I'm running the idf.py build command from the ESP-IDF command prompt.

If I try to build using msys32, I get the warning about the toolchain (haven't figured out how to get rid of this yet).

So...I'm kind of at a loss to explain this, and would greatly appreciate any ideas.

[mzimmers]

Update: I ignored the build warnings when building with V4.0 and flashed using make flash: behavior is not identical to that when building with cmake, but very similar: gibberish output to the console port. None of it is printing, but it's at least the right number of characters, so it's probably some UART setting.

Code: Select all

É ¨²¹© âïïôº ÅÓЭÉÄÆ ö´®°­âåôá² ²îä óôáçå âïïôìïáäåò
É ¨²¹© âïïôº ãïíðéìå ôéíå ±µº´°º³¶
É ¨³·© âïïôº Åîáâìéîç ÒÎÇ åáòìù åîôòïðù óïõòãå®®®
É ¨³¸© âïïôº ÓÐÉ Óðååä      º ´°ÍÈú
É ¨³¸© âïïôº ÓÐÉ Íïäå       º ÄÉÏ
É ¨´±© âïïôº ÓÐÉ Æìáóè Óéúå º ´ÍÂ
É ¨´µ© âïïôº Ðáòôéôéïî Ôáâìåº
É ¨´¸© âïïôº ££ Ìáâåì            Õóáçå          Ôùðå ÓÔ Ïææóåô   Ìåîçôè
É ¨µ¶© âïïôº  ° îöó              ×éÆé äáôá        °± °² °°°°¹°°° °°°°´°°°
É ¨¶³© âïïôº  ± ïôáäáôá          ÏÔÁ äáôá         °± °° °°°°ä°°° °°°°²°°°
É ¨·±© âïïôº  ² ðèùßéîéô         ÒÆ äáôá          °± °± °°°°æ°°° °°°°±°°°
É ¨·¸© âïïôº  ³ æáãôïòù          æáãôïòù áðð      °° °° °°°±°°°° °°±³°°°°
É ¨¸¶© âïïôº  ´ ïôáß°            ÏÔÁ áðð          °° ±° °°±´°°°° °°±³°°°°
É ¨¹³© âïïôº  µ ïôáß±            ÏÔÁ áðð          °° ±± °°²·°°°° °°±³°°°°
É ¨±°°© âïïôº Åîä ïæ ðáòôéôéïî ôáâìå
É ¨±°µ© âïïôº Äåæáõìôéîç ôï æáãôïòù éíáçå
É ¨±°¹© åóðßéíáçåº óåçíåîô °º ðáääò½°ø°°°±°°²° öáääò½°ø³æ´°°°²° óéúå½°ø´³ä¶´ ¨²··¸¶°© íáð
É ¨²±¸© åóðßéíáçåº óåçíåîô ±º ðáääò½°ø°°°µ³ä¸ã öáääò½°ø³ææâäⶰ óéúå½°ø°³·ä¸ ¨ ±´²¹¶© ìïáä
É ¨²²´© åóðßéíáçåº óåçíåîô ²º ðáääò½°ø°°°µ·µ¶ã öáääò½°ø´°°¸°°°° óéúå½°ø°°´°° ¨  ±°²´© ìïáä
É ¨²²¶© åóðßéíáçåº óåçíåîô ³º ðáääò½°ø°°°µ·¹·´ öáääò½°ø´°°¸°´°° óéúå½°ø°¸¶¹ã ¨ ³´´¶°© ìïáä
É ¨²´¸© åóðßéíáçåº óåçíåîô ´º ðáääò½°ø°°°¶°°±¸ öáääò½°ø´°°ä°°±¸ óéúå½°øã嶰¸ ¨¸´µ³²°© íáð
É ¨µµ²© åóðßéíáçåº óåçíåîô µº ðáääò½°ø°°±²å¶²¸ öáääò½°ø´°°¸¸á¹ã óéúå½°ø°á·¸¸ ¨ ´²¸¸¸© ìïáä
É ¨µ·°© åóðßéíáçåº óåçíåîô ¶º ðáääò½°ø°°±³¸ä⸠öáääò½°ø´°°ã°°°° óéúå½°ø°°°¶´ ¨   ±°°© ìïáä
É ¨µ¸±© âïïôº Ìïáäåä áðð æòïí ðáòôéôéïî áô ïææóåô °ø±°°°°

So, it looks like it's V4.0, not cmake.

EDIT: the above isn't 100% true. I hit the reset button on the board, and received console output identical to that when using cmake. Further evidence that the problem is with V4.0 and my app.

[ESP_Angus]

Thanks for the additional details. It's hard to tell what this could be without knowing what your project does.

Can you do some differential testing by disabling parts of your app's startup code and seeing if the problem goes away? Or use a debugger or some additional printf statements (and flushing out stdout) in order to figure out which step is introducing this problem?

EDIT: What crystal setting does your project have? https://docs.espressif.com/projects/esp ... l-freq-sel - if it's set to autodetect, can you try changing it to the actual crystal value?

[mzimmers]

Hi Angus -

Here's the top of my app_main():

Code: Select all

extern "C" void app_main()
{
    vTaskDelay(portMAX_DELAY);
    ...

Here's the relevant passage from my sdkconfig file:

Code: Select all

CONFIG_ESP32_XTAL_FREQ_40=y
# CONFIG_ESP32_XTAL_FREQ_26 is not set
# CONFIG_ESP32_XTAL_FREQ_AUTO is not set
CONFIG_ESP32_XTAL_FREQ=40

Thanks...

[mzimmers]

Hi Angus -

Here's the top of my app_main():

Code: Select all

extern "C" void app_main()
{
    vTaskDelay(portMAX_DELAY);
    ...

(Obviously the delay was added as a test; program problem still exists.)

Here's the relevant passage from my sdkconfig file:

Code: Select all

CONFIG_ESP32_XTAL_FREQ_40=y
# CONFIG_ESP32_XTAL_FREQ_26 is not set
# CONFIG_ESP32_XTAL_FREQ_AUTO is not set
CONFIG_ESP32_XTAL_FREQ=40

Thanks...