00001
00002
00003
00004
00005
00006
00007
00008
00009
00010
00011
00012
00013
00014
00015
00016
00017
00018
00019
00020
00021
00022
00023
00024 #include <mainapp/main_thread.h>
00025
00026 #include <mainapp/network_manager.h>
00027 #include <mainapp/thread_manager.h>
00028
00029 #include <core/threading/interruptible_barrier.h>
00030 #include <core/exceptions/system.h>
00031 #include <core/macros.h>
00032 #include <config/sqlite.h>
00033 #include <config/net_handler.h>
00034 #include <utils/logging/multi.h>
00035 #include <utils/logging/console.h>
00036 #include <utils/logging/liblogger.h>
00037 #include <utils/logging/factory.h>
00038 #include <utils/system/argparser.h>
00039 #include <utils/time/clock.h>
00040 #include <utils/time/wait.h>
00041 #include <netcomm/utils/network_logger.h>
00042
00043 #include <blackboard/local.h>
00044 #include <aspect/inifin.h>
00045 #include <plugin/manager.h>
00046 #include <plugin/net/handler.h>
00047
00048 #include <cstdio>
00049 #include <cstring>
00050
00051 using namespace fawkes;
00052
00053
00054
00055
00056
00057
00058
00059
00060
00061
00062
00063
00064
00065 FawkesMainThread::FawkesMainThread(ArgumentParser *argp)
00066 : Thread("FawkesMainThread")
00067 {
00068 __blackboard = NULL;
00069 __config_nethandler = NULL;
00070 __config = NULL;
00071 __plugin_manager = NULL;
00072 __network_manager = NULL;
00073 __thread_manager = NULL;
00074 __aspect_inifin = NULL;
00075
00076 __mainloop_thread = NULL;
00077 __mainloop_mutex = new Mutex();
00078 __mainloop_barrier = new InterruptibleBarrier(__mainloop_mutex, 2);
00079
00080 __argp = argp;
00081
00082
00083 const char *tmp;
00084 Logger::LogLevel log_level = Logger::LL_DEBUG;
00085 if ( __argp->has_arg("q") ) {
00086 log_level = Logger::LL_INFO;
00087 if ( (tmp = __argp->arg("q")) != NULL ) {
00088 for (unsigned int i = 0; i < strlen(tmp); ++i) {
00089 if ( tmp[i] == 'q' ) {
00090 switch (log_level) {
00091 case Logger::LL_INFO: log_level = Logger::LL_WARN; break;
00092 case Logger::LL_WARN: log_level = Logger::LL_ERROR; break;
00093 case Logger::LL_ERROR: log_level = Logger::LL_NONE; break;
00094 default: break;
00095 }
00096 }
00097 }
00098 }
00099 } else if ( (tmp = __argp->arg("l")) != NULL ) {
00100 if ( strcmp(tmp, "debug") == 0 ) {
00101 log_level = Logger::LL_DEBUG;
00102 } else if ( strcmp(tmp, "info") == 0 ) {
00103 log_level = Logger::LL_INFO;
00104 } else if ( strcmp(tmp, "warn") == 0 ) {
00105 log_level = Logger::LL_WARN;
00106 } else if ( strcmp(tmp, "error") == 0 ) {
00107 log_level = Logger::LL_ERROR;
00108 } else if ( strcmp(tmp, "none") == 0 ) {
00109 log_level = Logger::LL_NONE;
00110 } else {
00111 printf("Unknown log level '%s', using default\n", tmp);
00112 }
00113 }
00114
00115 if ( (tmp = __argp->arg("L")) != NULL ) {
00116 try {
00117 __multi_logger = LoggerFactory::multilogger_instance(tmp);
00118 } catch (Exception &e) {
00119 e.append("Initializing multi logger failed");
00120 destruct();
00121 throw;
00122 }
00123 } else {
00124 __multi_logger = new MultiLogger(new ConsoleLogger());
00125 }
00126
00127 __multi_logger->set_loglevel(log_level);
00128 LibLogger::init(__multi_logger);
00129
00130
00131 SQLiteConfiguration *sqliteconf = new SQLiteConfiguration(CONFDIR);
00132 __config = sqliteconf;
00133 __config->load(__argp->arg("c"), __argp->arg("d"));
00134
00135 try {
00136 SQLiteConfiguration::SQLiteValueIterator *i = sqliteconf->modified_iterator();
00137 while (i->next()) {
00138 std::string modtype = i->get_modtype();
00139 if (modtype == "changed") {
00140 __multi_logger->log_warn("FawkesMainThread", "Default config value CHANGED: %s (was: %s now: %s)",
00141 i->path(), i->get_oldvalue().c_str(),
00142 i->get_as_string().c_str());
00143 } else if (modtype == "erased") {
00144 __multi_logger->log_warn("FawkesMainThread", "Default config value ERASED: %s",
00145 i->path());
00146 } else {
00147 __multi_logger->log_debug("FawkesMainThread", "Default config value ADDED: %s (value: %s)",
00148 i->path(), i->get_as_string().c_str());
00149 }
00150 }
00151 delete i;
00152 } catch (Exception &e) {
00153 __multi_logger->log_warn("FawkesMainThread", "Failed to read modified default config values, no dump?");
00154 }
00155
00156
00157 __clock = Clock::instance();
00158
00159 std::string bb_magic_token = "";
00160 unsigned int bb_size = 2097152;
00161 try {
00162 bb_magic_token = __config->get_string("/fawkes/mainapp/blackboard_magic_token");
00163 __multi_logger->log_info("FawkesMainApp", "BlackBoard magic token defined. "
00164 "Using shared memory BlackBoard.");
00165 } catch (Exception &e) {
00166
00167 }
00168 try {
00169 bb_size = __config->get_uint("/fawkes/mainapp/blackboard_size");
00170 } catch (Exception &e) {
00171 __multi_logger->log_warn("FawkesMainApp", "BlackBoard size not defined. "
00172 "Will use %u, saving to default DB", bb_size);
00173 __config->set_default_uint("/fawkes/mainapp/blackboard_size", bb_size);
00174 }
00175
00176 unsigned int net_tcp_port = 1910;
00177 std::string net_service_name = "Fawkes on %h";
00178 try {
00179 net_tcp_port = __config->get_uint("/fawkes/mainapp/net/tcp_port");
00180 } catch (Exception &e) {}
00181 if (net_tcp_port > 65535) net_tcp_port = 1910;
00182 try {
00183 net_service_name = __config->get_string("/fawkes/mainapp/net/service_name");
00184 } catch (Exception &e) {}
00185
00186
00187 if ( __argp->has_arg("C") ) {
00188 LocalBlackBoard::cleanup(bb_magic_token.c_str(), true);
00189 }
00190
00191
00192 try {
00193 if ( bb_magic_token == "") {
00194 __blackboard = new LocalBlackBoard(bb_size);
00195 } else {
00196 __blackboard = new LocalBlackBoard(bb_size, bb_magic_token.c_str());
00197 }
00198 __thread_manager = new FawkesThreadManager();
00199 __aspect_inifin = new AspectIniFin(__blackboard,
00200 __thread_manager->aspect_collector(),
00201 __config, __multi_logger, __clock);
00202 __thread_manager->set_inifin(__aspect_inifin, __aspect_inifin);
00203 __plugin_manager = new PluginManager(__thread_manager, __config,
00204 "/fawkes/meta_plugins/");
00205 __network_manager = new FawkesNetworkManager(__thread_manager, net_tcp_port,
00206 net_service_name.c_str());
00207 __config_nethandler = new ConfigNetworkHandler(__config, __network_manager->hub());
00208 } catch (Exception &e) {
00209 e.append("Initializing managers failed");
00210 destruct();
00211 throw;
00212 }
00213
00214 __network_logger = new NetworkLogger(__network_manager->hub(), log_level);
00215 __multi_logger->add_logger(__network_logger);
00216
00217 __aspect_inifin->set_fnet_hub( __network_manager->hub() );
00218 __aspect_inifin->set_network_members( __network_manager->nnresolver(),
00219 __network_manager->service_publisher(),
00220 __network_manager->service_browser() );
00221 __aspect_inifin->set_plugin_manager(__plugin_manager);
00222 __aspect_inifin->set_mainloop_employer(this);
00223 __aspect_inifin->set_logger_employer(this);
00224 __aspect_inifin->set_blocked_timing_executor(__thread_manager);
00225
00226 __plugin_nethandler = new PluginNetworkHandler(__plugin_manager,
00227 __network_manager->hub() );
00228 __plugin_nethandler->start();
00229
00230 __blackboard->start_nethandler(__network_manager->hub());
00231
00232 __loop_start = new Time(__clock);
00233 __loop_end = new Time(__clock);
00234 try {
00235 __max_thread_time_usec = __config->get_uint("/fawkes/mainapp/max_thread_time");
00236 } catch (Exception &e) {
00237 __max_thread_time_usec = 30000;
00238 __multi_logger->log_info("FawkesMainApp", "Maximum thread time not set, assuming 30ms.");
00239 }
00240 __max_thread_time_nanosec = __max_thread_time_usec * 1000;
00241
00242 __time_wait = NULL;
00243 try {
00244 __desired_loop_time_usec = __config->get_uint("/fawkes/mainapp/desired_loop_time");
00245 if ( __desired_loop_time_usec > 0 ) {
00246 __time_wait = new TimeWait(__clock, __desired_loop_time_usec);
00247 }
00248 } catch (Exception &e) {
00249 __desired_loop_time_usec = 0;
00250 __multi_logger->log_info("FawkesMainApp", "Desired loop time not set, assuming 0");
00251 }
00252
00253 __desired_loop_time_sec = (float)__desired_loop_time_usec / 1000000.f;
00254
00255 try {
00256 __enable_looptime_warnings = __config->get_bool("/fawkes/mainapp/enable_looptime_warnings");
00257 if(!__enable_looptime_warnings) {
00258 __multi_logger->log_debug(name(), "loop time warnings are disabled");
00259 }
00260 } catch(Exception &e) {
00261 __enable_looptime_warnings = true;
00262 }
00263 }
00264
00265
00266
00267 FawkesMainThread::~FawkesMainThread()
00268 {
00269 destruct();
00270 }
00271
00272
00273
00274
00275
00276 void
00277 FawkesMainThread::destruct()
00278 {
00279
00280
00281 __multi_logger->remove_logger(__network_logger);
00282 delete __network_logger;
00283
00284 if ( __plugin_nethandler ) {
00285 __plugin_nethandler->cancel();
00286 __plugin_nethandler->join();
00287 delete __plugin_nethandler;
00288 }
00289 delete __plugin_manager;
00290 delete __blackboard;
00291 delete __config_nethandler;
00292 delete __config;
00293 delete __network_manager;
00294 delete __thread_manager;
00295 delete __aspect_inifin;
00296 delete __time_wait;
00297 delete __loop_start;
00298 delete __loop_end;
00299
00300 delete __mainloop_barrier;
00301 delete __mainloop_mutex;
00302
00303
00304 LibLogger::finalize();
00305
00306 Clock::finalize();
00307 }
00308
00309 void
00310 FawkesMainThread::once()
00311 {
00312 if ( __argp->has_arg("p") ) {
00313 try {
00314 __plugin_manager->load(__argp->arg("p"));
00315 } catch (Exception &e) {
00316 __multi_logger->log_error("FawkesMainThread", "Failed to load plugins %s, "
00317 "exception follows", __argp->arg("p"));
00318 __multi_logger->log_error("FawkesMainThread", e);
00319 }
00320 } else {
00321 try {
00322 __plugin_manager->load("default");
00323 } catch (Exception &e) {
00324
00325 __multi_logger->log_error("FawkesMainThread", "Failed to load default plugins, exception follows");
00326 __multi_logger->log_error("FawkesMainThread", e);
00327 }
00328 }
00329 }
00330
00331 void
00332 FawkesMainThread::set_mainloop_thread(Thread *mainloop_thread)
00333 {
00334 loopinterrupt_antistarve_mutex->lock();
00335 __mainloop_mutex->lock();
00336 if (mainloop_thread) __mainloop_barrier->interrupt();
00337 __mainloop_thread = mainloop_thread;
00338 __mainloop_mutex->unlock();
00339 __thread_manager->interrupt_timed_thread_wait();
00340 loopinterrupt_antistarve_mutex->unlock();
00341 }
00342
00343
00344 void
00345 FawkesMainThread::add_logger(Logger *logger)
00346 {
00347 __multi_logger->add_logger(logger);
00348 }
00349
00350
00351 void
00352 FawkesMainThread::remove_logger(Logger *logger)
00353 {
00354 __multi_logger->remove_logger(logger);
00355 }
00356
00357
00358 void
00359 FawkesMainThread::loop()
00360 {
00361 if (unlikely(__mainloop_thread != NULL)) {
00362 try {
00363 __mainloop_mutex->lock();
00364 if (likely(__mainloop_thread != NULL)) {
00365 __mainloop_thread->wakeup(__mainloop_barrier);
00366 __mainloop_barrier->wait();
00367 }
00368 __mainloop_mutex->unlock();
00369 } catch (Exception &e) {
00370 __multi_logger->log_warn("FawkesMainThread", e);
00371 }
00372
00373 } else {
00374 try {
00375 if ( ! __thread_manager->timed_threads_exist() ) {
00376 __multi_logger->log_debug("FawkesMainThread", "No timed threads exist, waiting");
00377 try {
00378 __thread_manager->wait_for_timed_threads();
00379 __multi_logger->log_debug("FawkesMainThread", "Timed threads have been added, "
00380 "running main loop now");
00381 } catch (InterruptedException &e) {
00382 __multi_logger->log_debug("FawkesMainThread", "Waiting for timed threads interrupted");
00383 return;
00384 }
00385 }
00386
00387 if ( __time_wait ) {
00388 __time_wait->mark_start();
00389 }
00390 __loop_start->stamp_systime();
00391
00392 try {
00393 __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_PRE_LOOP, __max_thread_time_nanosec );
00394 __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_SENSOR, __max_thread_time_nanosec );
00395 __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_SENSOR_PROCESS, __max_thread_time_nanosec );
00396 __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_WORLDSTATE, __max_thread_time_nanosec );
00397 __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_THINK, __max_thread_time_nanosec );
00398 __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_SKILL, __max_thread_time_nanosec );
00399 __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_ACT, __max_thread_time_nanosec );
00400 __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_ACT_EXEC, __max_thread_time_nanosec );
00401 __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_POST_LOOP, __max_thread_time_nanosec );
00402 } catch (Exception &e) {
00403 if(__enable_looptime_warnings) {
00404 __multi_logger->log_error("FawkesMainThread", e);
00405 }
00406 }
00407
00408 test_cancel();
00409
00410 __thread_manager->try_recover(__recovered_threads);
00411 if ( ! __recovered_threads.empty() ) {
00412
00413 __multi_logger->log_error(name(), "Threads recovered %zu", __recovered_threads.size());
00414 if(__enable_looptime_warnings) {
00415 if ( __recovered_threads.size() == 1 ) {
00416 __multi_logger->log_warn("FawkesMainThread", "The thread %s could be "
00417 "recovered and resumes normal operation",
00418 __recovered_threads.front().c_str());
00419 } else {
00420 std::string s;
00421 for (std::list<std::string>::iterator i = __recovered_threads.begin();
00422 i != __recovered_threads.end(); ++i) {
00423 s += *i + " ";
00424 }
00425
00426 __multi_logger->log_warn("FawkesMainThread", "The following threads could be "
00427 "recovered and resumed normal operation: %s", s.c_str());
00428 }
00429 }
00430 __recovered_threads.clear();
00431 }
00432
00433 if (__desired_loop_time_sec > 0) {
00434 __loop_end->stamp_systime();
00435 float loop_time = *__loop_end - __loop_start;
00436 if(__enable_looptime_warnings) {
00437 if (loop_time > __desired_loop_time_sec) {
00438 __multi_logger->log_warn("FawkesMainThread", "Loop time exceeded, "
00439 "desired: %f sec (%u usec), actual: %f sec",
00440 __desired_loop_time_sec, __desired_loop_time_usec,
00441 loop_time);
00442 }
00443 }
00444 }
00445 if ( __time_wait ) {
00446 __time_wait->wait_systime();
00447 } else {
00448 yield();
00449 }
00450 } catch (Exception &e) {
00451 __multi_logger->log_warn("FawkesMainThread",
00452 "Exception caught while executing default main "
00453 "loop, ignoring.");
00454 __multi_logger->log_warn("FawkesMainThread", e);
00455 } catch (std::exception &e) {
00456 __multi_logger->log_warn("FawkesMainThread",
00457 "STL Exception caught while executing default main "
00458 "loop, ignoring. (what: %s)", e.what());
00459 }
00460
00461
00462 }
00463 }
