FFAT and BluetoothSerial conflict causing boot loop on ESP32 #3265

omnitetranet · 2019-09-24T21:37:09Z

Hardware:

Board: Heltec ESP32 LoRa V2 Module
Core Installation version: 1.0.3-rc3
IDE name: Arduino IDE 1.8.10
Flash Frequency: 40Mhz
PSRAM enabled: no
Upload Speed: 921600
Computer OS: Windows 8.1

Description:

After a lot of hours spent to try to figure out what is wrong in my original source code, I've isolated the problem that causes the strange reboot.

I'm using esp32/1.0.3-rc3 - Heltec WiFi LoRa 32(v2) hardware board and I've edited the default partition table to simplify the tests:

I've the ESP32 64Mbit version and this is the partition table that I've used for 8MB version:

# Name,   Type, SubType, Offset,  Size, Flags
nvs,      data, nvs,     0x9000,  0x5000,
otadata,  data, ota,     0xe000,  0x2000,
app0,     app,  ota_0,   0x10000, 0x200000,
app1,     app,  ota_1,   0x210000,0x200000,
eeprom,   data, 0x99,    0x410000,0x1000,
ffat,     data, fat,     0x411000,0x3EF000,`

I've also created another partition table for 4MB version, but the result is the same:

# Name,   Type, SubType, Offset,  Size, Flags
nvs,      data, nvs,     0x9000,  0x5000,
otadata,  data, ota,     0xe000,  0x2000,
app0,     app,  ota_0,   0x10000, 0x200000,
ffat,     data, fat,     0x210000,0x1F0000,

Sketch:

This is my simple code extracted from FFAT example in esp32_fatfsimage-master library.

#include "FS.h"
#include "FFat.h"
#include "BluetoothSerial.h"

void setup(){
    Serial.begin(115200);
    Serial.setDebugOutput(true);
    Serial.println("Start");
    if(!FFat.begin()){
        Serial.println("FFat Mount Failed");
        FFat.format();
        Serial.println("Formatted");
        if(!FFat.begin()){
          Serial.println("FFat Re-Mount Failed");
          return;
        }
    }

    Serial.printf("Total space: %10lu\n", FFat.totalBytes());
    Serial.printf("Free space: %10lu\n", FFat.freeBytes());
    Serial.println( "Test complete" );
}

void loop(){
}

As you can see, the included library "BluetoothSerial.h" isn't really used in this example, but is sufficient include it to cause the issue.
The problem happen only if the FFAT partition isn't already formatted...but if it's formatted, the software don't crash, but I'm unable to format it again to wipe data in runtime, and format function always fail.

Debug Messages:

Output copied from serial monitor when the software crashes:

22:50:20.814 -> Start
22:50:20.848 -> [E][FFat.cpp:56] begin(): Mounting FFat partition failed! Error: -1
22:50:20.848 -> FFat Mount Failed
22:50:21.120 -> /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/queue.c:1796 (vQueueDelete)- assert failed!
22:50:21.120 -> abort() was called at PC 0x4008860f on core 1
22:50:21.120 ->
22:50:21.120 -> Backtrace: 0x4008b54c:0x3ffc3620 0x4008b779:0x3ffc3640 0x4008860f:0x3ffc3660 0x400d7fdd:0x3ffc3680 0x400d652a:0x3ffc36a0 0x400d8247:0x3ffc36e0 0x400d1d22:0x3ffc3720 0x400d0f84:0x3ffc3750 0x400d312f:0x3ffc3780 0x400877bd:0x3ffc37a0
22:50:21.155 ->
22:50:21.155 -> Rebooting...
22:50:21.155 -> ets Jun 8 2016 00:22:57
22:50:21.155 ->
22:50:21.155 -> rst:0xc (SW_CPU_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
22:50:21.155 -> configsip: 0, SPIWP:0xee
22:50:21.155 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
22:50:21.155 -> mode:DIO, clock div:1
22:50:21.155 -> load:0x3fff0018,len:4
22:50:21.155 -> load:0x3fff001c,len:1100
22:50:21.189 -> load:0x40078000,len:9564
22:50:21.189 -> ho 0 tail 12 room 4
22:50:21.189 -> load:0x40080400,len:6320
22:50:21.189 -> entry 0x400806a8

Output from serial monitor when it works well without BluetoothSerial.h #include line:

22:51:17.591 -> Start
22:51:17.591 -> [E][FFat.cpp:56] begin(): Mounting FFat partition failed! Error: -1
22:51:17.625 -> FFat Mount Failed
22:51:18.265 -> Formatted
22:51:18.299 -> Total space: 1982464
22:51:18.299 -> Free space: 1982464
22:51:18.299 -> Test complete

This is the command line that I've used to clear and re-initialize the ESP32 flash:

python esptool.py --port COM7 erase_flash

The text was updated successfully, but these errors were encountered:

lbernstone · 2019-09-24T22:42:32Z

Please decode your backtrace, as I am unable to reproduce.

omnitetranet · 2019-09-25T07:01:03Z

This is the output of the decoder:

Decoding stack results
0x4008b54c: invoke_abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 155
0x4008b779: abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 170
0x4008860f: vQueueDelete at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/queue.c line 1796
0x400d7fdd: ff_del_syncobj at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/fatfs/src/ffsystem.c line 73
0x400d652a: f_mount at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/fatfs/src/ff.c line 3515
0x400d8247: esp_vfs_fat_spiflash_mount at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/fatfs/src/vfs_fat_spiflash.c line 76
0x400d1d22: fs::F_Fat::format(bool, char*) at C:\Users\ale\AppData\Local\Arduino15\packages\esp32\hardware\esp32\1.0.3-rc3\libraries\FFat\src\FFat.cpp line 100
0x400d0f84: setup() at \kino\MyBookWorld\Sviluppo\Arduino\LORA\FFat_Test_BtSerial_Bug/FFat_Test_BtSerial_Bug.ino line 11
0x400d312f: loopTask(void*) at C:\Users\ale\AppData\Local\Arduino15\packages\esp32\hardware\esp32\1.0.3-rc3\cores\esp32\main.cpp line 14
0x400877bd: vPortTaskWrapper at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/port.c line 143

I hope that this can help you.

If it's useful, I have also tested the sketch with Heltec-ESP32 ver0.0.2-rc1 board distribution with edited partition map and this is the decoded stack result:

0x40085710: esp_restart_noos at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/system_api.c line 328
0x40085985: cache_sram_mmu_set at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/cache_sram_mmu.c line 106
0x400d80b1: fs::F_Fat::freeBytes() at C:\Users\ale\AppData\Local\Arduino15\packages\esp32\hardware\esp32\1.0.3-rc3\libraries\FFat\src\FFat.cpp line 127
0x400d651e: SdFile::seekSet(unsigned int) at C:\Users\ale\Documents\Arduino\libraries\esp32-micro-sdcard-master\utility\SdFile.cpp line 947
0x400d831b: OneWire::reset() at C:\Users\ale\Documents\Arduino\libraries\OneWire\util/OneWire_direct_gpio.h line 174
0x400d297b: ConfigureTemperatureSensors() at \kino\MyBookWorld\Sviluppo\Arduino\LORA\WiFi_LoRa_32FactoryTest/WiFi_LoRa_32FactoryTest.ino line 2335

In the additional board manager field I've added this line:

https://docs.heltec.cn/download/package_heltec_esp32_index.json

This hardware library is also worst respect all the other and have a lot of other bugs already resolved.

lbernstone · 2019-09-25T20:02:49Z

I think this will be fixed by ca88fdc. As a workaround, why not just use FFat.begin(true), which will format the filesystem if it is not already formatted.

omnitetranet · 2019-09-25T20:52:13Z

The new ffat.cpp resolves the boot loop issue, but something still goes wrong if I want to format manually the fat partition. In particular, take a look to this output:

22:39:00.251 -> FFat Mounting...
22:39:00.284 -> [W][FFat.cpp:44] begin(): Already Mounted!
22:39:00.284 -> a[E][vfs_api.cpp:22] open(): File system is not mounted
22:39:02.260 -> FFat.format
22:39:02.260 -> [W][FFat.cpp:85] format(): Already Mounted!
22:39:02.260 -> [E][FFat.cpp:72] end(): Unmounting FFat partition failed! Error: 259

...why the partition is already mounted on startup? Why format() is telling me that is already mounted and don't format the partition? And also, why if I try to unmount it with end() method it fails?

lbernstone · 2019-09-25T21:17:29Z

You need the new ffat.h as well.

omnitetranet · 2019-09-26T07:47:49Z

...a new boot loop to resolve...

23:28:16.194 -> entry 0x400806a8
23:28:16.329 -> Start
23:28:16.704 -> [E][FFat.cpp:60] begin(): Mounting FFat partition failed! Error: -1
23:28:16.704 -> FFat Mount Failed
23:28:16.704 -> [W][FFat.cpp:85] format(): Already Mounted!
23:28:16.704 -> [W][FFat.cpp:44] begin(): Already Mounted!
23:28:16.704 -> Guru Meditation Error: Core 1 panic'ed (LoadProhibited). Exception was unhandled.
23:28:16.704 -> Core 1 register dump:
23:28:16.704 -> PC : 0x400d845e PS : 0x00060d30 A0 : 0x800d502b A1 : 0x3ffb1ea0
23:28:16.738 -> A2 : 0x00000000 A3 : 0x00000000 A4 : 0x00000000 A5 : 0x00000001
23:28:16.738 -> A6 : 0x00060320 A7 : 0x00000000 A8 : 0x00000000 A9 : 0x3ffb1e80
23:28:16.738 -> A10 : 0x00000000 A11 : 0x3ffb1f57 A12 : 0x00000001 A13 : 0x00000001
23:28:16.738 -> A14 : 0x3ffb1f55 A15 : 0x00000000 SAR : 0x00000004 EXCCAUSE: 0x0000001c
23:28:16.772 -> EXCVADDR: 0x00000000 LBEG : 0x4000c428 LEND : 0x4000c42d LCOUNT : 0x00000000
23:28:16.772 ->
23:28:16.772 -> Backtrace: 0x400d845e:0x3ffb1ea0 0x400d5028:0x3ffb1ec0 0x400d7291:0x3ffb1f00 0x400d1dd6:0x3ffb1f50 0x400d0fba:0x3ffb1f80 0x400d318b:0x3ffb1fb0 0x400877bd:0x3ffb1fd0
23:28:16.772 ->
23:28:16.772 -> Rebooting...
23:28:16.772 -> ets Jun 8 2016 00:22:57
23:28:16.772 ->
23:28:16.772 -> rst:0xc (SW_CPU_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
23:28:16.805 -> configsip: 0, SPIWP:0xee
23:28:16.805 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
23:28:16.805 -> mode:DIO, clock div:1
23:28:16.805 -> load:0x3fff0018,len:4
23:28:16.805 -> load:0x3fff001c,len:1100
23:28:16.805 -> load:0x40078000,len:9564
23:28:16.805 -> ho 0 tail 12 room 4
23:28:16.805 -> load:0x40080400,len:6320

PC: 0x400d845e: ff_disk_initialize at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/fatfs/src/diskio.c line 61
EXCVADDR: 0x00000000

###Decoding stack results

0x400d845e: ff_disk_initialize at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/fatfs/src/diskio.c line 61
0x400d5028: find_volume at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/fatfs/src/ff.c line 3267
0x400d7291: f_getfree at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/fatfs/src/ff.c line 4614
0x400d1dd6: fs::F_Fat::totalBytes() at C:\Users\ale\AppData\Local\Arduino15\packages\esp32\hardware\esp32\1.0.3-rc3\libraries\FFat\src\FFat.cpp line 128
0x400d0fba: setup() at \kino\MyBookWorld\Sviluppo\Arduino\LORA\FFat_Test_BtSerial_Bug/FFat_Test_BtSerial_Bug.ino line 19
0x400d318b: loopTask(void*) at C:\Users\ale\AppData\Local\Arduino15\packages\esp32\hardware\esp32\1.0.3-rc3\cores\esp32\main.cpp line 14
0x400877bd: vPortTaskWrapper at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/port.c line 143

Only one more question about this issue...why if I comment out the BluetoothSerial.h include all perfectly works without any crash also if the partition is unformatted and with original ffat .cpp & .h files?

And why if the FAT partition is formatted and BluetoothSerial.h included, all works perfectly except format that don't crashes, but do nothing?

…handle and mountpoint before failing. Fixes #3265 (#3282)

omnitetranet · 2019-09-26T17:38:17Z

Simply perfect! Thanks a lot.
Now all is working well as expected.

lbernstone mentioned this issue Sep 26, 2019

FFat remount failure #3282

Merged

me-no-dev closed this as completed in #3282 Sep 26, 2019

me-no-dev pushed a commit that referenced this issue Sep 26, 2019

Better cleanup on mount failures, as the idf api now seems to assign …

f8c0689

…handle and mountpoint before failing. Fixes #3265 (#3282)

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

FFAT and BluetoothSerial conflict causing boot loop on ESP32 #3265

FFAT and BluetoothSerial conflict causing boot loop on ESP32 #3265

omnitetranet commented Sep 24, 2019

lbernstone commented Sep 24, 2019

omnitetranet commented Sep 25, 2019

lbernstone commented Sep 25, 2019

omnitetranet commented Sep 25, 2019

lbernstone commented Sep 25, 2019

omnitetranet commented Sep 26, 2019 •

edited

Loading

omnitetranet commented Sep 26, 2019

FFAT and BluetoothSerial conflict causing boot loop on ESP32 #3265

FFAT and BluetoothSerial conflict causing boot loop on ESP32 #3265

Comments

omnitetranet commented Sep 24, 2019

Hardware:

Description:

Sketch:

Debug Messages:

lbernstone commented Sep 24, 2019

omnitetranet commented Sep 25, 2019

lbernstone commented Sep 25, 2019

omnitetranet commented Sep 25, 2019

lbernstone commented Sep 25, 2019

omnitetranet commented Sep 26, 2019 • edited Loading

omnitetranet commented Sep 26, 2019

omnitetranet commented Sep 26, 2019 •

edited

Loading