UTC Time Delay in Auto Missions

Hi all,

I don’t have a deep background in GPS signals and such, but in the past I’ve been able to use the UTC delay command in Mission Planner with Arducopter to coordinate the auto missions of multiple copters to be “synchronized”. I don’t use this for light shows or anything like that, but it’s usually a fun visual and good exercise in mission planning for some of my students towards the end of the term. However, yesterday we tried this and had multiple failures where the copters seemed to miss a command at the precise UTC delay time and then would of course just sit waiting for that UTC time to come again in 24 hours. This happened even on the initial takeoff command to start the mission when the copters were already “at” the position they needed to be at for the next command. (they weren’t flying and just not getting to a new position fast enough)

I am aware of the AUTO_OPTIONS parameter and had that enabled to allow arming in auto and allow takeoff without raising throttle. In the past we were able to enable those AUTO_OPTIONS for the flight, temporarily disable the DISARM_DELAY and then arm the copters in auto a minute or so before the scheduled takeoff time. The copters would then sit with motors idling until the UTC time arrived and takeoff onto the pre-planned missions simultaneously. It is quite fun to watch.

Unfortunately this didn’t work yesterday after multiple attempts and resets and the one main variable that has changed from the last time we did this that I can think of is the GPS modules themselves. We were using Walksnail M181 GPS modules this time where in the past we’ve typically used Matek GPS’s. The Walksnail modules are definitely a cheaper module, which is why they’re nice in an educational setting, but I’m wondering if there’s something about them that affects clock timing or something similar, causing them to continually miss the UTC time “checkpoints” and to then start the wait for 24 hours until the UTC time comes around again.

Is there a key feature of higher quality GPS modules that would affect things in this way? Any insight would be appreciated!

This is interesting to me. Do you have a logfile from a couple of the aircraft showing this behaviour?

Hi @CraigElder thanks for taking a look! Here’s one of the log-files. I’m trying to round up the others (there were 3 total) from the students.

GroupFlight1.bin

Here is another log @CraigElder . I’m only going to be able to get 2 of the 3 logs, unfortunately. One of the students left for break and didn’t take his aircraft with him, so no way to access the log until August/Sept.

GroupFlight2.bin

@CraigElder Did you ever have a chance to look at these logs? I’m very curious what might be at the root cause of the issue here.

GPS is a time based algorithm. There’s no way that a module with a 3D fix or better misses a timestamp or fails to pass it on. If the cheaper modules didn’t achieve a fix, that might be to blame.

I can’t look at the logs right now, but maybe later this week if no one responds.

Thanks for taking a look, @Yuri_Rage. To my knowledge, the aircraft all had 3D fix at the time in question. These are inexpensive GPS modules, but it looks like they had over 20 satellites and a low HDOP during the flights.

Just checking:

You did use the commands in pairs as mentioned in the video from Randy/

Another thought: When creating the mission, did you account for your local daylight-saving time ? (if applicable)

Thanks for taking a look @Karl_S. We used the delay command, specifically the UTC “version” per the listing here - Copter Mission Command List — Copter documentation I think that is where your screenshot is from. I don’t think I have actually watched Randy’s video. I suppose our “pair of commands” would’ve been delay + takeoff. The strange thing(s) to me were:

  • We have done other “coordinated” flight groups like this in the past (with other copters) and things have gone off just fine - copters all taking off correctly, etc.
  • In this example from my original post, we had multiple copters with an identical or nearly identical missions that did have identical UTC time delays. Some copters would achieve these delays appropriately, and some would “miss” those UTC times.

We did account for daylight savings time and such and I can confirm that to the best of my knowledge because some of the copters/commands did happen at the correct times, and all the copters were using the same base mission plan that each individual pilot adjusted per their specific part in the coordinated mission. Hopefully that makes sense.

I’ve used Matek and Holybro GPS’s in the past, perhaps I should return to using those. These Walksnail modules seems to perform decently other than this instance, so I’m quite at a loss.

OK. You’ve provided a hint:

So, here is what I tink is happening:

All the GPS satellites have synchronized
atomic clocks in them. So the GPS receiver is getting a ridiculously
precise time signal (in human terms) - minus the signal delay.

This is beneficial in most scenarios , but can be a problem when processing such precise data. The catch is -

a) The speed at which the GPS receiver can process the data

b) The speed at which the data packets are
sent to the FC. - You might want to check the baud rate of the GPS
receivers. See if there are differences.

c) The speed at which the FC processes the data. For this you might want to check SHED_LOOP_RATE

My theory is that there is a mismatch in data
processing somewhere. As a consequence the odd data packet is missed and
hence not being used. If that occurs at the precise time the UTC
command should trigger, it might miss that time and hence fail to start.

So, as mentioned above, comparing those
different values is a start. If no difference is found then the specs of
the GPS receiver may have to be investigated further.

…..or return to the previously working GPS receivers.

The GPS hardware is almost certainly not to blame here. They had solid fixes, very few dropped frames, and the UTC time within the autopilot loop would’ve been appropriately set. You’re running the default loop rate at ~30% CPU load on an H7 autopilot, so there’s no processing bottleneck. @Karl_S’s interpretation of the internal processing is not correct, and it is not sensitive enough to cause those kinds of problems.

The delay command is processed and interpreted into a running elapsed timer, so it only needs UTC time upon entry to the command, not as a repeated update. Again, your autopilots had proper UTC references for each log shared.

I used SITL to run one of the exact missions from your logs with only the hours/minutes fields adjusted so I wouldn’t have to wait all day, and it functioned exactly as it should’ve.

Both logs show a takeoff within 1 second of 23 minutes past the hour, so I see no anomalies there.

The only things I can think of that might account for some missed takeoffs is failing to follow the procedure you outlined to disable DISARM_DELAY or maybe switching to AUTO before achieving a good GPS fix, which could cause the delay command to process improperly (probably resulting in a 19 hour and 23 minute delay). Neither of the logs you shared had those issues.

I’d need to see a log from a failed instance to diagnose further.

Thank you both @Karl_S and @Yuri_Rage for looking more into this.

@Yuri_Rage - I think there is an example of a failed instance in GroupFlight2 log above. Delaying 86399 seconds, almost 24 hours. In this mission, this would’ve been a failed/missed delay command.

Ah, I missed that. I keyed only on the initial takeoff timing in my review. I’ll have another look, but my gut says the arrival time at that waypoint/command was already after the desired UTC time, resulting in a wait until the next day.

The fact that it is within 1 second of exactly 24 hours is curious, and leads me to believe it could be a bug, but I’m reserving judgment on that for now.

Found it, and my intuition was correct.

There were multiple missions run, and I only analyzed the last one for which I retrieved the mission file that used relative delays except for initial takeoff timing.

The culprit was a previous mission where the delay command looks to have been an absolute UTC delay after waypoint 3, set to 18:57:20. The Copter processed that command at 18:57:20.246, which is immediately after the absolute delay time, so it returned a 86399 second timer, which is unfortunate but quite logical.

18:57:20.246 "Reached command #3" → "Mission: 4 Delay" → "Delaying 86399 sec"

I don’t see a bug, but rather a poorly planned mission where transit time from WP 2 to WP 3 gave no headroom for the intended delay to occur as expected.

Hmmm, thanks for the analasis, @Yuri_Rage . That entirely makes sense for that instance. I should’ve looked more into that before putting that forth as an example of one of the “missed" delays.

I do wish I could find a good example of a (failed) auto-takeoff with a UTC delay for you as well. I know we had a few of those, which would be a better example and would avoid the transit time miscalculation error you mentioned above. If I can find/get a log from one of those, I’ll post it here. Otherwise perhaps we just need some more testing to see if I can reproduce the error consistently or not (and more double- checking mission times). Thanks again!

I found a reproducible condition that appears like a genuine bug.

  • Upload a mission like the one below, specifying absolute UTC hours and -1 for minutes
    • (-1 for seconds is technically irrelevant to reproduce the issue)
      {027CCF2C-1A75-4F3D-95A5-0C928CFC8201}
  • Switch to AUTO mode during the last minute of the previous hour
    • In this case, between 16:59:00 and 16:59:59
  • Observe a delay of nearly 24 hours instead of less than 1 min

You can test this in SITL by changing the system time to something advantageous before starting the simulation.

@CraigElder @rmackay9

I recall we discussed this awhile back. Do we have a github bug report for this?

Not that I’m aware. I figure it’s like a 1-2 line fix (and probably affects ignored seconds in the same way but would only manifest at absolute second 59). I just hadn’t had a chance to dive in to fix. It might be as easy as truly ignoring -1 values, as I think they may get processed as negative delays in error.

Please create a bug report with your details to reproduce the error.