Periodic FATFS corruption
Posted: Sun May 23, 2021 9:27 pm
Hello,
I have an application that collects power metering info from 2 sources, the first is a pulse counter (using PCNT) and the second is a PZEM004T device that is handled via UART2.
The pulse counter uses an ISR to count the pulses from an S0 pulsemeter, a foreground task reports this counter every minute to a file called pwrmtr-3.log. No problem there.
The PZEM004T is read out every minute by sending a request via UART2, the PZEM004T response triggers an ISR for each byte received, the ISR is a state machine that collects bytes into a complete pakket and then posts it on a queue. The queue is read in above mentioned foreground task that reports the data to the same file pwrmtr-3.log. This also works fine.
This pwrmtr-3.log is part of 4 rotating files with a max size of 128Kb each, if pwrmtr-3.log is full then pwrmtr-0.log is deleted and pwrmtr-1.log is renamed to pwrmtr-0.log... and finally pwrmtr-3.log is renamed to pwrmtr-2.log. These files reside on a FAT partition of 1984Kb mounted with WL.
const esp_vfs_fat_mount_config_t mount_config = {
.format_if_mount_failed = true,
.max_files = 4,
.allocation_unit_size = CONFIG_WL_SECTOR_SIZE
};
int32_t err = esp_vfs_fat_spiflash_mount("/spiflash", "private", &mount_config, &m_vfsWlHandle);
These logfiles are reported by the HTTP server of my application, just open each file, read every entry and report it, then close the file (x4). There is no chance that HTTP server and the part collecting the data run together as these run in the same worker thread and as such will be active in turn but never together, thus we can use a lockless design.
But after a while pwrmtr-3.log seems to be disappeared/corrupted and is recreated empty, I am talking about 3-5 hours for this to happen. After that I see a second file that has unreadable characters in it's name.
The problem must be related to the use of the UART, when I disable the part that handles the PZEM004T (and no ISR for the UART) then there is no file corruption. But the same UART code is working fine in another project that also logs events into a file and allows reporting it via HTTP server.
Below is a logging detail of the moment it goes wrong, pwrmtr-3.log is fine upto 21:24:09 where it writes both the data of the PCNT (src,0) and the PZEM (src,1). But then at 21:25:10 opening of pwrmtr-3.log fails due to some reason and my application re-creates it. The only diff with previous writes seem to be the WL stepping in to do something.
>>>
2021-05-23,21:23:08,D,PWRM,<src,0,active,0.18,15mp,0.211,total,2.106
V (7455362) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7455362) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=1, count=1
D (7455372) wl_flash: read - src_addr= 0x00001000, size= 0x00001000
V (7455372) wl_flash: calcAddr - addr= 0x00001000 -> result= 0x001db000, dummy_addr= 0x000ec000
V (7455382) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=15, count=1
D (7455392) wl_flash: read - src_addr= 0x0000f000, size= 0x00001000
V (7455392) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7455402) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=15, count=1
D (7455412) wl_flash: erase_range - start_address= 0x0000f000, size= 0x00001000
D (7455422) wl_flash: erase_sector - sector= 0x0000000f
V (7455422) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7455472) wl_partition: erase_range - start_address=0x001e9000, size=0x00001000, result=0x00000000
V (7455472) wl_flash: erase_range - result= 0x00000000
D (7455472) wl_flash: write - dest_addr= 0x0000f000, size= 0x00001000
V (7455472) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7455492) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=2, count=1
D (7455492) wl_flash: read - src_addr= 0x00002000, size= 0x00001000
V (7455502) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7455512) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7455512) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7455522) wl_flash: erase_sector - sector= 0x00000002
V (7455532) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7455572) wl_partition: erase_range - start_address=0x001dc000, size=0x00001000, result=0x00000000
V (7455572) wl_flash: erase_range - result= 0x00000000
D (7455572) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7455582) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7455592) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:23:09,D,PWRM,<src,1,active,0.36,15mp,0.473,total,3.998,voltage,230.6,current,0.0,freq,50.0,pf,0.00
V (7455662) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7455662) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=1, count=1
D (7455672) wl_flash: read - src_addr= 0x00001000, size= 0x00001000
V (7455682) wl_flash: calcAddr - addr= 0x00001000 -> result= 0x001db000, dummy_addr= 0x000ec000
V (7455692) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=15, count=1
D (7455692) wl_flash: read - src_addr= 0x0000f000, size= 0x00001000
V (7455702) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7455712) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=15, count=1
D (7455712) wl_flash: erase_range - start_address= 0x0000f000, size= 0x00001000
D (7455722) wl_flash: erase_sector - sector= 0x0000000f
V (7455732) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7455772) wl_partition: erase_range - start_address=0x001e9000, size=0x00001000, result=0x00000000
V (7455772) wl_flash: erase_range - result= 0x00000000
D (7455772) wl_flash: write - dest_addr= 0x0000f000, size= 0x00001000
V (7455772) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7455792) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=2, count=1
D (7455792) wl_flash: read - src_addr= 0x00002000, size= 0x00001000
V (7455802) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7455812) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7455812) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7455822) wl_flash: erase_sector - sector= 0x00000002
V (7455832) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7455872) wl_partition: erase_range - start_address=0x001dc000, size=0x00001000, result=0x00000000
V (7455872) wl_flash: erase_range - result= 0x00000000
D (7455872) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7455882) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7455892) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:24:09,D,PWRM,<src,0,active,0.9,15mp,0.216,total,2.115
V (7515962) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7515962) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=1, count=1
D (7515972) wl_flash: read - src_addr= 0x00001000, size= 0x00001000
V (7515972) wl_flash: calcAddr - addr= 0x00001000 -> result= 0x001db000, dummy_addr= 0x000ec000
V (7515982) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=15, count=1
D (7515992) wl_flash: read - src_addr= 0x0000f000, size= 0x00001000
V (7516002) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7516012) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=15, count=1
D (7516012) wl_flash: erase_range - start_address= 0x0000f000, size= 0x00001000
D (7516022) wl_flash: erase_sector - sector= 0x0000000f
V (7516022) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7516072) wl_partition: erase_range - start_address=0x001e9000, size=0x00001000, result=0x00000000
V (7516072) wl_flash: erase_range - result= 0x00000000
D (7516072) wl_flash: write - dest_addr= 0x0000f000, size= 0x00001000
V (7516082) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7516092) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=2, count=1
D (7516092) wl_flash: read - src_addr= 0x00002000, size= 0x00001000
V (7516102) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7516112) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7516112) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7516122) wl_flash: erase_sector - sector= 0x00000002
V (7516132) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7516172) wl_partition: erase_range - start_address=0x001dc000, size=0x00001000, result=0x00000000
V (7516172) wl_flash: erase_range - result= 0x00000000
D (7516172) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7516182) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7516192) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:24:09,D,PWRM,<src,1,active,0.46,15mp,0.508,total,4.44,voltage,230.5,current,0.0,freq,50.0,pf,0.00
V (7516262) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7516272) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=1, count=1
D (7516272) wl_flash: read - src_addr= 0x00001000, size= 0x00001000
V (7516282) wl_flash: calcAddr - addr= 0x00001000 -> result= 0x001db000, dummy_addr= 0x000ec000
V (7516292) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=15, count=1
D (7516292) wl_flash: read - src_addr= 0x0000f000, size= 0x00001000
V (7516302) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7516312) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=15, count=1
D (7516322) wl_flash: erase_range - start_address= 0x0000f000, size= 0x00001000
D (7516322) wl_flash: erase_sector - sector= 0x0000000f
V (7516332) wl_flash: updateWL - access_count= 0x00000000, pos= 0x000000ec
V (7516372) wl_partition: erase_range - start_address=0x000ec000, size=0x00001000, result=0x00000000
V (7516512) wl_partition: erase_range - start_address=0x001eb000, size=0x00002000, result=0x00000000
V (7516602) wl_partition: erase_range - start_address=0x001ed000, size=0x00002000, result=0x00000000
D (7516602) wl_flash: updateWL - move_count= 0x00000012, pos= 0x00000000,
V (7516602) wl_flash: updateWL - result= 0x00000000
V (7516612) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e8000, dummy_addr= 0x00000000
V (7516652) wl_partition: erase_range - start_address=0x001e8000, size=0x00001000, result=0x00000000
V (7516652) wl_flash: erase_range - result= 0x00000000
D (7516652) wl_flash: write - dest_addr= 0x0000f000, size= 0x00001000
V (7516652) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e8000, dummy_addr= 0x00000000
V (7516672) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=2, count=1
D (7516672) wl_flash: read - src_addr= 0x00002000, size= 0x00001000
V (7516682) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7516692) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7516692) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7516702) wl_flash: erase_sector - sector= 0x00000002
V (7516712) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7516752) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7516752) wl_flash: erase_range - result= 0x00000000
D (7516752) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7516752) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7516772) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:25:10,D,PWRM,<src,0,active,0.16,15mp,0.201,total,2.131
V (7576842) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
D (7576842) vfs_fat: vfs_fat_open: fresult=4
V (7576842) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=602, mode=1b6
2021-05-23,21:25:10,I,PWRM,!Created /pwrmtr-3.log
V (7576852) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7576862) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7576872) wl_flash: erase_sector - sector= 0x00000002
V (7576872) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7576922) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7576922) wl_flash: erase_range - result= 0x00000000
D (7576922) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7576922) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7576942) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=1, count=1
D (7576942) wl_flash: read - src_addr= 0x00001000, size= 0x00001000
V (7576952) wl_flash: calcAddr - addr= 0x00001000 -> result= 0x001da000, dummy_addr= 0x00000000
V (7576962) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=19, count=1
D (7576962) wl_flash: erase_range - start_address= 0x00013000, size= 0x00001000
D (7576972) wl_flash: erase_sector - sector= 0x00000013
V (7576982) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7577022) wl_partition: erase_range - start_address=0x00002000, size=0x00001000, result=0x00000000
V (7577022) wl_flash: erase_range - result= 0x00000000
D (7577022) wl_flash: write - dest_addr= 0x00013000, size= 0x00001000
V (7577022) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7577042) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=1, count=1
D (7577042) wl_flash: erase_range - start_address= 0x00001000, size= 0x00001000
D (7577052) wl_flash: erase_sector - sector= 0x00000001
V (7577052) wl_flash: calcAddr - addr= 0x00001000 -> result= 0x001da000, dummy_addr= 0x00000000
V (7577102) wl_partition: erase_range - start_address=0x001da000, size=0x00001000, result=0x00000000
V (7577102) wl_flash: erase_range - result= 0x00000000
D (7577102) wl_flash: write - dest_addr= 0x00001000, size= 0x00001000
V (7577102) wl_flash: calcAddr - addr= 0x00001000 -> result= 0x001da000, dummy_addr= 0x00000000
V (7577122) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=2, count=1
D (7577122) wl_flash: read - src_addr= 0x00002000, size= 0x00001000
V (7577132) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7577142) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7577142) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7577152) wl_flash: erase_sector - sector= 0x00000002
V (7577162) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7577202) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7577202) wl_flash: erase_range - result= 0x00000000
D (7577202) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7577202) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7577222) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:25:10,D,PWRM,<src,1,active,0.22,15mp,0.497,total,4.66,voltage,230.6,current,0.0,freq,50.0,pf,0.00
V (7577292) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7577292) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=19, count=1
D (7577302) wl_flash: read - src_addr= 0x00013000, size= 0x00001000
V (7577312) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7577322) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=19, count=1
D (7577322) wl_flash: erase_range - start_address= 0x00013000, size= 0x00001000
D (7577332) wl_flash: erase_sector - sector= 0x00000013
V (7577332) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7577382) wl_partition: erase_range - start_address=0x00002000, size=0x00001000, result=0x00000000
V (7577382) wl_flash: erase_range - result= 0x00000000
D (7577382) wl_flash: write - dest_addr= 0x00013000, size= 0x00001000
V (7577392) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7577402) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7577402) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7577412) wl_flash: erase_sector - sector= 0x00000002
V (7577412) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7577452) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7577452) wl_flash: erase_range - result= 0x00000000
D (7577452) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7577452) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7577472) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:26:10,D,PWRM,<src,0,active,0.17,15mp,0.215,total,2.148
V (7637532) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7637532) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=19, count=1
D (7637542) wl_flash: read - src_addr= 0x00013000, size= 0x00001000
V (7637542) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7637552) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=19, count=1
D (7637562) wl_flash: erase_range - start_address= 0x00013000, size= 0x00001000
D (7637562) wl_flash: erase_sector - sector= 0x00000013
V (7637572) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7637612) wl_partition: erase_range - start_address=0x00002000, size=0x00001000, result=0x00000000
V (7637612) wl_flash: erase_range - result= 0x00000000
D (7637612) wl_flash: write - dest_addr= 0x00013000, size= 0x00001000
V (7637612) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7637632) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7637632) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7637642) wl_flash: erase_sector - sector= 0x00000002
V (7637642) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7637682) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7637682) wl_flash: erase_range - result= 0x00000000
D (7637682) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7637682) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7637702) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:26:11,D,PWRM,<src,1,active,0.57,15mp,0.514,total,4.123,voltage,230.7,current,0.0,freq,50.0,pf,0.00
V (7637772) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7637772) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=19, count=1
D (7637782) wl_flash: read - src_addr= 0x00013000, size= 0x00001000
V (7637792) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7637802) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=19, count=1
D (7637802) wl_flash: erase_range - start_address= 0x00013000, size= 0x00001000
D (7637812) wl_flash: erase_sector - sector= 0x00000013
V (7637812) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7637862) wl_partition: erase_range - start_address=0x00002000, size=0x00001000, result=0x00000000
V (7637862) wl_flash: erase_range - result= 0x00000000
D (7637862) wl_flash: write - dest_addr= 0x00013000, size= 0x00001000
V (7637872) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7637882) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7637882) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7637892) wl_flash: erase_sector - sector= 0x00000002
V (7637892) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7637942) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7637942) wl_flash: erase_range - result= 0x00000000
D (7637942) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7637942) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7637962) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:27:11,D,PWRM,<src,0,active,0.7,15mp,0.218,total,2.155
V (7698022) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7698022) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=19, count=1
D (7698032) wl_flash: read - src_addr= 0x00013000, size= 0x00001000
V (7698032) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7698042) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=19, count=1
D (7698052) wl_flash: erase_range - start_address= 0x00013000, size= 0x00001000
D (7698052) wl_flash: erase_sector - sector= 0x00000013
V (7698062) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7698102) wl_partition: erase_range - start_address=0x00002000, size=0x00001000, result=0x00000000
V (7698102) wl_flash: erase_range - result= 0x00000000
D (7698102) wl_flash: write - dest_addr= 0x00013000, size= 0x00001000
V (7698112) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7698122) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7698122) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7698132) wl_flash: erase_sector - sector= 0x00000002
V (7698132) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7698182) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7698182) wl_flash: erase_range - result= 0x00000000
D (7698182) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7698192) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7698202) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:27:11,D,PWRM,<src,1,active,0.9,15mp,0.464,total,4.132,voltage,229.2,current,0.0,freq,50.0,pf,0.00
V (7698272) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7698272) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=19, count=1
D (7698282) wl_flash: read - src_addr= 0x00013000, size= 0x00001000
V (7698292) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7698302) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=19, count=1
D (7698302) wl_flash: erase_range - start_address= 0x00013000, size= 0x00001000
D (7698312) wl_flash: erase_sector - sector= 0x00000013
V (7698312) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7698362) wl_partition: erase_range - start_address=0x00002000, size=0x00001000, result=0x00000000
V (7698362) wl_flash: erase_range - result= 0x00000000
D (7698362) wl_flash: write - dest_addr= 0x00013000, size= 0x00001000
V (7698372) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7698382) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7698382) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7698392) wl_flash: erase_sector - sector= 0x00000002
V (7698392) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7698442) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7698442) wl_flash: erase_range - result= 0x00000000
D (7698442) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7698452) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7698462) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
<<<
I have an application that collects power metering info from 2 sources, the first is a pulse counter (using PCNT) and the second is a PZEM004T device that is handled via UART2.
The pulse counter uses an ISR to count the pulses from an S0 pulsemeter, a foreground task reports this counter every minute to a file called pwrmtr-3.log. No problem there.
The PZEM004T is read out every minute by sending a request via UART2, the PZEM004T response triggers an ISR for each byte received, the ISR is a state machine that collects bytes into a complete pakket and then posts it on a queue. The queue is read in above mentioned foreground task that reports the data to the same file pwrmtr-3.log. This also works fine.
This pwrmtr-3.log is part of 4 rotating files with a max size of 128Kb each, if pwrmtr-3.log is full then pwrmtr-0.log is deleted and pwrmtr-1.log is renamed to pwrmtr-0.log... and finally pwrmtr-3.log is renamed to pwrmtr-2.log. These files reside on a FAT partition of 1984Kb mounted with WL.
const esp_vfs_fat_mount_config_t mount_config = {
.format_if_mount_failed = true,
.max_files = 4,
.allocation_unit_size = CONFIG_WL_SECTOR_SIZE
};
int32_t err = esp_vfs_fat_spiflash_mount("/spiflash", "private", &mount_config, &m_vfsWlHandle);
These logfiles are reported by the HTTP server of my application, just open each file, read every entry and report it, then close the file (x4). There is no chance that HTTP server and the part collecting the data run together as these run in the same worker thread and as such will be active in turn but never together, thus we can use a lockless design.
But after a while pwrmtr-3.log seems to be disappeared/corrupted and is recreated empty, I am talking about 3-5 hours for this to happen. After that I see a second file that has unreadable characters in it's name.
The problem must be related to the use of the UART, when I disable the part that handles the PZEM004T (and no ISR for the UART) then there is no file corruption. But the same UART code is working fine in another project that also logs events into a file and allows reporting it via HTTP server.
Below is a logging detail of the moment it goes wrong, pwrmtr-3.log is fine upto 21:24:09 where it writes both the data of the PCNT (src,0) and the PZEM (src,1). But then at 21:25:10 opening of pwrmtr-3.log fails due to some reason and my application re-creates it. The only diff with previous writes seem to be the WL stepping in to do something.
>>>
2021-05-23,21:23:08,D,PWRM,<src,0,active,0.18,15mp,0.211,total,2.106
V (7455362) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7455362) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=1, count=1
D (7455372) wl_flash: read - src_addr= 0x00001000, size= 0x00001000
V (7455372) wl_flash: calcAddr - addr= 0x00001000 -> result= 0x001db000, dummy_addr= 0x000ec000
V (7455382) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=15, count=1
D (7455392) wl_flash: read - src_addr= 0x0000f000, size= 0x00001000
V (7455392) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7455402) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=15, count=1
D (7455412) wl_flash: erase_range - start_address= 0x0000f000, size= 0x00001000
D (7455422) wl_flash: erase_sector - sector= 0x0000000f
V (7455422) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7455472) wl_partition: erase_range - start_address=0x001e9000, size=0x00001000, result=0x00000000
V (7455472) wl_flash: erase_range - result= 0x00000000
D (7455472) wl_flash: write - dest_addr= 0x0000f000, size= 0x00001000
V (7455472) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7455492) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=2, count=1
D (7455492) wl_flash: read - src_addr= 0x00002000, size= 0x00001000
V (7455502) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7455512) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7455512) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7455522) wl_flash: erase_sector - sector= 0x00000002
V (7455532) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7455572) wl_partition: erase_range - start_address=0x001dc000, size=0x00001000, result=0x00000000
V (7455572) wl_flash: erase_range - result= 0x00000000
D (7455572) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7455582) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7455592) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:23:09,D,PWRM,<src,1,active,0.36,15mp,0.473,total,3.998,voltage,230.6,current,0.0,freq,50.0,pf,0.00
V (7455662) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7455662) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=1, count=1
D (7455672) wl_flash: read - src_addr= 0x00001000, size= 0x00001000
V (7455682) wl_flash: calcAddr - addr= 0x00001000 -> result= 0x001db000, dummy_addr= 0x000ec000
V (7455692) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=15, count=1
D (7455692) wl_flash: read - src_addr= 0x0000f000, size= 0x00001000
V (7455702) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7455712) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=15, count=1
D (7455712) wl_flash: erase_range - start_address= 0x0000f000, size= 0x00001000
D (7455722) wl_flash: erase_sector - sector= 0x0000000f
V (7455732) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7455772) wl_partition: erase_range - start_address=0x001e9000, size=0x00001000, result=0x00000000
V (7455772) wl_flash: erase_range - result= 0x00000000
D (7455772) wl_flash: write - dest_addr= 0x0000f000, size= 0x00001000
V (7455772) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7455792) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=2, count=1
D (7455792) wl_flash: read - src_addr= 0x00002000, size= 0x00001000
V (7455802) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7455812) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7455812) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7455822) wl_flash: erase_sector - sector= 0x00000002
V (7455832) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7455872) wl_partition: erase_range - start_address=0x001dc000, size=0x00001000, result=0x00000000
V (7455872) wl_flash: erase_range - result= 0x00000000
D (7455872) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7455882) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7455892) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:24:09,D,PWRM,<src,0,active,0.9,15mp,0.216,total,2.115
V (7515962) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7515962) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=1, count=1
D (7515972) wl_flash: read - src_addr= 0x00001000, size= 0x00001000
V (7515972) wl_flash: calcAddr - addr= 0x00001000 -> result= 0x001db000, dummy_addr= 0x000ec000
V (7515982) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=15, count=1
D (7515992) wl_flash: read - src_addr= 0x0000f000, size= 0x00001000
V (7516002) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7516012) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=15, count=1
D (7516012) wl_flash: erase_range - start_address= 0x0000f000, size= 0x00001000
D (7516022) wl_flash: erase_sector - sector= 0x0000000f
V (7516022) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7516072) wl_partition: erase_range - start_address=0x001e9000, size=0x00001000, result=0x00000000
V (7516072) wl_flash: erase_range - result= 0x00000000
D (7516072) wl_flash: write - dest_addr= 0x0000f000, size= 0x00001000
V (7516082) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7516092) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=2, count=1
D (7516092) wl_flash: read - src_addr= 0x00002000, size= 0x00001000
V (7516102) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7516112) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7516112) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7516122) wl_flash: erase_sector - sector= 0x00000002
V (7516132) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7516172) wl_partition: erase_range - start_address=0x001dc000, size=0x00001000, result=0x00000000
V (7516172) wl_flash: erase_range - result= 0x00000000
D (7516172) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7516182) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001dc000, dummy_addr= 0x000ec000
V (7516192) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:24:09,D,PWRM,<src,1,active,0.46,15mp,0.508,total,4.44,voltage,230.5,current,0.0,freq,50.0,pf,0.00
V (7516262) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7516272) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=1, count=1
D (7516272) wl_flash: read - src_addr= 0x00001000, size= 0x00001000
V (7516282) wl_flash: calcAddr - addr= 0x00001000 -> result= 0x001db000, dummy_addr= 0x000ec000
V (7516292) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=15, count=1
D (7516292) wl_flash: read - src_addr= 0x0000f000, size= 0x00001000
V (7516302) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e9000, dummy_addr= 0x000ec000
V (7516312) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=15, count=1
D (7516322) wl_flash: erase_range - start_address= 0x0000f000, size= 0x00001000
D (7516322) wl_flash: erase_sector - sector= 0x0000000f
V (7516332) wl_flash: updateWL - access_count= 0x00000000, pos= 0x000000ec
V (7516372) wl_partition: erase_range - start_address=0x000ec000, size=0x00001000, result=0x00000000
V (7516512) wl_partition: erase_range - start_address=0x001eb000, size=0x00002000, result=0x00000000
V (7516602) wl_partition: erase_range - start_address=0x001ed000, size=0x00002000, result=0x00000000
D (7516602) wl_flash: updateWL - move_count= 0x00000012, pos= 0x00000000,
V (7516602) wl_flash: updateWL - result= 0x00000000
V (7516612) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e8000, dummy_addr= 0x00000000
V (7516652) wl_partition: erase_range - start_address=0x001e8000, size=0x00001000, result=0x00000000
V (7516652) wl_flash: erase_range - result= 0x00000000
D (7516652) wl_flash: write - dest_addr= 0x0000f000, size= 0x00001000
V (7516652) wl_flash: calcAddr - addr= 0x0000f000 -> result= 0x001e8000, dummy_addr= 0x00000000
V (7516672) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=2, count=1
D (7516672) wl_flash: read - src_addr= 0x00002000, size= 0x00001000
V (7516682) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7516692) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7516692) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7516702) wl_flash: erase_sector - sector= 0x00000002
V (7516712) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7516752) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7516752) wl_flash: erase_range - result= 0x00000000
D (7516752) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7516752) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7516772) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:25:10,D,PWRM,<src,0,active,0.16,15mp,0.201,total,2.131
V (7576842) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
D (7576842) vfs_fat: vfs_fat_open: fresult=4
V (7576842) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=602, mode=1b6
2021-05-23,21:25:10,I,PWRM,!Created /pwrmtr-3.log
V (7576852) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7576862) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7576872) wl_flash: erase_sector - sector= 0x00000002
V (7576872) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7576922) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7576922) wl_flash: erase_range - result= 0x00000000
D (7576922) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7576922) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7576942) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=1, count=1
D (7576942) wl_flash: read - src_addr= 0x00001000, size= 0x00001000
V (7576952) wl_flash: calcAddr - addr= 0x00001000 -> result= 0x001da000, dummy_addr= 0x00000000
V (7576962) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=19, count=1
D (7576962) wl_flash: erase_range - start_address= 0x00013000, size= 0x00001000
D (7576972) wl_flash: erase_sector - sector= 0x00000013
V (7576982) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7577022) wl_partition: erase_range - start_address=0x00002000, size=0x00001000, result=0x00000000
V (7577022) wl_flash: erase_range - result= 0x00000000
D (7577022) wl_flash: write - dest_addr= 0x00013000, size= 0x00001000
V (7577022) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7577042) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=1, count=1
D (7577042) wl_flash: erase_range - start_address= 0x00001000, size= 0x00001000
D (7577052) wl_flash: erase_sector - sector= 0x00000001
V (7577052) wl_flash: calcAddr - addr= 0x00001000 -> result= 0x001da000, dummy_addr= 0x00000000
V (7577102) wl_partition: erase_range - start_address=0x001da000, size=0x00001000, result=0x00000000
V (7577102) wl_flash: erase_range - result= 0x00000000
D (7577102) wl_flash: write - dest_addr= 0x00001000, size= 0x00001000
V (7577102) wl_flash: calcAddr - addr= 0x00001000 -> result= 0x001da000, dummy_addr= 0x00000000
V (7577122) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=2, count=1
D (7577122) wl_flash: read - src_addr= 0x00002000, size= 0x00001000
V (7577132) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7577142) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7577142) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7577152) wl_flash: erase_sector - sector= 0x00000002
V (7577162) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7577202) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7577202) wl_flash: erase_range - result= 0x00000000
D (7577202) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7577202) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7577222) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:25:10,D,PWRM,<src,1,active,0.22,15mp,0.497,total,4.66,voltage,230.6,current,0.0,freq,50.0,pf,0.00
V (7577292) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7577292) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=19, count=1
D (7577302) wl_flash: read - src_addr= 0x00013000, size= 0x00001000
V (7577312) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7577322) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=19, count=1
D (7577322) wl_flash: erase_range - start_address= 0x00013000, size= 0x00001000
D (7577332) wl_flash: erase_sector - sector= 0x00000013
V (7577332) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7577382) wl_partition: erase_range - start_address=0x00002000, size=0x00001000, result=0x00000000
V (7577382) wl_flash: erase_range - result= 0x00000000
D (7577382) wl_flash: write - dest_addr= 0x00013000, size= 0x00001000
V (7577392) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7577402) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7577402) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7577412) wl_flash: erase_sector - sector= 0x00000002
V (7577412) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7577452) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7577452) wl_flash: erase_range - result= 0x00000000
D (7577452) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7577452) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7577472) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:26:10,D,PWRM,<src,0,active,0.17,15mp,0.215,total,2.148
V (7637532) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7637532) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=19, count=1
D (7637542) wl_flash: read - src_addr= 0x00013000, size= 0x00001000
V (7637542) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7637552) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=19, count=1
D (7637562) wl_flash: erase_range - start_address= 0x00013000, size= 0x00001000
D (7637562) wl_flash: erase_sector - sector= 0x00000013
V (7637572) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7637612) wl_partition: erase_range - start_address=0x00002000, size=0x00001000, result=0x00000000
V (7637612) wl_flash: erase_range - result= 0x00000000
D (7637612) wl_flash: write - dest_addr= 0x00013000, size= 0x00001000
V (7637612) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7637632) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7637632) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7637642) wl_flash: erase_sector - sector= 0x00000002
V (7637642) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7637682) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7637682) wl_flash: erase_range - result= 0x00000000
D (7637682) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7637682) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7637702) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:26:11,D,PWRM,<src,1,active,0.57,15mp,0.514,total,4.123,voltage,230.7,current,0.0,freq,50.0,pf,0.00
V (7637772) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7637772) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=19, count=1
D (7637782) wl_flash: read - src_addr= 0x00013000, size= 0x00001000
V (7637792) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7637802) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=19, count=1
D (7637802) wl_flash: erase_range - start_address= 0x00013000, size= 0x00001000
D (7637812) wl_flash: erase_sector - sector= 0x00000013
V (7637812) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7637862) wl_partition: erase_range - start_address=0x00002000, size=0x00001000, result=0x00000000
V (7637862) wl_flash: erase_range - result= 0x00000000
D (7637862) wl_flash: write - dest_addr= 0x00013000, size= 0x00001000
V (7637872) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7637882) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7637882) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7637892) wl_flash: erase_sector - sector= 0x00000002
V (7637892) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7637942) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7637942) wl_flash: erase_range - result= 0x00000000
D (7637942) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7637942) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7637962) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:27:11,D,PWRM,<src,0,active,0.7,15mp,0.218,total,2.155
V (7698022) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7698022) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=19, count=1
D (7698032) wl_flash: read - src_addr= 0x00013000, size= 0x00001000
V (7698032) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7698042) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=19, count=1
D (7698052) wl_flash: erase_range - start_address= 0x00013000, size= 0x00001000
D (7698052) wl_flash: erase_sector - sector= 0x00000013
V (7698062) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7698102) wl_partition: erase_range - start_address=0x00002000, size=0x00001000, result=0x00000000
V (7698102) wl_flash: erase_range - result= 0x00000000
D (7698102) wl_flash: write - dest_addr= 0x00013000, size= 0x00001000
V (7698112) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7698122) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7698122) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7698132) wl_flash: erase_sector - sector= 0x00000002
V (7698132) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7698182) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7698182) wl_flash: erase_range - result= 0x00000000
D (7698182) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7698192) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7698202) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
2021-05-23,21:27:11,D,PWRM,<src,1,active,0.9,15mp,0.464,total,4.132,voltage,229.2,current,0.0,freq,50.0,pf,0.00
V (7698272) vfs_fat: vfs_fat_open: path="/pwrmtr-3.log", flags=2, mode=1b6
V (7698272) ff_diskio_spiflash: ff_wl_read - pdrv=0, sector=19, count=1
D (7698282) wl_flash: read - src_addr= 0x00013000, size= 0x00001000
V (7698292) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7698302) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=19, count=1
D (7698302) wl_flash: erase_range - start_address= 0x00013000, size= 0x00001000
D (7698312) wl_flash: erase_sector - sector= 0x00000013
V (7698312) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7698362) wl_partition: erase_range - start_address=0x00002000, size=0x00001000, result=0x00000000
V (7698362) wl_flash: erase_range - result= 0x00000000
D (7698362) wl_flash: write - dest_addr= 0x00013000, size= 0x00001000
V (7698372) wl_flash: calcAddr - addr= 0x00013000 -> result= 0x00002000, dummy_addr= 0x00000000
V (7698382) ff_diskio_spiflash: ff_wl_write - pdrv=0, sector=2, count=1
D (7698382) wl_flash: erase_range - start_address= 0x00002000, size= 0x00001000
D (7698392) wl_flash: erase_sector - sector= 0x00000002
V (7698392) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7698442) wl_partition: erase_range - start_address=0x001db000, size=0x00001000, result=0x00000000
V (7698442) wl_flash: erase_range - result= 0x00000000
D (7698442) wl_flash: write - dest_addr= 0x00002000, size= 0x00001000
V (7698452) wl_flash: calcAddr - addr= 0x00002000 -> result= 0x001db000, dummy_addr= 0x00000000
V (7698462) ff_diskio_spiflash: ff_wl_ioctl: cmd=0
<<<