]> git.mxchange.org Git - simgear.git/blob - simgear/structure/subsystem_mgr.cxx
Improve subsystem manager's timing statistics
[simgear.git] / simgear / structure / subsystem_mgr.cxx
1 // Written by David Megginson, started 2000-12
2 //
3 // Copyright (C) 2000  David Megginson, david@megginson.com
4 //
5 // This program is free software; you can redistribute it and/or
6 // modify it under the terms of the GNU General Public License as
7 // published by the Free Software Foundation; either version 2 of the
8 // License, or (at your option) any later version.
9 //
10 // This program is distributed in the hope that it will be useful, but
11 // WITHOUT ANY WARRANTY; without even the implied warranty of
12 // MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
13 // General Public License for more details.
14 //
15 // You should have received a copy of the GNU General Public License
16 // along with this program; if not, write to the Free Software
17 // Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
18 //
19 // $Id$
20
21 #include <simgear/debug/logstream.hxx>
22 #include <simgear/timing/timestamp.hxx>
23
24 #include "exception.hxx"
25 #include "subsystem_mgr.hxx"
26
27 #include <simgear/math/SGMath.hxx>
28
29
30 const int SG_MAX_SUBSYSTEM_EXCEPTIONS = 4;\f
31 ////////////////////////////////////////////////////////////////////////
32 // Implementation of SGSubsystem
33 ////////////////////////////////////////////////////////////////////////
34
35
36 SGSubsystem::SGSubsystem ()
37   : _suspended(false)
38 {
39 }
40
41 SGSubsystem::~SGSubsystem ()
42 {
43 }
44
45 void
46 SGSubsystem::init ()
47 {
48 }
49
50 void
51 SGSubsystem::postinit ()
52 {
53 }
54
55 void
56 SGSubsystem::reinit ()
57 {
58 }
59
60 void
61 SGSubsystem::shutdown ()
62 {
63 }
64
65 void
66 SGSubsystem::bind ()
67 {
68 }
69
70 void
71 SGSubsystem::unbind ()
72 {
73 }
74
75 void
76 SGSubsystem::suspend ()
77 {
78   _suspended = true;
79 }
80
81 void
82 SGSubsystem::suspend (bool suspended)
83 {
84   _suspended = suspended;
85 }
86
87 void
88 SGSubsystem::resume ()
89 {
90   _suspended = false;
91 }
92
93 bool
94 SGSubsystem::is_suspended () const
95 {
96   return _suspended;
97 }
98
99
100 void
101 SGSubsystem::printTimingInformation ()
102 {
103    SGTimeStamp startTime;
104    for ( eventTimeVecIterator i = timingInfo.begin();
105           i != timingInfo.end();
106           ++i) {
107        if (i == timingInfo.begin()) {
108            startTime = i->getTime();
109        } else {
110            SGTimeStamp endTime = i->getTime();
111            SG_LOG(SG_GENERAL, SG_ALERT, "- Getting to timestamp :   "
112                   << i->getName() << " takes " << endTime - startTime
113                   << " sec.");
114            startTime = endTime;
115        }
116    }
117 }
118
119
120
121 void SGSubsystem::stamp(const string& name)
122 {
123     timingInfo.push_back(TimingInfo(name, SGTimeStamp::now()));
124 }
125
126 \f
127 ////////////////////////////////////////////////////////////////////////
128 // Implementation of SGSubsystemGroup.
129 ////////////////////////////////////////////////////////////////////////
130
131 SGSubsystemGroup::SGSubsystemGroup () :
132   _fixedUpdateTime(-1.0),
133   _updateTimeRemainder(0.0)
134 {
135 }
136
137 SGSubsystemGroup::~SGSubsystemGroup ()
138 {
139     printTimingStatistics();
140
141     // reverse order to prevent order dependency problems
142     for (unsigned int i = _members.size(); i > 0; i--)
143     {
144         delete _members[i-1];
145     }
146 }
147
148 void
149 SGSubsystemGroup::init ()
150 {
151     for (unsigned int i = 0; i < _members.size(); i++)
152         _members[i]->subsystem->init();
153 }
154
155 void
156 SGSubsystemGroup::postinit ()
157 {
158     for (unsigned int i = 0; i < _members.size(); i++)
159         _members[i]->subsystem->postinit();
160 }
161
162 void
163 SGSubsystemGroup::reinit ()
164 {
165     for (unsigned int i = 0; i < _members.size(); i++)
166         _members[i]->subsystem->reinit();
167 }
168
169 void
170 SGSubsystemGroup::shutdown ()
171 {
172     // reverse order to prevent order dependency problems
173     for (unsigned int i = _members.size(); i > 0; i--)
174         _members[i-1]->subsystem->shutdown();
175 }
176
177 void
178 SGSubsystemGroup::bind ()
179 {
180     for (unsigned int i = 0; i < _members.size(); i++)
181         _members[i]->subsystem->bind();
182 }
183
184 void
185 SGSubsystemGroup::unbind ()
186 {
187     // reverse order to prevent order dependency problems
188     for (unsigned int i = _members.size(); i > 0; i--)
189        _members[i-1]->subsystem->unbind();
190 }
191
192 void
193 SGSubsystemGroup::update (double delta_time_sec)
194 {
195     int loopCount = 1;
196     // if dt == 0.0, we are paused, so we need to run one iteration
197     // of our members; if we have a fixed update time, we compute a
198     // loop count, and locally adjust dt
199     if ((delta_time_sec > 0.0) && (_fixedUpdateTime > 0.0)) {
200       double localDelta = delta_time_sec + _updateTimeRemainder;
201       loopCount = SGMiscd::roundToInt(localDelta / _fixedUpdateTime);
202       _updateTimeRemainder = delta_time_sec - (loopCount * _fixedUpdateTime);
203       delta_time_sec = _fixedUpdateTime;
204     }
205
206     while (loopCount-- > 0) {
207       for (unsigned int i = 0; i < _members.size(); i++)
208       {
209            SGTimeStamp timeStamp = SGTimeStamp::now();
210            _members[i]->update(delta_time_sec); // indirect call
211            timeStamp = SGTimeStamp::now() - timeStamp;
212            double b = timeStamp.toUSecs();
213            _members[i]->updateExecutionTime(b);
214            double threshold = _members[i]->getTimeWarningThreshold();
215            if (( b > threshold ) && (b > 10000)) {
216                _members[i]->printTimingInformation(b);
217            }
218       }
219     } // of multiple update loop
220 }
221
222 void 
223 SGSubsystemGroup::collectDebugTiming(bool collect)
224 {
225     for (unsigned int i = 0; i < _members.size(); i++)
226     {
227         _members[i]->collectDebugTiming(collect);
228     }
229 }
230
231 void 
232 SGSubsystemGroup::printTimingStatistics(double minMaxTime,double minJitter)
233 {
234     for (unsigned int i = _members.size(); i > 0; i--)
235     {
236         _members[i-1]->printTimingStatistics(minMaxTime, minJitter);
237         _members[i-1]->timeStat.reset();
238     }
239 }
240
241 void
242 SGSubsystemGroup::suspend ()
243 {
244     for (unsigned int i = 0; i < _members.size(); i++)
245         _members[i]->subsystem->suspend();
246 }
247
248 void
249 SGSubsystemGroup::resume ()
250 {
251     for (unsigned int i = 0; i < _members.size(); i++)
252         _members[i]->subsystem->resume();
253 }
254
255 bool
256 SGSubsystemGroup::is_suspended () const
257 {
258     return false;
259 }
260
261 void
262 SGSubsystemGroup::set_subsystem (const string &name, SGSubsystem * subsystem,
263                                  double min_step_sec)
264 {
265     Member * member = get_member(name, true);
266     if (member->subsystem != 0)
267         delete member->subsystem;
268     member->name = name;
269     member->subsystem = subsystem;
270     member->min_step_sec = min_step_sec;
271 }
272
273 SGSubsystem *
274 SGSubsystemGroup::get_subsystem (const string &name)
275 {
276     Member * member = get_member(name);
277     if (member != 0)
278         return member->subsystem;
279     else
280         return 0;
281 }
282
283 void
284 SGSubsystemGroup::remove_subsystem (const string &name)
285 {
286     for (unsigned int i = 0; i < _members.size(); i++) {
287         if (name == _members[i]->name) {
288             _members.erase(_members.begin() + i);
289             return;
290         }
291     }
292 }
293
294 void
295 SGSubsystemGroup::set_fixed_update_time(double dt)
296 {
297   _fixedUpdateTime = dt;
298 }
299
300 /**
301  * Print timing statistics.
302  * Only show data if jitter exceeds minJitter or
303  * maximum time exceeds minMaxTime. 
304  */
305 void
306 SGSubsystemGroup::Member::printTimingStatistics(double minMaxTime,double minJitter)
307 {
308     if (collectTimeStats) {
309         double minTime = timeStat.min()   / 1000;
310         double maxTime = timeStat.max()   / 1000;
311         double meanTime = timeStat.mean() / 1000;
312         double stddev   = timeStat.stdDev()   / 1000;
313
314         if ((maxTime - minTime >= minJitter)||
315             (maxTime >= minMaxTime))
316         {
317             char buffer[256];
318             snprintf(buffer, 256, "Timing summary for %20s.\n"
319                                   "-  mean time: %04.2f ms.\n"
320                                   "-  min time : %04.2f ms.\n"
321                                   "-  max time : %04.2f ms.\n"
322                                   "-  stddev   : %04.2f ms.\n", name.c_str(), meanTime, minTime, maxTime, stddev);
323             SG_LOG(SG_GENERAL, SG_ALERT, buffer);
324         }
325     }
326 }
327
328
329 bool
330 SGSubsystemGroup::has_subsystem (const string &name) const
331 {
332     return (((SGSubsystemGroup *)this)->get_member(name) != 0);
333 }
334
335 SGSubsystemGroup::Member *
336 SGSubsystemGroup::get_member (const string &name, bool create)
337 {
338     for (unsigned int i = 0; i < _members.size(); i++) {
339         if (_members[i]->name == name)
340             return _members[i];
341     }
342     if (create) {
343         Member * member = new Member;
344         _members.push_back(member);
345         return member;
346     } else {
347         return 0;
348     }
349 }
350
351
352 \f
353 ////////////////////////////////////////////////////////////////////////
354 // Implementation of SGSubsystemGroup::Member
355 ////////////////////////////////////////////////////////////////////////
356
357
358 SGSubsystemGroup::Member::Member ()
359     : name(""),
360       subsystem(0),
361       min_step_sec(0),
362       elapsed_sec(0),
363       collectTimeStats(false),
364       exceptionCount(0)
365 {
366 }
367
368 // This shouldn't be called due to subsystem pointer ownership issues.
369 SGSubsystemGroup::Member::Member (const Member &)
370 {
371 }
372
373 SGSubsystemGroup::Member::~Member ()
374 {
375     delete subsystem;
376 }
377
378 void
379 SGSubsystemGroup::Member::update (double delta_time_sec)
380 {
381     elapsed_sec += delta_time_sec;
382     if (elapsed_sec < min_step_sec) {
383         return;
384     }
385     
386     if (subsystem->is_suspended()) {
387         return;
388     }
389     
390     try {
391       subsystem->update(elapsed_sec);
392       elapsed_sec = 0;
393     } catch (sg_exception& e) {
394       SG_LOG(SG_GENERAL, SG_ALERT, "caught exception processing subsystem:" << name
395         << "\nmessage:" << e.getMessage());
396       
397       if (++exceptionCount > SG_MAX_SUBSYSTEM_EXCEPTIONS) {
398         SG_LOG(SG_GENERAL, SG_ALERT, "(exceptionCount=" << exceptionCount <<
399           ", suspending)");
400         subsystem->suspend();
401       }
402     }
403 }
404
405
406 void 
407 SGSubsystemGroup::Member::printTimingInformation(double time)
408 {
409      if (collectTimeStats) {
410          SG_LOG(SG_GENERAL, SG_ALERT, "Subsystem Timing Alert, subsystem \"" << name << "\": " << time/1000.0 << "ms");
411          subsystem->printTimingInformation();
412      }
413 }
414
415 double SGSubsystemGroup::Member::getTimeWarningThreshold()
416 {
417     return (timeStat.mean() + 3 * timeStat.stdDev());
418 }
419
420 void SGSubsystemGroup::Member::updateExecutionTime(double time)
421 {
422     if (collectTimeStats) {
423         timeStat += time;
424     }
425 }
426
427
428
429
430 \f
431 ////////////////////////////////////////////////////////////////////////
432 // Implementation of SGSubsystemMgr.
433 ////////////////////////////////////////////////////////////////////////
434
435
436 SGSubsystemMgr::SGSubsystemMgr ()
437 {
438   for (int i = 0; i < MAX_GROUPS; i++) {
439     _groups[i] = new SGSubsystemGroup;
440   }
441 }
442
443 SGSubsystemMgr::~SGSubsystemMgr ()
444 {
445   // ensure get_subsystem returns NULL from now onwards,
446   // before the SGSubsystemGroup destructors are run
447   _subsystem_map.clear();
448   
449   for (int i = 0; i < MAX_GROUPS; i++) {
450     delete _groups[i];
451   }
452 }
453
454 void
455 SGSubsystemMgr::init ()
456 {
457     for (int i = 0; i < MAX_GROUPS; i++)
458             _groups[i]->init();
459 }
460
461 void
462 SGSubsystemMgr::postinit ()
463 {
464     for (int i = 0; i < MAX_GROUPS; i++)
465             _groups[i]->postinit();
466 }
467
468 void
469 SGSubsystemMgr::reinit ()
470 {
471     for (int i = 0; i < MAX_GROUPS; i++)
472             _groups[i]->reinit();
473 }
474
475 void
476 SGSubsystemMgr::shutdown ()
477 {
478     // reverse order to prevent order dependency problems
479     for (int i = MAX_GROUPS-1; i >= 0; i--)
480         _groups[i]->shutdown();
481 }
482
483
484 void
485 SGSubsystemMgr::bind ()
486 {
487     for (int i = 0; i < MAX_GROUPS; i++)
488         _groups[i]->bind();
489 }
490
491 void
492 SGSubsystemMgr::unbind ()
493 {
494     // reverse order to prevent order dependency problems
495     for (int i = MAX_GROUPS-1; i >= 0; i--)
496         _groups[i]->unbind();
497 }
498
499 void
500 SGSubsystemMgr::update (double delta_time_sec)
501 {
502     for (int i = 0; i < MAX_GROUPS; i++) {
503         _groups[i]->update(delta_time_sec);
504     }
505 }
506
507 void 
508 SGSubsystemMgr::collectDebugTiming(bool collect)
509 {
510     for (int i = 0; i < MAX_GROUPS; i++) {
511         _groups[i]->collectDebugTiming(collect);
512     }
513 }
514
515 void
516 SGSubsystemMgr::suspend ()
517 {
518     for (int i = 0; i < MAX_GROUPS; i++)
519         _groups[i]->suspend();
520 }
521
522 void
523 SGSubsystemMgr::resume ()
524 {
525     for (int i = 0; i < MAX_GROUPS; i++)
526         _groups[i]->resume();
527 }
528
529 bool
530 SGSubsystemMgr::is_suspended () const
531 {
532     return false;
533 }
534
535 void
536 SGSubsystemMgr::add (const char * name, SGSubsystem * subsystem,
537                      GroupType group, double min_time_sec)
538 {
539     SG_LOG(SG_GENERAL, SG_INFO, "Adding subsystem " << name);
540     get_group(group)->set_subsystem(name, subsystem, min_time_sec);
541
542     if (_subsystem_map.find(name) != _subsystem_map.end()) {
543         SG_LOG(SG_GENERAL, SG_ALERT, "Adding duplicate subsystem " << name);
544         throw sg_exception("duplicate subsystem");
545     }
546     _subsystem_map[name] = subsystem;
547 }
548
549 SGSubsystem* 
550 SGSubsystemMgr::remove(const char* name)
551 {
552   SubsystemDict::iterator s =_subsystem_map.find(name);
553   if (s == _subsystem_map.end()) {
554     return NULL;
555   }
556   
557   SGSubsystem* sub = s->second;
558   _subsystem_map.erase(s);
559   
560 // tedious part - we don't know which group the subsystem belongs too
561   for (int i = 0; i < MAX_GROUPS; i++) {
562     if (_groups[i]->get_subsystem(name) == sub) {
563       _groups[i]->remove_subsystem(name);
564       break;
565     }
566   } // of groups iteration
567   
568   return sub;
569 }
570
571
572 SGSubsystemGroup *
573 SGSubsystemMgr::get_group (GroupType group)
574 {
575     return _groups[group];
576 }
577
578 SGSubsystem *
579 SGSubsystemMgr::get_subsystem (const string &name) const
580 {
581     SubsystemDict::const_iterator s =_subsystem_map.find(name);
582
583     if (s == _subsystem_map.end())
584         return 0;
585     else
586         return s->second;
587 }
588
589 void
590 SGSubsystemMgr::printTimingStatistics(double minMaxTime,double minJitter)
591 {
592     for (int i = 0; i < MAX_GROUPS; i++) {
593         _groups[i]->printTimingStatistics(minMaxTime, minJitter);
594     } // of groups iteration
595 }
596
597 // end of subsystem_mgr.cxx