I am logging mavlink messages coming from a PixHawk Cube Orange (Ardupilot 4.6.2) on a companion computer for sensor fusion purposes, and of course timestamping and synchronization is extremely important.
Therefore I have been looking into the TIMESYNC protocol.My approach is to send TIMESYNC requests to the autopilot and not answer to his requests. Therefore my timesync message contains
Ts1 = CC_epoch_0, Tc1 = AP_time_boot, Received timestamp = CC_epoch_1
I computed the transmission latency between my CC and the AP and it is almost always below 2ms
I also noticed that this delay has an oscillating behaviour and the period is around 20 seconds (not the point of this post, but still interesting)
I noticed a shift between the CC and the AP system clocks, but this is not something unexpected. It is approximately 100 ms/h. What is interesting to me is that the shift between the two system is linearly increasing without jumps, that means that none of the two system clocks are adjusted to GPS time or network time during the recording interval.
Therefore I created a linear function to compute the AP_epoch using CC_epoch and AP_time_boot (AP_epoch = a * AP_time_boot +b). Basically a mapping between the the two system clocks. I did this because I was curious to see if all the mavlink messages had a similar delay as those 2ms reported by the timesync protocol.
How do I do that: for example ATTITUDE msg contains time_boot_ms (my AP_time_boot) variable. With such info I can compute the AP_epoch and compare it with the received timestamp of that ATTITUDE msg (CC_epoch)
For some messages the latency is definitely in the same order of magnitude of the delay found via TIMESYNC
But then I found this behavior of the GPS_RAW_INT
According to Mavlink Message documentation GPS_RAW_INT represents the raw sensor value coming from the GPS module. I would expect raw sensor measurements to be the first ones to be transmitted as they require little processing (or at lease less processing time than a GLOBAL_POSITION_INT or ATTITUDE message). But in this case the raw sensor measurements have the highest delay. What does this mean?
The only logical explanation that I have is that all the other messages that I request are timestamped just before being sent and not really when the data is computed by the autopilot (ekf). GPS_RAW_INT on the other hand keeps the timestamp coming from the GPS sensor and therefore has this way higher delay.
Then should I expect that the values in an ATTITUDE message have been computed ~150 ms before the actual AP_time_boot?
Unfortunately I dont have the Autopilot log for my test as I did not while AP was disarmed. Would I be able to gain more insights by comparing the timestamps of the CC mavlink logger to the AP logfile itself?
Ultimately it would be useful to have a time coordinate specifying when the data (at least for the most basic navigation messages) have been computed, which is different from the time the message is sent.