ArduCopter-3.5-rc4: long loops

I am currently test-flying my modified branch based on Copter 3.5-rc4. During two different flights, I experienced major glitches in the RC output of my PixRacer, leading to very exciting maneuvers in one case, and to a minor crash in another. Between these two flights, there were about 10 successful flights without any glitch or even a single very long loop. Some of these successful flights where long time tests of up to 75 minutes in the air.

While analyzing the logs, it is very obvious that the glitches occur right before an PM message that reports an extremely large MaxT value (200k in one case, 450k in another). In other words: during the interval between the last PM and the most recent there was a single loop that was running for 450000 (flight 1), respectively 200000 (flight 2) microseconds (or 200ms, or 0.2s). This is 80 (140) times longer than normal, assuming 2.5 ms per loop at 400Hz mainloop rate.

During the second flight, I had a change in my code, that logged every single tuple of channel data written to the PX4IO. When looking at these high resolution RCOU log records, it is easy to confirm the timing information indicated by the PM message - the RCOU is not updated for >0.2 seconds, while we would expect to see 400 updates per second (i.e. one per 0.0025 seconds or 2.5 ms).

My modified branch is closely based on Copter 3.5-rc4, with some changes that I have backported from my Copter-3.4-based productive branch (which has several 100 hours of logged and uneventful air time).

Logs and branch sources for flight 1 (ends with crash):
http://steinhaus-home.de/cld8/index.php/s/v8tTVPbj3kbnwUW
https://github.com/DuraCopter/ardupilot/tree/crash_longloop

Logs and branch sources for flight 2 (detailed RCOU logging active):
http://steinhaus-home.de/cld8/index.php/s/tNzFSHytDOffafi
https://github.com/DuraCopter/ardupilot/tree/glitch_longloop

Log of a successful flight (74 minutes) on exactly the same firmware binary:
http://steinhaus-home.de/cld8/index.php/s/sm8MPoUgSTc53eM

Opened issue https://github.com/ArduPilot/ardupilot/issues/6123 .

Hi Holger,

I just had a look at your logs and I am wondering about the high vibration levels. Especially of IMU.AccY at the end of flight 2.

Some of the heavy spikes in AccY and AccX seem to be related to NLON and MaxT:

Nice find ;). The prolonged vibration at the end of the flight is a ground resonance with the throttle slightly below takeoff power. At the time of the flight I was unaware of the timing problems and my working hypothesis was that the glitches are related to the ESCs. I therefore intentionally kept the copter in resonance for some time to build up some temperature.

The spikes in vibration during the glitches must be caused by the jerks itself, plus the normal increase in vibration caused by the tremendously rising total power output during the glitch.