Data flash log is missing for certain duration

hello,
Can somebody help me to find out the cause for ardupilot not storing the data in flash log for certain period. I am trying to solve stability issues for this flight. Details of flight and observations-

  1. Firmware : Arduplane 3.5.2
  2. Flight incidents: Flight was meant to tune for pitch and roll. We started with tuning of pitch using AUTOTUNE mode. Then, we saw that canopy of plane came off. So, we thought of aborting the flight in course of pitch tuning. Then suddenly flight went to AUTO mode unintentionally. We saw it is loosing control and in companion laptop we have watched it continuously in AUTO mode. Then we thought of taking over the control changing mode to FBWA. But, by the time it already lost the control and we could not get the control on it. Finally, it smashed in ground.
  3. Observations :
    a) We never changed our mode to AUTO from AUTOTUNE using transmitter. But still we saw the flight ground station was getting a message that flight is in AUTO mode. It can be inferred from custom_mode_mavlink_heartbeat_t parameter in tlog. But in log file MODE message show only one message. It might have failed to store other mode changes.
    b) Flash log for certain time has failed to log the messages for variables. This you can see plotting any data like sensor values or attitude values, for which some data are missing in log.
    c) Flight went to roll tuning after mode change message from AUTOTUNE to AUTO came. This we can verify seeing ATRP variables (this stores the autotune variable in process of autotuning and its corresponding type, state, p values, servo, achieved and demanded values). The type field of this message says which autotune process is going on (0: roll, 1: pitch). In this particular case we went for pitch tuning. But, suddenly the log says the flight has gone for roll tuning. After that we have checked whether the mode change has happened or not using custom_mode_mavlink_heartbeat_t message logging time. Then, we found out that certainly it has happened. The flight has gone to AUTO mode before that. How much unlikely the case is that when ARDUPLANE mode changed from AUTOTUNE to AUTO (which is again not done by pilot), the ATRP variables have changed or gone for roll tuning from pitch tuning? Or this is like a normal process when mode change happens?
    d) Pitch tuned P value stored in P value. Ardupilot automatically saves these parameters in during autotuning process after each 10 seconds and stores the value 10 seconds earlier. Since, the overall flight time for AUTOTUNE mode was more than 10s, so definitely it has saved pitch tuning parameters. We have seen in ATRP message P value going to 2.0216 starting from 0.8 and ‘PTCH2SRV_P’ value in PARM message has the same value of 2.0216. This is perfectly fine behaviour of storing the value. But still this value is little bit in higher side it seems. So is there any chance that this parameter can make the flight unstable, since we have stopped the tuning process in this higher value of P.

Can somebody help me for debugging this log? I am attaching log and tlog files with it.

https://drive.google.com/open?id=0Bw-bcC5rtu3KX3FIWVFEYVZJZ2c

https://drive.google.com/open?id=0Bw-bcC5rtu3KQVFuck9pUmVtTG8

It appears that I have to “request permission” before downloading those files. Would you change the permissions on your end to make the logs open to the public?

Idea 1) Missing data in the dataflash log could indicate critical electrical failure. If that happened, I have no idea what strange behavior and transmissions could/couldn’t be observed. What if the detaching canopy pulled a key wire loose? Can anyone else confirm/deny this idea based on the evidence?

Idea 2) A common issue I’ve seen from others’ posts is that the plane was poorly constructed/balanced/trimmed physically. Successful flight in MANUAL mode prior to ArduPilot assisted modes (FBWA, AUTO, etc.) demonstrates this isn’t the case. Did you fly your craft in MANUAL during (or before) the log?

Idea 2.5) The canopy detaching is suspicious, as this will shift the CoG and the aerodynamics somewhat. Depending on the plane, the changes may or may not be noticed. So if you can’t find anything else wrong, this could be responsible for making the plane uncontrollable… I’m not sure how to verify.

Idea 3) The unintentional switch to AUTO is suspicious. In AUTO mode, the plane should attempt to fly a mission, or RTL, and the pilot may be able to “nudge” the plane (unless that parameter is unset) using the control sticks. What was the failsafe behavior of your TX/RX set to? A lost link could both switch the mode to AUTO and give input “nudges” to the AUTO mode causing the plane to crash uncontrollably. To prove/dismiss this idea, take a look at the RCIN values in the .bin log during the AUTO mode and see if they correspond to a pilot desperately attempting to fly a crashing plane?

I think the .bin log would give us more information, when that becomes available. But as you suggested, if the .bin log is missing data, we’re left to guesses…

What do you (and others) think?

Thanks for your reply and probable error suggestions. Sorry I forgot to make the logs public accessible. Now I have made it visible, you can see it.

@hunt0r
I went through your queries and possible ideas. I am replying to them one by one below.

Idea 1) Probably has happened. But if you see the data flash log you will find out that data stopped logging to memory card for a certain time when plane was losing its control then again started logging after that but it had already lost its control. Which is a strange behavior, means stopping to store data then again started storing the data. Is this a normal behavior? Does Ardupilot stop storing data during critical conditions like losing its attitude control?

Idea 2) According to our team yeah we did fly in MANUAL mode before this flight. But the log for this evidence we are unable to find. We do not suppose that the plane was poorly balanced.

Idea 2.5) Our plane is made up of EPO moulded materail, which is common for all electric vehicles. How much change in CoG and other aerodynamic effect you are expecting for coming out of the canopy of dimension 5182 on average?

Idea 3) We did not set any failsafe for the plane as well as for the transmitter, but Throttle_nudge was in enabled mode. The rest part of this idea are still need to be verified.

Thank you

I’m looking at the logfile you uploaded.
[TL;DR] My best guess is that you experienced some sort of blackout from electrical loose connection.

The log begins in FBWA mode (ModeNum = 5) and has no other mode changes recorded.
– There is a point where you disarmed the plane, and re-armed it. Disarming stops the logging, so I am not sure if mode changes during this portion are recorded?
– Did you takeoff in AUTOTUNE mode? I’m guessing this is the case, although personally I always takeoff in MANUAL on an airframe I intend to tune, that’s the safest.

At time 1286 [s] the plane is armed again. Thus logging begins.
At time 1326 [s] the plane begins climbing (indicated by POS.RelAlt). This seems to be takeoff.
Over the next 50 [s] the plane climbs to a maximum altitude around 250 [m], achieved around 1389 [s].
It stays around 250 [m] until 1407 [s] then begins descending.
From 1374 [s] to 1394 [s] I see RC Ch2 input alternating max-and-min for about 1 [s] each. This looks like your pitch autotuning.
From 1394 [s] till the first blackout, the pilot has Ch1 (presumably roll) either near zero, or far below it. What was the plane doing?
– In fact, it’s maxed out for 5 [s] from 1401 to 1406. Was this “roll tuning” or inability to control the craft? If roll tuning, why such long doublets, and why none in the opposite direction?
– I see 2 more pitch-doublets in Ch2 after this Ch1, and then the pilot basically never centers the Ch1 stick for the rest of the flight. Was this the pilot attempting to control the craft?
– After the 6 [s] log gap, when logging resumes, the Ch1 (roll) is in the OPPOSITE direction. I presume this is the pilot attempting to save a crashing craft.
During descent, around 95 [m] alt and 1433 [s] there is a gap in the log, which lasts 6 [s].
– Is this the gap in logging where you saw “AUTO” on the GCS?
The last portion of the log (after the 6 [s] gap) is only 2 [s] long, then then log ends. Based on the altitude, the plane was still almost 70 [m] above the ground… I presume it crashed.

So… I wonder what caused the logging to stop for 6 [s] midair (while descending) but to come back on, and to terminate when you were still 70 [m] AGL?

I checked POWR voltages, they look fine.
I checked VIBE values, no sudden impact events were recorded.
I am new to reading ATRP values, but it looks like the Autotune continually adjusted P with each pitch tuning. Depending on what point you were trying to save a crash, rather than trying to Autotune, this might have worked against you?

Anyways, I can’t find anything else in the log suggesting the cause of the crash, and blackouts are always hard to prove. But that (unfortunate) hypothesis explains why the PixHawk couldn’t fly the plane, why the GCS told you something very confusing, and why the logging stops.

Does anyone else have ideas?

Thanks for your verification of blackout @hunt0r. It seems so.

  1. But still the behavior is strange that without any mechanical vibration (except the canopy came out), autopilot board went to black out mode. If I think that some loose contact from electrical wire might have caused this, then suddenly after 7s how can it be corrected own-self. This behavior of black out and again in good condition is shocking to me.

  2. We took off in AUTOTUNE mode obviously. You can check this in tlog.

By the by, I checked from .tlog that pilot was trying to save the plane. His desired action was to correct the orientation initially. You can see in the starting of AUTO mode that pilot wanted to correct the roll action. You can see it using tlog Attitude message ‘Roll’ field and comparing with RC_CHANNELS_RAW message ‘chan1_raw’ as well SERVO_OUTPUT_RAW message ‘servo1_raw’ field (better to have custom_mode field of HEARTBEAT message also). But since the plane was in AUTO mode, and suddenly we noticed that pilot tried to switch to FBWA mode 1st and then try to correct roll action. This all happens in 3s. By the time roll was off and pilot could not take over the control. Time was less and in AUTO mode the plane lost its control in roll direction.

So why plane lost its roll control in AUTO mode. I have given the plot here.


You can see here navigation roll in AUTO mode just before crash was around 25 degree. Around 9:59:53 time nav_roll is around -25 degree and actual roll is around -13 degree, so the error in roll will come around -12. To correct that the SERVO_OUTPUT_RAW’s ‘servo1_raw’ field will generate a signal around 1330, which is logically correct direction wise since the trim value of RC channel 1 (ie. RC1_TRIM) is set to 1479 in Parameter list of the same file. Similarly, just after 9:59:53 time actual roll becomes -35 degree when nav_roll still remains -25 degree. To correct that corresponding servo output becomes more than 1479, which is around 1540. Action direction wise it seems perfect. But, still roll was going off starting from there.

Is this the problem of roll controller? Or this is the consequence of some other thing?

We have observed that during tuning process of Pitch, Roll tune also happened and the roll P value was stored in RLL2SRV_P value in the parameter list, which is equal to 1.334857. This value seems to be less comparing with other Flight parameter list. Other values of roll controller are-
RLL2SRV_FF 0
RLL2SRV_I 0.1502
RLL2SRV_IMAX 2000
RLL2SRV_P 1.334857
RLL2SRV_RMAX 90
RLL2SRV_TCONST 0.4

We have seen that the time constant (RLL2SRV_TCONST) for roll is less by 0.1 from the noominal value and the RLL2SRV_P is less by .2 from nominal value. Can it cause a severe problem in Roll controller action? I have a doubt on it, because smaller P value in PID controller will cause the response to be sluggish.