src/mainapp/main_thread.cpp

   1
   2 /***************************************************************************
   3  *  main_thread.cpp - Fawkes main thread
   4  *
   5  *  Created: Thu Nov  2 16:47:50 2006
   6  *  Copyright  2006-2009  Tim Niemueller [www.niemueller.de]
   7  *
   8  ****************************************************************************/
   9
  10 /*  This program is free software; you can redistribute it and/or modify
  11  *  it under the terms of the GNU General Public License as published by
  12  *  the Free Software Foundation; either version 2 of the License, or
  13  *  (at your option) any later version. A runtime exception applies to
  14  *  this software (see LICENSE.GPL_WRE file mentioned below for details).
  15  *
  16  *  This program is distributed in the hope that it will be useful,
  17  *  but WITHOUT ANY WARRANTY; without even the implied warranty of
  18  *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  19  *  GNU Library General Public License for more details.
  20  *
  21  *  Read the full text in the LICENSE.GPL_WRE file in the doc directory.
  22  */
  23
  24 #include <mainapp/main_thread.h>
  25
  26 #include <mainapp/network_manager.h>
  27 #include <mainapp/thread_manager.h>
  28
  29 #include <core/threading/interruptible_barrier.h>
  30 #include <core/exceptions/system.h>
  31 #include <core/macros.h>
  32 #include <config/sqlite.h>
  33 #include <config/net_handler.h>
  34 #include <utils/logging/multi.h>
  35 #include <utils/logging/console.h>
  36 #include <utils/logging/liblogger.h>
  37 #include <utils/logging/factory.h>
  38 #include <utils/system/argparser.h>
  39 #include <utils/time/clock.h>
  40 #include <utils/time/wait.h>
  41 #include <netcomm/utils/network_logger.h>
  42
  43 #include <blackboard/local.h>
  44 #include <aspect/inifin.h>
  45 #include <plugin/manager.h>
  46 #include <plugin/loader.h>
  47 #include <plugin/net/handler.h>
  48
  49 #include <cstdio>
  50 #include <cstring>
  51
  52 using namespace fawkes;
  53
  54 /** @class FawkesMainThread mainapp/main_thread.h
  55  * Fawkes main thread.
  56  * This thread initializes all important stuff like the BlackBoard,
  57  * handles plugins and wakes up threads at defined hooks.
  58  *
  59  * @author Tim Niemueller
  60  */
  61
  62
  63 /** Constructor.
  64  * @param argp argument parser
  65  */
  66 FawkesMainThread::FawkesMainThread(ArgumentParser *argp)
  67   : Thread("FawkesMainThread")
  68 {
  69   __blackboard        = NULL;
  70   __config_nethandler = NULL;
  71   __config            = NULL;
  72   __plugin_manager    = NULL;
  73   __network_manager   = NULL;
  74   __thread_manager    = NULL;
  75   __aspect_inifin     = NULL;
  76
  77   __mainloop_thread   = NULL;
  78   __mainloop_mutex    = new Mutex();
  79   __mainloop_barrier  = new InterruptibleBarrier(__mainloop_mutex, 2);
  80
  81   __argp = argp;
  82
  83   /* Logging stuff */
  84   const char *tmp;
  85   Logger::LogLevel log_level = Logger::LL_DEBUG;
  86   if ( __argp->has_arg("q") ) {
  87     log_level = Logger::LL_INFO;
  88     if ( (tmp = __argp->arg("q")) != NULL ) {
  89       for (unsigned int i = 0; i < strlen(tmp); ++i) {
  90         if ( tmp[i] == 'q' ) {
  91           switch (log_level) {
  92           case Logger::LL_INFO:  log_level = Logger::LL_WARN; break;
  93           case Logger::LL_WARN:  log_level = Logger::LL_ERROR; break;
  94           case Logger::LL_ERROR: log_level = Logger::LL_NONE; break;
  95           default: break;
  96           }
  97         }
  98       }
  99     }
 100   } else if ( (tmp = __argp->arg("l")) != NULL ) {
 101     if ( strcmp(tmp, "debug") == 0 ) {
 102       log_level = Logger::LL_DEBUG;
 103     } else if ( strcmp(tmp, "info") == 0 ) {
 104       log_level = Logger::LL_INFO;
 105     } else if ( strcmp(tmp, "warn") == 0 ) {
 106       log_level = Logger::LL_WARN;
 107     } else if ( strcmp(tmp, "error") == 0 ) {
 108       log_level = Logger::LL_ERROR;
 109     } else if ( strcmp(tmp, "none") == 0 ) {
 110       log_level = Logger::LL_NONE;
 111     } else {
 112       printf("Unknown log level '%s', using default\n", tmp);
 113     }
 114   }
 115
 116   if ( (tmp = __argp->arg("L")) != NULL ) {
 117     try {
 118       __multi_logger = LoggerFactory::multilogger_instance(tmp);
 119     } catch (Exception &e) {
 120       e.append("Initializing multi logger failed");
 121       destruct();
 122       throw;
 123     }
 124   } else {
 125     __multi_logger = new MultiLogger(new ConsoleLogger());
 126   }
 127
 128   __multi_logger->set_loglevel(log_level);
 129   LibLogger::init(__multi_logger);
 130
 131   /* Config stuff */
 132   SQLiteConfiguration *sqliteconf = new SQLiteConfiguration(CONFDIR);
 133   __config = sqliteconf;
 134   __config->load(__argp->arg("c"), __argp->arg("d"));
 135
 136   try {
 137     SQLiteConfiguration::SQLiteValueIterator *i = sqliteconf->modified_iterator();
 138     while (i->next()) {
 139       std::string modtype = i->get_modtype();
 140       if (modtype == "changed") {
 141         __multi_logger->log_warn("FawkesMainThread",  "Default config value CHANGED: %s (was: %s now: %s)",
 142                                  i->path(), i->get_oldvalue().c_str(),
 143                                  i->get_as_string().c_str());
 144       } else if (modtype == "erased") {
 145         __multi_logger->log_warn("FawkesMainThread",  "Default config value ERASED:  %s",
 146                                  i->path());
 147       } else {
 148         __multi_logger->log_debug("FawkesMainThread", "Default config value ADDED:   %s (value: %s)",
 149                                   i->path(), i->get_as_string().c_str());
 150       }
 151     }
 152     delete i;
 153   } catch (Exception &e) {
 154     __multi_logger->log_warn("FawkesMainThread", "Failed to read modified default config values, no dump?");
 155   }
 156
 157   /* Clock */
 158   __clock = Clock::instance();
 159
 160   std::string bb_magic_token = "";
 161   unsigned int bb_size = 2097152;
 162   try {
 163     bb_magic_token = __config->get_string("/fawkes/mainapp/blackboard_magic_token");
 164     __multi_logger->log_info("FawkesMainApp", "BlackBoard magic token defined. "
 165                              "Using shared memory BlackBoard.");
 166   } catch (Exception &e) {
 167     // ignore
 168   }
 169   try {
 170     bb_size = __config->get_uint("/fawkes/mainapp/blackboard_size");
 171   } catch (Exception &e) {
 172     __multi_logger->log_warn("FawkesMainApp", "BlackBoard size not defined. "
 173                              "Will use %u, saving to default DB", bb_size);
 174     __config->set_default_uint("/fawkes/mainapp/blackboard_size", bb_size);
 175   }
 176
 177   unsigned int net_tcp_port     = 1910;
 178   std::string  net_service_name = "Fawkes on %h";
 179   try {
 180     net_tcp_port = __config->get_uint("/fawkes/mainapp/net/tcp_port");
 181   } catch (Exception &e) {}  // ignore, we stick with the default
 182   if (net_tcp_port > 65535)  net_tcp_port = 1910;
 183   try {
 184     net_service_name = __config->get_string("/fawkes/mainapp/net/service_name");
 185   } catch (Exception &e) {}  // ignore, we stick with the default
 186
 187   // Cleanup stale BlackBoard shared memory segments if requested
 188   if ( __argp->has_arg("C") ) {
 189     LocalBlackBoard::cleanup(bb_magic_token.c_str(), /* output with lister? */ true);
 190   }
 191
 192   /* Managers */
 193   try {
 194     if ( bb_magic_token == "") {
 195       __blackboard       = new LocalBlackBoard(bb_size);
 196     } else {
 197       __blackboard       = new LocalBlackBoard(bb_size, bb_magic_token.c_str());
 198     }
 199     __thread_manager     = new FawkesThreadManager();
 200     __aspect_inifin      = new AspectIniFin(__blackboard,
 201                                             __thread_manager->aspect_collector(),
 202                                             __config, __multi_logger, __clock);
 203     __thread_manager->set_inifin(__aspect_inifin, __aspect_inifin);
 204     __plugin_manager     = new PluginManager(__thread_manager, __config,
 205                                              "/fawkes/meta_plugins/");
 206     __network_manager    = new FawkesNetworkManager(__thread_manager, net_tcp_port,
 207                                                     net_service_name.c_str());
 208     __config_nethandler  = new ConfigNetworkHandler(__config, __network_manager->hub());
 209   } catch (Exception &e) {
 210     e.append("Initializing managers failed");
 211     destruct();
 212     throw;
 213   }
 214
 215   __network_logger = new NetworkLogger(__network_manager->hub(), log_level);
 216   __multi_logger->add_logger(__network_logger);
 217
 218   __aspect_inifin->set_fnet_hub( __network_manager->hub() );
 219   __aspect_inifin->set_network_members( __network_manager->nnresolver(),
 220                                         __network_manager->service_publisher(),
 221                                         __network_manager->service_browser() );
 222   __aspect_inifin->set_plugin_manager(__plugin_manager);
 223   __aspect_inifin->set_mainloop_employer(this);
 224   __aspect_inifin->set_logger_employer(this);
 225   __aspect_inifin->set_blocked_timing_executor(__thread_manager);
 226
 227   __plugin_nethandler = new PluginNetworkHandler(__plugin_manager,
 228                                                  __network_manager->hub() );
 229   __plugin_nethandler->start();
 230
 231   __blackboard->start_nethandler(__network_manager->hub());
 232
 233   __loop_start = new Time(__clock);
 234   __loop_end   = new Time(__clock);
 235   try {
 236     __max_thread_time_usec = __config->get_uint("/fawkes/mainapp/max_thread_time");
 237   } catch (Exception &e) {
 238     __max_thread_time_usec = 30000;
 239     __multi_logger->log_info("FawkesMainApp", "Maximum thread time not set, assuming 30ms.");
 240   }
 241   __max_thread_time_nanosec = __max_thread_time_usec * 1000;
 242
 243   __time_wait = NULL;
 244   try {
 245     __desired_loop_time_usec = __config->get_uint("/fawkes/mainapp/desired_loop_time");
 246     if ( __desired_loop_time_usec > 0 ) {
 247       __time_wait = new TimeWait(__clock, __desired_loop_time_usec);
 248     }
 249   } catch (Exception &e) {
 250     __desired_loop_time_usec = 0;
 251     __multi_logger->log_info("FawkesMainApp", "Desired loop time not set, assuming 0");
 252   }
 253
 254   __desired_loop_time_sec  = (float)__desired_loop_time_usec / 1000000.f;
 255
 256   try {
 257     __enable_looptime_warnings = __config->get_bool("/fawkes/mainapp/enable_looptime_warnings");
 258     if(!__enable_looptime_warnings) {
 259       __multi_logger->log_debug(name(), "loop time warnings are disabled");
 260     }
 261   } catch(Exception &e) {
 262     __enable_looptime_warnings = true;
 263   }
 264 }
 265
 266
 267 /** Destructor. */
 268 FawkesMainThread::~FawkesMainThread()
 269 {
 270   destruct();
 271 }
 272
 273
 274 /** Destruct.
 275  * Mimics destructor, but may be called in ctor exceptions.
 276  */
 277 void
 278 FawkesMainThread::destruct()
 279 {
 280   // Must delete network logger first since network manager has to die before the LibLogger
 281   // is finalized.
 282   __multi_logger->remove_logger(__network_logger);
 283   delete __network_logger;
 284
 285   if ( __plugin_nethandler ) {
 286     __plugin_nethandler->cancel();
 287     __plugin_nethandler->join();
 288     delete __plugin_nethandler;
 289   }
 290   delete __plugin_manager;
 291   delete __blackboard;
 292   delete __config_nethandler;
 293   delete __config;
 294   delete __network_manager;
 295   delete __thread_manager;
 296   delete __aspect_inifin;
 297   delete __time_wait;
 298   delete __loop_start;
 299   delete __loop_end;
 300
 301   delete __mainloop_barrier;
 302   delete __mainloop_mutex;
 303
 304   // implicitly frees multi_logger and all sub-loggers
 305   LibLogger::finalize();
 306
 307   Clock::finalize();
 308 }
 309
 310 void
 311 FawkesMainThread::once()
 312 {
 313   if ( __argp->has_arg("p") ) {
 314     try {
 315       __plugin_manager->load(__argp->arg("p"));
 316     } catch (Exception &e) {
 317       __multi_logger->log_error("FawkesMainThread", "Failed to load plugins %s, "
 318                                 "exception follows", __argp->arg("p"));
 319       __multi_logger->log_error("FawkesMainThread", e);
 320     }
 321   } else {
 322     try {
 323       __plugin_manager->load("default");
 324     } catch (PluginLoadException &e) {
 325       if (e.plugin_name() != "default") {
 326         // only print if name is not default, i.e. one of the plugins that
 327         // the default meta plugin
 328         __multi_logger->log_error("FawkesMainThread", "Failed to load default "
 329                                   "plugins, exception follows");
 330         __multi_logger->log_error("FawkesMainThread", e);
 331       }
 332     } catch (Exception &e) {
 333         __multi_logger->log_error("FawkesMainThread", "Failed to load default "
 334                                   "plugins, exception follows");
 335         __multi_logger->log_error("FawkesMainThread", e);
 336     }
 337   }
 338 }
 339
 340 void
 341 FawkesMainThread::set_mainloop_thread(Thread *mainloop_thread)
 342 {
 343   loopinterrupt_antistarve_mutex->lock();
 344   __mainloop_mutex->lock();
 345   if (mainloop_thread)  __mainloop_barrier->interrupt();
 346   __mainloop_thread = mainloop_thread;
 347   __mainloop_mutex->unlock();
 348   __thread_manager->interrupt_timed_thread_wait();
 349   loopinterrupt_antistarve_mutex->unlock();
 350 }
 351
 352
 353 void
 354 FawkesMainThread::add_logger(Logger *logger)
 355 {
 356   __multi_logger->add_logger(logger);
 357 }
 358
 359
 360 void
 361 FawkesMainThread::remove_logger(Logger *logger)
 362 {
 363   __multi_logger->remove_logger(logger);
 364 }
 365
 366
 367 void
 368 FawkesMainThread::loop()
 369 {
 370   if (unlikely(__mainloop_thread != NULL)) {
 371     try {
 372       __mainloop_mutex->lock();
 373       if (likely(__mainloop_thread != NULL)) {
 374         __mainloop_thread->wakeup(__mainloop_barrier);
 375         __mainloop_barrier->wait();
 376       }
 377       __mainloop_mutex->unlock();
 378     } catch (Exception &e) {
 379       __multi_logger->log_warn("FawkesMainThread", e);
 380     }
 381
 382   } else {
 383     try {
 384       if ( ! __thread_manager->timed_threads_exist() ) {
 385         __multi_logger->log_debug("FawkesMainThread", "No timed threads exist, waiting");
 386         try {
 387           __thread_manager->wait_for_timed_threads();
 388           __multi_logger->log_debug("FawkesMainThread", "Timed threads have been added, "
 389                                     "running main loop now");
 390         } catch (InterruptedException &e) {
 391           __multi_logger->log_debug("FawkesMainThread", "Waiting for timed threads interrupted");
 392           return;
 393         }
 394       }
 395
 396       if ( __time_wait ) {
 397         __time_wait->mark_start();
 398       }
 399       __loop_start->stamp_systime();
 400
 401       try {
 402         __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_PRE_LOOP,       __max_thread_time_nanosec );
 403         __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_SENSOR,         __max_thread_time_nanosec );
 404         __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_SENSOR_PROCESS, __max_thread_time_nanosec );
 405         __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_WORLDSTATE,     __max_thread_time_nanosec );
 406         __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_THINK,          __max_thread_time_nanosec );
 407         __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_SKILL,          __max_thread_time_nanosec );
 408         __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_ACT,            __max_thread_time_nanosec );
 409         __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_ACT_EXEC,       __max_thread_time_nanosec );
 410         __thread_manager->wakeup_and_wait( BlockedTimingAspect::WAKEUP_HOOK_POST_LOOP,      __max_thread_time_nanosec );
 411       } catch (Exception &e) {
 412         if(__enable_looptime_warnings) {
 413           __multi_logger->log_error("FawkesMainThread", e);
 414         }
 415       }
 416
 417       test_cancel();
 418
 419       __thread_manager->try_recover(__recovered_threads);
 420       if ( ! __recovered_threads.empty() ) {
 421         // threads have been recovered!
 422         __multi_logger->log_error(name(), "Threads recovered %zu", __recovered_threads.size());
 423         if(__enable_looptime_warnings) {
 424           if ( __recovered_threads.size() == 1 ) {
 425             __multi_logger->log_warn("FawkesMainThread", "The thread %s could be "
 426                                      "recovered and resumes normal operation",
 427                                      __recovered_threads.front().c_str());
 428           } else {
 429             std::string s;
 430             for (std::list<std::string>::iterator i = __recovered_threads.begin();
 431                  i != __recovered_threads.end(); ++i) {
 432               s += *i + " ";
 433             }
 434
 435             __multi_logger->log_warn("FawkesMainThread", "The following threads could be "
 436                                      "recovered and resumed normal operation: %s", s.c_str());
 437           }
 438         }
 439         __recovered_threads.clear();
 440       }
 441
 442       if (__desired_loop_time_sec > 0) {
 443         __loop_end->stamp_systime();
 444         float loop_time = *__loop_end - __loop_start;
 445         if(__enable_looptime_warnings) {
 446           if (loop_time > __desired_loop_time_sec) {
 447             __multi_logger->log_warn("FawkesMainThread", "Loop time exceeded, "
 448                 "desired: %f sec (%u usec),  actual: %f sec",
 449                 __desired_loop_time_sec, __desired_loop_time_usec,
 450                 loop_time);
 451           }
 452         }
 453       }
 454       if ( __time_wait ) {
 455         __time_wait->wait_systime();
 456       } else {
 457         yield();
 458       }
 459     } catch (Exception &e) {
 460       __multi_logger->log_warn("FawkesMainThread",
 461                                "Exception caught while executing default main "
 462                                "loop, ignoring.");
 463       __multi_logger->log_warn("FawkesMainThread", e);
 464     } catch (std::exception &e) {
 465       __multi_logger->log_warn("FawkesMainThread",
 466                                "STL Exception caught while executing default main "
 467                                "loop, ignoring. (what: %s)", e.what());
 468     }
 469     // catch ... is not a good idea, would catch cancellation exception
 470     // at least needs to be rethrown.
 471   }
 472 }