search

PX4 / PX4-Autopilot

PX4 Autopilot Software
https://px4.io
BSD 3-Clause "New" or "Revised" License
8k stars 13.29k forks source link

SD Card issues on Matek H743 Slim board #19155

Closed spiderkeys closed 2 years ago

spiderkeys commented 2 years ago

Describe the bug SD card operations only seem to partially work on the Matek H743 Slim board. The firmware seems to be able to write files to the card, but seems to have issues reading files. Operations in nsh like ls seem to work in the /fs/microsd/ directory, but cat always fails with read errors for files on the SD card. cat works as expected on other ROMFS files. There are also various errors relating to parameters upon startup.

Building from master, commit: 33ce1b9b642ca78f44315394ddd1fa2f8ca69922 Host OS: Ubuntu 20.04, x86_64

To Reproduce Steps to reproduce the behavior: NOTE: Start with no SD card inserted

  1. Build the bootloader target for the Slim make matek_h743-slim_bootloader
  2. Put the chip in DFU mode and connect to host machine over USB
  3. Use STM32CubeProgrammer to completely erase all flash sectors of the chip
  4. Use STM32CubeProgrammer (or dfu-util) to flash the Matek h743 Slim Bootloader to 0x08000000
  5. Disconnect the USB cable
  6. Build the firmware target for the Slim make matek_h743-slim_default
  7. Connect the FMU directly to the host machine via USB and wait for it to come up (/dev/ttyACM0 in my case)
  8. Use Tools/px_uploader.py --port /dev/ttyACM0 build/matek_h743-slim_default/matek_h743-slim_default.px4 to flash the firmware
  9. Disconnect the USB cable from the FMU
  10. Format a fresh (4/16/32GB sandisk) SD card using mkdosfs /dev/sdb -s 32 -F 32 -I (the results are the same after manually writing a .format file to the SD card and allowing the firmware to do the format)
  11. Insert the SD card into the FMU
  12. Connect the USART1 interface on the FMU to the host machine via USB FTDI adapter
  13. Start a terminal emulator session on the system console interface (for me: picocom -b 57600 /dev/ttyUSB0)
  14. Reconnect the USB cable from the host to the FMU to power on
  15. System console starts sending messages - pasted below
  16. Once nsh is available, confirm that I can ls files in /fs/microsd and that there are files there
  17. Try to cat the param_import_fail.txt file, which fails with a read failed: I/O error
  18. Try to create a file using echo "hello" > /fs/microsd/test, which seems to succeed
  19. Confirm the file exists with ls /fs/microsd/
  20. Try to cat the contents of that file as well, which raises another read failure, but this time the reason is invalid argument
  21. Try to cat the contents of a ROMFS file (/etc/mixers/vectored6dof.main.mix as an example), which succeeds and prints the contents

I tested a very similar process with the mRO Pixhawk1 board, and everything worked as expected (and there were no errors during the boot process).

Expected behavior Operations like cat should work in nsh on SD card files. There should not be so many errors during boot up relating to reading from and writing to the SD card.

Log Files and Screenshots System Console Output

picocom v3.1

port is        : /dev/ttyUSB0
flowcontrol    : none
baudrate is    : 57600
parity is      : none
databits are   : 8
stopbits are   : 1
escape is      : C-a
local echo is  : no
noinit is      : no
noreset is     : no
hangup is      : no
nolock is      : no
send_cmd is    : sz -vv
receive_cmd is : rz -vv -E
imap is        : 
omap is        : 
emap is        : crcrlf,delbs,
logfile is     : none
initstring     : none
exit_after is  : not set
exit is        : no

Type [C-a] [C-h] to see available commands
Terminal ready
[boot] Fault Log info File No 4 Length 3177 flags:0x01 state:1
[boot] Fault Log is Armed
sercon: Registering CDC/ACM serial driver
sercon: Successfully registered the CDC/ACM serial driver
HW arch: MATEK_H743_SLIM
FW git-hash: 33ce1b9b642[hardfault_log] Fault Log is Armed
ca78f44315394ddd1fa2f8ca69922
FW version: 1.13.0 0 (17629184)
FW git-branch: master
OS: NuttX
OS version: Release 8.2.0 (134349055)
OS git-hash: 017aa15746bcf6b57bb185e14dce7fa0876fc751
Build datetime: Feb  8 2022 21:41:50
Build uri: localhost
Build variant: default
Toolchain: GNU GCC, 9.3.1 20200408 (release)
PX4GUID: 000600000000343834323139510b00410030
MCU: STM32H7[4|5]xxx, rev. V
INFO  [param] selected parameter default file /fs/microsd/params
ERROR [param] open '/fs/microsd/params' failed (2)
ERROR [init] param import failed
ERROR [param] open '/fs/microsd/params' failed (2)
dmesg [23:100]
cp [29:100]
nsh: cp: open failed: No such file or directory
INFO  [param] selected parameter backup file /fs/microsd/parameters_backup.bson
Board architecture defaults: /etc/init.d/rc.board_arch_defaults
Board defaults: /etc/init.d/rc.board_defaults
INFO  [dataman] data manager file '/fs/microsd/dataman' size is 62560 bytes
INFO  [uavcan] Node ID 1, bitrate 1000000
Board sensors: /etc/init.d/rc.board_sensors
icm20602 #0 on SPI bus 4 rotation 12
mpu6000 #0 on SPI bus 1 rotation 12
dps310 #0 on I2C bus 2 address 0x76
ERROR [SPI_I2C] qmc5883l: no instance started (no device on bus?)
nsh: icm20948_i2c_passthrough: command not found
Starting Main GPS on /dev/ttyS1
Starting MAVLink on /dev/ttyS2
INFO  [mavlink] mode: Normal, data rate: 1200 B/s on /dev/ttyS2 @ 57600B
No autostart ID found
ekf2 [562:100]
Board extras: /etc/init.d/rc.board_extras
atxxxx #0 on SPI bus 2
INFO  [logger] logger started (mode=all)

NuttShell (NSH) NuttX-10.2.0
nsh> INFO  [logger] log root dir created: /fs/microsd/log
[boot] Fault Log info File No 4 Length 3177 flags:0x01 state:1
[boot] Fault Log is Armed
sercon: Registering CDC/ACM serial driver
sercon: Successfully registered the CDC/ACM serial driver
HW arch: MATEK_H743_SLIM
FW git-hash: 33ce1b9[hardfault_log] Fault Log is Armed
b642ca78f44315394ddd1fa2f8ca69922
FW version: 1.13.0 0 (17629184)
FW git-branch: master
OS: NuttX
OS version: Release 8.2.0 (134349055)
OS git-hash: 017aa15746bcf6b57bb185e14dce7fa0876fc751
Build datetime: Feb  8 2022 21:41:50
Build uri: localhost
Build variant: default
Toolchain: GNU GCC, 9.3.1 20200408 (release)
PX4GUID: 000600000000343834323139510b00410030
MCU: STM32H7[4|5]xxx, rev. V
INFO  [param] selected parameter default file /fs/microsd/params
ERROR [param] open '/fs/microsd/params' failed (2)
ERROR [init] param import failed
ERROR [param] open '/fs/microsd/params' failed (2)
dmesg [23:100]
cp [29:100]
nsh: cp: open failed: No such file or directory
INFO  [param] selected parameter backup file /fs/microsd/parameters_backup.bson
Board architecture defaults: /etc/init.d/rc.board_arch_defaults
Board defaults: /etc/init.d/rc.board_defaults
INFO  [dataman] data manager file '/fs/microsd/dataman' size is 62560 bytes
INFO  [uavcan] Node ID 1, bitrate 1000000
Board sensors: /etc/init.d/rc.board_sensors
icm20602 #0 on SPI bus 4 rotation 12
mpu6000 #0 on SPI bus 1 rotation 12
dps310 #0 on I2C bus 2 address 0x76
ERROR [SPI_I2C] qmc5883l: no instance started (no device on bus?)
nsh: icm20948_i2c_passthrough: command not found
Starting Main GPS on /dev/ttyS1
Starting MAVLink on /dev/ttyS2
INFO  [mavlink] mode: Normal, data rate: 1200 B/s on /dev/ttyS2 @ 57600B
No autostart ID found
ekf2 [562:100]
Board extras: /etc/init.d/rc.board_extras
atxxxx #0 on SPI bus 2
INFO  [logger] logger started (mode=all)

NuttShell (NSH) NuttX-10.2.0
nsh> ls fs/microsd
/fs/microsd:
 param_import_fail.txt
 dataman
 ufw/
 uavcan.db/
 log/
nsh> cat fs/microsd/param_import_fail.txt
nsh: cat: read failed: I/O error
nsh> INFO  [gyro_calibration] gyro 0 (3670050) updating offsets [0.000, 0.000, 0.000]->[-0.010, -0.006, -0.002] 38.1 degC
INFO  [gyro_calibration] gyro 1 (2162698) updating offsets [0.000, 0.000, 0.000]->[0.010, -0.016, 0.015] 34.6 degC
ERROR [tinybson] file write error -1, errno:22 (Invalid argument)
ERROR [tinybson] killed: file write error
ERROR [tinybson] killed: write error on BSON_DOUBLE
ERROR [parameters] BSON append failed for 'CAL_GYRO1_ZOFF'
ERROR [parameters] parameter export to /fs/microsd/params failed (-1) attempt 1
ERROR [tinybson] file write error -1, errno:22 (Invalid argument)
ERROR [tinybson] killed: file write error
ERROR [tinybson] killed: write error on BSON_DOUBLE
ERROR [parameters] BSON append failed for 'CAL_GYRO1_ZOFF'
ERROR [parameters] parameter export to /fs/microsd/params failed (-1) attempt 2
ERROR [tinybson] file write error -1, errno:22 (Invalid argument)
ERROR [tinybson] killed: file write error
ERROR [tinybson] killed: write error on BSON_DOUBLE
ERROR [parameters] BSON append failed for 'CAL_GYRO1_ZOFF'
ERROR [parameters] parameter export to /fs/microsd/params failed (-1) attempt 3
ERROR [parameters] param export failed (-1)
ERROR [parameters] param auto save failed (-1)

nsh> echo "hello" > fs/microsd/test
nsh> ls /fs/microsd/test
 /fs/microsd/test
nsh> cat /fs/microsd/test
nsh: cat: read failed: Invalid argument
nsh> ls /fs/microsd/
/fs/microsd:
 param_import_fail.txt
 dataman
 ufw/
 uavcan.db/
 log/
 params
 test
nsh> cat /etc/mixers/vectored6dof.main.mix
M: 3
S: 0 2 -4000 -4000 0 -4000 +4000
S: 0 3 +4000 +4000 0 -4000 +4000
S: 0 4 +4000 +4000 0 -4000 +4000
M: 3
S: 0 2 +4000 +4000 0 -4000 +4000
S: 0 3 +4000 +4000 0 -4000 +4000
S: 0 4 -4000 -4000 0 -4000 +4000
M: 3
S: 0 2 -4000 -4000 0 -4000 +4000
S: 0 3 +4000 +4000 0 -4000 +4000
S: 0 4 -4000 -4000 0 -4000 +4000
M: 3
S: 0 2 +4000 +4000 0 -4000 +4000
S: 0 3 +4000 +4000 0 -4000 +4000
S: 0 4 +4000 +4000 0 -4000 +4000
M: 3
S: 0 0 -4000 -4000 0 -4000 +4000
S: 0 1 +4000 +4000 0 -4000 +4000
S: 0 5 +4000 +4000 0 -4000 +4000
M: 3
S: 0 0 -4000 -4000 0 -4000 +4000
S: 0 1 -4000 -4000 0 -4000 +4000
S: 0 5 -4000 -4000 0 -4000 +4000
M: 3
S: 0 0 +4000 +4000 0 -4000 +4000
S: 0 1 +4000 +4000 0 -4000 +4000
S: 0 5 -4000 -4000 0 -4000 +4000
M: 3
S: 0 0 +4000 +4000 0 -4000 +4000
S: 0 1 -4000 -4000 0 -4000 +4000
S: 0 5 +4000 +4000 0 -4000 +4000
spiderkeys commented 2 years ago

Some progress on this issue:

My previous steps above indicated that formatting the SD card via ".format" was ultimately behaving the same as manually formatting the card. This turns out to be both false and somewhat true.

I don't know if this is actually related to having PX4 do the formatting or not, as I have not yet walked through this "reboot and try again" process with a manually flashed SD card.

dagar commented 2 years ago

Is this reproducible on multiple units?

@vvladic did you notice any issues?

spiderkeys commented 2 years ago

@dagar yes, I have reliably reproduced the results on multiple boards with multiple SD cards. As mentioned, the issue does not happen on the mRO Pixhawk1.

I currently don't have any other H743-based FMUs laying around to test on. I was trying to see if there were any fairly stable FMUv6 boards out there that people are regularly using and having success with, such that I can order one and use it as a "control" in my development process. The supported hardware page in the docs only mentions boards up to FMUv5X (from Holybro). I know Holybro has the Durandal, which is described as in beta, but don't have any reference for how stable/behaved it is in practice. Any feedback on that would be appreciated, to help decouple these issues from the Matek board specifically.

spiderkeys commented 2 years ago

Another (potential) issue/symptom, despite things otherwise seeming to be working at this stage.

I tried to run sd_bench, but keep getting an I/O error (5) upon write:

nsh> sd_bench -r 50
INFO  [sd_bench] Using block size = 4096 bytes, sync=0
INFO  [sd_bench] 
INFO  [sd_bench] Testing Sequential Write Speed...
ERROR [sd_bench] Write error: 5

This may just be a misunderstanding of how to use sd_bench, though I thought I should mention it, in case it was relevant.

sd_stress seems to function as expected:

nsh> sd_stress
iteration 0 took 1466055 us: OK
iteration 1 took 1487907 us: OK
iteration 2 took 1488032 us: OK
iteration 3 took 1468720 us: OK
iteration 4 took 1487426 us: OK
spiderkeys commented 2 years ago

Additional failure: I tried to adjust the block size for sd_bench, just as an experiment, and the following series of errors occurred:

nsh> sd_bench -b 512
INFO  [sd_bench] Using block size = 512 bytes, sync=0
INFO  [sd_bench] 
INFO  [sd_bench] Testing Sequential Write Speed...
ERROR [sd_bench] Write error: 5
nsh> sd_bench -b 16
ERROR [sd_bench] Can't open benchmark file /fs/microsd/benchmark.tmp
nsh> sd_bench -b 16
ERROR [sd_bench] Can't open benchmark file /fs/microsd/benchmark.tmp
nsh> sd_bench -b 512
ERROR [sd_bench] Can't open benchmark file /fs/microsd/benchmark.tmp
nsh> ls fs/microsd
/fs/microsd:
nsh>

On the first try with -b 512, I got the same write error, but then afterwards, the temporary benchmark file could not be created at all. Running ls on the microsd directory shows nothing, as if the card was unmounted.

Mounting the SD card on my desktop to examine the files, I have:

spiderkeys@spiderdesk:/media/spiderkeys/disk$ ls -al
total 196
drwxr-xr-x  5 spiderkeys spiderkeys 16384 Dec 31  1969 .
drwxr-x---+ 3 root       root        4096 Feb  9 16:26 ..
-rw-r--r--  1 spiderkeys spiderkeys     0 Dec 31  1999 benchmark.tmp
-rw-r--r--  1 spiderkeys spiderkeys 62560 Dec 31  1999 dataman
drwxr-xr-x  2 spiderkeys spiderkeys 16384 Dec 31  1999 log
-rw-r--r--  1 spiderkeys spiderkeys   139 Dec 31  1999 parameters_backup.bson
-rw-r--r--  1 spiderkeys spiderkeys   791 Dec 31  1999 param_import_fail.txt
-rw-r--r--  1 spiderkeys spiderkeys   139 Dec 31  1999 params
-rw-r--r--  1 spiderkeys spiderkeys     4 Dec 31  1999 test
drwxr-xr-x  2 spiderkeys spiderkeys 16384 Dec 31  1999 uavcan.db
drwxr-xr-x  2 spiderkeys spiderkeys 16384 Dec 31  1999 ufw
spiderkeys@spiderdesk:/media/spiderkeys/disk$ ls -al log/
total 32
drwxr-xr-x 2 spiderkeys spiderkeys 16384 Dec 31  1999 .
drwxr-xr-x 5 spiderkeys spiderkeys 16384 Dec 31  1969 ..
spiderkeys@spiderdesk:/media/spiderkeys/disk$

The benchmark file does seem to exist, but is 0 bytes, and there are no logs/fault reports anywhere.

spiderkeys commented 2 years ago

Given that the issue is fairly inconsistent and intermittent, I had the same notion as @dagar that it might be related to clock configuration, where we are pushing on the boundaries of some hardware/driver limitation.

Doing some comparisons between PX4 and Ardupilot, I noticed a PR in Ardupilot that explicitly dropped the max frequency for the SDIO interface to 12.5MHz for "increased reliability": https://github.com/ArduPilot/ardupilot/pull/17316

Cross-referencing that with the current settings in PX4, I found that the max is currently configured to 25MHz: https://github.com/PX4/PX4-Autopilot/blob/master/boards/matek/h743-slim/nuttx-config/include/board.h#L292-L297

I took a stab at increasing the divider by 1 to drop the clock frequency to 12MHz, and so far all of the symptoms have gone away. I haven't gone through the task of walking through the whole clock tree to confirm/validate the actual numbers, but this seems to have made a positive impact at the least.

sd_bench is now working and I'm getting decent results, compared to the table of benchmarked SD card speeds in the developer guide:

nsh> sd_bench -r 50
INFO  [sd_bench] Using block size = 4096 bytes, sync=0
INFO  [sd_bench] 
INFO  [sd_bench] Testing Sequential Write Speed...
INFO  [sd_bench]   Run  0:   485.45 KB/s, max write time: 25 ms (= 160.00 KB/s), fsync: 6 ms
INFO  [sd_bench]   Run  1:   485.80 KB/s, max write time: 13 ms (= 307.69 KB/s), fsync: 5 ms
INFO  [sd_bench]   Run  2:   485.28 KB/s, max write time: 26 ms (= 153.85 KB/s), fsync: 5 ms
INFO  [sd_bench]   Run  3:   484.79 KB/s, max write time: 28 ms (= 142.86 KB/s), fsync: 4 ms
INFO  [sd_bench]   Run  4:   492.37 KB/s, max write time: 11 ms (= 363.64 KB/s), fsync: 5 ms
INFO  [sd_bench]   Run  5:   484.63 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 5 ms
INFO  [sd_bench]   Run  6:   489.70 KB/s, max write time: 12 ms (= 333.33 KB/s), fsync: 5 ms
INFO  [sd_bench]   Run  7:   485.62 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 7 ms
INFO  [sd_bench]   Run  8:   486.62 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 5 ms
INFO  [sd_bench]   Run  9:   486.40 KB/s, max write time: 13 ms (= 307.69 KB/s), fsync: 5 ms
INFO  [sd_bench]   Run 10:   488.16 KB/s, max write time: 26 ms (= 153.85 KB/s), fsync: 5 ms
INFO  [sd_bench]   Run 11:   483.99 KB/s, max write time: 26 ms (= 153.85 KB/s), fsync: 5 ms
INFO  [sd_bench]   Run 12:   491.07 KB/s, max write time: 12 ms (= 333.33 KB/s), fsync: 4 ms
INFO  [sd_bench]   Run 13:   481.05 KB/s, max write time: 25 ms (= 160.00 KB/s), fsync: 6 ms
INFO  [sd_bench]   Run 14:   491.72 KB/s, max write time: 12 ms (= 333.33 KB/s), fsync: 5 ms
INFO  [sd_bench]   Run 15:   487.35 KB/s, max write time: 26 ms (= 153.85 KB/s), fsync: 5 ms
INFO  [sd_bench]   Run 16:   480.47 KB/s, max write time: 41 ms (=  97.56 KB/s), fsync: 5 ms
INFO  [sd_bench]   Run 17:   490.35 KB/s, max write time: 13 ms (= 307.69 KB/s), fsync: 7 ms
INFO  [sd_bench]   Run 18:   485.57 KB/s, max write time: 36 ms (= 111.11 KB/s), fsync: 5 ms

Will keep testing to see if anything crops up, and will try and find some time to validate the clock tree at some point.

vvladic commented 2 years ago

Hello and thanks for reporting this. I tried to follow your procedure above, but I was unable to reproduce any errors. I am using some generic low quality Kingston 8gb card formatted on Windows machine.

I can try it again today after work using some different high performance SanDisk cards, and maybe play with frequencies.

If using the reduced clock frequency tends to bring more stable results on more SD card types and logging with all options selected still works, please consider opening a pull request with your changes.

nsh> sd_bench -r 50
INFO  [sd_bench] Using block size = 4096 bytes, sync=0
INFO  [sd_bench] 
INFO  [sd_bench] Testing Sequential Write Speed...
INFO  [sd_bench]   Run  0:   225.88 KB/s, max write time: 30 ms (= 133.33 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run  1:   218.98 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 96 ms
INFO  [sd_bench]   Run  2:   231.43 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 10 ms
INFO  [sd_bench]   Run  3:   218.11 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 92 ms
INFO  [sd_bench]   Run  4:   228.92 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 19 ms
INFO  [sd_bench]   Run  5:   227.62 KB/s, max write time: 28 ms (= 142.86 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run  6:   217.32 KB/s, max write time: 108 ms (=  37.04 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run  7:   230.38 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run  8:   216.89 KB/s, max write time: 29 ms (= 137.93 KB/s), fsync: 89 ms
INFO  [sd_bench]   Run  9:   227.70 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 12 ms
INFO  [sd_bench]   Run 10:   226.17 KB/s, max write time: 29 ms (= 137.93 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 11:   218.07 KB/s, max write time: 115 ms (=  34.78 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 12:   227.06 KB/s, max write time: 35 ms (= 114.29 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 13:   217.48 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 92 ms
INFO  [sd_bench]   Run 14:   227.18 KB/s, max write time: 26 ms (= 153.85 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 15:   221.66 KB/s, max write time: 44 ms (=  90.91 KB/s), fsync: 13 ms
INFO  [sd_bench]   Run 16:   216.40 KB/s, max write time: 28 ms (= 142.86 KB/s), fsync: 95 ms
INFO  [sd_bench]   Run 17:   224.58 KB/s, max write time: 26 ms (= 153.85 KB/s), fsync: 10 ms
INFO  [sd_bench]   Run 18:   214.53 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 92 ms
INFO  [sd_bench]   Run 19:   225.72 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 13 ms
INFO  [sd_bench]   Run 20:   215.46 KB/s, max write time: 28 ms (= 142.86 KB/s), fsync: 90 ms
INFO  [sd_bench]   Run 21:   226.21 KB/s, max write time: 36 ms (= 111.11 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 22:   223.22 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 10 ms
INFO  [sd_bench]   Run 23:   215.78 KB/s, max write time: 103 ms (=  38.83 KB/s), fsync: 10 ms
INFO  [sd_bench]   Run 24:   223.24 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 25:   223.40 KB/s, max write time: 26 ms (= 153.85 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 26:   214.57 KB/s, max write time: 108 ms (=  37.04 KB/s), fsync: 10 ms
INFO  [sd_bench]   Run 27:   222.35 KB/s, max write time: 38 ms (= 105.26 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 28:   215.17 KB/s, max write time: 28 ms (= 142.86 KB/s), fsync: 91 ms
INFO  [sd_bench]   Run 29:   222.27 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 10 ms
INFO  [sd_bench]   Run 30:   223.71 KB/s, max write time: 28 ms (= 142.86 KB/s), fsync: 13 ms
INFO  [sd_bench]   Run 31:   212.45 KB/s, max write time: 110 ms (=  36.36 KB/s), fsync: 10 ms
INFO  [sd_bench]   Run 32:   227.23 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 33:   148.33 KB/s, max write time: 557 ms (=   7.18 KB/s), fsync: 93 ms
INFO  [sd_bench]   Run 34:   222.93 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 35:   217.22 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 92 ms
INFO  [sd_bench]   Run 36:   224.67 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 37:   223.90 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 13 ms
INFO  [sd_bench]   Run 38:   215.95 KB/s, max write time: 114 ms (=  35.09 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 39:   223.77 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 40:   218.13 KB/s, max write time: 26 ms (= 153.85 KB/s), fsync: 93 ms
INFO  [sd_bench]   Run 41:   222.70 KB/s, max write time: 28 ms (= 142.86 KB/s), fsync: 14 ms
INFO  [sd_bench]   Run 42:   225.82 KB/s, max write time: 35 ms (= 114.29 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 43:   214.26 KB/s, max write time: 108 ms (=  37.04 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 44:   224.42 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 12 ms
INFO  [sd_bench]   Run 45:   213.46 KB/s, max write time: 26 ms (= 153.85 KB/s), fsync: 97 ms
INFO  [sd_bench]   Run 46:   222.73 KB/s, max write time: 28 ms (= 142.86 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 47:   224.61 KB/s, max write time: 27 ms (= 148.15 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run 48:   212.41 KB/s, max write time: 26 ms (= 153.85 KB/s), fsync: 116 ms
INFO  [sd_bench]   Run 49:   223.91 KB/s, max write time: 30 ms (= 133.33 KB/s), fsync: 11 ms
INFO  [sd_bench]   Avg   :   220.03 KB/s
nsh> sd_bench -b 512
INFO  [sd_bench] Using block size = 512 bytes, sync=0
INFO  [sd_bench] 
INFO  [sd_bench] Testing Sequential Write Speed...
INFO  [sd_bench]   Run  0:   215.79 KB/s, max write time: 11 ms (=  45.45 KB/s), fsync: 91 ms
INFO  [sd_bench]   Run  1:   219.45 KB/s, max write time: 28 ms (=  17.86 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run  2:   144.83 KB/s, max write time: 108 ms (=   4.63 KB/s), fsync: 12 ms
INFO  [sd_bench]   Run  3:   216.69 KB/s, max write time: 11 ms (=  45.45 KB/s), fsync: 89 ms
INFO  [sd_bench]   Run  4:   223.10 KB/s, max write time: 23 ms (=  21.74 KB/s), fsync: 11 ms
INFO  [sd_bench]   Avg   :   204.16 KB/s
nsh> sd_bench -b 16
INFO  [sd_bench] Using block size = 16 bytes, sync=0
INFO  [sd_bench] 
INFO  [sd_bench] Testing Sequential Write Speed...
INFO  [sd_bench]   Run  0:   198.01 KB/s, max write time: 12 ms (=   1.30 KB/s), fsync: 91 ms
INFO  [sd_bench]   Run  1:   205.45 KB/s, max write time: 12 ms (=   1.30 KB/s), fsync: 12 ms
INFO  [sd_bench]   Run  2:   208.25 KB/s, max write time: 11 ms (=   1.42 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run  3:   200.64 KB/s, max write time: 92 ms (=   0.17 KB/s), fsync: 11 ms
INFO  [sd_bench]   Run  4:   206.79 KB/s, max write time: 11 ms (=   1.42 KB/s), fsync: 11 ms
INFO  [sd_bench]   Avg   :   203.78 KB/s
nsh> sd_stress
iteration 0 took 3466164 us: OK
iteration 1 took 4092254 us: OK
iteration 2 took 3569119 us: OK
iteration 3 took 4048710 us: OK
iteration 4 took 3467683 us: OK
nsh>
spiderkeys commented 2 years ago

@vvladic I've put up a PR which includes my very basic fix for the issue (on my board). I mispoke earlier saying that I had set it to 12MHz to solve the problem, and in fact had lowered it to 20MHz by incrementing the divisor value to 6.

https://github.com/PX4/PX4-Autopilot/pull/19177

spiderkeys commented 2 years ago

Have never seen any issues after the PR was merged. Closing.

zvikaf commented 1 year ago

WOW... this is alarming, as we suffer from the same in INAV buildups for the H743 ...