20,741
edits
Howto:Exposing Subsystems to Nasal: Difference between revisions
Jump to navigation
Jump to search
Howto:Exposing Subsystems to Nasal (view source)
Revision as of 20:32, 14 February 2016
, 14 February 2016→Focus
m (→SimGear: fix up untested pseudo code) |
(→Focus) |
||
| (8 intermediate revisions by the same user not shown) | |||
| Line 6: | Line 6: | ||
== Focus == | == Focus == | ||
{{Main article|Resource Tracking for FlightGear}} | |||
This article will specifically cover how to access the FlightGear event manager (SGEventMgr) and the listener API (SGPropertyChangeListener) to track registration and invocation of Nasal callbacks per frame. | This article will specifically cover how to access the FlightGear event manager (SGEventMgr) and the listener API (SGPropertyChangeListener) to track registration and invocation of Nasal callbacks per frame. | ||
| Line 11: | Line 12: | ||
The main mechanism for triggering scripted Nasal code to be executed within the FlightGear main loop are so called listeners (Nasal callbacks that are stored in a property-specific vector/list, that get executed in a for-each loop whenever a property is modified), and timers, which represent "delays" (typically in seconds or milliseconds) after which a timer expires and fires its callback to be executed. | The main mechanism for triggering scripted Nasal code to be executed within the FlightGear main loop are so called listeners (Nasal callbacks that are stored in a property-specific vector/list, that get executed in a for-each loop whenever a property is modified), and timers, which represent "delays" (typically in seconds or milliseconds) after which a timer expires and fires its callback to be executed. | ||
Unfortunately, these two mechanisms are rather low-level and tedious/error-prone to use correctly, so that code (Nasal callbacks) may be triggered accidently, and unnecessarily, which ultimately eats up considerable resources while creating a frame, sooner or later causing frame stuttering. | Accordingly, this means that Nasal callbacks will be either invoked by the events subsystem (timers) or by whatever subsystem modifies a property that has a Nasal listener bound to it, given that nature of the Nasal garbage collector (GC), this may make frame rates less determinstic/predictable. | ||
Unfortunately, these two mechanisms are also rather low-level and tedious/error-prone to use correctly, so that code (Nasal callbacks) may be triggered accidently, and unnecessarily, which ultimately eats up considerable resources while creating a frame, sooner or later causing frame stuttering. | |||
This would typically be the case when a function is invoked "too often", i.e. more often than necessary, without the programmer being aware of it - e.g. consider callbacks that are registered to be invoked multiple times: | |||
<syntaxhighlight lang="nasal"> | |||
var foo = func() { | |||
settimer(foo, 0); | |||
settimer(foo, 0); | |||
} | |||
foo(); | |||
</syntaxhighlight> | |||
While the example shown above is trivial, and straightforward to fix, the underlynig problem is a very common one in scripted FlightGear code. | |||
Equally, listeners are a constant source of trouble, because people tend to register callbacks too often (i.e. spread across multiple functions/files): | |||
<syntaxhighlight lang="nasal"> | |||
var foo = func() { | |||
} | |||
setlistener("/sim/signals/fdm-initialized", foo); | |||
setlistener("/sim/signals/fdm-initialized", foo); | |||
setlistener("/sim/signals/fdm-initialized", foo); | |||
</syntaxhighlight> | |||
What this will do, is execute the function 3 times whenever the property is modified. | |||
What needs to be kept in mind here that these are very much contrived examples, and that the code in question is often much more complex, and that such bugs may depend on certain features being in use - e.g. when using reset/re-init, many modules won't behave properly, so that redundant listeners may be registered. | |||
Even more unfortunate is the fact that FlightGear does not currently provide any mechanisms/APIs to look behind the scenes, i.e. to see how often a callback is actually executed, and where the callback is registered to be executed. | Even more unfortunate is the fact that FlightGear does not currently provide any mechanisms/APIs to look behind the scenes, i.e. to see how often a callback is actually executed, and where the callback is registered to be executed. | ||
| Line 36: | Line 66: | ||
== Patching == | == Patching == | ||
=== SimGear === | === SimGear === | ||
For starters, we will just add some debugging statements to the event manager | For starters, we will just add some debugging statements to the event manager. The event manager maintains two queues for timers, one for timers intended to work with simulation time, and one with realtime (i.e. those also executing when paused). These timers are fields/members of the SGEventMgr class which inherits from SGSubsystem, they are accessible as _simQueue and _rtQueue, using the interface of the SGTimerQueue class, the size of the queue is stored in the private _numEntries field (int), which can be made accessible by adding a public getter method, which in turn can then be used by the SGEventMgr subsystem to access the size of each queue: | ||
<syntaxhighlight lang="diff"> | <syntaxhighlight lang="diff"> | ||
diff --git a/simgear/structure/event_mgr.cxx b/simgear/structure/event_mgr.cxx | diff --git a/simgear/structure/event_mgr.cxx b/simgear/structure/event_mgr.cxx | ||
| Line 106: | Line 137: | ||
</syntaxhighlight> | </syntaxhighlight> | ||
However, permanently logging all that info to the console/log file can obviously become heavy - so the next thing we are going to do is to use so called property objects to directly expose this information in the form of properties, for each event queue - so that this needs to be implemented at the SGTimerQueue level. | However, permanently logging all that info to the console/log file can obviously become heavy - so the next thing we are going to do is to use so called [[Howto:Use Property Tree Objects|property objects]] to directly expose this information in the form of properties, for each event queue - so that this needs to be implemented at the SGTimerQueue level. | ||
In particular, we need to expose the following information for each queue: | In particular, we need to expose the following information for each queue: | ||
| Line 117: | Line 148: | ||
=== FlightGear === | === FlightGear === | ||
{{Note|In its current form, this patch works perfectly well, but is specific to just the settimer() API, i.e. does not handle NasalTimerObj instances created via maketimer. However, the undelying approach is trivial enough, so can be easily extended. | |||
Equally, it would make sense to not just log this info to the console but expose it in the property tree, or even provide dedicated Nasal APIs for getting this info at runtime, i.e. for further processing (think a dedicated GUI dialog)}} | |||
<syntaxhighlight lang="diff"> | |||
diff --git a/src/Scripting/NasalSys.cxx b/src/Scripting/NasalSys.cxx | |||
index dcd9965..27eb4c8 100644 | |||
--- a/src/Scripting/NasalSys.cxx | |||
+++ b/src/Scripting/NasalSys.cxx | |||
@@ -1307,6 +1307,13 @@ void FGNasalSys::setTimer(naContext c, int argc, naRef* args) | |||
t->gcKey = gcSave(handler); | |||
t->nasal = this; | |||
+ SG_LOG(SG_NASAL, SG_ALERT, | |||
+ "Nasal timer registration via settimer():\n" | |||
+ "\tfile: " << naStr_data(naGetSourceFile(c,0)) << | |||
+ "\tline: " << naGetLine(c,0) << std::endl | |||
+ | |||
+ ); | |||
+ | |||
globals->get_event_mgr()->addEvent("NasalTimer", | |||
t, &NasalTimer::timerExpired, | |||
delta.num, simtime); | |||
</syntaxhighlight> | |||
To make the whole thing more useful, we will lower the logging priority and instead change the name of the added event to include the file name of the Nasal module and the line number where the settimer() call is invoked (which will be primarily useful in conjunction with the simgear patch above): | |||
<syntaxhighlight lang="diff"> | |||
diff --git a/src/Scripting/NasalSys.cxx b/src/Scripting/NasalSys.cxx | |||
index dcd9965..7f49b18 100644 | |||
--- a/src/Scripting/NasalSys.cxx | |||
+++ b/src/Scripting/NasalSys.cxx | |||
@@ -1307,7 +1307,25 @@ void FGNasalSys::setTimer(naContext c, int argc, naRef* args) | |||
t->gcKey = gcSave(handler); | |||
t->nasal = this; | |||
- globals->get_event_mgr()->addEvent("NasalTimer", | |||
+ SG_LOG(SG_NASAL, SG_DEBUG, | |||
+ "Nasal timer registration via settimer():\n" | |||
+ "\tfile: " << naStr_data(naGetSourceFile(c,0)) << | |||
+ "\tline: " << naGetLine(c,0) << std::endl | |||
+ | |||
+ ); | |||
+ | |||
+ if(delta.num <= 0.1) | |||
+ SG_LOG(SG_NASAL, SG_ALERT, "Warning: settimer() should rarely be used per-frame !!"); | |||
+ | |||
+ std::string timerName("NasalTimer: "); | |||
+ | |||
+ std::stringstream line; | |||
+ line << naGetLine(c,0); | |||
+ | |||
+ timerName += std::string(naStr_data(naGetSourceFile(c,0))) +" via line:"+line.str() ; | |||
+ | |||
+ | |||
+ globals->get_event_mgr()->addEvent(timerName, | |||
t, &NasalTimer::timerExpired, | |||
delta.num, simtime); | |||
} | |||
</syntaxhighlight> | |||
Next, we can explore logging everything via properties, i.e. so that all this info shows up in the property tree using property objects | |||
=== Base Package === | === Base Package === | ||