Experiencing apparently solved problems with SD deck

Discussions and questions about the Crazyflie Nano Quadcopter
dominik.natter
Beginner
Posts: 17
Joined: Tue Jun 01, 2021 6:38 am

Experiencing apparently solved problems with SD deck

Post by dominik.natter »

Hi guys,

I'm currently getting my feet wet with logging using the SD deck. Unfortunately, I experience issues that apparently have been solved before. This post tries to outline these issues. Maybe we find out that they are not solved, or that the behavior points to other errors (or a faulty setup on my side). Sorry for creating yet another post on SD deck problems, but I didn't find a specific post where it'd be best to chime in.

I have a Crazyflie 2.1 flashed with the newest firmware (2022.01). The SD card is some multiple year old 16 GB Samsung EVO formatted with FAT32 (I currently have no information about its writing speed).

I report tests in these four conditions:

Code: Select all

                       | all decks mounted  | only SD deck mounted
-------------------------------------------------------------------
fixed frequency logs   | test #1            | test #4
event-based logs       | test #2            | test #3
"all decks" means: SD deck, multiranger deck, flow deck, UWB deck.

For experiments with fixed frequency, this is the log config file:

Code: Select all

1     # version
2048   # buffer size in bytes
sd_log   # file name
0     # enable on startup (0/1)
on:fixedFrequency
100     # frequency
1     # mode (0: disabled, 1: synchronous stabilizer, 2: asynchronous)
# IMU
acc.x
acc.y
acc.z
gyro.x
gyro.y
gyro.z
For experiments with event-based logging, this is the log config file:

Code: Select all

1     # version
2048  # buffer size in bytes
sd_log   # file name
0     # enable on startup (0/1)
on:estGyroscope
gyro.x
gyro.y
gyro.z
on:estAcceleration
acc.x
acc.y
acc.z
For each experiment, the procedure looks like this:
* adapt log config file on sd card to fit the desired conditions
* mount or unmount decks to fit the desired conditions
* insert sd card into Crazyflie
* start Crazyflie
* connect to Crazyflie via cfclient
* set parameter usd.logging to 1 to start logging
* wait a bit to collect data
* set parameter usd.logging to 0 to stop logging
* turn off Crazyflie
* store console output for reporting in the forum
* copy resulting log from sd card for reporting in the forum

Here are the console outputs for the four experiments:
Test 1: all decks, fixed frequency

Code: Select all

SYS: Crazyflie 2.1 is up and running!
SYS: Build 0:31573f2fd1d5 (2022.01) CLEAN
SYS: I am 0x20303743575350170023001F and I have 1024KB of flash!
CFGBLK: v1, verification [OK]
DECK_CORE: 4 deck(s) found
DECK_CORE: Calling INIT on driver bcUSD for deck 0
uSD: mount SD-Card [OK].
DECK_CORE: Calling INIT on driver bcMultiranger for deck 1
uSD: wait for sensors
DECK_CORE: Calling INIT on driver bcFlow2 for deck 2
ZR2: Z-down sensor [OK]
PMW: Motion chip id: 0x49:0xB6
DECK_CORE: Calling INIT on driver bcDWM1000 for deck 3
IMU: BMI088: Using I2C interface.
IMU: BMI088 Gyro connection [OK].
IMU: BMI088 Accel connection [OK]
IMU: BMP388 I2C connection [OK]
ESTIMATOR: Using Kalman (2) estimator
CONTROLLER: Using PID (1) controller
MTR-DRV: Using brushed motor driver
SYS: About to run tests in system.c.
EEPROM: I2C connection [OK].
STORAGE: Storage check [OK].
IMU: BMI088 gyro self-test [OK]
DECK_CORE: Deck 0 test [OK].
MR: Init front sensor [OK]
MR: Init back sensor [OK]
MR: Init up sensor [OK]
MR: Init left sensor [OK]
MR: Init right sensor [OK]
DECK_CORE: Deck 1 test [OK].
DECK_CORE: Deck 2 test [OK].
DECK_CORE: Deck 3 test [OK].
SYS: Self test passed!
STAB: Wait for sensor calibration...
SYS: Free heap: 11840 bytes
STAB: Ready to fly.
uSD: Config read [OK].
uSD: malloc buffer 2048 bytes uSD: [OK].
uSD: Logging to: sd_log15
uSD: Wrote 28588 B to: sd_log15 (2856 of 2856 events)

Test 2: all decks, event-based

Code: Select all

SYS: ----------------------------
SYS: Crazyflie 2.1 is up and running!
SYS: Build 0:31573f2fd1d5 (2022.01) CLEAN
SYS: I am 0x20303743575350170023001F and I have 1024KB of flash!
CFGBLK: v1, verification [OK]
DECK_CORE: 4 deck(s) found
DECK_CORE: Calling INIT on driver bcUSD for deck 0
uSD: mount SD-Card [OK].
DECK_CORE: Calling INIT on driver bcMultiranger for deck 1
uSD: wait for sensors
DECK_CORE: Calling INIT on driver bcFlow2 for deck 2
ZR2: Z-down sensor [OK]
PMW: Motion chip id: 0x49:0xB6
DECK_CORE: Calling INIT on driver bcDWM1000 for deck 3
IMU: BMI088: Using I2C interface.
IMU: BMI088 Gyro connection [OK].
IMU: BMI088 Accel connection [OK]
IMU: BMP388 I2C connection [OK]
ESTIMATOR: Using Kalman (2) estimator
CONTROLLER: Using PID (1) controller
MTR-DRV: Using brushed motor driver
SYS: About to run tests in system.c.
EEPROM: I2C connection [OK].
STORAGE: Storage check [OK].
IMU: BMI088 gyro self-test [OK]
DECK_CORE: Deck 0 test [OK].
MR: Init front sensor [OK]
MR: Init back sensor [OK]
MR: Init up sensor [OK]
MR: Init left sensor [OK]
MR: Init right sensor [OK]
DECK_CORE: Deck 1 test [OK].
DECK_CORE: Deck 2 test [OK].
DECK_CORE: Deck 3 test [OK].
SYS: Self test passed!
STAB: Wait for sensor calibration...
SYS: Free heap: 11840 bytes
STAB: Ready to fly.
uSD: Config read [OK].
uSD: malloc buffer 2048 bytes uSD: [OK].
uSD: Logging to: sd_log16
SYS: ----------------------------
SYS: Crazyflie 2.1 is up and running!
SYS: Build 0:31573f2fd1d5 (2022.01) CLEAN
ash!
CFGBLK: v1, verification [OK]
OW: Cmd 0x22 timeout.
DECK_INFO: Reading deck nr:0 [FAILED]. No driver will be initialized!
OW: Cmd 0x22 timeout.
DECK_INFO: Reading deck nr:1 [FAILED]. No driver will be initialized!
DECK_CORE: 0 deck(s) found
IMU: BMI088: Using I2C interface.
IMU: BMI088 Gyro connection [OK].
IMU: BMI088 Accel connection [OK]
IMU: BMP388 I2C connection [OK]
ESTIMATOR: Using Complementary (1) estimator
CONTROLLER: Using PID (1) controller
MTR-DRV: Using brushed motor driver
SYS: About to run tests in system.c.
EEPROM: I2C connection [OK].
STORAGE: Storage check [OK].
IMU: BMI088 gyro self-test [OK]
SYS: The system resumed after a failed assert [WARNING]
SYS: Assert failed at .//src/deck/drivers/src/usddeck.c:795
SYS: cfAssertNormalStart [FAIL]


Test 3: only SD deck, event-based

Code: Select all

SYS: ----------------------------
SYS: Crazyflie 2.1 is up and running!
SYS: Build 0:31573f2fd1d5 (2022.01) CLEAN
SYS: I am 0x20303743575350170023001F and I have 1024KB of flash!
CFGBLK: v1, verification [OK]
DECK_CORE: 1 deck(s) found
DECK_CORE: Calling INIT on driver bcUSD for deck 0
uSD: mount SD-Card [OK].
IMU: BMI088: Using I2C interface.
uSD: wait for sensors
IMU: BMI088 Gyro connection [OK].
IMU: BMI088 Accel connection [OK]
IMU: BMP388 I2C connection [OK]
ESTIMATOR: Using Complementary (1) estimator
CONTROLLER: Using PID (1) controller
MTR-DRV: Using brushed motor driver
SYS: About to run tests in system.c.
EEPROM: I2C connection [OK].
STORAGE: Storage check [OK].
IMU: BMI088 gyro self-test [OK]
DECK_CORE: Deck 0 test [OK].
SYS: Self test passed!
STAB: Wait for sensor calibration...
SYS: Free heap: 18712 bytes
STAB: Ready to fly.
uSD: Config read [OK].
uSD: malloc buffer 2048 bytes uSD: [OK].
uSD: Logging to: sd_log17
uSD: Wrote 770367 B to: sd_log17 (35012 of 38622 events)

Test 4: only SD deck, fixed frequency

Code: Select all

SYS: ----------------------------
SYS: Crazyflie 2.1 is up and running!
SYS: Build 0:31573f2fd1d5 (2022.01) CLEAN
SYS: I am 0x20303743575350170023001F and I have 1024KB of flash!
CFGBLK: v1, verification [OK]
DECK_CORE: 1 deck(s) found
DECK_CORE: Calling INIT on driver bcUSD for deck 0
uSD: mount SD-Card [OK].
IMU: BMI088: Using I2C interface.
uSD: wait for sensors
IMU: BMI088 Gyro connection [OK].
IMU: BMI088 Accel connection [OK]
IMU: BMP388 I2C connection [OK]
ESTIMATOR: Using Complementary (1) estimator
CONTROLLER: Using PID (1) controller
MTR-DRV: Using brushed motor driver
SYS: About to run tests in system.c.
EEPROM: I2C connection [OK].
STORAGE: Storage check [OK].
IMU: BMI088 gyro self-test [OK]
DECK_CORE: Deck 0 test [OK].
SYS: Self test passed!
STAB: Wait for sensor calibration...
SYS: Free heap: 18712 bytes
STAB: Ready to fly.
uSD: Config read [OK].
uSD: malloc buffer 2048 bytes uSD: [OK].
uSD: Logging to: sd_log18
uSD: Wrote 22008 B to: sd_log18 (2198 of 2198 events)
Here are the corresponding log files:
test 1: sd_log15
test 2: The file on my PC has 0 Byte, but upon uploading the forum says "Error: file too large". Sorry for that.
test 3: sd_log17
test 4: sd_log18
Note: I had to add .txt in order to upload it to the forum, but these are actually binaries without file extension):

Summary of the results

Code: Select all

                       | all decks mounted             | only SD deck mounted
------------------------------------------------------------------------------------------------------
fixed frequency logs   | only some timestamps logged   | only some timestamps logged
event-based logs       | assert error                  | works
My notes on the results:
When using event-based logs with only the SD deck (test 3) it works well. This is good to know as a baseline (aka the SD card works, the Crazyflie works etc.). However, I am mostly interested in logging UWB and flow values, so it's not enough in my case.
With fixed frequency (tests 1 and 4) I only receive timestamps in the logs irrespective of the amount of decks. I've reported this initially in this issue, but thought I'll collect it into this analysis too. The logs are considerably smaller than the functioning log from test 3. Thus I think it's not simply a problem with reading the log incorrectly, but rather actually a writing problem.
When using event-based logs and all decks mounted (test 2), I receive an assert error. Such errors have been reported previously both in this issue and in this issue. In both cases, the errors were solved with a pull request. Unfortunately, that is not true for me here.

Just as a side note: Before updating to the newest firmware I had a Build 68:308ceb323945 (2021.06 +68) flashed on the Crazyflie. In this configuration and for test 2 (event-based logs, all decks mounted), a log file was created (console output said "uSD: Logging to: log09") but in that very moment the red LED stopped. Also, it was not possible to deactivate logging via the cfclient. The parameter value would always stay at 1 and became highlighted in red. When checking the file on the SD card, it was empty. This might not be relevant here, as it could be a bug that was solved by moving to 2022.01. However, it could be relevant because at least the assert error was not present at this stage (or the code just failed before reaching the assert call).

I hope my exhaustive report allows us to figure out what the problem(s) is (are). Hopefully, it's just a stupid mistake somewhere on my side :)
Attachments
sd_log18.txt
(21.49 KiB) Downloaded 266 times
sd_log17.txt
(752.31 KiB) Downloaded 248 times
sd_log15.txt
(27.92 KiB) Downloaded 264 times
tobias
Bitcraze
Posts: 2339
Joined: Mon Jan 28, 2013 7:17 pm
Location: Sweden

Re: Experiencing apparently solved problems with SD deck

Post by tobias »

Big thanks for doing this extensive testing!

The sd-logging is a bit challenging as it is resource limited and when getting close to the limit strange things start to happen. Best would be if it didn't but we are not there yet. By resources I mean mainly CPU time and SPI bus time. As both UWB and flow deck use the same bus this limits the amount of logging a lot. Especially if running UWB - TWR which is very chatty on the SPI bus.

Test #1 & Test #3
Some SD-cards take longer to write down data, which it does in chunks. Do you have another SD-card to try with. You could also try and increase the buffer size as much as possible as it helps for slow sd-cards.

Test #2
I suspect this is a boot-up order bug. The usd module is probably not initialized/started before it gets an event or similar.
dominik.natter
Beginner
Posts: 17
Joined: Tue Jun 01, 2021 6:38 am

Re: Experiencing apparently solved problems with SD deck

Post by dominik.natter »

Hi Tobias,

yeah I've read about such limitations. However, given that many GitHub issues were marked as solved and your docs only say "In some cases, it might be beneficial to use another SPI bus" I expected these problems to be rather rare and hence the SD deck easily usable together with the flow and UWB deck (at least when logging rates and amount of variables are not pushed to the max).

About your suggestions (btw I guess you meant Test #1 and #4, not #3. Sorry for the potentially confusing number choice):
In fact I bought a brand new 32 GB Class 10 Philips SD card in order to avoid problems of too slow SD cards (following your suggestion here). However, I only got a "uSD: mount SD-Card [FAIL]." in the console when using this card. The only relevant issue for that I've found is here, where the solution is to format it correctly. Unfortunately, I think my new SD card is formatted in the exact same way as my old one (as suggested by the enclosed screenshots). Maybe you have another suggestion to that.

In the mean time I will try to a) perform tests with the old SD card and a higher buffer size, and b) find a third SD card to test with that one too. For a) I wonder though: shouldn't the SD card be able to write at least some values after the logging has been stopped via the parameter? It's not that I unplugged the battery while logging or similar, so this explanation does not fully resonate with me.
Attachments
sd_card_settings_samsung_old.png
sd_card_settings_philips_new.png
tobias
Bitcraze
Posts: 2339
Joined: Mon Jan 28, 2013 7:17 pm
Location: Sweden

Re: Experiencing apparently solved problems with SD deck

Post by tobias »

There might be bugs still but in general the logging should work.

I did some tests (#1 and #2) with 2022.01_rc1 and it worked well for me. I used a Kingston 32GB Class 10 A1 (Canvas select plus). I wonder what the difference for me is, and also why your SD-card doesn't work...
sdcard-format.png
sdcard_format.png
You can check the uSD write rates using the usd log variables. Maybe that will tell us something. Below are mine from my two tests:
Test #1
usd-write-rate.png
sd_log00.bin
(69.88 KiB) Downloaded 274 times
Test #2
usd-write-event.png
sd_log01.bin
(433.44 KiB) Downloaded 259 times
How was your UWB system setup when you ran the tests?
dominik.natter
Beginner
Posts: 17
Joined: Tue Jun 01, 2021 6:38 am

Re: Experiencing apparently solved problems with SD deck

Post by dominik.natter »

Hei Tobias,

thanks for doing those tests! Also good to learn about the logging variables (I could have thought about that myself, sorry).

Interesting that your SD card works. Luckily, I've found a third SD card in our office (a Transcend UHS-I microSD 300S, 16 GB, up to 95 MB/s), which seems to work somewhat better. Let's look at details.
All the reports following here use this new SD card. Regarding my UWB setup: I have just mounted the SD deck on the Crazyflie, but no anchors in use. Just like you I too re-performed tests #1 (fixed frequency, all decks) and #2 (event based, all decks). This time I have increased the buffer size to 8192 bytes.

Console output for test #1:

Code: Select all

SYS: ----------------------------
SYS: Crazyflie 2.1 is up and running!
SYS: Build 0:31573f2fd1d5 (2022.01) CLEAN
SYS: I am 0x20303743575350170023001F and I have 1024KB of flash!
CFGBLK: v1, verification [OK]
DECK_CORE: 4 deck(s) found
DECK_CORE: Calling INIT on driver bcUSD for deck 0
uSD: mount SD-Card [OK].
DECK_CORE: Calling INIT on driver bcMultiranger for deck 1
uSD: wait for sensors
DECK_CORE: Calling INIT on driver bcFlow2 for deck 2
ZR2: Z-down sensor [OK]
PMW: Motion chip id: 0x49:0xB6
DECK_CORE: Calling INIT on driver bcDWM1000 for deck 3
IMU: BMI088: Using I2C interface.
IMU: BMI088 Gyro connection [OK].
IMU: BMI088 Accel connection [OK]
IMU: BMP388 I2C connection [OK]
ESTIMATOR: Using Kalman (2) estimator
CONTROLLER: Using PID (1) controller
MTR-DRV: Using brushed motor driver
SYS: About to run tests in system.c.
EEPROM: I2C connection [OK].
STORAGE: Storage check [OK].
IMU: BMI088 gyro self-test [OK]
DECK_CORE: Deck 0 test [OK].
MR: Init front sensor [OK]
MR: Init back sensor [OK]
MR: Init up sensor [OK]
MR: Init left sensor [OK]
MR: Init right sensor [OK]
DECK_CORE: Deck 1 test [OK].
DECK_CORE: Deck 2 test [OK].
DECK_CORE: Deck 3 test [OK].
SYS: Self test passed!
STAB: Wait for sensor calibration...
SYS: Free heap: 11840 bytes
STAB: Ready to fly.
uSD: Config read [OK].
uSD: malloc buffer 8192 bytes uSD: [OK].
uSD: Logging to: sd_log08
uSD: Wrote 47028 B to: sd_log08 (4700 of 4700 events)
Screenshot of logging variables for test #1:
log_vars_fixed-frequency_all_decks.png
Resulting log file for test #1:
sd_log08.bin
(45.93 KiB) Downloaded 239 times

Console output for test #2:

Code: Select all

SYS: ----------------------------
SYS: Crazyflie 2.1 is up and running!
SYS: Build 0:31573f2fd1d5 (2022.01) CLEAN
SYS: I am 0x20303743575350170023001F and I have 1024KB of flash!
CFGBLK: v1, verification [OK]
DECK_CORE: 4 deck(s) found
DECK_CORE: Calling INIT on driver bcUSD for deck 0
uSD: mount SD-Card [OK].
DECK_CORE: Calling INIT on driver bcMultiranger for deck 1
uSD: wait for sensors
DECK_CORE: Calling INIT on driver bcFlow2 for deck 2
ZR2: Z-down sensor [OK]
PMW: Motion chip id: 0x49:0xB6
DECK_CORE: Calling INIT on driver bcDWM1000 for deck 3
IMU: BMI088: Using I2C interface.
IMU: BMI088 Gyro connection [OK].
IMU: BMI088 Accel connection [OK]
IMU: BMP388 I2C connection [OK]
ESTIMATOR: Using Kalman (2) estimator
CONTROLLER: Using PID (1) controller
MTR-DRV: Using brushed motor driver
SYS: About to run tests in system.c.
EEPROM: I2C connection [OK].
STORAGE: Storage check [OK].
IMU: BMI088 gyro self-test [OK]
DECK_CORE: Deck 0 test [OK].
MR: Init front sensor [OK]
MR: Init back sensor [OK]
MR: Init up sensor [OK]
MR: Init left sensor [OK]
MR: Init right sensor [OK]
DECK_CORE: Deck 1 test [OK].
DECK_CORE: Deck 2 test [OK].
DECK_CORE: Deck 3 test [OK].
SYS: Self test passed!
STAB: Wait for sensor calibration...
SYS: Free heap: 11840 bytes
STAB: Ready to fly.
uSD: Config read [OK].
uSD: malloc buffer 8192 bytes uSD: [OK].
uSD: Logging to: sd_log07
uSD: Wrote 1241431 B to: sd_log07 (56424 of 56424 events)
Screenshot of logging variables for test #2:
log_vars_event-based_all_decks.png
Resulting log file for test #2:
The file was too large to be uploaded (1.2 MB).

My observation / assessment:
Fixed frequency still only logs timestamps, despite switching SD card and increasing buffer size.
Isn't this the case for you too? Your writing rates do not look tremendously higher. And when I analyze your log with cfusdlog.py the output is:

Code: Select all

{'fixedFrequency': {'timestamp': array([140742.056, 140751.972, 140761.9  , ..., 211669.776, 211679.695,
       211689.619])}}
which I interpret as "only timestamps logged". Please correct me if this interpretation is wrong (aka my fixed frequency logs have been working all the time).
About your statement in a previous post on "some SD cards write in batches": In my console output for test #1 the log output is:

Code: Select all

uSD: malloc buffer 8192 bytes uSD: [OK].
uSD: Logging to: sd_log08
uSD: Wrote 47028 B to: sd_log08 (4700 of 4700 events)
So the data being written in total is larger than the buffer. Doesn't that contradict your theory of batch-writing being the problem? Or is the needed buffer size visible in the log plots (in your case it spikes up to ~6500 bytes)? Maybe I lack some knowledge here, just raising a hypothesis.

I could live without fixed frequency working, if event-based logging worked reliably.
Indeed, the log I've shown here worked. However, sometimes again assert errors show up. This is not necessarily when logging is started, but can happen some time later (maybe some seconds, maybe some dozen seconds). I've seen this both for buffer sizes of 2048 and 8192 bytes.

Here's exemplary console output for 2048 bytes

Code: Select all

SYS: ----------------------------
SYS: Crazyflie 2.1 is up and running!
SYS: Build 0:31573f2fd1d5 (2022.01) CLEAN
SYS: I am 0x20303743575350170023001F and I have 1024KB of flash!
CFGBLK: v1, verification [OK]
DECK_CORE: 4 deck(s) found
DECK_CORE: Calling INIT on driver bcUSD for deck 0
uSD: mount SD-Card [OK].
DECK_CORE: Calling INIT on driver bcMultiranger for deck 1
uSD: wait for sensors
DECK_CORE: Calling INIT on driver bcFlow2 for deck 2
ZR2: Z-down sensor [OK]
PMW: Motion chip id: 0x49:0xB6
DECK_CORE: Calling INIT on driver bcDWM1000 for deck 3
IMU: BMI088: Using I2C interface.
IMU: BMI088 Gyro connection [OK].
IMU: BMI088 Accel connection [OK]
IMU: BMP388 I2C connection [OK]
ESTIMATOR: Using Kalman (2) estimator
CONTROLLER: Using PID (1) controller
MTR-DRV: Using brushed motor driver
SYS: About to run tests in system.c.
EEPROM: I2C connection [OK].
STORAGE: Storage check [OK].
IMU: BMI088 gyro self-test [OK]
DECK_CORE: Deck 0 test [OK].
MR: Init front sensor [OK]
MR: Init back sensor [OK]
MR: Init up sensor [OK]
MR: Init left sensor [OK]
MR: Init right sensor [OK]
DECK_CORE: Deck 1 test [OK].
DECK_CORE: Deck 2 test [OK].
DECK_CORE: Deck 3 test [OK].
SYS: Self test passed!
STAB: Wait for sensor calibration...
SYS: Free heap: 11840 bytes
STAB: Ready to fly.
uSD: Config read [OK].
uSD: malloc buffer 2048 bytes uSD: [OK].
ESTKALMAN: State out of bounds, resetting
uSD: Logging to: sd_log05
SYS: ----------------------------
SYS: Crazyflie 2.1 is up and running!
SYS: Build 0:31573f2fd1d5 (2022.01) CLEAN
ash!
CFGBLK: v1, verification [OK]
DECK_CORE: 4 deck(s) found
DECK_CORE: Calling INIT on driver bcUSD for deck 0
uSD: mount SD-Card [OK].
DECK_CORE: Calling INIT on driver bcMultiranger for deck 1
uSD: wait for sensors
DECK_CORE: Calling INIT on driver bcFlow2 for deck 2
ZR2: Z-down sensor [OK]
PMW: Motion chip id: 0x49:0xB6
SYS: ----------------------------
SYS: Crazyflie 2.1 is up and running!
SYS: Build 0:31573f2fd1d5 (2022.01) CLEAN
ash!
CFGBLK: v1, verification [OK]
OW: Cmd 0x22 timeout.
DECK_INFO: Reading deck nr:0 [FAILED]. No driver will be initialized!
OW: Cmd 0x22 timeout.
DECK_INFO: Reading deck nr:1 [FAILED]. No driver will be initialized!
DECK_CORE: 0 deck(s) found
IMU: BMI088: Using I2C interface.
IMU: BMI088 Gyro connection [OK].
IMU: BMI088 Accel connection [OK]
IMU: BMP388 I2C connection [OK]
ESTIMATOR: Using Complementary (1) estimator
CONTROLLER: Using PID (1) controller
MTR-DRV: Using brushed motor driver
SYS: About to run tests in system.c.
EEPROM: I2C connection [OK].
STORAGE: Storage check [OK].
IMU: BMI088 gyro self-test [OK]
SYS: The system resumed after a failed assert [WARNING]
SYS: Assert failed at .//src/hal/src/radiolink.c:164
SYS: cfAssertNormalStart [FAIL]
... and 8192 bytes:

Code: Select all

SYS: ----------------------------
SYS: Crazyflie 2.1 is up and running!
SYS: Build 0:31573f2fd1d5 (2022.01) CLEAN
SYS: I am 0x20303743575350170023001F and I have 1024KB of flash!
CFGBLK: v1, verification [OK]
DECK_CORE: 4 deck(s) found
DECK_CORE: Calling INIT on driver bcUSD for deck 0
uSD: mount SD-Card [OK].
DECK_CORE: Calling INIT on driver bcMultiranger for deck 1
uSD: wait for sensors
DECK_CORE: Calling INIT on driver bcFlow2 for deck 2
ZR2: Z-down sensor [OK]
PMW: Motion chip id: 0x49:0xB6
DECK_CORE: Calling INIT on driver bcDWM1000 for deck 3
IMU: BMI088: Using I2C interface.
IMU: BMI088 Gyro connection [OK].
IMU: BMI088 Accel connection [OK]
IMU: BMP388 I2C connection [OK]
ESTIMATOR: Using Kalman (2) estimator
CONTROLLER: Using PID (1) controller
MTR-DRV: Using brushed motor driver
SYS: About to run tests in system.c.
EEPROM: I2C connection [OK].
STORAGE: Storage check [OK].
IMU: BMI088 gyro self-test [OK]
DECK_CORE: Deck 0 test [OK].
MR: Init front sensor [OK]
MR: Init back sensor [OK]
MR: Init up sensor [OK]
MR: Init left sensor [OK]
MR: Init right sensor [OK]
DECK_CORE: Deck 1 test [OK].
DECK_CORE: Deck 2 test [OK].
DECK_CORE: Deck 3 test [OK].
SYS: Self test passed!
STAB: Wait for sensor calibration...
SYS: Free heap: 11840 bytes
STAB: Ready to fly.
uSD: Config read [OK].
uSD: malloc buffer 8192 bytes uSD: [OK].
uSD: Logging to: sd_log06
SYS: ----------------------------
SYS: Crazyflie 2.1 is up and running!
SYS: Build 0:31573f2fd1d5 (2022.01) CLEAN
ash!
CFGBLK: v1, verification [OK]
OW: Cmd 0x22 timeout.
DECK_INFO: Reading deck nr:0 [FAILED]. No driver will be initialized!
OW: Cmd 0x22 timeout.
DECK_INFO: Reading deck nr:1 [FAILED]. No driver will be initialized!
DECK_CORE: 0 deck(s) found
IMU: BMI088: Using I2C interface.
IMU: BMI088 Gyro connection [OK].
IMU: BMI088 Accel connection [OK]
IMU: BMP388 I2C connection [OK]
ESTIMATOR: Using Complementary (1) estimator
CONTROLLER: Using PID (1) controller
MTR-DRV: Using brushed motor driver
SYS: About to run tests in system.c.
EEPROM: I2C connection [OK].
STORAGE: Storage check [OK].
IMU: BMI088 gyro self-test [OK]
SYS: The system resumed after a failed assert [WARNING]
SYS: Assert failed at .//src/deck/drivers/src/usddeck.c:795
SYS: cfAssertNormalStart [FAIL]
Overall, it seems a bit more promising now. So maybe switching the SD card helped, maybe it was the buffer size. If I find time, I will do more tests for event-based logging with this new SD card and 8192 bytes buffer size (e.g., log more stuff than just IMU data to see the limits of the system, or log with smaller buffer size to see whether changing the SD card alone was enough). For fixed frequency I currently don't know what to test.
Maybe in the mean time you have some good realizations too :)
tobias
Bitcraze
Posts: 2339
Joined: Mon Jan 28, 2013 7:17 pm
Location: Sweden

Re: Experiencing apparently solved problems with SD deck

Post by tobias »

Hi Dominik,

I missed the fact that the fixed frequency test did not write down any log variable data. I debugged it and it turns out that our parser is not that robust and can't handle a fully commented line. So the "# IMU" in the fixed frequency test get interpreted as there are no variables to log. If you remove that line it should work much better.

I suggest we update the github issue and either improve the parser or the documentation.

When I talked about batch writing I was referring to when the SD card writes data to flash from it's buffer. When this happens it does not accept new data and the Crazyflie buffer fills up. This should be reported by the written events after logging is stopped.

The problem that the Crazyflie asserts is of course not good and would be nice to fix. My guess is that it is because CPU utilization gets to high and things that need to run doesn't get time.
dominik.natter
Beginner
Posts: 17
Joined: Tue Jun 01, 2021 6:38 am

Re: Experiencing apparently solved problems with SD deck

Post by dominik.natter »

Hi Tobias,

thanks for debugging. Indeed, without the "# IMU" it works. For the sake of completeness (and future people uncertain about what a log should look like) I add the working example here too.

Test #1 (fixed frequency, all decks).
Used log config:

Code: Select all

1     # version
8192   # buffer size in bytes
sd_log   # file name
0     # enable on startup (0/1)
on:fixedFrequency
100     # frequency
1     # mode (0: disabled, 1: synchronous stabilizer, 2: asynchronous)
acc.x
acc.y
acc.z
gyro.x
gyro.y
gyro.z
Resulting console output:

Code: Select all

SYS: ----------------------------
SYS: Crazyflie 2.1 is up and running!
SYS: Build 0:31573f2fd1d5 (2022.01) CLEAN
SYS: I am 0x20303743575350170023001F and I have 1024KB of flash!
CFGBLK: v1, verification [OK]
DECK_CORE: 4 deck(s) found
DECK_CORE: Calling INIT on driver bcUSD for deck 0
uSD: mount SD-Card [OK].
DECK_CORE: Calling INIT on driver bcMultiranger for deck 1
uSD: wait for sensors
DECK_CORE: Calling INIT on driver bcFlow2 for deck 2
ZR2: Z-down sensor [OK]
PMW: Motion chip id: 0x49:0xB6
DECK_CORE: Calling INIT on driver bcDWM1000 for deck 3
IMU: BMI088: Using I2C interface.
IMU: BMI088 Gyro connection [OK].
IMU: BMI088 Accel connection [OK]
IMU: BMP388 I2C connection [OK]
ESTIMATOR: Using Kalman (2) estimator
CONTROLLER: Using PID (1) controller
MTR-DRV: Using brushed motor driver
SYS: About to run tests in system.c.
EEPROM: I2C connection [OK].
STORAGE: Storage check [OK].
IMU: BMI088 gyro self-test [OK]
DECK_CORE: Deck 0 test [OK].
MR: Init front sensor [OK]
MR: Init back sensor [OK]
MR: Init up sensor [OK]
MR: Init left sensor [OK]
MR: Init right sensor [OK]
DECK_CORE: Deck 1 test [OK].
DECK_CORE: Deck 2 test [OK].
DECK_CORE: Deck 3 test [OK].
SYS: Self test passed!
STAB: Wait for sensor calibration...
SYS: Free heap: 11840 bytes
STAB: Ready to fly.
uSD: Config read [OK].
uSD: malloc buffer 8192 bytes uSD: [OK].
uSD: Logging to: sd_log09
uSD: Wrote 75395 B to: sd_log09 (2215 of 2215 events)
Resulting log file:
sd_log09.bin
(73.63 KiB) Downloaded 259 times

Thanks for the clarification on the batch writing. As expected, I don't have full overview over the technical details here.

Seems like I move forward with fixed frequency logs then. If I may, can I ask 2 questions to be sure?
1. In fixed frequency values for every variable specified in the log config will be logged at this rate, even if, e.g., a particular sensor does not measure new values at such a high rate? (Example: fixed frequency 1000 Hz, IMU samples at 1000 Hz while multiranger only samples at 100 Hz. Will it log an individual IMU value for each timestamp and 10 of the same multiranger values between new multiranger measurements?).
2. for large config files I get "uSD: Skip log variable fixedFrequency: motion.Rawsum (out of storage)" in the console output. Is there any way to calculate the resulting storage of a config file and find out the max storage in beforehand, or do I have to use trial and error to find config files that fit my Crazyflie?

Thanks a lot for your help. It's great to see how actively this forum is supervised!
tobias
Bitcraze
Posts: 2339
Joined: Mon Jan 28, 2013 7:17 pm
Location: Sweden

Re: Experiencing apparently solved problems with SD deck

Post by tobias »

I'm glad it works much better but I pretty sure you will hit more bugs when you stress things. Let us know if so.

About your questions:
1. Yes that is correct. Fixed frequency is simpler. For events, code has to be added, but you will get each event at the right rate.
2. I think the limit is 20 variables. We don't really know the limit as it changes from case to case but you could increase it in the code if you want to test.
dominik.natter
Beginner
Posts: 17
Joined: Tue Jun 01, 2021 6:38 am

Re: Experiencing apparently solved problems with SD deck

Post by dominik.natter »

Hi Tobias,

yes, I will keep you updated in case of undesirable events - thanks for that.

Cool, thanks for that input!
dominik.natter
Beginner
Posts: 17
Joined: Tue Jun 01, 2021 6:38 am

Re: Experiencing apparently solved problems with SD deck

Post by dominik.natter »

Hei,

I'm using the SD deck now on a daily basis in fixedFrequency mode and it works quite well. However, I've noted that assert() errors also arise during fixedFrequency mode (while this issue so far only observed them in event-based mode). Your suggestion was "My guess is that it is because CPU utilization gets to high and things that need to run doesn't get time.". Indeed, given that it happens with both modes, it might just be a too crowded CPU. I've seen this post about CPU analysis. I wanted to give that a try, but for now the respective button is greyed out. I'll ask in the other post for clarification on that.

Just wanted to give u a heads up here, as you asked for updates in case of (un)desirable events.

Best,
Dominik
Post Reply