UAVCAN message corruption on ArduPlane

[JamesStewy]

Issue details

We are experiencing an issue where UAVCAN messages sent from ArduPilot have a very high corruption rate as seen on a Zubax Babel. Exactly why this starts happening is a little unclear however when it starts working incorrectly it does so with a small percentage of messages sent from ArduPilot corrupting and over a period of about 1-10 seconds this rate of corruption increases to nearly every message. Once the message corruption starts we have not found a way to get it to stop apart from a cold reboot. This corruption appears to affect all sent messages from ArduPilot including uavcan.equipment.actuator.ArrayCommand, uavcan.equipment.esc.RawCommand, uavcan.protocol.NodeStatus and uavcan.protocol.GetNodeInfo responses. Corrupted messages appear in the UAVCAN GUI Tool Bus Monitor as messages whose value is not present and replaced with Transfer could not be decoded along with errors such as CRC mismatch: expected xxxx, got xxxx for payload byte, Toggle bit value x incorrect on frame x, or EOT not found.

We have found that this issue does not occur as described above in Manual mode, but testing in Auto, FBWA and RTL has all resulted in corruption occurring. We have also found that the SCHED_LOOP_RATE parameter has a big effect. With SCHED_LOOP_RATE=300 (recommend value for quadplanes), the safety switch in and with constant RC inputs, ArduPilot puts out around 1800 CAN frames per second and will fail normally within a minute (although we have had it take up to a few minutes to fail). The same test but with SCHED_LOOP_RATE=50 results in ArduPilot only outputting around 300 CAN frames per second and it does not fail (we ran multiple tests including one over 40 minutes and everything continued to work). In these tests constant RC inputs are important as the esc/actuator message output rate from ArduPilot appears to be proportional to the amount of ‘activity’ that is occurring.

All our testing to date has been on multiple Pixhawk 2.1s running ArduPlane 3.8.4. To confirm this isn’t an issue with the CAN network we have tested on a network with other UAVCAN devices all of which continue to work even when ArduPilot starts sending corrupted messages. We have also tested ArduPilot alone with just a Babel connected and the corruption still occurs.

Steps to replicate

1. Enable UAVCAN actuator and/or ESC outputs in the parameters.
2. Set SCHED_LOOP_RATE to 300.
3. Set mode to FBWA.
4. Press in safety switch.
5. Provide constant RC inputs until UAVCAN messages start corrupting.

Another Issue

This issue is potentially unrelated but, in our testing, we also found that with UAVCAN enabled it was possible to force ArduPlane into io failsafe due to fmu shutdown by pressing the safety switch too soon after booting. We found that waiting 10 seconds after all the starting noises had completed was enough to mitigate the issue.

Version

ArduPlane 3.8.4

Platform

[ ] All
[ ] AntennaTracker
[ ] Copter
[x] Plane
[ ] Rover
[ ] Submarine

Airframe type

Quadplane

Hardware type

Pixhawk 2.1

[auturgy]

@EShamaev @magicrub

[hdtechk]

If can H and can L wires are not the exact same length the signal from can H and can L will be out of sync and messages will be corrupted. I see this on motorcycles all the time when someone puts tall handlebars on there bikes. Not saying that is your issue. But it's worth mentioning

[pavel-kirienko]

If can H and can L wires are not the exact same length

It has nothing to do with corrupted CAN frames; if that were the case, you wouldn't see anything on the bus monitor in the first place. My bet is that the problem is caused by the TX buffer getting overrun. When that happens, the CAN stack has to triage the outgoing CAN frames, letting higher priority frames out while sacrificing lower priority ones, hence broken transfers. The TX queue is being read by the driver from one end and written by the stack from the other end; apparently the read/write rate difference is such that it takes about a minute for the queue to overrun (judging by the description from @JamesStewy ). I can propose two solutions:

• Increase the priority of the CAN IRQ
• Reduce the TX traffic

[JamesStewy]

apparently the read/write rate difference is such that it takes about a minute for the queue to overrun

This does line up with our experience that their is a cumulative nature to it.

My bet is that the problem is caused by the TX buffer getting overrun

Is there a particular mechanism which would cause this to become a permanent issue? As soon as the issue occurs, even if you back off the data rate, it does not recover until a reboot.

[pavel-kirienko]

Could be that the driver's inner state gets somehow damaged. I think you should get a debugger and make sure that the driver handles queue overrun properly.

[magicrub]

This should be tested on a ChibiOS build. The CPU usage is much lower, I bet the problem goes away. However, if we are hitting the queue limits then it may not matter. Just too much data and the bus is busy.

Question: how many motors is it considered for?

[jschall]

I have seen issues with the UAVCAN GUI tool where it cannot keep up and starts to behave this way. This is due to a pyuavcan bug where the data type signature is computed on every transfer (OpenCyphal/pycyphal#31)

Even after fixing this bug, at very high bus utilization (4000+ frames per second) I've seen the UAVCAN GUI tool start to display node errors. Restarting the GUI tool seems to fix it temporarily.

Let's confirm that this is actually an ardupilot issue.

[JamesStewy]

@pavel-kirienko

get a debugger and make sure that the driver handles queue overrun properly

We can absolutly do this test but what should we be looking out for? How will we know if the driver (I assume that means libuavcan) handles queue overrun successfully?

@magicrub

how many motors is it considered for?

All of our testing was done with 8 outputs including one fixed wing motor and 4 quad motors.

This should be tested on a ChibiOS build.

What versions of ArduPlane should we use to test with ChibiOS?

I bet the problem goes away

We have already seen that the problem goes away if you reduce the data rate (and presumably the CPU load as well at the same time). However, the lingering threat of the CAN side of ardupilot failing terminally worries us.

@jschall

Restarting the GUI tool seems to fix it temporarily

This doesn't line up with our testing. Restarting the GUI tool did not subside the errors even temporarily. It should also be noted that while the issue is occuring, the GUI tool sometimes crashes due to collecting to many CAN errors.

Let's confirm that this is actually an ardupilot issue

We have also tested using a simple board with an ST microcontroller running libuavcan connected on the bus. The board converts the last received uavcan.equipment.actuator.ArrayCommand message into a PWM signal to actuate a servo. When the issue starts occuring you can see the same thing that is suggested by the GUI tool. Only a very small fraction of messages get through intact. This test has been completed with and without a Babel attached to the network and it makes no difference.

However, despite saying all this, when I next get a chance I will run the GUI tool with (OpenCyphal/pycyphal#31) applied and report back if it makes a difference.

[jschall]

What versions of ArduPlane should we use to test with ChibiOS?

Per @magicrub: should just be master, built for fmuv2

[jschall]

Can we get your parameters? We are trying to reproduce your problem.

[JamesStewy]

These parameters cause the issue for us: quadplane - high SCHED_LOOP_RATE.txt

The same parameters but with SCHED_LOOP_RATE lowered to 50: quadplane - low SCHED_LOOP_RATE.txt

[JamesStewy]

Tested using the GUI tool with (OpenCyphal/pycyphal#31) applied and it didn't make a difference.

Also tested using master ardupilot and it ultimately didn't fix the problem. A combination of providing constant transmitter inputs and shaking the pixhawk in FWBA a bit was enough to cause the failure. Over multiple tests it did appear to take longer (maybe 50% longer) to fail.

[JamesStewy]

Completed some more tests.

ArduCopter 3.5.5 and 3.6.0-rc1 both have the same issue (@rmackay9).

Tried ArduPlane 3.7.1 as well as using PX4 but both did not output 'uavcan.equipment.actuator.ArrayCommand' messages which likely reduced the amount of CAN frames enough for the issue to not occur.

Is there anything else that anyone would like to see tested to try to narrow down on the issue?

[magicrub]

just to confirm if it's a bandwdith vs cpu problem, can you reduce the CAN_D1_UC_ESC_BM and CAN_D1_UC_SRV_BM masks. Right now they're both set to forward any servo data to the UAVCAN bus. It is a bitfield. Can you try reducing the bits down one by and see if it suddenly stops? if so, it's probably a bandwidth issue.

Also, are you using terminators on your bus?

[JamesStewy]

Tested by shaking constantly shaking the Pixhawk in FBWA runnning master ArduPlane.

SCHED_LOOP_RATE	Both bitmasks	Message output rate	CAN frames/sec	Test duration	Resulted in failure
50	255	50Hz (steady)	400	>10 min	No
300	255	270-295Hz (varies)	2400	<1 min	Yes
300	1	300Hz (steady)	600	>15 min	No
50	65535	50Hz (steady)	800	~6 min	Yes

are you using terminators on your bus?

Yes

[magicrub]

Next test would be to use ChibiOS. It's a new OS we're switching too which is much faster.

http://firmware.us.ardupilot.org/Plane/2018-04/2018-04-27-21:04/fmuv3/

Use the apj file.

Make sure to back up your params before uploading this firmware. I'm not sure anyone has done a vtol flight with it so I'd suggest just a bench test for now.

[JamesStewy]

I loaded the apj file using Mission Planner and set all the CAN_* parameters as normal but when I safety in there are no ESC or Actuator CAN messages.

[magicrub]

And you've loaded all your old params and rebooted?

[JamesStewy]

My steps:

1. Use Mission Planner to flash the latest stable ArduCopter (to reset the params)
2. Wait for tones then hard reboot
3. Flash apj file using Mission Planner
4. Wait for tones then hard reboot (one thing is that only the boot tone sounds not the completed IO firmware upload tone)
5. Set ARMING_CHECK = 0, SCHED_LOOP_RATE = 300, CAN_P1_DRIVER = 1 and CAN_P2_DRIVER = 1
6. Hard reboot
7. Check all the CAN parameters have appeared
8. Press safety switch

On the GUI Tool org.ardupilot appears on the node list but it does not output the ESC or Actuator messages on safety in. Another note is that when I boot the apj build the boot tone sounds slightly wrong and it doesn't make the ready to fly tone despite arming checks being disabled.

Is there a difference between the apj file and building and flashing ardupilot master using waf?

[magicrub]

Depends how you're building. We are moving away from using NuttX OS, which is the "px4-v2" (or v3) target and changing it to "fmuv2" (or v3) which is the ChibiOS target. The ChibiOS build will have a different file extension but otherwise should run the same way.

[JamesStewy]

Ok. That makes sense. Up until now we have been building master against NuttX with px4-v3.

I rebuilt using fmuv3 and flashed using waf and had the same issue as described in my previous comment. I connected up a debugger and found that the ChibiOS version doesn't appear to send the channel values though to the AP_UAVCAN stuff. So I implemented that based off what is in AP_HAL_PX4: https://github.com/MonashUAS/ardupilot/tree/uavcan_esc_chibios.

Running that new version with SCHED_LOOP_RATE=300 is definitely the best I have seen. For a brief period of time (~2-4 minutes) after pressing the safety switch the ESC and Actuator messages come at a steady 300Hz but it ultimately still failed with the same issue as all other versions I have tried.

[tridge]

@JamesStewy thanks for your patch!
It did make me think of a problem though. Just as HAL_PX4, this unconditionally sends all the UAVCAN actuator messages. I assume that means it uses the bus bandwidth for them even if you don't have any CAN ESCs.
For example, our OctaQuad quadplane has 13 actuators, 8 of which are ESCs. The ESCs are not on CAN, but we have UAVCAN GPS and compass. Would this change mean that the bus could get clogged up badly with UAVCAN ESC messages and the GPS and mag could end up failing.
Unless there is something else that prevents this in the uavcan layer, I think we need a "we have CAN ESCs and want to output actuators at X Hz" parameter, or auto-detect based on what we find on the bus.

[JamesStewy]

My patch, like HAL_PX4, unconditionally sends all the channel values to AP_UAVCAN however the CAN_D1_UC_ESC_BM and CAN_D1_UC_SRV_BM bitmask parameters filter these channels. So it is currently possible to configure AP to only output a subset of ESC and Actuator messages to the bus.

I do agree that a parameter to set the CAN actuator and ESC output rate would be useful.

[magicrub]

Agreed, an output rate would be nice. Doesn't really solve the problem though because, like in Tridge's example but with CAN ESCs, the vtol motors would probably want to update faster than the fwd motors so they would all end up running at 300 anyway.

If the problem only happens after a few minutes, and nuttxx Gail's sooner than ChibiOS, it smells like a memory leak. Tridge, can you check the mem/stack usage with UAVCAN sending to an esc?

[tridge]

@JamesStewy we should really set these automatically based on what nodes are detected on the bus.

[tridge]

@JamesStewy any chance you could test #7882 ? That removes the need for your PR for HAL_ChibiOS/RCOutput

[JamesStewy]

@tridge I tried #7882 built for both ChibiOS and NuttX and neither resolved this issue.

However #7882 does look like a good idea and the conversation in this thread might suggests that this code should go in its own loop with a configurable rate.

[tridge]

@JamesStewy if you set either CAN_D1_UC_ESC_BM or CAN_D1_UC_SRV_BM to zero then does that prevent the issue? I'm thinking we should change the default to zero for both of those, and ask users of UAVCAN servos or ESCs to set them correctly.

[JamesStewy]

@tridge @magicrub @pavel-kirienko @EShamaev @jschall

We would really like to see this issue resolved as we at MonashUAS truly believe that CAN ESCs and actuators provide an enormous amount of flexibility.

However, currently it is our view that using CAN ESCs and Actuators with any build of ArduPilot is dangerous and we are not willing to fly with it until we can be relatively confident that the issues outlined in this thread are resolved. Current documentation suggests that

Copter, Plane and Rover support UAVCAN Electronic Speed Controllers (ESCs)

and as far as we can tell, anybody who takes this suggestion is unknowingly taking a significant risk and could experience a terminal failure, with very little warning, which results in a complete loss of control.

We have resources available which can be put towards solving this issue. However, @JMare and I are not as familiar with the ArduPilot and UAVCAN codebases as you are nor their design decisions and goals. We would really appreciate some guidance on how to test for and identify the root cause of this issue.

@pavel-kirienko suggested at the top of this thread that the UAVCAN driver could be overrunning and/or having its internal state damaged under high load. Is this code in ArduPilot or libuavcan?

@pavel-kirienko is there a way to test libuavcan in isolation to see if it is the cause of the issue?

@tridge @magicrub, as I have said before I think a fixed, configurable UAVCAN output loop is a good idea long term and it is something I am willing to implement. Should the loop be done using AP_SCHEDULER, a separate thread or something else? Should this be done on top of #7882? As, @tridge pointed out this isn’t a solution to this issue though as if it is set too high (say 300Hz) then the issue will still occur.

@tridge I saw your suggestion in the ArduPilot gitter that the ESC and Actuator bitmasks should default to 0 and I agree that is a good solution for the short term.

Is there anything stopping #7882 getting merged that we can help with?

@jschall where you able to replicate the issue using the parameters I posted?

Thanks,
James

[pavel-kirienko]

Doesn't that increase just the transmit queue?

That particular example does. There's a similar command for RX queue.

I've reverted and re-applied and behaviour was the same. Unless there is something else at play that I'm missing I'd say that missing messages was the current issue.

May I ask you to submit a pull request to PyUAVCAN increasing the maximum queue size to a much larger value (say, 1 million) for non-OSX systems?

[OXINARF]

That particular example does. There's a similar command for RX queue.

I didn't try with ifconfig, but tried with ip and it didn't have a rxqueuelen. Everything I found on the internet said that didn't exist and you had to use SO_RCVBUF.

May I ask you to submit a pull request to PyUAVCAN increasing the maximum queue size to a much larger value (say, 1 million) for non-OSX systems?

Sure, probably not today, I'm tired of looking at CAN 😄

[OXINARF]

@pavel-kirienko As requested: OpenCyphal/pycyphal#33 (damn, that was a fast merge 😃)

I have more info in the SocketCAN case: I had an error in my code so it wasn't actually increasing the buffer. Unfortunately, even after increasing it by more than 38x I could still get errors after a while - it took much longer for that to happen though so it seems to be related to full buffer as well (when I comment the buffer increase code it just takes a second to get errors) - I should also mention that increasing the buffer size requires elevated privileges so it's not a good solution. I'll recommend that you add a reading thread in there too.

[pavel-kirienko]

I'll recommend that you add a reading thread in there too.

I encourage all to contribute that. Fast merge guaranteed. ;)

[tridge]

@JamesStewy would you be able to test the latest changes I made on PR #7882
The key change is to use setTxTimeout(0) on the periodic messages (ESC, servo and LEDs). That prevents the uavcan layer from keeping the messages queued. What seemed to be happening is we were pushing out messages faster than it could handle, and asking for the uavcan layer to keep them for 20ms. For repeated messages that really doesn't make sense. It led to a massive memory leak too.
@pavel-kirienko are there any problems with using a timeout of 0?

[tridge]

I also found my USBTin adapter, so now I can see the error messages in the GUI as well

[tridge]

after discussions with @pavel-kirienko I've changed the timeout to 1ms

[JamesStewy]

@tridge I tried #7882 using px4-v3, the port labeled as CAN 1 and a 300Hz loop rate and it definitely is a big improvement however after a few minutes the message rate still slows to almost nothing due to message corruption and the gui tool still eventually crashes.

Out of intrest, where was the memory leak?

[magicrub]

@JamesStewy it was a tricky thing where resends would get queued unnecessarily

[tridge]

I've made a fair bit more progress today. I ended up writing new two UAVCAN sniffers. One is here:
http://uav.tridgell.net/UAVCAN/uavcan_listen.py
that works on Linux and displays message counts. It seemingly showed a very high rate of message loss. I was a bit suspicious, so I wrote a new sniffer that uses a Pixhawk1. I've checked that into libraries/AP_UAVCAN/examples/UAVCAN_sniffer in the #7882
The PH1 based sniffer is a much better way of looking at this issue, as it bypasses any problems with queue length on Linux can devices. It gives results like this:

uavcan.equipment.air_data.StaticPressure: 29
uavcan.equipment.air_data.StaticTemperature: 29
uavcan.equipment.ahrs.MagneticFieldStrength: 20
uavcan.protocol.NodeStatus: 6
uavcan.equipment.gnss.Fix: 10
uavcan.equipment.gnss.Auxiliary: 1
uavcan.equipment.actuator.ArrayCommand: 45
uavcan.equipment.esc.RawCommand: 368

that is printed at 1Hz, showing the count of message types.

I have pushed some improvements to the PR #7882 that prevent the issues that you have been seeing. It now works nicely on HAL_ChibiOS and HAL_PX4 (its better on ChibiOS, but HAL_PX4 isn't too bad).
One key change I made is to add a parameter CAN_D1_UC_SRV_RT which is the maximum rate in Hz that servo msgs are sent. It defaults to 50. That leaves more bandwidth for ESCs.

I've run with the new PR for quite a long time under both HAL_PX4 and HAL_ChibiOS with both servo and ESC bitmasks at 255. It seems reliable for me.

[tridge]

I'm going to close this now, as I believe all the required fixes are merged in ArduPilot master.
To summaries what the problem was:

1. the Linux based CAN sniffers could not keep up with the packet rates involved in ESC and servo output
2. we were sending ESC and servo msgs very inefficiently in AP_UAVCAN (eg. holding semaphores while doing bus operations)
3. the spin times and delays were much too long
4. the ChibiOS wait() method in libuavcan was rounding down to nearest ms, so when it asked for 200usec (for example) it actually did a poll, which meant the thread sucked up all the available cpu time
5. we were inappropriately sending servo msgs at 400Hz. We now have a parameter for max servo rate (default 50Hz)

With all the changes I can run a copter with HAL_ChibiOS (fmuv3) with SCHED_LOOP_RATE=800 and get 800Hz CAN ESC msgs out reliably with both CAN ports enabled, and still have plenty of spare CPU left. I've left it to run for over an hour with no issues. I can do the same with HAL_PX4, although it does get a fair number of scheduling misses at 800Hz. The CAN ESC msgs do get out though (at around 790Hz).

It would be nice to work out how to make the Linux sniffers handle high packet rates, but that isn't an ArduPilot bug. Meanwhile we can use the UAVCAN_sniffer firmware I put in AP_UAVCAN/examples to sniff at high rates without msg loss.

@JamesStewy many thanks for reporting this, it was a complex problem and led to some really significant improvements in our uavcan support

[Evan1010]

Perhaps slightly off-topic, but has this been tested with live UAVCAN servos/actuators?
I've lately hunted for UAVCAN servos/actuators, but to no avail.
Are the implementations you use all external, DIY control boards for regular PWM servos? Or just SITL nodes?

The closest I've found is the CBS-15 produced by Currawong, which was originally going to include support for UAVCAN, but after a lack of customer interest, UAVCAN was dropped (I am currently querying the potential for a continuation, however).

Just let me know if this question is better suited to the discussion forum.

[pavel-kirienko]

@Evan1010 I heard that these support UAVCAN https://www.uavcomp.com/electronics/micro-uartcan-servos/

[proficnc]

Hitech make UAVCAN servos

[Evan1010]

@proficnc Hitech, or Hitec?
I read the same a couple days back, but was only able to find large RS485 (optional) servos on their commercial site.
If you don't mind, do you have a part number or information link? I'll contact Hitec directly either way, but I'd rather be prepared when speaking to them.

@pavel-kirienko Thank you for the lead - I've contacted them for more information.

[proficnc]

Hitec sorry about the spelling!
They announced them at AUVSI

[proficnc]

MD250MW-CAN

[Evan1010]

@proficnc Thank you, with the part number I was able to find a document with a product listing.

[proficnc]

Awesome

[antoinealb]

Where did you find that this is a UAVCAN servo? I only found that it supports CAN. Also do you know when they should be available?

[Evan1010]

@antoinealb I just started talking to them, and they have responded positively that UAVCAN is an available option. That said, it could still be a misunderstanding (i.e., they referred to them at one point as "CAN UAV servos"). I likely can't quote availability, but they've been very good about responding.

@pavel-kirienko @proficnc I was asked "the CAN Sample Point and the Baud-Rate" for the system. I understand that Baud-Rate is probably 1 Mbit/s, but I can't think what "CAN Sample Point" means. Perhaps its PWM Resolution (i.e., 2048 steps), or update rate (50Hz - 300Hz)?

[pavel-kirienko]

@Evan1010 it is the point within a single bit when the signal is sampled.

The recommendations for UAVCAN are listed here: http://uavcan.org/Specification/8._Hardware_design_recommendations/#can-bus-parameters

[JamesStewy]

Hi @tridge, sorry for disappearing. Thank you for fixing this issue.

Do you currently have a time frame for a beta of ArduPlane 3.9 with this fix in it?
If not, would it be possible to backport it to AdruPlane 3.8?

Thanks,
James