ArduPilot / ArduPilot/MAVProxy
Mysterious FC performance penalty on MAVLink streaming
- Dominant language
- Python
- Stars
- 595
- Forks
- 773
- Avg merge
- 2d 6h
- Merged PRs (30d)
- 18
Description
MAVProxy is doing something that is causing flight controller performance slowdowns. It seems to be caused by MAVLink streaming.
I have a system with a Cube Black connected via serial UART to a TX1 running MAVProxy.
This is typical performance on one of my drones in Loiter while inactive (using `sched_debug 1`):
```
LOITER> APM: PERF: 42/4000 max=3655 min=2209 F=2521 sd=81
APM: PERF: 43/4000 max=3757 min=2203 F=2527 sd=86
```
Current streamrate settings:
```
SR0_ADSB 0.000000
SR0_EXTRA1 0.000000
SR0_EXTRA2 0.000000
SR0_EXTRA3 0.000000
SR0_EXT_STAT 0.000000
SR0_PARAMS 0.000000
SR0_POSITION 0.000000
SR0_RAW_CTRL 0.000000
SR0_RAW_SENS 0.000000
SR0_RC_CHAN 0.000000
SR1_ADSB 0.000000
SR1_EXTRA1 4.000000
SR1_EXTRA2 4.000000
SR1_EXTRA3 4.000000
SR1_EXT_STAT 4.000000
SR1_PARAMS 10.000000
SR1_POSITION 4.000000
SR1_RAW_CTRL 4.000000
SR1_RAW_SENS 4.000000
SR1_RC_CHAN 4.000000
SR2_ADSB 0.000000
SR2_EXTRA1 0.000000
SR2_EXTRA2 0.000000
SR2_EXTRA3 0.000000
SR2_EXT_STAT 0.000000
SR2_PARAMS 0.000000
SR2_POSITION 0.000000
SR2_RAW_CTRL 0.000000
SR2_RAW_SENS 0.000000
SR2_RC_CHAN 0.000000
SR3_ADSB 0.000000
SR3_EXTRA1 0.000000
SR3_EXTRA2 0.000000
SR3_EXTRA3 0.000000
SR3_EXT_STAT 0.000000
SR3_PARAMS 0.000000
SR3_POSITION 0.000000
SR3_RAW_CTRL 0.000000
SR3_RAW_SENS 0.000000
SR3_RC_CHAN 0.000000
APM: PERF: 40/4000 max=3640 min=2202 F=2517 sd=79
APM: PERF: 42/4000 max=3747 min=2188 F=2521 sd=84
APM: PERF: 43/4000 max=3647 min=2207 F=2523 sd=85
APM: PERF: 44/4000 max=3701 min=2221 F=2522 sd=87
APM: PERF: 41/4000 max=3728 min=2206 F=2519 sd=84
APM: PERF: 42/4000 max=3573 min=2165 F=2525 sd=78
```
As you can see, I set most streamrates to 0 except serial1 which are 4Hz, MAVProxy default. Performance is steady at ~40 loop overruns.
Just to make a point, set SR1 params to existing values
```
LOITER> param set SR1_EXTRA1 4.000000
LOITER> param set SR1_EXTRA2 4.000000
LOITER> param set SR1_EXTRA3 4.000000
LOITER> param set SR1_EXT_STAT 4.000000
LOITER> param set SR1_PARAMS 10.000000
LOITER> param set SR1_POSITION 4.000000
LOITER> param set SR1_RAW_CTRL 4.000000
LOITER> param set SR1_RAW_SENS 4.000000
LOITER> param set SR1_RC_CHAN 4.000000
APM: PERF: 44/4000 max=3701 min=2215 F=2524 sd=85
LOITER> APM: PERF: 45/4000 max=3718 min=2215 F=2521 sd=87
APM: PERF: 44/4000 max=3780 min=2235 F=2521 sd=88
APM: PERF: 44/4000 max=3697 min=2198 F=2528 sd=90
```
Performance hasn't changed, of course.
Now set streamrate params to 0
```
LOITER> param set SR1_ADSB 0
LOITER> param set SR1_EXTRA1 0
LOITER> param set SR1_EXTRA2 0
LOITER> param set SR1_EXTRA3 0
LOITER> param set SR1_EXT_STAT 0
LOITER> param set SR1_PARAMS 0
LOITER> param set SR1_POSITION 0
LOITER> param set SR1_RAW_CTRL 0
LOITER> param set SR1_RAW_SENS 0
LOITER> param set SR1_RC_CHAN 0
```
7. Issue `param fetch` to refresh params. Once it's finished, check streamrate params again and observe that some streamrates are reset to 4Hz:
```
LOITER> param set sr1_*
LOITER> SR1_ADSB 0.000000
SR1_EXTRA1 4.000000
SR1_EXTRA2 4.000000
SR1_EXTRA3 4.000000
SR1_EXT_STAT 4.000000
SR1_PARAMS 10.000000
SR1_POSITION 4.000000
SR1_RAW_CTRL 4.000000
SR1_RAW_SENS 4.000000
SR1_RC_CHAN 4.000000
```
Params are exactly the same as they were at the start. Mavproxy is requesting these streams at its default rate.
Performance has improved, even though the params are unchanged!
```
APM: PERF: 1/4000 max=3014 min=2209 F=2513 sd=24
APM: PERF: 0/4000 max=2922 min=2248 F=2512 sd=22
APM: PERF: 1/4000 max=3010 min=2204 F=2513 sd=23
APM: PERF: 1/4000 max=3040 min=2166 F=2513 sd=26
```
*This performance improvement lasts until the FC is rebooted.* Restarting MAVproxy doesn't change anything. I tested this on multiple Cubes and TX1s. Changing the SR params one at a time has incremental performance gains, so they all seem involved.
I am trying to find where this performance hit is coming from. It's apparently related to mavlink streaming - maybe MAVProxy is accidentally requesting a very high stream rate on these messages? I do not specify `set streamrate`, so it defaults to 4.
Contributor guide
No contributing guide indexed for this repository
Research direction
Reproduce the reported behavior with MAVProxy, a Cube Black, and the listed SR1 settings, comparing performance before and after `param fetch` and an FC reboot. Start by tracing MAVProxy's default stream requests and parameter-fetch handling; done means the source of the unexpected stream behavior is identified and the performance difference is explained or corrected.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- python
- Domain
- cli, performance
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 35/100