Board index FlightGear Development Aircraft

777 freezes and FPS loss

Questions and discussion about creating aircraft. Flight dynamics, 3d models, cockpits, systems, animation, textures.

Re: 777 freezes and FPS loss

Postby biloute974 » Sun Jan 31, 2016 9:20 pm

Hooray wrote in Sun Jan 31, 2016 8:39 pm:
biloute974 wrote in Sun Jan 31, 2016 8:21 pm:Hi,

i can confirm that freeze is fixed ;)
But FPS loss... not. For example, T/O at LFLL with 80 FPS and landing at LFPG with 35 FPS after 45 minutes of flight.


based on what we "know" so far, it's probably leaking Nasal callbacks that are re-registering themselves over time, so that they end up being called dozens of times per frame

To learn where your code is leaking Nasal callbacks, you would need to use the Nasal call()/caller() APIs

you can wrap settimer() and make it add each callback to a vector using the identify of the callback: id(callback) - once you do that, you can get the number of all registered timers and print/size() them to the console, this should also enable you to tell if there are identical callbacks registered that don't expire.

Otherwise, you would need to patch the C++ code to do just that in FGNasalSys


I would like to do this, but my knowledge is Nasal is below zero ... I do not shrink from adversity but I have no time to learn this language... I can, just help with test different sort of things with the 777 and give an opinion.
Intel I7 7700 - 16Gb DDR4 - Nvidia GTX970 - FG 2017.4.0 from D&C
biloute974
 
Posts: 193
Joined: Mon Feb 23, 2015 9:49 am
Callsign: U974
Version: 2016.1.0
OS: Mint 17.2

Re: 777 freezes and FPS loss

Postby Hooray » Sun Jan 31, 2016 9:31 pm

There is a lot of Nasal/Nasal GC bashing going on, but in most cases we've seen so far, it's really improper use of lower-level APIs like timers and listeners that are not properly managed by aircraft developers - which is unlikely to show up on powerful systems, unless you keep FG running for a long time - because the only thing that is really happening is that callbacks (=code) is triggered more often than necessary.

Imagine it like configuring your mobile phone to check your eMail inbox once per hour - in FlightGear, there is no notion of a "scheduler" to do this correctly, instead "timers" and "listeners" are used to associate callbacks (=code routines) with certain events, such as a timer expiring (e.g. after a few seconds) or a certain property changing (or any combination of these, i.e. by triggering listeners to be registered when a timer expires and vice versa).

What is happening behind the scenes is a bit obscure, but that has nothing to do with Nasal or its garbage collection (GC) scheme, it has more to do with the low-level nature of the functions provided by core developers to "manage" such callbacks, i.e. the settimer() and setlistener() APIs are particularly tedious to manage properly - but the de facto practice is to use those as the main building blocks to write/integrate full subsystems into the FlightGear main loop - tiny coding errors may not have much of an effect, but under certain circumstances, those coding errors will add up (i.e. over time), so that the original "task" of checking your inbox once per hour, ends up being executed hundreds of times per second - the underlying code would still be correct though, it's just the event handling code that is not written correctly, which is often the case when using reset/re-init or when changing locations - because the simulator hasn't been designed, developed and maintained with these requirements in mind.

Furthermore, there's not introspection facility provided that would allow people to look behind the scenes of the simulator to understand just how often a certain timer/listener is registered and triggered, so that the whole thing is extremely obscure - but like I said, this is not a problem inherent to Nasal coding, it also happens/happened at the C++ level - e.g. look at Torsten's fix for the effects code, which was also leaking/re-running listeners like crazy (unnecessarily) - thus, it's redundant work that is getting re-scheduled to over and over again due to buggy code - the problem is not necessarily the buggy code though (writing broken code is part of the whole process), the real problem is that we don't provide any functionality that would allow people to look at where their resources (CPU, RAM, VRAM, GPU) are utilized, so that uninformed conclusions are drawn by some people (like "Nasal is bad ... and needs to be replaced with .... ").

Thus, what you can do is to overload the corresponding APIs (extension functions) and treat the id() of the callback as the key for a hash lookup to gather data on how many timers/listeners are registered, and sample those over time.

You will almost certainly end up seeing dozens of unnecessary callbacks being invoked by certain code - even though that may not necessarily be restricted to Nasal code, like I said.
Please don't send support requests by PM, instead post your questions on the forum so that all users can contribute and benefit
Thanks & all the best,
Hooray
Help write next month's newsletter !
pui2canvas | MapStructure | Canvas Development | Programming resources
Hooray
 
Posts: 12707
Joined: Tue Mar 25, 2008 9:40 am
Pronouns: THOU

Re: 777 freezes and FPS loss

Postby Hyde » Sun Jan 31, 2016 9:52 pm

Hooray wrote in Sun Jan 31, 2016 8:39 pm:To learn where your code is leaking Nasal callbacks, you would need to use the Nasal call()/caller() APIs

you can wrap settimer() and make it add each callback to a vector using the identify of the callback: id(callback) - once you do that, you can get the number of all registered timers and print/size() them to the console, this should also enable you to tell if there are identical callbacks registered that don't expire.

Otherwise, you would need to patch the C++ code to do just that in FGNasalSys

Hooray, where can I refer the call()/caller() APIs description in the Wiki?
Sorry, I couldn't find.
Hyde
 
Posts: 724
Joined: Fri Aug 12, 2011 2:09 pm
Location: Peachtree city, GA
Callsign: N407DS
Version: GIT
OS: Fedora 25

Re: 777 freezes and FPS loss

Postby Hooray » Sun Jan 31, 2016 10:24 pm

See: http://wiki.flightgear.org/Nasal_library

To learn more about timers and how they work in Nasal, see $FG_SRC/Scripting/NasalSys.cxx

The settimer() API is mapped to the f_settimer() C function here: http://sourceforge.net/p/flightgear/fli ... s.cxx#l781
The C code for this extension function can be seen here: http://sourceforge.net/p/flightgear/fli ... s.cxx#l471
That's only 3 lines of code, which ends up calling the FGNasalSys::setTimer() API at: http://sourceforge.net/p/flightgear/fli ... .cxx#l1265
Code: Select all
// settimer(func, dt, simtime) extension function.  The first argument
// is a Nasal function to call, the second is a delta time (from now),
// in seconds.  The third, if present, is a boolean value indicating
// that "real world" time (rather than simulator time) is to be used.
//
// Implementation note: the FGTimer objects don't live inside the
// garbage collector, so the Nasal handler functions have to be
// "saved" somehow lest they be inadvertently cleaned.  In this case,
// they are inserted into a globals.__gcsave hash and removed on
// expiration.

void FGNasalSys::setTimer(naContext c, int argc, naRef* args)
{
    // Extract the handler, delta, and simtime arguments:
    naRef handler = argc > 0 ? args[0] : naNil();
    if(!(naIsCode(handler) || naIsCCode(handler) || naIsFunc(handler))) {
        naRuntimeError(c, "settimer() with invalid function argument");
        return;
    }

    naRef delta = argc > 1 ? args[1] : naNil();
    if(naIsNil(delta)) {
        naRuntimeError(c, "settimer() with invalid time argument");
        return;
    }

    bool simtime = (argc > 2 && naTrue(args[2])) ? false : true;

    // Generate and register a C++ timer handler
    NasalTimer* t = new NasalTimer;
    t->handler = handler;
    t->gcKey = gcSave(handler);
    t->nasal = this;

    globals->get_event_mgr()->addEvent("NasalTimer",
                                       t, &NasalTimer::timerExpired,
                                       delta.num, simtime);
}


What this will do is create a temporary NasalTimer object, for the class/struct refer to: http://sourceforge.net/p/flightgear/fli ... s.hxx#l163

It will then set up the NasalTimer object according to the arguments you passed to settimer() - and ultimately, it will invoke the event manager to register the timer object: http://sourceforge.net/p/flightgear/fli ... .cxx#l1298

That really is all you need to know in order to check if a Nasal callback gets re-added, or if it is already running, because the "handler" parameter can be checked (e.g. use SG_LOG() to print out the address of the pointer).

Most of this would be also applicable to the setlistener() API, with the difference being that calls will not be specific to any particular subsystem like "events", but can be triggered by arbitrary subsystems which end up writing/modifying a property with a registered Nasal callback/listener.

These two are the most likely suspects when it comes to leaking callbacks and having redundant callbacks registered to be executed unnecessarily.

Note that the event manager lives in SimGear, and one simple thing you can do is to log the number of active timers to the console and/or to the property tree (e.g. using a propertyObject) - you will almost certainly see those grow over time, probably even with identical callbacks: http://api-docs.freeflightsim.org/simge ... ntMgr.html

The other thing that can be done is to use SGTimeStamp::now() to benchmark the execution time of different callbacks.

None of this would be specific to the 777 - it would benefit any/all aircraft and other Nasal code suffering from these coding errors


Even if you don't feel comfortable writing C++ code, all you need to know is how to use the SG_LOG() macro to dump the size of a the timer queue: http://api-docs.freeflightsim.org/simge ... Queue.html

It's _numEntries that's relevant here, which is private, but can be exposed by adding a corresponding method
Please don't send support requests by PM, instead post your questions on the forum so that all users can contribute and benefit
Thanks & all the best,
Hooray
Help write next month's newsletter !
pui2canvas | MapStructure | Canvas Development | Programming resources
Hooray
 
Posts: 12707
Joined: Tue Mar 25, 2008 9:40 am
Pronouns: THOU

Re: 777 freezes and FPS loss

Postby biloute974 » Sun Feb 07, 2016 11:35 am

Hi,

very long flight isn't possible, with a 777. This night i've made Rio to Paris, at take off i've 90 and more FPS and when arrived at Paris 9-10 FPS... I will test the same flight without ALS and after the same with Rembrandt.
We can solve FPS loss by restart the aircraft by menu but we lost sound.
Intel I7 7700 - 16Gb DDR4 - Nvidia GTX970 - FG 2017.4.0 from D&C
biloute974
 
Posts: 193
Joined: Mon Feb 23, 2015 9:49 am
Callsign: U974
Version: 2016.1.0
OS: Mint 17.2

Re: 777 freezes and FPS loss

Postby Thorsten » Sun Feb 07, 2016 11:43 am

very long flight isn't possible, with a 777. This night i've made Rio to Paris, at take off i've 90 and more FPS and when arrived at Paris 9-10 FPS... I will test the same flight without ALS and after the same with Rembrandt.


You can save yourself the trouble - what's on the graphics card has no real memory of the history of what you've been doing - things start to get thrown out of the processing pipeline as soon as you look elsewhere, it's conceptually out of the question that you'd accumulate a framerate drag over hours by using one Shader set over another one.
Thorsten
 
Posts: 12490
Joined: Mon Nov 02, 2009 9:33 am

Re: 777 freezes and FPS loss

Postby Hooray » Sun Feb 07, 2016 12:00 pm

Like Thorsten said, it's more likely to be something else, i.e. improperly-managed Nasal callbacks or even C++ code accumulating runtime overhead over time.
Please don't send support requests by PM, instead post your questions on the forum so that all users can contribute and benefit
Thanks & all the best,
Hooray
Help write next month's newsletter !
pui2canvas | MapStructure | Canvas Development | Programming resources
Hooray
 
Posts: 12707
Joined: Tue Mar 25, 2008 9:40 am
Pronouns: THOU

Re: 777 freezes and FPS loss

Postby Hooray » Sun Feb 07, 2016 7:49 pm

Okay, I have added a patch to the wiki that demonstrates how to inspect the SGTimerQueue objects for simtime/realtime events in the SGEventMgr class: http://wiki.flightgear.org/Howto:Exposi ... al#SimGear

It should be straightforward to expose the same info via properties using the propertyObject<> template - equally, we can provide Nasal APIs to populate a corresponding UI dialog.
Please don't send support requests by PM, instead post your questions on the forum so that all users can contribute and benefit
Thanks & all the best,
Hooray
Help write next month's newsletter !
pui2canvas | MapStructure | Canvas Development | Programming resources
Hooray
 
Posts: 12707
Joined: Tue Mar 25, 2008 9:40 am
Pronouns: THOU

Re: 777 freezes and FPS loss

Postby Hyde » Sun Feb 07, 2016 11:37 pm

@Hooray,
Thank you for the patch.
I added it and flied but timer spawning was well controlled.
simtime queues is 23
realtime queues is 10
constant but framerate decreased from 40 to 26 after 1h20m flight from RJTT to RJFU.

@biolute974,
Please don't use the Paris for this type of testing.
It's a framerate eater.
Hyde
 
Posts: 724
Joined: Fri Aug 12, 2011 2:09 pm
Location: Peachtree city, GA
Callsign: N407DS
Version: GIT
OS: Fedora 25

Re: 777 freezes and FPS loss

Postby biloute974 » Mon Feb 08, 2016 8:13 am

Hi,

I've tested with and without TS, with Terramaster tiles, with and without ALS but FPS loss persist. With Rembrandt too.
Intel I7 7700 - 16Gb DDR4 - Nvidia GTX970 - FG 2017.4.0 from D&C
biloute974
 
Posts: 193
Joined: Mon Feb 23, 2015 9:49 am
Callsign: U974
Version: 2016.1.0
OS: Mint 17.2

Re: 777 freezes and FPS loss

Postby biloute974 » Mon Feb 08, 2016 9:46 am

Hyde wrote in Sun Feb 07, 2016 11:37 pm:@biolute974,
Please don't use the Paris for this type of testing.
It's a framerate eater.


Yes, i've tried with another airport and FPS loss persist.

EDit: with an old version 3.7 (october/november 2015) there is no problem with FPS and the 777.

With A330 too, no FPF loss.

@Hyde, if you want, i can give you my old 3.7 version to compare.
Intel I7 7700 - 16Gb DDR4 - Nvidia GTX970 - FG 2017.4.0 from D&C
biloute974
 
Posts: 193
Joined: Mon Feb 23, 2015 9:49 am
Callsign: U974
Version: 2016.1.0
OS: Mint 17.2

Re: 777 freezes and FPS loss

Postby Hooray » Mon Feb 08, 2016 3:24 pm

thanks for testing - note that the patch does not currently check if there are callbacks executed several times per frame, it also does not take into account anything invoked via listeners.

Also, the patch does not run any GC related checks

If memory is an issue, it could be a leak obviously - if in doubt, check the instructions on the wiki to use git bisect to find the offending commits.

Being able to use valgrind/address sanitizer and/or gdb would be a plus.
Please don't send support requests by PM, instead post your questions on the forum so that all users can contribute and benefit
Thanks & all the best,
Hooray
Help write next month's newsletter !
pui2canvas | MapStructure | Canvas Development | Programming resources
Hooray
 
Posts: 12707
Joined: Tue Mar 25, 2008 9:40 am
Pronouns: THOU

Re: 777 freezes and FPS loss

Postby Hyde » Tue Feb 09, 2016 3:08 am

biloute974 wrote in Mon Feb 08, 2016 9:46 am:Yes, i've tried with another airport and FPS loss persist.

EDit: with an old version 3.7 (october/november 2015) there is no problem with FPS and the 777.

With A330 too, no FPF loss.

@Hyde, if you want, i can give you my old 3.7 version to compare.

Hi biloute974,
What exact 3.7 version did you use? I tried
simgear:10/29 08fb4339236536be2a31768d03d9826d1491437d
flightgear:10/30 a0e31b55654e6f1e98066e804f374220047389c4
fgdata:10/29 ec37636b02310c3bf36fe93bb7ba58871d3c6245
Frame rate is low from the beginning around 14 normally 40 with the latest code but never decreasing.
I want to try with your version.

I knew this is not 777 issue. :o
Hyde
 
Posts: 724
Joined: Fri Aug 12, 2011 2:09 pm
Location: Peachtree city, GA
Callsign: N407DS
Version: GIT
OS: Fedora 25

Re: 777 freezes and FPS loss

Postby biloute974 » Tue Feb 09, 2016 8:04 am

Hi,

how can i check my version ?
Intel I7 7700 - 16Gb DDR4 - Nvidia GTX970 - FG 2017.4.0 from D&C
biloute974
 
Posts: 193
Joined: Mon Feb 23, 2015 9:49 am
Callsign: U974
Version: 2016.1.0
OS: Mint 17.2

Re: 777 freezes and FPS loss

Postby Hooray » Tue Feb 09, 2016 4:51 pm

about dialog (See the wiki for details)
Please don't send support requests by PM, instead post your questions on the forum so that all users can contribute and benefit
Thanks & all the best,
Hooray
Help write next month's newsletter !
pui2canvas | MapStructure | Canvas Development | Programming resources
Hooray
 
Posts: 12707
Joined: Tue Mar 25, 2008 9:40 am
Pronouns: THOU

PreviousNext

Return to Aircraft

Who is online

Users browsing this forum: No registered users and 13 guests