(solved) My app now hangs on boot

[mzimmers]

Here's what I get:

Code: Select all

I (29) boot: ESP-IDF v3.3-rc-dirty 2nd stage bootloader
I (29) boot: compile time 15:17:55
I (38) boot: Enabling RNG early entropy source...
I (38) boot: SPI Speed      : 40MHz
I (38) boot: SPI Mode       : DIO
I (41) boot: SPI Flash Size : 4MB
I (45) boot: Partition Table:
I (49) boot: ## Label            Usage          Type ST Offset   Length
I (56) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (63) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (71) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (78) boot:  3 factory          factory app      00 00 00010000 00130000
I (86) boot:  4 ota_0            OTA app          00 10 00140000 00130000
I (93) boot:  5 ota_1            OTA app          00 11 00270000 00130000
I (101) boot: End of partition table
I (105) boot: Defaulting to factory image
I (110) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x42f60 (274272) map
I (215) esp_image: segment 1: paddr=0x00052f88 vaddr=0x3ffbdb60 size=0x035ac ( 13740) load
I (220) esp_image: segment 2: paddr=0x0005653c vaddr=0x40080000 size=0x00400 (  1024) load
I (222) esp_image: segment 3: paddr=0x00056944 vaddr=0x40080400 size=0x096cc ( 38604) load
I (246) esp_image: segment 4: paddr=0x00060018 vaddr=0x400d0018 size=0xd39ec (866796) map
I (550) esp_image: segment 5: paddr=0x00133a0c vaddr=0x40089acc size=0x0a15c ( 41308) load
I (568) esp_image: segment 6: paddr=0x0013db70 vaddr=0x400c0000 size=0x00064 (   100) load
I (580) boot: Loaded app from partition at offset 0x10000
I (580) boot: Disabling RNG early entropy source...
I (580) cpu_start: Pro cpu up.
I (584) cpu_start: Application information:
I (589) cpu_start: Project name:     WifiButton
I (594) cpu_start: App version:      V0.1-15-g3b88e35-dirty
I (600) cpu_start: Compile time:     Aug 20 2019 15:18:04
I (606) cpu_start: ELF file SHA256:  c0563386cb011152...
I (612) cpu_start: ESP-IDF:          v3.3-rc-dirty
I (618) cpu_start: Starting app cpu, entry point is 0x40081308
I (0) cpu_start: App cpu up.
I (628) heap_init: Initializing. RAM available for dynamic allocation:
I (635) heap_init: At 3FFAE6E0 len 0000F480 (61 KiB): DRAM
I (641) heap_init: At 3FFD6238 len 00009DC8 (39 KiB): DRAM
I (647) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (654) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (661) heap_init: At 40093C28 len 0000C3D8 (48 KiB): IRAM
I (666) cpu_start: Pro cpu start user code

It then hangs for about 7-8 seconds, and repeats. This was working as of a couple hours ago. I was experimenting with using Eclipse, but I don't see how that could have affected this.

Any ideas what I did to screw this up? Thanks...

[ESP_Angus]

If you put a log statement or printf() as the first line in app_main(), do you get anything?

What's the full output when it "repeats". The reset should give some clues about the reset cause, and if we're lucky it will print the PC address when the WDT reset triggered.

[mzimmers]

Hi Angus - that is the full output I get. I do have a log message at the top of app_main(); it doesn't print.

Thanks...

[ESP_Angus]

I'm guessing you have ROM boot messages disabled by pulling MTDO (GPIO15) low? Can you temporarily pull it high and see if you get any additional output?

[mzimmers]

This isn't an area I'm really familiar with -- this GPIO15, is it something I could have done purely in software? If so, it has to be something that I inadvertently did with Eclipse. I'm happy to throw away all of my Eclipse work, but I don't know how this will restore my app. I've already pulled a fresh copy of the IDF from git.

[ESP_Angus]

No, there's a strapping pin that controls whether the ROM prints any early boot messages. Consult ESP32 datasheet section 2.4 for details.

[chegewara]

https://github.com/espressif/esptool/wi ... -Selection

[mzimmers]

Hi guys - I'm sorry -- I misspoke above; the output above is what I see repeated. The first time it starts, I get this:

Code: Select all

(28) boot: ESP-IDF v3.3-rc-dirty 2nd stage bootloader
I (28) boot: compile time 15:17:55
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 (51) boot: ## Label            Usage          Type ST Offset   Length
I (58) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (65) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (73) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (80) boot:  3 factory          factory app      00 00 00010000 00130000
I (88) boot:  4 ota_0            OTA app          00 10 00140000 00130000
I (95) boot:  5 ota_1            OTA app          00 11 00270000 00130000
I (103) boot: End of partition table
I (107) boot: Defaulting to factory image
I (112) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x42f60 (274272) map
I (217) esp_image: segment 1: paddr=0x00052f88 vaddr=0x3ffbdb60 size=0x035ac ( 13740) load
I (222) esp_image: segment 2: paddr=0x0005653c vaddr=0x40080000 size=0x00400 (  1024) load
I (224) esp_image: segment 3: paddr=0x00056944 vaddr=0x40080400 size=0x096cc ( 38604) load
I (248) esp_image: segment 4: paddr=0x00060018 vaddr=0x400d0018 size=0xd39f0 (866800) map
I (28) boot: ESP-IDF v3.3-rc-dirty 2nd stage bootloader
I (29) boot: compile time 15:17:55
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 (51) boot: ## Label            Usage          Type ST Offset   Length
I (58) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (65) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (73) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (80) boot:  3 factory          factory app      00 00 00010000 00130000
I (88) boot:  4 ota_0            OTA app          00 10 00140000 00130000
I (95) boot:  5 ota_1            OTA app          00 11 00270000 00130000
I (103) boot: End of partition table
I (107) boot: Defaulting to factory image
I (112) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x42f60 (274272) map
I (217) esp_image: segment 1: paddr=0x00052f88 vaddr=0x3ffbdb60 size=0x035ac ( 13740) load
I (222) esp_image: segment 2: paddr=0x0005653c vaddr=0x40080000 size=0x00400 (  1024) load
I (224) esp_image: segment 3: paddr=0x00056944 vaddr=0x40080400 size=0x096cc ( 38604) load
I (248) esp_image: segment 4: paddr=0x00060018 vaddr=0x400d0018 size=0xd39f0 (866800) map
I (552) esp_image: segment 5: paddr=0x00133a10 vaddr=0x40089acc size=0x0a15c ( 41308) load
I (570) esp_image: segment 6: paddr=0x0013db74 vaddr=0x400c0000 size=0x00064 (   100) load
I (582) boot: Loaded app from partition at offset 0x10000
I (582) boot: Disabling RNG early entropy source...
I (582) cpu_start: Pro cpu up.
I (586) cpu_start: Application information:
I (591) cpu_start: Project name:     WifiButton
I (596) cpu_start: App version:      V0.1-15-g3b88e35-dirty
I (602) cpu_start: Compile time:     Aug 20 2019 15:18:04
I (608) cpu_start: ELF file SHA256:  f5b60813307272a0...
I (614) cpu_start: ESP-IDF:          v3.3-rc-dirty
I (620) cpu_start: Starting app cpu, entry point is 0x40081308
I (0) cpu_start: App cpu up.
I (630) heap_init: Initializing. RAM available for dynamic allocation:
I (637) heap_init: At 3FFAE6E0 len 0000F480 (61 KiB): DRAM
I (643) heap_init: At 3FFD6238 len 00009DC8 (39 KiB): DRAM
I (649) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (655) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (663) heap_init: At 40093C28 len 0000C3D8 (48 KiB): IRAM
I (668) cpu_start: Pro cpu start user code

There's a little more information in there, but nothing that looks like a problem.

Regarding MTDO: it's the same that it's always been.

I still have a feeling that this must have something to do with my experimentation with Eclipse yesterday. As mentioned above, I completely refreshed the IDF, and I didn't make any changes to my code. What else can I rebuild to get back to my pre-Eclipse configuration?

[mzimmers]

Another data point: here's the output from "make flash monitor:"

Code: Select all

$ make flash monitor
Toolchain path: /opt/xtensa-esp32-elf/bin/xtensa-esp32-elf-gcc
Toolchain version: crosstool-ng-1.22.0-80-g6c4433a5
Compiler version: 5.2.0
Python requirements from C:/esp-idf/requirements.txt are satisfied.

App "WifiButton" version: V0.1-16-gf1d5de4-dirty
CC build/app_update/esp_app_desc.o
AR build/app_update/libapp_update.a
Generating libapp_update.a.sections_info
Generating esp32.project.ld
LD build/WifiButton.elf
esptool.py v2.6
Flashing binaries to serial port COM7 (app at offset 0x10000)...
esptool.py v2.6
Serial port COM7
Connecting....
Chip is ESP32D0WDQ6 (revision 1)
Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
MAC: 3c:71:bf:5e:db:2c
Uploading stub...
Running stub...
Stub running...
Changing baud rate to 921600
Changed.
Configuring flash size...
Auto-detected Flash size: 4MB
Compressed 8192 bytes to 31...
Wrote 8192 bytes (31 compressed) at 0x0000d000 in 0.0 seconds (effective 4154.2 kbit/s)...
Hash of data verified.
Compressed 24400 bytes to 14541...
Wrote 24400 bytes (14541 compressed) at 0x00001000 in 0.2 seconds (effective 1113.4 kbit/s)...
Hash of data verified.
Compressed 1235968 bytes to 666114...
Wrote 1235968 bytes (666114 compressed) at 0x00010000 in 13.4 seconds (effective 738.2 kbit/s)...
Hash of data verified.
Compressed 3072 bytes to 143...
Wrote 3072 bytes (143 compressed) at 0x00008000 in 0.0 seconds (effective 1533.8 kbit/s)...
Hash of data verified.

Leaving...
Hard resetting via RTS pin...
MONITOR
--- idf_monitor on COM7 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---


rst:0x1 (POWERON_RESET),boot:0x12 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:6436
load:0x40078000,len:11388
load:0x40080400,len:6472
entry 0x40080760
ets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x12 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:6436
load:0x40078000,len:11388
load:0x40080400,len:6472
entry 0x40080760

The last part (with the RTCWDT_RTC_RESET) repeats every several seconds.

This is rather baffling: I've cleaned and rebuilt everything I can think of; what change could I have introduced to cause this?

[mzimmers]

Well, I got it working. I deleted my entire esp-idf repository (which was just a clone from github anyway), and rebuilt all my tools. It now boots and runs. I still don't know what went wrong, but it's water under the bridge now. Thanks to all who looked and helped...

EDIT:

I forgot to mention: on startup, I'm getting this warning:

W (40) cpu_start: Chip revision is higher than the one configured in menuconfig. Suggest to upgrade it.

I can't find anything in my sdkconfig file that mentions chip revisions; can someone tell me where this is? Thanks.