00001
00002
00003
00004
00005
00006
00007
00008
00009
00010
00011
00012
00013
00014
00015
00016
00017
00018
00019
00020
00021
00022
00023 #include "exec_thread.h"
00024
00025 #include <core/exceptions/software.h>
00026 #include <core/exceptions/system.h>
00027 #include <core/threading/mutex.h>
00028 #include <utils/logging/component.h>
00029 #ifdef SKILLER_TIMETRACKING
00030 # include <utils/time/tracker.h>
00031 #endif
00032
00033 #include <lua/context.h>
00034 #include <lua/interface_importer.h>
00035
00036 #include <interfaces/SkillerInterface.h>
00037 #include <interfaces/SkillerDebugInterface.h>
00038
00039 #include <lua.hpp>
00040 #include <tolua++.h>
00041
00042 #include <string>
00043 #include <cstring>
00044
00045 using namespace std;
00046 using namespace fawkes;
00047
00048
00049
00050
00051
00052
00053
00054
00055
00056
00057 SkillerExecutionThread::SkillerExecutionThread()
00058 : Thread("SkillerExecutionThread", Thread::OPMODE_WAITFORWAKEUP),
00059 BlockedTimingAspect(BlockedTimingAspect::WAKEUP_HOOK_SKILL),
00060 BlackBoardInterfaceListener("SkillerExecutionThread")
00061 {
00062 __continuous_run = false;
00063 __continuous_reset = false;
00064 __error_written = false;
00065
00066 __lua = NULL;
00067 }
00068
00069
00070
00071 SkillerExecutionThread::~SkillerExecutionThread()
00072 {
00073 }
00074
00075
00076
00077
00078
00079 void
00080 SkillerExecutionThread::init_failure_cleanup()
00081 {
00082 try {
00083 if ( __skiller_if ) blackboard->close(__skiller_if);
00084 if ( __skdbg_if ) blackboard->close(__skdbg_if);
00085
00086 delete __lua_ifi;
00087 delete __clog;
00088
00089 } catch (...) {
00090
00091
00092
00093 logger->log_error(name(), "Really screwed up while finalizing, aborting cleanup. "
00094 "Fawkes is no longer in a clean state. Restart!");
00095 }
00096 }
00097
00098
00099 void
00100 SkillerExecutionThread::init()
00101 {
00102 __last_exclusive_controller = 0;
00103 __reader_just_left = false;
00104 __continuous_run = false;
00105 __continuous_reset = false;
00106 __skdbg_what = "ACTIVE";
00107 __skdbg_graphdir = "TB";
00108 __skdbg_graphcolored = true;
00109 __clog = NULL;
00110 __sksf_pushed = false;
00111
00112 try {
00113 __cfg_skillspace = config->get_string("/skiller/skillspace");
00114 __cfg_watch_files = config->get_bool("/skiller/watch_files");
00115 } catch (Exception &e) {
00116 e.append("Insufficient configuration for Skiller");
00117 throw;
00118 }
00119
00120 logger->log_debug("SkillerExecutionThread", "Skill space: %s", __cfg_skillspace.c_str());
00121
00122 __clog = new ComponentLogger(logger, "SkillerLua");
00123
00124 __lua = NULL;
00125 __lua_ifi = NULL;
00126 __skiller_if = NULL;
00127 __skdbg_if = NULL;
00128
00129 std::string reading_prefix = "/skiller/interfaces/" + __cfg_skillspace + "/reading/";
00130 std::string writing_prefix = "/skiller/interfaces/" + __cfg_skillspace + "/writing/";
00131
00132 try {
00133 __skiller_if = blackboard->open_for_writing<SkillerInterface>("Skiller");
00134 __skdbg_if = blackboard->open_for_writing<SkillerDebugInterface>("Skiller");
00135
00136 __lua = new LuaContext(__cfg_watch_files);
00137
00138 __lua_ifi = new LuaInterfaceImporter(__lua, blackboard, config, logger);
00139 __lua_ifi->open_reading_interfaces(reading_prefix);
00140 __lua_ifi->open_writing_interfaces(writing_prefix);
00141 __lua_ifi->add_interface("skdbg", __skdbg_if);
00142 __lua_ifi->add_interface("skiller", __skiller_if);
00143
00144 __lua->add_package_dir(LUADIR);
00145 __lua->add_cpackage_dir(LUALIBDIR);
00146
00147 __lua->add_package("fawkesutils");
00148 __lua->add_package("fawkesconfig");
00149 __lua->add_package("fawkesinterface");
00150 __lua->add_package("fawkesgeometry");
00151
00152 __lua->set_string("SKILLSPACE", __cfg_skillspace.c_str());
00153 __lua->set_usertype("config", config, "Configuration", "fawkes");
00154 __lua->set_usertype("logger", __clog, "ComponentLogger", "fawkes");
00155 __lua->set_usertype("clock", clock, "Clock", "fawkes");
00156
00157 __lua_ifi->push_interfaces();
00158
00159 __lua->set_start_script(LUADIR"/skiller/start.lua");
00160
00161 __skiller_if->set_skill_string("");
00162 __skiller_if->set_status(SkillerInterface::S_INACTIVE);
00163 __skiller_if->write();
00164
00165 __skdbg_if->set_graph("");
00166 __skdbg_if->set_graph_fsm("ACTIVE");
00167
00168 } catch (Exception &e) {
00169 init_failure_cleanup();
00170 throw;
00171 }
00172
00173
00174 bbil_add_reader_interface(__skiller_if);
00175 blackboard->register_listener(this, BlackBoard::BBIL_FLAG_READER);
00176
00177 #ifdef SKILLER_TIMETRACKING
00178 __tt = new TimeTracker();
00179 __ttc_total = __tt->add_class("Total");
00180 __ttc_msgproc = __tt->add_class("Message Processing");
00181 __ttc_luaprep = __tt->add_class("Lua Preparation");
00182 __ttc_luaexec = __tt->add_class("Lua Execution");
00183 __ttc_publish = __tt->add_class("Publishing");
00184 __tt_loopcount = 0;
00185 #endif
00186 }
00187
00188
00189 void
00190 SkillerExecutionThread::finalize()
00191 {
00192 #ifdef SKILLER_TIMETRACKING
00193 delete __tt;
00194 #endif
00195 delete __lua_ifi;
00196
00197 blackboard->unregister_listener(this);
00198 blackboard->close(__skiller_if);
00199 blackboard->close(__skdbg_if);
00200
00201 delete __lua;
00202 delete __clog;
00203 }
00204
00205
00206 void
00207 SkillerExecutionThread::bb_interface_reader_removed(Interface *interface,
00208 unsigned int instance_serial) throw()
00209 {
00210 if ( instance_serial == __skiller_if->exclusive_controller() ) {
00211 logger->log_debug("SkillerExecutionThread", "Controlling interface instance was closed, "
00212 "revoking exclusive control");
00213
00214 __last_exclusive_controller = instance_serial;
00215 __reader_just_left = true;
00216
00217 __skiller_if->set_exclusive_controller(0);
00218 __skiller_if->write();
00219 }
00220 }
00221
00222
00223
00224
00225
00226
00227
00228 void
00229 SkillerExecutionThread::publish_skill_status(std::string &curss)
00230 {
00231 const char *sst = "Unknown";
00232 LUA_INTEGER running = 0, final = 0, failed = 0;
00233
00234 SkillerInterface::SkillStatusEnum old_status = __skiller_if->status();
00235 SkillerInterface::SkillStatusEnum new_status = __skiller_if->status();
00236
00237 try {
00238
00239 if ( curss == "" ) {
00240
00241 sst = "S_INACTIVE/empty";
00242 __skiller_if->set_status(SkillerInterface::S_INACTIVE);
00243
00244 } else {
00245 __lua->get_global("skillenv");
00246
00247 __lua->get_field(-1, "get_status");
00248 if ( __lua->is_function(-1) ) {
00249 __lua->pcall(0, 3);
00250 running = __lua->to_integer(-3);
00251 final = __lua->to_integer(-2);
00252 failed = __lua->to_integer(-1);
00253
00254 __lua->pop(4);
00255 } else {
00256 __lua->pop(2);
00257 throw LuaRuntimeException("C++:publish_skill_status", "skillenv.get_status is not a function");
00258 }
00259
00260 if ( failed > 0 ) {
00261 sst = "S_FAILED";
00262 new_status = SkillerInterface::S_FAILED;
00263 } else if ( (final > 0) && (running == 0) ) {
00264 sst = "S_FINAL";
00265 new_status = SkillerInterface::S_FINAL;
00266 } else if ( running > 0 ) {
00267 sst = "S_RUNNING";
00268 new_status = SkillerInterface::S_RUNNING;
00269 } else {
00270
00271 sst = "S_INACTIVE";
00272 new_status = SkillerInterface::S_INACTIVE;
00273 }
00274 }
00275
00276 if ( (old_status != new_status) ||
00277 (curss != __skiller_if->skill_string()) ||
00278 (__skiller_if->is_continuous() != __continuous_run) ) {
00279
00280
00281
00282
00283
00284
00285
00286 __skiller_if->set_skill_string(curss.c_str());
00287 __skiller_if->set_continuous(__continuous_run);
00288
00289 __skiller_if->set_status(new_status);
00290
00291 if ( ! __error_written && (new_status == SkillerInterface::S_FAILED) ) {
00292 publish_error();
00293 __error_written = __continuous_run;
00294 } else if (new_status == SkillerInterface::S_RUNNING ||
00295 new_status == SkillerInterface::S_FINAL) {
00296 __skiller_if->set_error("");
00297 __error_written = false;
00298 }
00299
00300 __skiller_if->write();
00301 }
00302
00303 } catch (Exception &e) {
00304 logger->log_error("SkillerExecutionThread", "Failed to retrieve skill status");
00305 logger->log_error("SkillerExecutionThread", e);
00306 try {
00307 __skiller_if->set_status(SkillerInterface::S_FAILED);
00308 } catch (Exception &e2) {
00309 logger->log_error("SkillerExecutionThread", "Failed to set FAILED as skill "
00310 "status value during error handling");
00311 logger->log_error("SkillerExecutionThread", e2);
00312 }
00313 }
00314
00315 }
00316
00317
00318 void
00319 SkillerExecutionThread::publish_skdbg()
00320 {
00321 try {
00322 __lua->do_string("skillenv.write_skiller_debug(interfaces.writing.skdbg, \"%s\", \"%s\", %s)",
00323 __skdbg_what.c_str(), __skdbg_graphdir.c_str(),
00324 __skdbg_graphcolored ? "true" : "false");
00325 } catch (Exception &e) {
00326 logger->log_warn("SkillerExecutionThread", "Error writing graph");
00327 logger->log_warn("SkillerExecutionThread", e);
00328 }
00329 }
00330
00331 void
00332 SkillerExecutionThread::lua_loop_reset()
00333 {
00334 try {
00335 __lua->do_string("skillenv.reset_loop()");
00336 } catch (Exception &e) {
00337 logger->log_warn("SkillerExecutionThread", "Lua Loop Reset failed");
00338 logger->log_warn("SkillerExecutionThread", e);
00339 }
00340 }
00341
00342
00343 void
00344 SkillerExecutionThread::publish_error()
00345 {
00346 try {
00347 __lua->do_string("skillenv.write_fsm_error(skillenv.get_skill_fsm(skillenv.get_active_skills()), interfaces.writing.skiller)");
00348 } catch (Exception &e) {
00349 logger->log_warn("SkillerExecutionThread", "Error writing error");
00350 logger->log_warn("SkillerExecutionThread", e);
00351 __skiller_if->set_error("Failed to set Lua error");
00352 __skiller_if->write();
00353 }
00354 }
00355
00356
00357 void
00358 SkillerExecutionThread::process_skdbg_messages()
00359 {
00360 while ( ! __skdbg_if->msgq_empty() ) {
00361 if ( __skdbg_if->msgq_first_is<SkillerDebugInterface::SetGraphMessage>() ) {
00362 SkillerDebugInterface::SetGraphMessage *m = __skdbg_if->msgq_first<SkillerDebugInterface::SetGraphMessage>();
00363 logger->log_warn(name(), "Setting skiller debug what to: %s", m->graph_fsm());
00364 __skdbg_what = m->graph_fsm();
00365 } else if (__skdbg_if->msgq_first_is<SkillerDebugInterface::SetGraphDirectionMessage>() ) {
00366 SkillerDebugInterface::SetGraphDirectionMessage *m = __skdbg_if->msgq_first<SkillerDebugInterface::SetGraphDirectionMessage>();
00367 switch (m->graph_dir()) {
00368 case SkillerDebugInterface::GD_BOTTOM_TOP: __skdbg_graphdir = "BT"; break;
00369 case SkillerDebugInterface::GD_LEFT_RIGHT: __skdbg_graphdir = "LR"; break;
00370 case SkillerDebugInterface::GD_RIGHT_LEFT: __skdbg_graphdir = "RL"; break;
00371 default: __skdbg_graphdir = "TB"; break;
00372 }
00373
00374 } else if (__skdbg_if->msgq_first_is<SkillerDebugInterface::SetGraphColoredMessage>() ) {
00375 SkillerDebugInterface::SetGraphColoredMessage *m = __skdbg_if->msgq_first<SkillerDebugInterface::SetGraphColoredMessage>();
00376 __skdbg_graphcolored = m->is_graph_colored();
00377 }
00378
00379 __skdbg_if->msgq_pop();
00380 }
00381 }
00382
00383
00384 void
00385 SkillerExecutionThread::loop()
00386 {
00387 #ifdef SKILLER_TIMETRACKING
00388 __tt->ping_start(__ttc_total);
00389 #endif
00390 #ifdef HAVE_INOTIFY
00391 __lua->process_fam_events();
00392 #endif
00393 __lua_ifi->read();
00394
00395
00396 std::string curss = "";
00397
00398 unsigned int excl_ctrl = __skiller_if->exclusive_controller();
00399 bool write_skiller_if = false;
00400 bool last_was_continuous = __continuous_run;
00401
00402 #ifdef SKILLER_TIMETRACKING
00403 __tt->ping_start(__ttc_msgproc);
00404 #endif
00405 process_skdbg_messages();
00406
00407 while ( ! __skiller_if->msgq_empty() ) {
00408 if ( __skiller_if->msgq_first_is<SkillerInterface::AcquireControlMessage>() ) {
00409 Message *m = __skiller_if->msgq_first();
00410 if ( excl_ctrl == 0 ) {
00411 logger->log_debug("SkillerExecutionThread", "%s is new exclusive controller",
00412 m->sender_thread_name());
00413 __skiller_if->set_exclusive_controller(m->sender_id());
00414 write_skiller_if = true;
00415 excl_ctrl = m->sender_id();
00416 } else {
00417 logger->log_warn("SkillerExecutionThread", "%s tried to acquire exclusive control, "
00418 "but another controller exists already", m->sender_thread_name());
00419 }
00420
00421 } else if ( __skiller_if->msgq_first_is<SkillerInterface::ReleaseControlMessage>() ) {
00422 Message *m = __skiller_if->msgq_first();
00423 if ( excl_ctrl == m->sender_id() ) {
00424 logger->log_debug("SkillerExecutionThread", "%s releases exclusive control",
00425 m->sender_thread_name());
00426
00427 if ( __continuous_run ) {
00428 __continuous_run = false;
00429 __continuous_reset = true;
00430 }
00431 __last_exclusive_controller = __skiller_if->exclusive_controller();
00432 __skiller_if->set_exclusive_controller(0);
00433 write_skiller_if = true;
00434 excl_ctrl = 0;
00435 } else {
00436 if ( !__reader_just_left || (m->sender_id() != __last_exclusive_controller)) {
00437 logger->log_warn("SkillerExecutionThread", "%s tried to release exclusive control, "
00438 "it's not the controller", m->sender_thread_name());
00439 }
00440 }
00441 } else if ( __skiller_if->msgq_first_is<SkillerInterface::ExecSkillMessage>() ) {
00442 SkillerInterface::ExecSkillMessage *m = __skiller_if->msgq_first<SkillerInterface::ExecSkillMessage>();
00443
00444 if ( m->sender_id() == excl_ctrl ) {
00445 if ( curss != "" ) {
00446 logger->log_warn("SkillerExecutionThread", "More than one skill string enqueued, "
00447 "ignoring previous string (%s).", curss.c_str());
00448 }
00449 logger->log_debug("SkillerExecutionThread", "%s wants me to execute '%s'",
00450 m->sender_thread_name(), m->skill_string());
00451
00452 if ( __continuous_run ) {
00453 __continuous_run = false;
00454 __continuous_reset = true;
00455 }
00456 curss = m->skill_string();
00457 } else {
00458 logger->log_debug("SkillerExecutionThread", "%s tries to exec while not controller",
00459 m->sender_thread_name());
00460 }
00461
00462 } else if ( __skiller_if->msgq_first_is<SkillerInterface::ExecSkillContinuousMessage>() ) {
00463 SkillerInterface::ExecSkillContinuousMessage *m = __skiller_if->msgq_first<SkillerInterface::ExecSkillContinuousMessage>();
00464
00465 if ( m->sender_id() == excl_ctrl ) {
00466 if ( curss != "" ) {
00467 logger->log_warn("SkillerExecutionThread", "More than one skill string enqueued, "
00468 "ignoring successive string (%s).", m->skill_string());
00469 } else {
00470 logger->log_debug("SkillerExecutionThread", "%s wants me to continuously execute '%s'",
00471 m->sender_thread_name(), m->skill_string());
00472
00473 curss = m->skill_string();
00474 __continuous_reset = last_was_continuous;
00475 __continuous_run = true;
00476 }
00477 } else {
00478 logger->log_debug("SkillerExecutionThread", "%s tries to exec while not controller",
00479 m->sender_thread_name());
00480 }
00481
00482 } else if ( __skiller_if->msgq_first_is<SkillerInterface::StopExecMessage>() ) {
00483 SkillerInterface::StopExecMessage *m = __skiller_if->msgq_first<SkillerInterface::StopExecMessage>();
00484
00485 if ( (m->sender_id() == excl_ctrl) ||
00486 (__reader_just_left && (m->sender_id() == __last_exclusive_controller)) ) {
00487 logger->log_debug("SkillerExecutionThread", "Stopping continuous execution");
00488 if ( __continuous_run ) {
00489 __continuous_run = false;
00490 __continuous_reset = true;
00491 curss = "";
00492 }
00493 } else {
00494 logger->log_debug("SkillerExecutionThread", "%s tries to stop exec while not controller",
00495 m->sender_thread_name());
00496 }
00497 } else {
00498 logger->log_warn("SkillerExecutionThread", "Unhandled message of type %s in "
00499 "skiller interface", __skiller_if->msgq_first()->type());
00500 }
00501
00502 __skiller_if->msgq_pop();
00503 }
00504
00505 if ( __continuous_run && (curss == "") ) {
00506 curss = __skiller_if->skill_string();
00507 }
00508
00509 #ifdef SKILLER_TIMETRACKING
00510 __tt->ping_end(__ttc_msgproc);
00511 #endif
00512
00513 if ( __continuous_reset ) {
00514 logger->log_debug("SkillerExecutionThread", "Continuous reset forced"); try {
00515 if (__sksf_pushed) {
00516 __sksf_pushed = false;
00517 __lua->pop(1);
00518 }
00519 __lua->do_string("skillenv.reset_all()");
00520 } catch (Exception &e) {
00521 logger->log_warn("SkillerExecutionThread", "Caught exception while resetting skills, ignored, output follows");
00522 logger->log_warn("SkillerExecutionThread", e);
00523 }
00524
00525 __skiller_if->set_status(SkillerInterface::S_INACTIVE);
00526 __skiller_if->set_skill_string("");
00527
00528
00529
00530 __error_written = false;
00531 __continuous_reset = false;
00532 write_skiller_if = true;
00533 }
00534
00535 if ( write_skiller_if ) __skiller_if->write();
00536
00537 if ( curss != "" ) {
00538
00539
00540 #ifdef SKILLER_TIMETRACKING
00541 __tt->ping_start(__ttc_luaprep);
00542 #endif
00543
00544
00545 if ( __continuous_run ) {
00546
00547
00548 try {
00549 __lua->do_string("skillenv.reset_status()");
00550 } catch (Exception &e) {
00551 logger->log_warn("SkillerExecutionThread", "Caught exception while resetting status, ignored, output follows");
00552 logger->log_warn("SkillerExecutionThread", e);
00553 }
00554 }
00555
00556 try {
00557 if (! __sksf_pushed) {
00558
00559 __lua->load_string(curss.c_str());
00560 __lua->do_string("return skillenv.gensandbox()");
00561 __lua->setfenv();
00562 __sksf_pushed = true;
00563 }
00564 #ifdef SKILLER_TIMETRACKING
00565 __tt->ping_end(__ttc_luaprep);
00566 __tt->ping_start(__ttc_luaexec);
00567 #endif
00568 __lua->push_value(-1);
00569 __lua->pcall();
00570
00571 } catch (Exception &e) {
00572 logger->log_error("SkillerExecutionThread", e);
00573 __skiller_if->set_error("Skill string execution failed with Lua error, see log");
00574 __skiller_if->write();
00575 __continuous_reset = true;
00576 __continuous_run = false;
00577 }
00578 #ifdef SKILLER_TIMETRACKING
00579 __tt->ping_end(__ttc_luaexec);
00580 #endif
00581
00582 if ( ! __continuous_run ) {
00583
00584 logger->log_debug("SkillerExecutionThread", "Resetting skills");
00585 try {
00586 if (__sksf_pushed) {
00587 __sksf_pushed = false;
00588 __lua->pop(1);
00589 }
00590 __lua->do_string("skillenv.reset_all()");
00591 } catch (Exception &e) {
00592 logger->log_warn("SkillerExecutionThread", "Caught exception while resetting skills, ignored, output follows");
00593 logger->log_warn("SkillerExecutionThread", e);
00594 }
00595 }
00596
00597 }
00598
00599 #ifdef SKILLER_TIMETRACKING
00600 __tt->ping_start(__ttc_publish);
00601 #endif
00602 publish_skill_status(curss);
00603 publish_skdbg();
00604 lua_loop_reset();
00605
00606 __reader_just_left = false;
00607
00608 __lua_ifi->write();
00609 #ifdef SKILLER_TIMETRACKING
00610 __tt->ping_end(__ttc_publish);
00611 __tt->ping_end(__ttc_total);
00612 if (++__tt_loopcount >= SKILLER_TT_MOD) {
00613
00614 __tt_loopcount = 0;
00615 __tt->print_to_stdout();
00616 }
00617 #endif
00618 }