Our GCS implements a 4 second timeout between heartbeats it expects from AP. Unfortunately, we’re getting this timeout pretty often when running the SITL, even though everything is working fine. We’ve even had it triggered a few times in actual flights.
I’ve added a print of the HAL time (AP_HAL::millis) and monotonic-clock time (clock_gettime(CLOCK_MONOTONIC,...)) to GCS_MAVLINK::send_heartbeat and I’m indeed seeing a large variability in the monotonic-clock period between sends, while the HAL time period is usually (but not always) 1000ms.
Any idea why this would be happening?
Set parameter SIM_SPEEDUP to 1.000000
Home: 31.862567 34.914328 alt=158.000000m hdg=0.000000
Starting sketch 'ArduCopter'
Starting SITL input
Using Irlock at port : 9005
bind port 5760 for 0
Serial port 0 on TCP port 5760
Waiting for connection ....
Connection on serial port 0
Loaded defaults from copter.parm
Smoothing reset at 0.001
bind port 5762 for 2
Serial port 2 on TCP port 5762
bind port 5763 for 3
Serial port 3 on TCP port 5763
validate_structures:411: Validating structures
Loaded defaults from copter.parm
hal_time=1042 wall_time=439305546 hal_time_dt=0 wall_time_dt=0
hal_time=2010 wall_time=439306560 hal_time_dt=968 wall_time_dt=1014
hal_time=2035 wall_time=439306594 hal_time_dt=25 wall_time_dt=34
hal_time=3033 wall_time=439307625 hal_time_dt=998 wall_time_dt=1031
hal_time=4033 wall_time=439310268 hal_time_dt=1000 wall_time_dt=2643
hal_time=5033 wall_time=439311238 hal_time_dt=1000 wall_time_dt=970
hal_time=6033 wall_time=439312183 hal_time_dt=1000 wall_time_dt=945
hal_time=7033 wall_time=439313100 hal_time_dt=1000 wall_time_dt=917
hal_time=8033 wall_time=439314008 hal_time_dt=1000 wall_time_dt=908
hal_time=9033 wall_time=439314940 hal_time_dt=1000 wall_time_dt=932
hal_time=10033 wall_time=439315892 hal_time_dt=1000 wall_time_dt=952
hal_time=11033 wall_time=439316879 hal_time_dt=1000 wall_time_dt=987
hal_time=12033 wall_time=439317894 hal_time_dt=1000 wall_time_dt=1015
hal_time=13033 wall_time=439318937 hal_time_dt=1000 wall_time_dt=1043
hal_time=14033 wall_time=439319991 hal_time_dt=1000 wall_time_dt=1054
hal_time=15033 wall_time=439321015 hal_time_dt=1000 wall_time_dt=1024
hal_time=16033 wall_time=439322007 hal_time_dt=1000 wall_time_dt=992
hal_time=17033 wall_time=439322974 hal_time_dt=1000 wall_time_dt=967
hal_time=18033 wall_time=439323971 hal_time_dt=1000 wall_time_dt=997
hal_time=19033 wall_time=439324982 hal_time_dt=1000 wall_time_dt=1011
hal_time=20033 wall_time=439325994 hal_time_dt=1000 wall_time_dt=1012
hal_time=21033 wall_time=439326983 hal_time_dt=1000 wall_time_dt=989
hal_time=22033 wall_time=439327983 hal_time_dt=1000 wall_time_dt=1000
hal_time=23033 wall_time=439328991 hal_time_dt=1000 wall_time_dt=1008
hal_time=24033 wall_time=439329985 hal_time_dt=1000 wall_time_dt=994
hal_time=25033 wall_time=439330988 hal_time_dt=1000 wall_time_dt=1003
hal_time=26033 wall_time=439331988 hal_time_dt=1000 wall_time_dt=1000
hal_time=27033 wall_time=439332987 hal_time_dt=1000 wall_time_dt=999
hal_time=28033 wall_time=439334008 hal_time_dt=1000 wall_time_dt=1021
hal_time=29033 wall_time=439335002 hal_time_dt=1000 wall_time_dt=994
hal_time=30033 wall_time=439336002 hal_time_dt=1000 wall_time_dt=1000
hal_time=31033 wall_time=439337631 hal_time_dt=1000 wall_time_dt=1629
hal_time=32033 wall_time=439340139 hal_time_dt=1000 wall_time_dt=2508
hal_time=33033 wall_time=439342101 hal_time_dt=1000 wall_time_dt=1962
hal_time=34033 wall_time=439344542 hal_time_dt=1000 wall_time_dt=2441
hal_time=35033 wall_time=439347137 hal_time_dt=1000 wall_time_dt=2595
hal_time=36033 wall_time=439349680 hal_time_dt=1000 wall_time_dt=2543
hal_time=37033 wall_time=439352563 hal_time_dt=1000 wall_time_dt=2883
hal_time=38033 wall_time=439355305 hal_time_dt=1000 wall_time_dt=2742
hal_time=39033 wall_time=439358375 hal_time_dt=1000 wall_time_dt=3070
hal_time=40033 wall_time=439359151 hal_time_dt=1000 wall_time_dt=776
hal_time=41033 wall_time=439359906 hal_time_dt=1000 wall_time_dt=755
hal_time=42033 wall_time=439360662 hal_time_dt=1000 wall_time_dt=756
hal_time=43033 wall_time=439361426 hal_time_dt=1000 wall_time_dt=764
hal_time=44033 wall_time=439362220 hal_time_dt=1000 wall_time_dt=794
hal_time=45033 wall_time=439363028 hal_time_dt=1000 wall_time_dt=808
hal_time=46033 wall_time=439364098 hal_time_dt=1000 wall_time_dt=1070
hal_time=46083 wall_time=439364167 hal_time_dt=50 wall_time_dt=69
hal_time=46115 wall_time=439364201 hal_time_dt=32 wall_time_dt=34
hal_time=47033 wall_time=439366622 hal_time_dt=918 wall_time_dt=2421
hal_time=48033 wall_time=439369591 hal_time_dt=1000 wall_time_dt=2969
hal_time=49033 wall_time=439372094 hal_time_dt=1000 wall_time_dt=2503
hal_time=50033 wall_time=439374508 hal_time_dt=1000 wall_time_dt=2414
hal_time=51033 wall_time=439377101 hal_time_dt=1000 wall_time_dt=2593
hal_time=52033 wall_time=439379583 hal_time_dt=1000 wall_time_dt=2482
hal_time=53033 wall_time=439381922 hal_time_dt=1000 wall_time_dt=2339
hal_time=53313 wall_time=439382578 hal_time_dt=280 wall_time_dt=656
hal_time=53578 wall_time=439383130 hal_time_dt=265 wall_time_dt=552
hal_time=53613 wall_time=439383249 hal_time_dt=35 wall_time_dt=119
hal_time=53845 wall_time=439383574 hal_time_dt=232 wall_time_dt=325
hal_time=54033 wall_time=439384097 hal_time_dt=188 wall_time_dt=523
hal_time=55033 wall_time=439386723 hal_time_dt=1000 wall_time_dt=2626
hal_time=56033 wall_time=439389193 hal_time_dt=1000 wall_time_dt=2470
hal_time=57033 wall_time=439391749 hal_time_dt=1000 wall_time_dt=2556
hal_time=58033 wall_time=439393892 hal_time_dt=1000 wall_time_dt=2143
hal_time=59033 wall_time=439396599 hal_time_dt=1000 wall_time_dt=2707
hal_time=60033 wall_time=439399606 hal_time_dt=1000 wall_time_dt=3007
hal_time=61033 wall_time=439401831 hal_time_dt=1000 wall_time_dt=2225
hal_time=62033 wall_time=439404021 hal_time_dt=1000 wall_time_dt=2190
hal_time=63033 wall_time=439406593 hal_time_dt=1000 wall_time_dt=2572
hal_time=64033 wall_time=439408850 hal_time_dt=1000 wall_time_dt=2257
hal_time=65033 wall_time=439410064 hal_time_dt=1000 wall_time_dt=1214
hal_time=66033 wall_time=439410621 hal_time_dt=1000 wall_time_dt=557
hal_time=67033 wall_time=439411190 hal_time_dt=1000 wall_time_dt=569
hal_time=68033 wall_time=439412097 hal_time_dt=1000 wall_time_dt=907
hal_time=68640 wall_time=439413784 hal_time_dt=607 wall_time_dt=1687
hal_time=68873 wall_time=439414158 hal_time_dt=233 wall_time_dt=374
hal_time=69033 wall_time=439414297 hal_time_dt=160 wall_time_dt=139
hal_time=70033 wall_time=439416682 hal_time_dt=1000 wall_time_dt=2385
hal_time=71033 wall_time=439418768 hal_time_dt=1000 wall_time_dt=2086
hal_time=72033 wall_time=439421954 hal_time_dt=1000 wall_time_dt=3186
hal_time=73033 wall_time=439424694 hal_time_dt=1000 wall_time_dt=2740
hal_time=74033 wall_time=439427724 hal_time_dt=1000 wall_time_dt=3030
hal_time=75033 wall_time=439430349 hal_time_dt=1000 wall_time_dt=2625
hal_time=76033 wall_time=439433298 hal_time_dt=1000 wall_time_dt=2949
hal_time=77033 wall_time=439434614 hal_time_dt=1000 wall_time_dt=1316
hal_time=78033 wall_time=439437166 hal_time_dt=1000 wall_time_dt=2552
hal_time=79033 wall_time=439439370 hal_time_dt=1000 wall_time_dt=2204
hal_time=80033 wall_time=439441724 hal_time_dt=1000 wall_time_dt=2354
hal_time=81033 wall_time=439443957 hal_time_dt=1000 wall_time_dt=2233
hal_time=82033 wall_time=439445371 hal_time_dt=1000 wall_time_dt=1414
hal_time=83033 wall_time=439447692 hal_time_dt=1000 wall_time_dt=2321
hal_time=84033 wall_time=439450006 hal_time_dt=1000 wall_time_dt=2314
hal_time=85033 wall_time=439452577 hal_time_dt=1000 wall_time_dt=2571
hal_time=86033 wall_time=439455280 hal_time_dt=1000 wall_time_dt=2703
hal_time=87033 wall_time=439458113 hal_time_dt=1000 wall_time_dt=2833
hal_time=88033 wall_time=439460807 hal_time_dt=1000 wall_time_dt=2694
hal_time=89033 wall_time=439463274 hal_time_dt=1000 wall_time_dt=2467
hal_time=90033 wall_time=439465232 hal_time_dt=1000 wall_time_dt=1958
hal_time=91033 wall_time=439467079 hal_time_dt=1000 wall_time_dt=1847
hal_time=92033 wall_time=439469723 hal_time_dt=1000 wall_time_dt=2644
hal_time=93033 wall_time=439472315 hal_time_dt=1000 wall_time_dt=2592
hal_time=94033 wall_time=439474902 hal_time_dt=1000 wall_time_dt=2587
hal_time=95033 wall_time=439478044 hal_time_dt=1000 wall_time_dt=3142
hal_time=96033 wall_time=439479682 hal_time_dt=1000 wall_time_dt=1638
hal_time=97033 wall_time=439482019 hal_time_dt=1000 wall_time_dt=2337
hal_time=98033 wall_time=439484723 hal_time_dt=1000 wall_time_dt=2704
hal_time=99033 wall_time=439487183 hal_time_dt=1000 wall_time_dt=2460
hal_time=100033 wall_time=439489290 hal_time_dt=1000 wall_time_dt=2107
hal_time=101033 wall_time=439492260 hal_time_dt=1000 wall_time_dt=2970
hal_time=102033 wall_time=439494829 hal_time_dt=1000 wall_time_dt=2569
hal_time=103033 wall_time=439497350 hal_time_dt=1000 wall_time_dt=2521
hal_time=103593 wall_time=439498593 hal_time_dt=560 wall_time_dt=1243
hal_time=103793 wall_time=439498868 hal_time_dt=200 wall_time_dt=275
hal_time=104033 wall_time=439499719 hal_time_dt=240 wall_time_dt=851
hal_time=105033 wall_time=439501723 hal_time_dt=1000 wall_time_dt=2004
hal_time=106033 wall_time=439503831 hal_time_dt=1000 wall_time_dt=2108
hal_time=107033 wall_time=439505966 hal_time_dt=1000 wall_time_dt=2135
hal_time=108033 wall_time=439508325 hal_time_dt=1000 wall_time_dt=2359
hal_time=109033 wall_time=439510356 hal_time_dt=1000 wall_time_dt=2031
hal_time=109091 wall_time=439510594 hal_time_dt=58 wall_time_dt=238
hal_time=110033 wall_time=439512729 hal_time_dt=942 wall_time_dt=2135
hal_time=111033 wall_time=439515050 hal_time_dt=1000 wall_time_dt=2321
hal_time=112033 wall_time=439517280 hal_time_dt=1000 wall_time_dt=2230
hal_time=113033 wall_time=439518927 hal_time_dt=1000 wall_time_dt=1647
hal_time=114033 wall_time=439520892 hal_time_dt=1000 wall_time_dt=1965
hal_time=115033 wall_time=439522609 hal_time_dt=1000 wall_time_dt=1717
hal_time=116033 wall_time=439524885 hal_time_dt=1000 wall_time_dt=2276
hal_time=117033 wall_time=439527262 hal_time_dt=1000 wall_time_dt=2377
hal_time=118033 wall_time=439529622 hal_time_dt=1000 wall_time_dt=2360
hal_time=119033 wall_time=439531402 hal_time_dt=1000 wall_time_dt=1780
hal_time=120033 wall_time=439533591 hal_time_dt=1000 wall_time_dt=2189
hal_time=121033 wall_time=439536097 hal_time_dt=1000 wall_time_dt=2506
hal_time=122033 wall_time=439538546 hal_time_dt=1000 wall_time_dt=2449
hal_time=123033 wall_time=439540982 hal_time_dt=1000 wall_time_dt=2436
hal_time=124033 wall_time=439543332 hal_time_dt=1000 wall_time_dt=2350
hal_time=125033 wall_time=439545654 hal_time_dt=1000 wall_time_dt=2322
hal_time=126033 wall_time=439547838 hal_time_dt=1000 wall_time_dt=2184
hal_time=127033 wall_time=439549952 hal_time_dt=1000 wall_time_dt=2114
hal_time=127548 wall_time=439550723 hal_time_dt=515 wall_time_dt=771
hal_time=127616 wall_time=439550802 hal_time_dt=68 wall_time_dt=79
hal_time=127848 wall_time=439551012 hal_time_dt=232 wall_time_dt=210
hal_time=128033 wall_time=439551294 hal_time_dt=185 wall_time_dt=282
hal_time=129033 wall_time=439553876 hal_time_dt=1000 wall_time_dt=2582
hal_time=130033 wall_time=439556154 hal_time_dt=1000 wall_time_dt=2278
hal_time=131033 wall_time=439558267 hal_time_dt=1000 wall_time_dt=2113
hal_time=132033 wall_time=439560809 hal_time_dt=1000 wall_time_dt=2542
hal_time=133033 wall_time=439563298 hal_time_dt=1000 wall_time_dt=2489
hal_time=134033 wall_time=439565678 hal_time_dt=1000 wall_time_dt=2380
hal_time=135033 wall_time=439567724 hal_time_dt=1000 wall_time_dt=2046
hal_time=136033 wall_time=439569723 hal_time_dt=1000 wall_time_dt=1999
hal_time=137033 wall_time=439571890 hal_time_dt=1000 wall_time_dt=2167
hal_time=138033 wall_time=439574955 hal_time_dt=1000 wall_time_dt=3065
hal_time=139033 wall_time=439577201 hal_time_dt=1000 wall_time_dt=2246
hal_time=140033 wall_time=439579249 hal_time_dt=1000 wall_time_dt=2048
hal_time=141033 wall_time=439581333 hal_time_dt=1000 wall_time_dt=2084
hal_time=142033 wall_time=439583802 hal_time_dt=1000 wall_time_dt=2469
hal_time=143033 wall_time=439586048 hal_time_dt=1000 wall_time_dt=2246
hal_time=144033 wall_time=439588229 hal_time_dt=1000 wall_time_dt=2181
hal_time=145033 wall_time=439590899 hal_time_dt=1000 wall_time_dt=2670
hal_time=146033 wall_time=439594026 hal_time_dt=1000 wall_time_dt=3127
hal_time=147033 wall_time=439596256 hal_time_dt=1000 wall_time_dt=2230
hal_time=148033 wall_time=439599050 hal_time_dt=1000 wall_time_dt=2794
hal_time=149033 wall_time=439601618 hal_time_dt=1000 wall_time_dt=2568
hal_time=150033 wall_time=439604209 hal_time_dt=1000 wall_time_dt=2591
hal_time=151033 wall_time=439606363 hal_time_dt=1000 wall_time_dt=2154
hal_time=152033 wall_time=439608514 hal_time_dt=1000 wall_time_dt=2151
hal_time=153033 wall_time=439609393 hal_time_dt=1000 wall_time_dt=879
hal_time=154033 wall_time=439609886 hal_time_dt=1000 wall_time_dt=493
hal_time=155033 wall_time=439611599 hal_time_dt=1000 wall_time_dt=1713
hal_time=156033 wall_time=439615081 hal_time_dt=1000 wall_time_dt=3482
hal_time=157033 wall_time=439617724 hal_time_dt=1000 wall_time_dt=2643
hal_time=158033 wall_time=439619922 hal_time_dt=1000 wall_time_dt=2198
hal_time=159033 wall_time=439621777 hal_time_dt=1000 wall_time_dt=1855
hal_time=160033 wall_time=439624159 hal_time_dt=1000 wall_time_dt=2382
hal_time=161033 wall_time=439626522 hal_time_dt=1000 wall_time_dt=2363
hal_time=162033 wall_time=439628977 hal_time_dt=1000 wall_time_dt=2455
hal_time=162135 wall_time=439629141 hal_time_dt=102 wall_time_dt=164
hal_time=162403 wall_time=439629301 hal_time_dt=268 wall_time_dt=160
hal_time=163033 wall_time=439629656 hal_time_dt=630 wall_time_dt=355
hal_time=164033 wall_time=439630256 hal_time_dt=1000 wall_time_dt=600
hal_time=165033 wall_time=439630894 hal_time_dt=1000 wall_time_dt=638
hal_time=166033 wall_time=439631526 hal_time_dt=1000 wall_time_dt=632
hal_time=167033 wall_time=439633585 hal_time_dt=1000 wall_time_dt=2059
hal_time=168033 wall_time=439636296 hal_time_dt=1000 wall_time_dt=2711
hal_time=169033 wall_time=439639068 hal_time_dt=1000 wall_time_dt=2772
hal_time=170033 wall_time=439639807 hal_time_dt=1000 wall_time_dt=739
hal_time=171033 wall_time=439640534 hal_time_dt=1000 wall_time_dt=727
hal_time=172033 wall_time=439642087 hal_time_dt=1000 wall_time_dt=1553
hal_time=173033 wall_time=439644722 hal_time_dt=1000 wall_time_dt=2635
hal_time=174033 wall_time=439647273 hal_time_dt=1000 wall_time_dt=2551
hal_time=175033 wall_time=439649627 hal_time_dt=1000 wall_time_dt=2354
hal_time=176033 wall_time=439652275 hal_time_dt=1000 wall_time_dt=2648
hal_time=177033 wall_time=439655255 hal_time_dt=1000 wall_time_dt=2980
hal_time=178033 wall_time=439658273 hal_time_dt=1000 wall_time_dt=3018
hal_time=179033 wall_time=439660322 hal_time_dt=1000 wall_time_dt=2049
hal_time=179728 wall_time=439662113 hal_time_dt=695 wall_time_dt=1791
hal_time=179996 wall_time=439662322 hal_time_dt=268 wall_time_dt=209
hal_time=180033 wall_time=439662529 hal_time_dt=37 wall_time_dt=207