d51r3verse commented 4 years ago

M5Burner's prebuilt(unknown commit#) binary(MD5: 99ecacaed6c69ef954751042f54783fe) was successfully loads. But, blank screen on both latest commits from here and @tobozo 's repo. Arduino 1.8.13, M5Stack-FIRE target with FastLED 3.003.003

Lastest M5Stack core and Chimera core
M5Stack SD Updater 1.0a or 0.5.2
"PSRAM" enabled/disabled

Flashing 40/80 MHz Build success without any warnings/errors except FastLED's "No hardware SPI pin defined" casual message. Above all test combinations same results: blank screen I have no idea why...


esptool.py -c esp32 -b 1500000 -p /dev/ttyUSB0 write_flash -e -ff 40m -fm dio -fs 16MB --verify -z 0x1000 hashmonster.bin     esptool.py v2.8
Serial port /dev/ttyUSB0
Connecting....
Chip is ESP32D0WDQ6 (revision 1)
Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
Crystal is 40MHz
MAC: 24:6f:28:ae:88:3c
Uploading stub...
Running stub...
Stub running...
Changing baud rate to 1500000
Changed.
Configuring flash size...
Erasing flash (this may take a while)...
Chip erase completed successfully in 3.5s
Flash params set to 0x0240
Compressed 993024 bytes to 483268...
Wrote 993024 bytes (483268 compressed) at 0x00001000 in 7.3 seconds (effective 1092.9 kbit/s)...
Hash of data verified.

Leaving... Verifying just-written flash... (This option is deprecated, flash contents are now always read back after flashing.) Flash params set to 0x0240 Verifying 0xf2700 (993024) bytes @ 0x00001000 in flash against hashmonster.bin... -- verify OK (digest matched) Hard resetting via RTS pin...

After flash, reboots infinitely

rst:0x10 (RTCWDT_RTC_RESET),boot:0x17 (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:0x3f400020,len:348784


After few flashing tests, power off( two short click ) does not work anymore(just reboots). even factory image.
Weird

tobozo commented 4 years ago

Hey thanks for your feedback, a few things you may try :

set Core Debug level to "Warn" for more verbose output at boot
checkout M5Stack-SD-Updater code from the main git branch instead of using the Library Manager
select "M5Stack-Core-ESP32" from the Arduino Tools/Board menu, and re-flash
check your SD Card for filesystem errors

d51r3verse commented 3 years ago

Hi, @tobozo. Thank you for your support.

I replaced M5Stack-SD-Updater to 1.0.0-alpha-18-gea04f9c and M5Stack to 0.3.0-28-gf106485 /w Debug:'Warning'

Target(M5Stack-FIRE) : Boots up, M5Stack-Fire bottom LED finally working, Last CH remembered.
Target(M5Stack-Core-ESP32) : Boots up, M5Stack-Fire bottom LED stucked, Last CH remembered.

The difference between this and your repo was the color of the graph( orig:green, yours:white )

But, both target(Fire/Core) binary with SD issue. Even 40/80MHz, PSRAM en/dis, Partitioning(Default/Large), esp32 toolchain 1.0.2 or 1.0.4

07:32:24.249 -> SD_MMC Card Type: SDHC
07:32:24.249 -> SD_MMC Card Size: 15193MB
07:32:24.249 -> /0.pcap
07:32:24.249 -> [E][vfs_api.cpp:265] VFSFileImpl(): fopen(/sd/0.pcap) failed

For sure, I tested SD R/W with LovyanLauncher: No problems. Any suggestion about this behavior?

Below is M5Burner's unknown version of prebuilt ESP32-WiFi-Hash-Monster(MD5:99ecacaed6c69ef954751042f54783fe) binary test result

M5Stack-Fire bottom LED not working.
SD card file rotation works fine.
No NVRAM support. Always starting CH1.
SD works only when flashing 40MHz( Seems no dependency on PSRAM en/dis status )
Flashing with esp32tool, starting 0x1000

tobozo commented 3 years ago

thanks for this report, sounds like calling SD.open() several times can give strange results, I've updated the setupSD() so it only happens once, and tested this on both official M5Stack and ESP32-Chimera-Core versions without any noticeable error message in the serial console (log_level=warn) :

// ===== functions ===================================================

static bool SDSetupDone = false;

bool setupSD() {
  if( SDSetupDone ) return true;
  if (!SD.begin( TFCARD_CS_PIN )) {
    SDSetupDone = false;
    Serial.println("Card Mount Failed"); return false;
  }
  uint8_t cardType = SD.cardType();
  if (cardType == CARD_NONE) {
    SDSetupDone = false;
    Serial.println("No SD_MMC card attached"); return false;
  }
  Serial.print("SD_MMC Card Type: ");
  if (cardType == CARD_MMC) {
    Serial.println("MMC");
  } else if (cardType == CARD_SD) {
    Serial.println("SDSC");
  } else if (cardType == CARD_SDHC) {
    Serial.println("SDHC");
  } else {
    Serial.println("UNKNOWN");
  }
  uint64_t cardSize = SD.cardSize() / (1024 * 1024);
  Serial.printf("SD_MMC Card Size: %lluMB\n", cardSize);
  SDSetupDone = true;
  return true;
}

please let me know it this change improved the situation on your M5Fire

G4lile0 commented 3 years ago

I just compile it using:

Arduino 1.8.10, M5Stack-FIRE target with FastLED 3.003.003
M5Stack 0.3.0
M5Stack-SD-Updater 0.5.2
"PSRAM" enabled

I just received the FastLED's casual message, and directly upload to the M5stack, it run smoothly without problems.

d51r3verse commented 3 years ago

Dear @tobozo , @G4lile0 Thank you for advice.

File rotation only works with unknown prebuilt binary from M5Burner(MD5:99ecacaed6c69ef954751042f54783fe). Still fails to rotate pcap files. -Arduino 1.8.13 Windows x64 -Latest(1.0.4) ESP32 toolchain -Latest(0.3.0-28-gf106485) M5Stack -Latest(1.0.1-beta) M5Stack-SD-Updater

ESP32-WiFi-Hash-Monster -3f6bba0(G4lile0's latest): File rotation failed & bottom LED sweeps fine -116c58c(tobozo's latest): File rotation failed & bottom LED sweeps fine & main graph color white

#Changed buffer.cpp's starting index( avoiding overwrite/conflict existing 0 ~ 19.cap saved by unknown prebuilt binary )
#Even starting 0, failed to open 0.pcap or rotate to 20.pcap
16:44:31.746 -> pues esta encendido
16:44:31.746 -> SD_MMC Card Type: SDHC
16:44:31.746 -> SD_MMC Card Size: 15193MB
16:44:31.746 -> /100.pcap
16:44:31.746 -> [E][vfs_api.cpp:265] VFSFileImpl(): fopen(/sd/100.pcap) failed
16:44:31.746 ->  SD CHECK OPEN
16:44:31.746 -> pues esta encendido2
...
...(several SD en/dis)
...
16:44:41.705 -> [E][vfs_api.cpp:265] VFSFileImpl(): fopen(/sd/100.pcap) failed
16:44:41.705 -> saved 3117 bytes
16:44:41.705 -> file closed
16:44:45.490 -> /100.pcap
16:44:45.525 -> [E][vfs_api.cpp:265] VFSFileImpl(): fopen(/sd/100.pcap) failed
16:45:28.865 -> [E][vfs_api.cpp:265] VFSFileImpl(): fopen(/sd/100.pcap) failed
16:45:28.865 -> saved 24 bytes
16:45:28.865 -> file closed
16:45:31.335 -> /100.pcap
16:45:31.370 -> [E][vfs_api.cpp:265] VFSFileImpl(): fopen(/sd/100.pcap) failed

Conditions I found: Without SD -> reset -> insert SD : OK to write/rotate fine. Is this designed behavior I was missed?

Manual reset(card removed) >> 17:19:28.424 -> ets Jun  8 2016 00:22:57
17:19:28.424 -> 
17:19:28.424 -> rst:0x1 (POWERON_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
17:19:28.424 -> configsip: 0, SPIWP:0xee
17:19:28.424 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
17:19:28.424 -> mode:DIO, clock div:1
17:19:28.424 -> load:0x3fff0018,len:4
17:19:28.424 -> load:0x3fff001c,len:1044
17:19:28.424 -> load:0x40078000,len:8896
17:19:28.424 -> load:0x40080400,len:5816
17:19:28.424 -> entry 0x400806ac
17:19:30.272 -> M5Stack initializing...[W][sd_diskio.cpp:137] sdCommand(): no token received
17:19:30.376 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
17:19:30.481 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
17:19:30.586 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
17:19:30.586 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
17:19:30.899 -> OK
17:19:30.934 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
17:19:31.037 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
17:19:31.142 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
17:19:31.246 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
17:19:31.246 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
... Error until inserting SD
17:19:36.887 -> flash init //tcp init
17:19:36.887 -> 2
17:19:36.887 -> 3
17:19:36.887 -> 4 
17:19:36.957 -> 5 
17:19:36.957 -> 6 
17:19:36.957 -> 7 
17:19:36.957 -> 8 
17:19:36.957 -> wifi done
17:19:36.992 ->  SSID count: 1
17:19:36.992 ->  pack lengt: 205
... snip SSIDes
17:19:41.031 -> pues esta encendido
17:19:41.031 -> SD_MMC Card Type: SDHC
17:19:41.031 -> SD_MMC Card Size: 15193MB
Auto rotates without error >> 17:19:41.450 -> /1006.pcap
17:19:41.624 ->  SD CHECK OPEN
17:19:41.624 -> pues esta encendido2
17:19:41.659 -> Setting default channel
17:19:41.659 -> Channel set !
17:19:47.649 -> saved 24 bytes
17:19:47.649 -> file closed
17:19:53.605 -> SD_MMC Card Type: SDHC
17:19:53.605 -> SD_MMC Card Size: 15193MB
Manual rotates without error >> 17:19:54.545 -> /1007.pcap
17:20:00.119 -> saved 24 bytes
17:20:00.119 -> file closed
Manual reset(still card inserted) >> 17:20:03.673 -> ets Jun  8 2016 00:22:57
17:20:03.673 -> 
17:20:03.673 -> rst:0x1 (POWERON_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
17:20:03.673 -> configsip: 0, SPIWP:0xee
17:20:03.673 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
17:20:03.673 -> mode:DIO, clock div:1
17:20:03.673 -> load:0x3fff0018,len:4
17:20:03.673 -> load:0x3fff001c,len:1044
17:20:03.673 -> load:0x40078000,len:8896
17:20:03.673 -> load:0x40080400,len:5816
17:20:03.673 -> entry 0x400806ac
17:20:05.519 -> M5Stack initializing...OK
17:20:05.902 -> flash init //tcp init
17:20:05.936 -> 2
17:20:05.936 -> 3
17:20:05.936 -> 4 
17:20:06.004 -> 5 
17:20:06.004 -> 6 
17:20:06.004 -> 7 
17:20:06.004 -> 8 
17:20:06.004 -> wifi done
17:20:06.038 ->  SSID count: 1
17:20:06.038 ->  pack lengt: 205
... snip SSIDes
17:20:10.041 -> pues esta encendido
17:20:10.041 -> SD_MMC Card Type: SDHC
17:20:10.041 -> SD_MMC Card Size: 15193MB
Auto rotate failed >> 17:20:10.041 -> /1000.pcap
17:20:10.075 -> [E][vfs_api.cpp:265] VFSFileImpl(): fopen(/sd/1000.pcap) failed
17:20:10.075 ->  SD CHECK OPEN
17:20:10.075 -> pues esta encendido2
17:20:10.109 -> Setting default channel
17:20:10.109 -> Channel set !
Rotate fails until remove-SD&reset&insert-SD trick

tobozo commented 3 years ago

@d51r3verse thanks for this feedback

I haven't seen any working example of warm removal & reinsertion of a SD Card but if you know such example I'll be happy to look at the code :eyes:

Now about the auto rotation failure : could it be a bad sector on the SD or some corrupted file from a previous glitch ?

As I didn't see any existing logic to handle occasional SD failures I'm now testing some changes on Buffer::open() so it tells when fs->open fails, the thing is I don't have any errors on my M5Fire, so I'll push the code on my fork and let you test with that.

Anyway, /1000.pcap sounds like a lot of files for a root directory. As FAT16 is limited to 512 files in its root directory, it may be better to stick with the lowest values than speculating on the filesystem (FAT32 has a much higher limitation, and so do the FAT16 folders).

So I've improved the file handling :

pcap files are saved in a folder (max 65536 files)
pcap file names are hexadecimal (ex 0bad.pcap ) much easier for natural sorting

https://github.com/tobozo/ESP32-WiFi-Hash-Monster

d51r3verse commented 3 years ago

Dear @tobozo . Reporting again.

/w M5Stack lib: Main graph color=white /w ESP32-Chimera-Core lib: Main graph color=yellow(same color as lower RSSI graph color) If SD fails when boot, upper right 'SD' still glowing.

It seems to be glitch when CPU reset/boot( boot time default pull-up/down issue? )

M5Stack-Fire(MPU6886 version)
SanDisk Ultra PLUS 16GB
Card works well with another MicroPython ESP32, STM32 boards and my digital camera/drones, Android devices as well.
Format several times again with 512(ESP32 fixed 512?) ~ 4K allocation size: No luck

When flashing, It beeps twice then connection failed sometimes.

Flashed(Card inserted)
19:36:54.103 -> ESP32-Chimera-Core initializing...[W][LGFX_Config_AutoDetectESP32.hpp:235] init_impl(): [Autodetect] panel id:ffff7f00
19:36:54.135 -> [W][LGFX_Config_AutoDetectESP32.hpp:292] init_impl(): [Autodetect] panel id:ffff3f00
19:36:54.170 -> [W][LGFX_Config_AutoDetectESP32.hpp:350] init_impl(): [Autodetect] panel id:ffffffff
19:36:54.170 -> [W][LGFX_Config_AutoDetectESP32.hpp:391] init_impl(): [Autodetect] panel id:000000e3
19:36:54.170 -> [W][LGFX_Config_AutoDetectESP32.hpp:429] init_impl(): [Autodetect] M5Stack
19:36:54.546 -> OK
19:36:56.113 -> flash init //tcp init
19:36:56.147 -> 2
19:36:56.147 -> 3
19:36:56.147 -> 4 
19:36:56.214 -> 5 
19:36:56.214 -> 6 
19:36:56.214 -> 7 
19:36:56.214 -> 8 
19:36:56.214 -> wifi done
... snip SSIDes
19:37:00.276 -> pues esta encendido
19:37:00.276 -> SD_MMC Card Type: SDHC
19:37:00.276 -> SD_MMC Card Size: 15193MB
19:37:00.276 -> /pcap/0000.pcap
FAIL(Upper right 'SD' still on) >>> 19:37:00.276 -> [E][vfs_api.cpp:265] VFSFileImpl(): fopen(/sd/pcap/0000.pcap) failed
19:37:00.276 ->  SD ERROR, Can't create file
19:37:00.311 -> Setting default channel
19:37:00.311 -> Channel set !
... Reboot without card, then insert card trick
19:37:08.023 -> ets Jun  8 2016 00:22:57
19:37:08.023 -> 
19:37:08.023 -> rst:0x1 (POWERON_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
19:37:08.023 -> configsip: 0, SPIWP:0xee
19:37:08.023 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
19:37:08.023 -> mode:DIO, clock div:1
19:37:08.023 -> load:0x3fff0018,len:4
19:37:08.023 -> load:0x3fff001c,len:1044
19:37:08.023 -> load:0x40078000,len:8896
19:37:08.023 -> load:0x40080400,len:5816
19:37:08.023 -> entry 0x400806ac
19:37:09.866 -> ESP32-Chimera-Core initializing...[W][sd_diskio.cpp:137] sdCommand(): no token received
19:37:09.970 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
19:37:10.074 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
19:37:10.179 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
19:37:10.179 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
19:37:10.179 -> [W][LGFX_Config_AutoDetectESP32.hpp:235] init_impl(): [Autodetect] panel id:ffff7f00
19:37:10.179 -> [W][LGFX_Config_AutoDetectESP32.hpp:292] init_impl(): [Autodetect] panel id:ffff7f00
19:37:10.214 -> [W][LGFX_Config_AutoDetectESP32.hpp:350] init_impl(): [Autodetect] panel id:ffffffff
19:37:10.214 -> [W][LGFX_Config_AutoDetectESP32.hpp:391] init_impl(): [Autodetect] panel id:000000e3
19:37:10.214 -> [W][LGFX_Config_AutoDetectESP32.hpp:429] init_impl(): [Autodetect] M5Stack
19:37:10.596 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
19:37:10.701 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
19:37:10.806 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
19:37:10.909 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
19:37:10.909 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
19:37:10.909 -> OK
19:37:12.470 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
19:37:12.575 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
19:37:12.679 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
19:37:12.784 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
19:37:12.784 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
... Warns until card inserted
19:37:15.286 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
19:37:15.391 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
19:37:15.598 -> flash init //tcp init
19:37:15.633 -> 2
19:37:15.633 -> 3
19:37:15.633 -> 4 
19:37:15.702 -> 5 
19:37:15.702 -> 6 
19:37:15.702 -> 7 
19:37:15.702 -> 8 
19:37:15.702 -> wifi done
... snip SSIDes
19:37:19.733 -> pues esta encendido
19:37:19.733 -> SD_MMC Card Type: SDHC
19:37:19.733 -> SD_MMC Card Size: 15193MB
OK >>> 19:37:19.870 -> /pcap/0000.pcap
19:37:19.905 ->  SD CHECK OPEN
19:37:19.905 -> pues esta encendido2
19:37:19.939 -> Setting default channel
19:37:19.939 -> Channel set !
... snip SSIDes
19:37:31.933 -> saved 3573 bytes
19:37:31.933 -> file closed
... snip SSIDes
OK >>> 19:38:11.570 -> /pcap/0001.pcap
... snip SSIDes
19:38:28.327 -> saved 1128 bytes
19:38:28.327 -> file closed
... snip SSIDes
19:49:39.010 -> /pcap/0002.pcap
19:50:11.093 -> saved 24 bytes
19:50:11.093 -> file closed
... Reboot again(with card)
19:51:35.450 -> pues esta encendido
19:51:35.450 -> SD_MMC Card Type: SDHC
19:51:35.450 -> SD_MMC Card Size: 15193MB
19:51:35.450 -> /pcap/0000.pcap
19:51:35.484 -> [E][vfs_api.cpp:265] VFSFileImpl(): fopen(/sd/pcap/0000.pcap) failed
19:51:35.484 ->  SD ERROR, Can't create file
19:51:35.484 -> Setting default channel
19:51:35.517 -> Channel set !

Modified SD_Test for M5Stack-Fire SPIClass sdhander(HSPI); sdhander.begin(18, 19, 23, 4); if(!SD.begin(4, sdhander, 20000000)){

Flash SD_Test( still card inserted )
20:03:14.495 -> ets Jun  8 2016 00:22:57
20:03:14.495 -> 
20:03:14.495 -> rst:0x1 (POWERON_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
20:03:14.495 -> configsip: 0, SPIWP:0xee
20:03:14.495 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
20:03:14.495 -> mode:DIO, clock div:1
20:03:14.495 -> load:0x3fff0018,len:4
20:03:14.495 -> load:0x3fff001c,len:1044
20:03:14.495 -> load:0x40078000,len:8896
20:03:14.495 -> load:0x40080400,len:5816
20:03:14.495 -> entry 0x400806ac
FAILED >>> 20:03:16.064 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(d)
20:03:16.064 -> Card Mount Failed
... Reboot again(without card)
20:03:43.557 -> ets Jun  8 2016 00:22:57
20:03:43.557 -> 
20:03:43.557 -> rst:0x1 (POWERON_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
20:03:43.557 -> configsip: 0, SPIWP:0xee
20:03:43.557 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
20:03:43.557 -> mode:DIO, clock div:1
20:03:43.557 -> load:0x3fff0018,len:4
20:03:43.557 -> load:0x3fff001c,len:1044
20:03:43.557 -> load:0x40078000,len:8896
20:03:43.557 -> load:0x40080400,len:5816
20:03:43.557 -> entry 0x400806ac
20:03:45.124 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
20:03:45.229 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
20:03:45.333 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
20:03:45.437 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
20:03:45.437 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
20:03:45.437 -> Card Mount Failed
... Card insert, then reboot
20:03:50.826 -> ets Jun  8 2016 00:22:57
20:03:50.826 -> 
20:03:50.826 -> rst:0x1 (POWERON_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
20:03:50.826 -> configsip: 0, SPIWP:0xee
20:03:50.826 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
20:03:50.826 -> mode:DIO, clock div:1
20:03:50.826 -> load:0x3fff0018,len:4
20:03:50.826 -> load:0x3fff001c,len:1044
20:03:50.826 -> load:0x40078000,len:8896
20:03:50.826 -> load:0x40080400,len:5816
20:03:50.826 -> entry 0x400806ac
20:03:52.563 -> SD Card Type: SDHC
20:03:52.563 -> SD Card Size: 15193MB
20:03:52.563 -> Listing directory: /
20:03:52.563 ->   DIR : /.Spotlight-V100
20:03:52.563 ->   DIR : /.fseventsd
20:03:52.563 ->   FILE: /test.txt  SIZE: 0
20:03:52.563 ->   DIR : /pcap
20:03:52.563 ->   FILE: /foo.txt  SIZE: 140
20:03:52.563 -> Creating Dir: /mydir
20:03:52.668 -> Dir created
20:03:52.668 -> Listing directory: /
20:03:52.668 ->   DIR : /.Spotlight-V100
20:03:52.668 ->   DIR : /.fseventsd
20:03:52.668 ->   FILE: /test.txt  SIZE: 0
20:03:52.668 ->   DIR : /mydir
20:03:52.668 ->   DIR : /pcap
20:03:52.668 ->   FILE: /foo.txt  SIZE: 140
20:03:52.668 -> Removing Dir: /mydir
20:03:52.668 -> Dir removed
20:03:52.668 -> Listing directory: /
20:03:52.668 ->   DIR : /.Spotlight-V100
20:03:52.668 -> Listing directory: /.Spotlight-V100
20:03:52.668 ->   DIR : /.Spotlight-V100/Store-V2
20:03:52.668 -> Listing directory: /.Spotlight-V100/Store-V2
20:03:52.668 ->   DIR : /.Spotlight-V100/Store-V2/64A50359-E14C-4A23-B9ED-9C9223FFBE72
20:03:52.668 ->   DIR : /.Spotlight-V100/Store-V1
20:03:52.668 -> Listing directory: /.Spotlight-V100/Store-V1
20:03:52.703 ->   FILE: /.Spotlight-V100/Store-V1/VolumeConfig.plist  SIZE: 348
20:03:52.703 ->   FILE: /.Spotlight-V100/VolumeConfiguration.plist  SIZE: 4113
20:03:52.703 ->   DIR : /.fseventsd
20:03:52.703 -> Listing directory: /.fseventsd
20:03:52.703 ->   FILE: /.fseventsd/fseventsd-uuid  SIZE: 36
20:03:52.703 ->   FILE: /.fseventsd/00000000009d6814  SIZE: 46
20:03:52.703 ->   FILE: /.fseventsd/00000000009d6815  SIZE: 71
20:03:52.703 ->   FILE: /test.txt  SIZE: 0
20:03:52.703 ->   DIR : /pcap
20:03:52.703 -> Listing directory: /pcap
OK >>> 20:03:52.703 ->   FILE: /pcap/0000.pcap  SIZE: 3573
OK >>> 20:03:52.703 ->   FILE: /pcap/0001.pcap  SIZE: 1128
OK >>> 20:03:52.703 ->   FILE: /pcap/0002.pcap  SIZE: 24
20:03:52.703 ->   FILE: /foo.txt  SIZE: 140
20:03:52.771 -> Writing file: /hello.txt
20:03:52.771 -> File written
20:03:52.771 -> Appending to file: /hello.txt
20:03:52.771 -> Message appended
20:03:52.771 -> Reading file: /hello.txt
20:03:52.771 -> Read from file: Hello World!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
20:03:52.771 -> Deleting file: /foo.txt
20:03:52.771 -> File deleted
20:03:52.771 -> Renaming file /hello.txt to /foo.txt
20:03:52.771 -> File renamed
20:03:52.771 -> Reading file: /foo.txt
20:03:52.771 -> Read from file: Hello World!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
20:03:52.771 -> 0 bytes read for 0 ms
20:03:55.065 -> 1048576 bytes written for 2293 ms
20:03:55.065 -> Total space: 15185MB
20:03:55.065 -> Used space: 4MB

Appreciate again for the great support🍻

tobozo commented 3 years ago

Thanks for this quality feedback :+1:

When flashing, It beeps twice then connection failed sometimes.

This sounds like a known hardware bug with the M5Fire, I've seen that happen randomly whatever the sketch :sweat:, sometimes after a double reset or a crash boot loop.

It's as if the power management suddenly switches to a different mode and renders both the uart and spi much less operative, until a hard reset occurs.

Usually a long press on the reset button fixes it, but keep in mind there are different M5Fire versions so your may want to try different button shortcuts whenever this happens.

Good thing is it does not happen when the M5Fire is unplugged, or after a cold boot, so if these are the only symptoms left, your WiFi Hash Monster is good to go ^^

d51r3verse commented 3 years ago

My workaround( Hints from #1, #2 ) test report.

Force MISO pull-up before enabling SPI
Add some delays

Loop until SD accessable -> Weird 0x0d error([E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(d)) totally gone -> Hard to get see fail(0x3) messages. If failed, it will accessable within 20 fails.

void setup(){
Serial.begin(115200);
//https://github.com/espressif/arduino-esp32/blob/master/libraries/SD/examples/SD_Test/SD_Test.ino
SPIClass sdhander(HSPI);
pinMode(19,INPUT_PULLUP); //https://github.com/espressif/arduino-esp32/issues/524#issuecomment-319878474
delay(100);
sdhander.begin(18, 19, 23, 4);
delay(100);
while(!SD.begin(4, sdhander, 20000000)){  //https://github.com/espressif/arduino-esp32/issues/2171
  Serial.println("Card Mount Failed");
}/*
if(!SD.begin(4, sdhander, 20000000)){
    Serial.println("Card Mount Failed");
    return;
}*/
uint8_t cardType = SD.cardType();

Hard to get see errors😃 Now, Trigger error on purpose( reboot while R/W on SD )

Fail type#1([W][sd_diskio.cpp:137] sdCommand(): no token received)

18:50:21.537 -> entry 0x400806ac
18:50:23.067 -> [D][esp32-hal-psram.c:47] psramInit(): PSRAM enabled
18:50:23.136 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:23.206 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:23.311 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:23.415 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:50:23.415 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:50:23.415 -> Card Mount Failed
18:50:23.415 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:23.518 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:23.623 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:23.727 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:50:23.727 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:50:23.727 -> Card Mount Failed
18:50:23.727 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:23.832 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:23.936 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:24.039 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:50:24.039 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:50:24.039 -> Card Mount Failed
18:50:24.039 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:24.144 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:24.248 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:24.353 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:50:24.353 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:50:24.353 -> Card Mount Failed
18:50:24.353 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:24.456 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:24.560 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:24.665 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:50:24.665 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:50:24.665 -> Card Mount Failed
18:50:24.665 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:24.735 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:24.839 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:24.944 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:50:24.944 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:50:24.944 -> Card Mount Failed
18:50:24.944 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:25.048 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
18:50:25.152 -> [W][sd_diskio.cpp:149] sdCommand(): token error [0] 0x23
18:50:25.152 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:50:25.152 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:50:25.187 -> SD Card Type: SDHC
18:50:25.187 -> SD Card Size: 15193MB
18:50:25.187 -> Listing directory: /

Fail type#2([W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed)

18:54:07.349 -> entry 0x400806ac
18:54:08.881 -> [D][esp32-hal-psram.c:47] psramInit(): PSRAM enabled
18:54:08.985 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:08.985 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:08.985 -> Card Mount Failed
18:54:08.985 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:08.985 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:08.985 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:08.985 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:08.985 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:08.985 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.020 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.020 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.020 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.020 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.020 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.020 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.020 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.020 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.089 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.089 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.089 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.089 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.089 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.089 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.089 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.089 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.089 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.124 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.124 -> 
18:54:09.124 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.124 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.124 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.124 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.124 -> 
18:54:09.124 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.124 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.124 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.160 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.160 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.160 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.160 -> 
18:54:09.160 -> [W][sd_diskio.cpp:471] ff_sd_initialize(): GO_IDLE_STATE failed
18:54:09.160 -> [E][sd_diskio.cpp:739] sdcard_mount(): f_mount failed 0x(3)
18:54:09.194 -> SD Card Type: SDHC
18:54:09.194 -> SD Card Size: 15193MB
18:54:09.194 -> Listing directory: /

@tobozo , How about this workaround( retry SD initialize until 20 fails : others reported succeeded within 20 errors too ) to ESP32-Chimera-Core for better compatibility?

tobozo commented 3 years ago

Thanks for this feedback.

SD.end(); seems to take care of all this, just tried a SD removal/reinsertion while it was logging and the card got remounted OK

I've pushed some changes now so you can try, this is what I get :

Normal boot

13:24:29.018 -> SD_MMC Card Type: SDHC
13:24:29.018 -> SD_MMC Card Size: 14910MB
13:24:29.947 -> /pcap/0012.pcap
13:24:30.080 ->  SD CHECK OPEN

# > Manual removal of the SD card
# > Manual toggle of BtnA (stop logging on SD)

13:26:48.582 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:26:48.681 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:26:48.781 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:26:48.880 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:26:48.980 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:26:49.079 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:26:49.179 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:26:49.278 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:26:49.378 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:26:49.477 -> [E][vfs_api.cpp:265] VFSFileImpl(): fopen(/sd/pcap/0012.pcap) failed
13:26:49.477 -> saved 5101 bytes
13:26:49.477 -> file closed

# > Manual reinsertion of the SD Card (no restart)
# > Manual toggle of BtnA (start logging on SD)

13:28:15.800 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:15.900 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:15.999 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:16.099 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:16.198 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:16.297 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:16.397 -> /pcap/0000.pcap
13:28:16.397 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:16.496 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:16.596 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:16.695 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:16.795 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:16.894 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:16.993 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:17.093 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:17.192 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:17.292 -> [E][vfs_api.cpp:265] VFSFileImpl(): fopen(/sd/pcap/0000.pcap) failed
13:28:17.292 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:17.391 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:17.491 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:17.590 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:17.689 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:17.789 -> [W][sd_diskio.cpp:137] sdCommand(): no token received
13:28:17.888 ->  SD ERROR, Can't create file, disabling SD

# > Manual toggle of BtnA (start logging on SD)

13:28:28.631 -> SD_MMC Card Type: SDHC
13:28:28.631 -> SD_MMC Card Size: 14910MB
13:28:30.388 -> /pcap/0013.pcap

d51r3verse commented 3 years ago

You're right simple SD.end() was the key. File rotation was expected. How about add this workaround to M5Stack-SD-Updater Really appreciate.

tobozo commented 3 years ago

Thank you for spotting this, the hardcoded pin number could be problematic on some builds using a non standard TFCARD_CS_PIN (e.g. Twatch, TTGO, Wrover-Kit) so I've made sure it uses the default TFCARD_CS_PIN macro, and added a constructor so these defaults can be overloaded.

    checkSDUpdater(
      SD,           // filesystem (default=SD)
      MENU_BIN,     // path to binary (default = /menu.bin, empty = rollback only)
      0,            // wait delay, (default=0, will be forced to 2000 upon ESP.restart() )
      TFCARD_CS_PIN // (usually default=4 but your mileage may vary)
    );

Please note this does not appear yet in the Arduino Library Manager, it is still being tested on a secondary branch as there are a lot of ongoing changes since M5Core2 got released.

Also I'm not sure it's necessary to add a SD.begin()/SD.end() hammering logic to this library, sd-errors are recoverable by resetting, and the sd-updater is designed to only act after a reset so it would very likely be dead code.

G4lile0 / ESP32-WiFi-Hash-Monster

Unstable SD initialize on M5Stack-FIRE #10

It seems to be glitch when CPU reset/boot( boot time default pull-up/down issue? )

Normal boot