Hi,
It looks like I'm beginning to get a bit of a handle on the periodic hang-ups
appearing in FlightGear/Plib.
All tests ran on an AMD Athlon XP 2400+, 1024 MB ram, with a GeForce FX 5700
(256 mb texture ram IIRC) video card (AGP based). Suse Linux 10.2 is
installed, and FlightGear, SimGear, and plib were compiled using
gcc 4.1.2 20061115 (prerelease) (SUSE Linux)
Tests were conducted using the following settings in my .fgfsrc file:
--airport=EHAM
--time-match-local
--prop:/environment/params/real-world-weather-fetch=true
--fg-scenery=/home/durk/FlightGear-Scenery-0.9.10/
--fg-root=/home/durk/src/FlightGear-0.9/data-cvs
#--atlas=socket,out,1,localhost,5500,udp
#--nmea=socket,out,1,42.0.1.4,5501,udp
--verbose
--visibility-miles=25
--geometry=1280x1024
Using the SenecaII-jsbsim as aircraft, specified on the command line. Here are
some results.
Firstly, yesterday I managed to speed-up the replay system, by using dynamic
allocation instead of pushing copies of rather large objects into the STL
lists. Using the timestamping code I mentioned yesterday, and committed to
CVS earler today, I found that memory allocation was very slow on my machine.
By preallocating a significant number of replay objects, and recycling used
ones instead of reallocating them I managed to get minimize the amount of
replay timing errors considerably.
Secondly, there are a selected number of processes that take disproportionally
long to execute. The most significant one I found sofar is a call in
src/Input/input.cxx (around line 911). I have surrounded this statement by
debug timestamp information:
stamp("update_joystick_fire_prep ");
a.bindings[modifiers][k]->fire(axis_values[j]);
stamp("update_joystick_fire_end");
and plotted the time it takes between the "update_joystick_fire_prep"
and "update_joystick_fire_end" stamps. The result is rather dramatic:
http://durktalsma.xs4all.nl/FlightGear/joystick-timing.png
X-axis displays the rank number of all FGInput calls with a timing Alert.
Y-axis shows the executiontime of the
a.bindings[modifiers][k]->fire(axis_values[j]);
line.
Thirdly, there is a relation between execution time and listeners, as proven
by the following experiment:
The heading indicator is one instrument showing frequent timing warnings. So I
also booby trapped the FGHeadingIndicator::update() function. Timing
information shows that it consistently takes about 4 usec to get from the
start of this function to the
_heading_out_node->setDoubleValue(heading);
line and than can take up to several ms or more to execute this statement.
That would be rather bizarre, because the update function also contains a
call to _offset_node->setDoubleValue(offset), which is executed within the
total of 4 useconds to execute the first function. That is, until I found
that the SenecaII has a listener attached to the property that
_heading_out_node refers to.
So I decided to do a little experiment: I copied the listener in
data/Aircraft/SenecaII/Nasal/hsi.nas, but set it to listen to offset-deg, the
property updated by _offset_node:
setlistener( "/instrumentation/heading-indicator/offset-deg", func {
h = cmdarg().getValue();
v = h - aphb.getValue();
if( v < 0.0 ) {
v = v + 360.0;
}
hsihb.setDoubleValue( v );
v = h - rad.getValue();
if( v < 0.0 ) {
v = v + 360.0;
}
hsics.setDoubleValue( v );
});
Of course, the function as such doesn't make sense, but it would serve to
verify my hypothesis that if attaching a listener to a property slows its
execution, I would now expect to see that running the first half of the
function would take a lot longer. And this is indeed what happened:
Subsystem Timing Alert : 16032 instrument-8-heading-indicator
Getting to timestamp : HDG_06 takes 15936 usec.
Getting to timestamp : HDG_07 takes 91 usec.
Subsystem Timing Alert : 19071 instrumentation
Subsystem Timing Alert : 17724 instrument-8-heading-indicator
Getting to timestamp : HDG_06 takes 58 usec.
Getting to timestamp : HDG_07 takes 17655 usec.
When we remove the fake listener, _heading_out_node updating is consistently
fast again. One interesting observation from the above test, though, is that
the setDoubleValue() call is not consistently slow. So it's probably not the
listener itself, but probably an unexpected side effect we're dealing with.
I'm still hoping to find a common cause that can explain all of the stutters.
B.t.w., if you're interested, you can find the logfile of an about one hour
session here.
http://durktalsma.xs4all.nl/FlightGear/logfile
Cheers,
Durk
-------------------------------------------------------------------------
This SF.net email is sponsored by: Microsoft
Defy all challenges. Microsoft(R) Visual Studio 2005.
http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/
_______________________________________________
Flightgear-devel mailing list
Flightgear-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/flightgear-devel
