thread.cpp
00001
00002
00003
00004
00005
00006
00007
00008
00009
00010
00011
00012
00013
00014
00015
00016
00017
00018
00019
00020
00021
00022
00023 #include "thread.h"
00024
00025 #include <core/exceptions/system.h>
00026 #include <utils/time/tracker.h>
00027 #include <utils/time/wait.h>
00028
00029 using namespace fawkes;
00030
00031
00032
00033
00034
00035
00036
00037 TimeTrackerMainLoopThread::TimeTrackerMainLoopThread()
00038 : Thread("TimeTrackerMainLoopThread", Thread::OPMODE_WAITFORWAKEUP)
00039 {
00040 }
00041
00042
00043
00044 TimeTrackerMainLoopThread::~TimeTrackerMainLoopThread()
00045 {
00046 }
00047
00048
00049 void
00050 TimeTrackerMainLoopThread::init()
00051 {
00052 __loop_start = new Time(clock);
00053 __loop_end = new Time(clock);
00054 try {
00055 __max_thread_time_usec = config->get_uint("/fawkes/mainapp/max_thread_time");
00056 } catch (Exception &e) {
00057 __max_thread_time_usec = 30000;
00058 logger->log_info("FawkesMainApp", "Maximum thread time not set, assuming 30ms.");
00059 }
00060
00061 __time_wait = NULL;
00062 try {
00063 __desired_loop_time_usec = config->get_uint("/fawkes/mainapp/desired_loop_time");
00064 if ( __desired_loop_time_usec > 0 ) {
00065 __time_wait = new TimeWait(clock, __desired_loop_time_usec);
00066 }
00067 } catch (Exception &e) {
00068 __desired_loop_time_usec = 0;
00069 logger->log_info("FawkesMainApp", "Desired loop time not set, assuming 0");
00070 }
00071
00072 try {
00073 __output_interval = config->get_uint("/ttmainloop/output_interval");
00074 } catch (Exception &e) {
00075 __output_interval = 5.0;
00076 logger->log_info(name(), "Output interval not set, using 5 seconds.");
00077 }
00078
00079
00080 __last_outp_time = new Time(clock);
00081 __now = new Time(clock);
00082 __last_outp_time->stamp();
00083
00084 __tt = new TimeTracker("time.log");
00085 __tt_loopcount = 0;
00086 __ttc_pre_loop = __tt->add_class("Pre Loop");
00087 __ttc_sensor = __tt->add_class("Sensor");
00088 __ttc_worldstate = __tt->add_class("World State");
00089 __ttc_think = __tt->add_class("Think");
00090 __ttc_skill = __tt->add_class("Skill");
00091 __ttc_act = __tt->add_class("Act");
00092 __ttc_post_loop = __tt->add_class("Post Loop");
00093 __ttc_netproc = __tt->add_class("Net Proc");
00094 __ttc_full_loop = __tt->add_class("Full Loop");
00095 __ttc_real_loop = __tt->add_class("Real Loop");
00096 }
00097
00098
00099 #define TIMETRACK_START(c1, c2, c3) \
00100 __tt->ping_start(c1); \
00101 __tt->ping_start(c2); \
00102 __tt->ping_start(c3);
00103
00104 #define TIMETRACK_INTER(c1, c2) \
00105 __tt->ping_end(c1); \
00106 __tt->ping_start(c2);
00107
00108 #define TIMETRACK_END(c) \
00109 __tt->ping_end(c);
00110
00111 void
00112 TimeTrackerMainLoopThread::finalize()
00113 {
00114 delete __time_wait;
00115 delete __tt;
00116 }
00117
00118 void
00119 TimeTrackerMainLoopThread::loop()
00120 {
00121 if ( ! blocked_timing_executor->timed_threads_exist() ) {
00122 logger->log_debug("TimeTrackerMainLoopThread", "No threads exist, waiting");
00123 try {
00124 blocked_timing_executor->wait_for_timed_threads();
00125 logger->log_debug("TimeTrackerMainLoopThread", "Timed threads have been "
00126 "added, running main loop now");
00127 } catch (InterruptedException &e) {
00128 logger->log_debug("TimeTrackerMainLoopThread", "Waiting for timed threads interrupted");
00129 return;
00130 }
00131 }
00132
00133 TIMETRACK_START(__ttc_real_loop, __ttc_full_loop, __ttc_pre_loop);
00134
00135 if ( __time_wait ) {
00136 __time_wait->mark_start();
00137 }
00138 __loop_start->stamp_systime();
00139
00140 blocked_timing_executor->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_PRE_LOOP );
00141
00142 TIMETRACK_INTER(__ttc_pre_loop, __ttc_sensor)
00143
00144 blocked_timing_executor->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_SENSOR );
00145 blocked_timing_executor->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_SENSOR_PROCESS );
00146
00147 TIMETRACK_INTER(__ttc_sensor, __ttc_worldstate)
00148
00149 blocked_timing_executor->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_WORLDSTATE );
00150
00151 TIMETRACK_INTER(__ttc_worldstate, __ttc_think)
00152
00153 blocked_timing_executor->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_THINK );
00154
00155 TIMETRACK_INTER(__ttc_think, __ttc_skill)
00156
00157 blocked_timing_executor->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_SKILL );
00158
00159 TIMETRACK_INTER(__ttc_skill, __ttc_act)
00160
00161 blocked_timing_executor->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_ACT );
00162 blocked_timing_executor->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_ACT_EXEC );
00163
00164 TIMETRACK_INTER(__ttc_act, __ttc_post_loop)
00165
00166 blocked_timing_executor->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_POST_LOOP );
00167
00168 TIMETRACK_INTER(__ttc_post_loop, __ttc_netproc)
00169
00170 TIMETRACK_END(__ttc_netproc);
00171 TIMETRACK_END(__ttc_real_loop);
00172
00173 test_cancel();
00174
00175 if ( __time_wait ) {
00176 __time_wait->wait_systime();
00177 } else {
00178 yield();
00179 }
00180
00181 TIMETRACK_END(__ttc_full_loop);
00182
00183 __now->stamp();
00184 if ( (*__now - __last_outp_time) >= __output_interval ) {
00185 __tt->print_to_stdout();
00186 __tt->print_to_file();
00187 __tt->reset();
00188 *__last_outp_time = *__now;
00189 }
00190
00191 try {
00192 blocked_timing_executor->try_recover(__recovered_threads);
00193 if ( ! __recovered_threads.empty() ) {
00194
00195 std::string s;
00196 if ( __recovered_threads.size() == 1 ) {
00197 s = std::string("The thread ") + __recovered_threads.front() +
00198 " could be recovered and resumes normal operation";
00199 } else {
00200 s = "The following threads could be recovered and resumed normal operation: ";
00201 for (std::list<std::string>::iterator i = __recovered_threads.begin();
00202 i != __recovered_threads.end(); ++i) {
00203 s += *i + " ";
00204 }
00205 }
00206 __recovered_threads.clear();
00207 logger->log_warn("FawkesMainThread", "%s", s.c_str());
00208 }
00209
00210 if (__desired_loop_time_sec > 0) {
00211 __loop_end->stamp_systime();
00212 float loop_time = *__loop_end - __loop_start;
00213 if (loop_time > __desired_loop_time_sec) {
00214 logger->log_warn("FawkesMainThread", "Loop time exceeded, "
00215 "desired: %f sec (%u usec), actual: %f sec",
00216 __desired_loop_time_sec, __desired_loop_time_usec,
00217 loop_time);
00218 }
00219 }
00220 if ( __time_wait ) {
00221 __time_wait->wait_systime();
00222 } else {
00223 yield();
00224 }
00225 } catch (Exception &e) {
00226 logger->log_warn("FawkesMainThread",
00227 "Exception caught while executing default main "
00228 "loop, ignoring.");
00229 logger->log_warn("FawkesMainThread", e);
00230 } catch (std::exception &e) {
00231 logger->log_warn("FawkesMainThread",
00232 "STL Exception caught while executing default main "
00233 "loop, ignoring. (what: %s)", e.what());
00234 }
00235
00236
00237 }
