ArduPlane JSBSim Synchronization/Lock-Step-Mechanism Issues

simfinite · February 19, 2019, 5:22pm

Hey everyone,

i have experienced some synchronization issues between JSBSim and ArduPlane SITL, which I would like to discuss here before opening an issue.

I have modified the JSBSim startup code a little in order to have JSBSim create a CSV-logfile on its own (by passing an additional logdirective file via the commandline). When I compare the JSBSim log against ArduPlane logs, it looks like this:
arduplane_jsbsim_sync_issue

Essentially, there seems to be an increasing time lag in ArduPlane SITL compared to JSBSim simulation time. I have tried this with the old JSBSim version from @tridge as well, and it’s even worse than with the latest version shown in the plot.

I looked at the code of how time is kept inside ArduPlane. I figured that it’s basically an “open-loop” synchronization: Everytime JSBSim is run (‘iterate 1’ used to be ‘step’ in old version), the internal clock is incremented by the frame time. What I find odd is the fact that JSBSim is run in ‘–realtime’ mode which explicitely does not support the ‘iterate’ command.

I tried to have JSBSim started up in batch/non-realtime mode, which results in a massive slowdown of everything (takes >5 minutes until I can arm the aicraft), which is weird because my CPU is idle most of the time and I would have expected it to run faster than in realtime mode.

So at this point I would like to ask:

Can anyone explain the lock-step mechanism as it is implemented in more detail?
Does anyone know why we start up JSBSim in realtime mode and yet try to have it synced to the ArduPlane SITL application?
Any other ideas / remarks / things I should try?

simfinite · February 24, 2019, 10:36am

So I got some further insights into this issue that I would like to share:

I applied a minor change to JSBSim’s FlightGear UPD output protocol, such that the current simulation time is sent along with the state vector. This allows to instrument the time-sync code in ArduPlane and to inspect the time lag between ArduPlane and JSBSim simulation time. Here is an excerpt of the output:

time lag: 103000 us, ArduPlane time: 28187000 us , JSBSim time: 28084000 us
time lag: 103000 us, ArduPlane time: 28188000 us , JSBSim time: 28085000 us
time lag: 103000 us, ArduPlane time: 28189000 us , JSBSim time: 28086000 us
time lag: 103000 us, ArduPlane time: 28190000 us , JSBSim time: 28087000 us
time lag: 103000 us, ArduPlane time: 28191000 us , JSBSim time: 28088000 us
time lag: 103000 us, ArduPlane time: 28192000 us , JSBSim time: 28089000 us
time lag: 103000 us, ArduPlane time: 28193000 us , JSBSim time: 28090000 us
time lag: 103000 us, ArduPlane time: 28194000 us , JSBSim time: 28091000 us
time lag: 103000 us, ArduPlane time: 28195000 us , JSBSim time: 28092000 us
time lag: 104000 us, ArduPlane time: 28196000 us , JSBSim time: 28092000 us
time lag: 104000 us, ArduPlane time: 28197000 us , JSBSim time: 28093000 us
time lag: 104000 us, ArduPlane time: 28198000 us , JSBSim time: 28094000 us
time lag: 104000 us, ArduPlane time: 28199000 us , JSBSim time: 28095000 us
time lag: 104000 us, ArduPlane time: 28200000 us , JSBSim time: 28096000 us
time lag: 104000 us, ArduPlane time: 28201000 us , JSBSim time: 28097000 us
time lag: 104000 us, ArduPlane time: 28202000 us , JSBSim time: 28098000 us
time lag: 104000 us, ArduPlane time: 28203000 us , JSBSim time: 28099000 us
time lag: 104000 us, ArduPlane time: 28204000 us , JSBSim time: 28100000 us

It looks like on ArduPlane side, some of the JSBSim simulation frames are received twice, which then leads to an increase in time lag between ArduPlane and JSBSim time. My first thought was that this may have something to do with JSBSim’s realtime mode, which - as stated above - doesn’t actually support the ‘iterate 1’ command that is being used in ArduPlane. So, I spend some time to get JSBSim to run in batch mode (i.e. without --realtime option). The changes can be found here.

Although, I believe that running JSBSim in batch mode instead of realtime mode is the correct way, unfortunately, it did not solve the synchronization issue. In fact, on my machine things got a little worse and almost every frame is being received twice now:

time lag: 1991000 us, ArduPlane time: 8257000 us , JSBSim time: 6266000 us
time lag: 1992000 us, ArduPlane time: 8258000 us , JSBSim time: 6266000 us
time lag: 1992000 us, ArduPlane time: 8259000 us , JSBSim time: 6267000 us
time lag: 1993000 us, ArduPlane time: 8260000 us , JSBSim time: 6267000 us
time lag: 1993000 us, ArduPlane time: 8261000 us , JSBSim time: 6268000 us
time lag: 1994000 us, ArduPlane time: 8262000 us , JSBSim time: 6268000 us
time lag: 1994000 us, ArduPlane time: 8263000 us , JSBSim time: 6269000 us
time lag: 1995000 us, ArduPlane time: 8264000 us , JSBSim time: 6269000 us
time lag: 1995000 us, ArduPlane time: 8265000 us , JSBSim time: 6270000 us
time lag: 1996000 us, ArduPlane time: 8266000 us , JSBSim time: 6270000 us

Now, I am not a network expert, but I now that UDP communication can be unreliable and hence, one should probably expect simulation frames to be dropped or received multiple times. With the above mentioned modification of JSBSim and with the changes to run JSBSim in batch mode, the synchronization issue can be resolved by using the transmitted simulation time instead of incrementing by the sample time. I implemented this work-around here and it works like a charm on my setup.

From here on, I see 3 possible ways of resolving this issue:

Have the JSBSim team adapt the protocol to send the simulation time via UDP (maybe they could agree on using the currently unused member ‘cur_time’ as I did for my work-around)
Use a more reliable communication mechanism than UDP
Implement another way of detecting duplicate frame receival (e.g. checksum)