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