Dynamic lib selection and deployment
[anna.git] / example / diameter / launcher / testing / TestStep.cpp
index b1da8fb..fdbd798 100644 (file)
 // Standard
 #include <string>
 #include <iostream>
-#include <stdio.h>
 #include <errno.h>
 
+#include <signal.h>    // sigaction, sigemptyset, struct sigaction, SIGCHLD, SA_RESTART, SA_NOCLDSTOP
+#include <stdio.h>     // perror
+#include <stdlib.h>    // exit
+#include <sys/wait.h>  // waitpid, pid_t, WNOHANG
+
+// cmd with fork:
+#include <sys/types.h>
+#include <unistd.h>
+
+
 // Project
 #include <anna/xml/Compiler.hpp>
 #include <anna/core/util/Millisecond.hpp>
 #include <anna/diameter.comm/Message.hpp>
+#include <anna/diameter.comm/ClientSession.hpp>
+#include <anna/diameter.comm/ServerSession.hpp>
+#include <anna/diameter.comm/Server.hpp>
 #include <anna/core/tracing/Logger.hpp>
 #include <anna/diameter/codec/functions.hpp>
 #include <anna/diameter/helpers/base/functions.hpp>
 
 // Process
-#include <RealmNode.hpp>
+#include <OriginHost.hpp>
 #include <MyDiameterEntity.hpp>
 #include <MyLocalServer.hpp>
 #include <TestStep.hpp>
-#include <Launcher.hpp>
 #include <TestCase.hpp>
 #include <TestManager.hpp>
 #include <TestTimer.hpp>
+#include <Launcher.hpp>
 
 
 namespace {
+
+  void handle_sigchld(int sig) {
+    while (waitpid((pid_t)(-1 /* any child (the only) */), 0, WNOHANG|WNOWAIT) > 0) {}
+  }
+
   void cmdRunOnThread (TestStepCmd *step, const std::string &cmd) {
+
+    // Thread running:
     step->setThreadRunning(true);
-    int rc = system(cmd.c_str());
-    if (rc < 0 && errno == ECHILD) rc = 0; // ignore, it could happens
-    // I know one reason for this is that SICCHLD is set to SIG_IGN but this
-    // should not be the case here. SIGCHLD is explicity set to SIG_DFL
-    // using a sigaction before the call to system(). (Although it is
-    // normally set to SIG_IGN). There should not be any other threads
-    // messing about with SIGCHLD.
-
-    if (rc < 0) {
-      step->setErrorMsg(anna::functions::asString("errno = %d", errno));
-      //std::terminate;
+
+    int status = -2;
+
+    struct sigaction sa;
+    sa.sa_handler = &handle_sigchld;
+    sigemptyset(&sa.sa_mask);
+    sa.sa_flags = SA_RESTART | SA_NOCLDSTOP;
+    if (sigaction(SIGCHLD, &sa, 0) != -1) {
+      status = system(cmd.c_str());
+      /* POPEN version:
+          char readbuf[256];
+          FILE *fp = popen(cmd.c_str(), "r");
+          if (fp) {
+            while(fgets(readbuf, sizeof(readbuf), fp))
+              step->appendOutput("\n");
+              step->appendOutput(readbuf);
+              status = pclose(fp);
+          }
+          else {
+            status = -1;
+          }
+       */
     }
     else {
-      rc >>= 8; // divide by 256
+      perror(0);
+    }
+    // This can be implemented portably and somewhat more concisely with the signal function if you prefer:
+    // if (signal(SIGCHLD, SIG_IGN) == SIG_ERR) {
+    //   perror(0);
+    //   exit(1);
+    // }
+
+    if (status < 0) {
+      char buf[256];
+      char const * str = strerror_r(errno, buf, 256);
+      step->setErrorMsg(anna::functions::asString("errno = %d (%s)", errno, str));
     }
 
-    step->setResultCode(rc);
+    step->setResultCode(WEXITSTATUS(status)); // rc = status >>= 8; // divide by 256
     step->complete();
-    // TODO: timeout the system call
+    // TODO: terminate thread when deprecated (RT signal ?)
+    // TODO: mutex the step while setting data here !!
+  }
+
+  void cmdRunOnThreadWithFork (TestStepCmd *step, const std::string &cmd) {
+
+    // Thread running:
+    step->setThreadRunning(true);
+
+    pid_t cpid, w;
+    int status = -2;
+
+    if ((cpid = fork()) < 0) {
+      step->setErrorMsg("Error in fork()");
+    }
+    else if (cpid == 0) {
+      // child
+      status = system(cmd.c_str());
+      _exit(WEXITSTATUS(status));
+    }
+    else {
+      // parent
+      step->setChildPid(cpid);
+      do {
+        w = waitpid(cpid, &status, WUNTRACED | WCONTINUED);
+        if (w != -1) {
+
+          if (WIFEXITED(status)) {
+            step->setResultCode(WEXITSTATUS(status)); // rc = status >>= 8; // divide by 256
+            break;
+          }
+          else if (WIFSIGNALED(status)) {
+            step->setErrorMsg(anna::functions::asString("killed by signal %d", WTERMSIG(status)));
+            step->setResultCode(128 + WTERMSIG(status));
+            break;
+          } else if (WIFSTOPPED(status)) {
+            step->setErrorMsg(anna::functions::asString("stopped by signal %d", WSTOPSIG(status)));
+          } else if (WIFCONTINUED(status)) {
+            step->setErrorMsg("continued");
+          }
+        }
+        else {
+          step->setErrorMsg("waitpid error");
+          step->setResultCode(-1);
+          break;
+        }
+      } while (!WIFEXITED(status) && !WIFSIGNALED(status));
+
+      step->complete();
+    }
+  }
+
+  bool decodeMessage(const anna::DataBlock &message, anna::diameter::codec::Message &messageCodec) throw() {
+
+    if (message.isEmpty())
+      return false;
+
+    bool result = true;
+    try {
+      messageCodec.clear();
+      messageCodec.decode(message);
+    }
+    catch (anna::RuntimeException &ex) {
+      ex.trace();
+      result = false;
+    }
+
+    return result;
   }
 }
 
@@ -69,13 +177,27 @@ void TestStep::initialize(TestCase *testCase) {
   a_number = testCase->steps() + 1; // testCase is not NULL
 }
 
+bool TestStep::decodeMessage(bool trust) throw() {
+  if (a_messageCodec) return true;
+  a_messageCodec = new anna::diameter::codec::Message;
+  if (::decodeMessage(a_message, *a_messageCodec)) return true;
+  if (trust) {
+    LOGDEBUG(anna::Logger::debug("Error DECODING, but trusting it ...", ANNA_FILE_LOCATION));
+    return true;
+  }
+
+  delete a_messageCodec;
+  a_messageCodec = NULL;
+  return false;
+}
+
 const char* TestStep::asText(const Type::_v type)
 throw() {
-  static const char* text [] = { "Unconfigured", "Timeout", "Sendxml2e", "Sendxml2c", "Delay", "Wait", "Cmd" };
+  static const char* text [] = { "Unconfigured", "Timeout", "Sendxml2e", "Sendxml2c", "Delay", "Wait", "Command" };
   return text [type];
 }
 
-anna::xml::Node* TestStep::asXML(anna::xml::Node* parent) const
+anna::xml::Node* TestStep::asXML(anna::xml::Node* parent)
 throw() {
   anna::xml::Node* result = parent->createChild("TestStep");
 
@@ -85,41 +207,52 @@ throw() {
 
   // Begin
   std::string s_aux = a_beginTimestamp.asString();
-//  int deltaMs = (int)(a_beginTimestamp - a_testCase->getStartTimestamp());
-//  if (a_beginTimestamp != 0 && deltaMs > 0) s_aux += anna::functions::asString(" [%.3f]", deltaMs/1000.0);
+  //  int deltaMs = (int)(a_beginTimestamp - a_testCase->getStartTimestamp());
+  //  if (a_beginTimestamp != 0 && deltaMs > 0) s_aux += anna::functions::asString(" [%.3f]", deltaMs/1000.0);
   result->createAttribute("BeginTimestamp", s_aux);
 
   // End
   s_aux = a_endTimestamp.asString();
-//  deltaMs = (int)(a_endTimestamp - a_testCase->getStartTimestamp());
-//  if (a_endTimestamp != 0 && deltaMs > 0) s_aux += anna::functions::asString(" [%.3f]", deltaMs/1000.0);
+  //  deltaMs = (int)(a_endTimestamp - a_testCase->getStartTimestamp());
+  //  if (a_endTimestamp != 0 && deltaMs > 0) s_aux += anna::functions::asString(" [%.3f]", deltaMs/1000.0);
   result->createAttribute("EndTimestamp", s_aux);
 
   return result;
 }
 
-std::string TestStep::asXMLString() const throw() {
+std::string TestStep::asXMLString() throw() {
   anna::xml::Node root("root");
   return anna::xml::Compiler().apply(asXML(&root));
 }
 
 bool TestStep::execute() throw() {
-  LOGDEBUG(anna::Logger::debug(anna::functions::asString("EXECUTING %s (step number %d) for Test Case %llu (%p) (%p)", asText(a_type), a_number, a_testCase->getId(), (TestCaseStep*)this, this), ANNA_FILE_LOCATION));
+
+  int ia = a_testCase->interactiveAmount();
+  if (ia > -1) {
+    if (ia == 0) return false;
+    a_testCase->interactiveExecution();
+    LOGDEBUG(anna::Logger::debug("Interactive execution ...", ANNA_FILE_LOCATION));
+    if (a_executed) return false; // avoid repeating (this implies amount consumption)
+  }
+
+  LOGDEBUG(anna::Logger::debug(anna::functions::asString("EXECUTING %s (step number %d) for Test Case %llu (%p)", asText(a_type), a_number, a_testCase->getId(), this), ANNA_FILE_LOCATION));
   setBeginTimestamp(anna::functions::millisecond());
+  a_executed = true;
   return do_execute();
 }
 
 void TestStep::complete() throw() {
-  LOGDEBUG(anna::Logger::debug(anna::functions::asString("COMPLETE %s (step number %d) for Test Case %llu (%p) (%p)", asText(a_type), a_number, a_testCase->getId(), (TestCaseStep*)this, this), ANNA_FILE_LOCATION));
+  LOGDEBUG(anna::Logger::debug(anna::functions::asString("COMPLETE %s (step number %d) for Test Case %llu (%p)", asText(a_type), a_number, a_testCase->getId(), this), ANNA_FILE_LOCATION));
   a_completed = true;
   setEndTimestamp(anna::functions::millisecond());
   do_complete();
 }
 
 void TestStep::reset() throw() {
-  LOGDEBUG(anna::Logger::debug(anna::functions::asString("RESET %s (step number %d) for Test Case %llu (%p) (%p)", asText(a_type), a_number, a_testCase->getId(), (TestCaseStep*)this, this), ANNA_FILE_LOCATION));
+  LOGDEBUG(anna::Logger::debug(anna::functions::asString("RESET %s (step number %d) for Test Case %llu (%p)", asText(a_type), a_number, a_testCase->getId(), this), ANNA_FILE_LOCATION));
   // type and testCase kept
   a_completed = false;
+  a_executed = false;
   a_beginTimestamp = 0;
   a_endTimestamp = 0;
   do_reset();
@@ -134,7 +267,7 @@ void TestStep::next() throw() {
 ////////////////////////////////////////////////////////////////////////////////////////////////////////
 // TestStepTimeout
 ////////////////////////////////////////////////////////////////////////////////////////////////////////
-anna::xml::Node* TestStepTimeout::asXML(anna::xml::Node* parent) const
+anna::xml::Node* TestStepTimeout::asXML(anna::xml::Node* parent)
 throw() {
   anna::xml::Node* result = TestStep::asXML(parent); // end timestamp will be 0 if test finished OK
   //parent->createChild("TestStepTimeout");
@@ -171,8 +304,6 @@ void TestStepTimeout::do_complete() throw() {
 }
 
 void TestStepTimeout::do_reset() throw() {
-  LOGDEBUG(anna::Logger::debug(anna::functions::asString("REXXXXXET %s for Test Case %llu (%p) (%p) (a_timer %p)", asText(a_type), a_testCase->getId(), (TestCaseStep*)this, this, a_timer), ANNA_FILE_LOCATION));
-
   try {
     TestManager::instantiate().cancelTimer(a_timer);
   }
@@ -186,7 +317,7 @@ void TestStepTimeout::do_reset() throw() {
 ////////////////////////////////////////////////////////////////////////////////////////////////////////
 // TestStepSendxml
 ////////////////////////////////////////////////////////////////////////////////////////////////////////
-anna::xml::Node* TestStepSendxml::asXML(anna::xml::Node* parent) const
+anna::xml::Node* TestStepSendxml::asXML(anna::xml::Node* parent)
 throw() {
   anna::xml::Node* result = TestStep::asXML(parent);
   //parent->createChild("TestStepSendxml");
@@ -202,16 +333,13 @@ throw() {
     }
   }
 
-  if (!a_message.isEmpty()) {
-    try {
-      Launcher& my_app = static_cast <Launcher&>(anna::app::functions::getApp());
-      static anna::diameter::codec::Message codecMsg(my_app.getCodecEngine());
-      codecMsg.decode(a_message);
-      xmlmsg = "\n"; xmlmsg += codecMsg.asXMLString(); xmlmsg += "\n";
-    }
-    catch (anna::RuntimeException &ex) {
-      ex.trace();
-    }
+  if (decodeMessage()) {
+    xmlmsg = "\n";
+    xmlmsg += a_messageCodec->asXMLString();
+    xmlmsg += "\n";
+  }
+  else {
+    xmlmsg = "<unable to decode, check traces>"; 
   }
 
   if (msg != "") result->createAttribute("Message", msg);
@@ -224,64 +352,126 @@ throw() {
 }
 
 bool TestStepSendxml::do_execute() throw() {
-  anna::diameter::comm::Message *msg = a_realmNode->createCommMessage();
   bool success = false;
-  std::string failReason, s_warn;
+  std::string failReason;
+  MyDiameterEntity *entity = a_originHost->getEntity(); // by default
+  MyLocalServer *localServer = a_originHost->getDiameterServer(); // by default
+  const TestStepWait *tsw = NULL;
+  anna::diameter::comm::Message *msg = a_originHost->createCommMessage();
 
   try {
-    // Update sequence for answers:
-    if (a_waitForRequestStepNumber != -1) { // is an answer: try to copy sequence information; alert about Session-Id discrepance
-      // Request which was received:
-      const TestStepWait *tsw = (const TestStepWait*)(a_testCase->getStep(a_waitForRequestStepNumber));
-      const anna::DataBlock &request = tsw->getMsgDataBlock();
-      anna::diameter::HopByHop hbh = anna::diameter::codec::functions::getHopByHop(request);
-      anna::diameter::EndToEnd ete = anna::diameter::codec::functions::getEndToEnd(request);
-      // Update sequence:
-      anna::diameter::codec::functions::setHopByHop(a_message, hbh);
-      anna::diameter::codec::functions::setEndToEnd(a_message, ete);
-
-      // Check Session-Id for warning ...
-      std::string sessionIdAnswer = anna::diameter::helpers::base::functions::getSessionId(a_message);
-      std::string sessionIdRequest = anna::diameter::helpers::base::functions::getSessionId(request);
-      if (sessionIdRequest != sessionIdAnswer) {
-        s_warn = anna::functions::asString("Sending an answer which Session-Id (%s) is different than supposed corresponding request (%s)", sessionIdAnswer.c_str(), sessionIdRequest.c_str());
-        LOGWARNING(anna::Logger::warning(s_warn, ANNA_FILE_LOCATION));
-        a_testCase->addDebugSummaryHint(s_warn);
+
+    if (a_waitForRequestStepNumber != -1) {
+
+      // Referenced request in the 'wait for request step':
+      tsw = static_cast<const TestStepWait*>(a_testCase->getStep(a_waitForRequestStepNumber));
+      const anna::DataBlock &referenceRequest = tsw->getMsgDataBlock();
+      std::string sessionIdReferenceRequest = anna::diameter::helpers::base::functions::getSessionId(referenceRequest);
+      bool thisIsAnswer = anna::diameter::codec::functions::isRequest(getMsgDataBlock());
+
+      if (thisIsAnswer) { // is an answer: try to copy sequence information; alert about Session-Id discrepance
+        anna::diameter::HopByHop hbh = anna::diameter::codec::functions::getHopByHop(referenceRequest);
+        anna::diameter::EndToEnd ete = anna::diameter::codec::functions::getEndToEnd(referenceRequest);
+
+        // Update sequence:
+        anna::diameter::codec::functions::setHopByHop(a_message, hbh);
+        anna::diameter::codec::functions::setEndToEnd(a_message, ete);
+      }
+
+      // Session-Id substitution:
+      std::string thisSessionId = anna::diameter::helpers::base::functions::getSessionId(getMsgDataBlock());
+      if (thisSessionId != sessionIdReferenceRequest) {
+        static anna::diameter::codec::Message codecMsg;
+        codecMsg.decode(getMsgDataBlock());
+        codecMsg.getAvp("Session-Id")->getUTF8String()->setValue(sessionIdReferenceRequest);
+        a_message = codecMsg.code();
+        std::string trace = anna::functions::asString("Replacing %s Session-Id (%s) to set the corresponding request one (%s)", (thisIsAnswer ? "answer":"request"), thisSessionId.c_str(), sessionIdReferenceRequest.c_str());
+        LOGDEBUG(anna::Logger::debug(trace, ANNA_FILE_LOCATION));
+        a_testCase->addDebugSummaryHint(trace);
       }
     }
 
+    // Create comm message:
+    //msg->clearBody();
+    msg->setBody(a_message);
+
+
     if (getType() == Type::Sendxml2e) {
-      MyDiameterEntity *entity = a_realmNode->getEntity();
-      if (entity) {
-        //msg->clearBody();
-        msg->setBody(a_message);
-        /* response = NULL =*/entity->send(msg);
-        success = true;
+      anna::diameter::comm::ClientSession *usedClientSession = NULL;
+
+      if (tsw) { // is an answer for a received request on wait condition
+        anna::diameter::comm::ClientSession *clientSession = tsw->getClientSession();
+        if (clientSession) {
+          /* response NULL (is an answer) */clientSession->send(msg);
+          success = true;
+          usedClientSession = clientSession;
+        }
+        else {
+          failReason = "Reference wait step didn't store a valid client session. Unable to send the message";
+          LOGWARNING(anna::Logger::warning(failReason, ANNA_FILE_LOCATION));
+        }
       }
       else {
-        failReason = "There is no diameter entity currently configured. Unable to send the message";
-        LOGWARNING(anna::Logger::warning(failReason, ANNA_FILE_LOCATION));
+        if (entity) {
+          success = entity->send(msg);
+          anna::diameter::comm::Server *usedServer = entity->getLastUsedResource();
+          usedClientSession = usedServer ? usedServer->getLastUsedResource() : NULL;
+        }
+        else {
+          failReason = "There is no diameter entity currently configured. Unable to send the message";
+          LOGWARNING(anna::Logger::warning(failReason, ANNA_FILE_LOCATION));
+        }
+      } // else (normal sending)
+
+      // Detailed log:
+      if(a_originHost->logEnabled()) {
+        if (decodeMessage(true /* trust */)) {
+          std::string detail = usedClientSession ? usedClientSession->asString() : "<null client session>"; // shouldn't happen
+          a_originHost->writeLogFile(*a_messageCodec, (success ? "sent2e" : "send2eError"), detail);
+        }
       }
     }
     else if (getType() == Type::Sendxml2c) {
-      MyLocalServer *localServer = a_realmNode->getDiameterServer();
-      if (localServer) {
-        //msg->clearBody();
-        msg->setBody(a_message);
-        /* response = NULL =*/localServer->send(msg);
-        success = true;
+      anna::diameter::comm::ServerSession *usedServerSession = NULL;
+
+      if (tsw) { // is an answer for a received request on wait condition
+        anna::diameter::comm::ServerSession *serverSession = tsw->getServerSession();
+        if (serverSession) {
+          /* response NULL (is an answer) */serverSession->send(msg);
+          success = true;
+          usedServerSession = serverSession;
+        }
+        else {
+          failReason = "Reference wait step didn't store a valid server session. Unable to send the message";
+          LOGWARNING(anna::Logger::warning(failReason, ANNA_FILE_LOCATION));
+        }
       }
       else {
-        failReason = "There is no diameter local server currently configured. Unable to send the message";
-        LOGWARNING(anna::Logger::warning(failReason, ANNA_FILE_LOCATION));
+        if (localServer) {
+          success = localServer->send(msg);
+          usedServerSession = localServer->getLastUsedResource();
+        }
+        else {
+          failReason = "There is no diameter local server currently configured. Unable to send the message";
+          LOGWARNING(anna::Logger::warning(failReason, ANNA_FILE_LOCATION));
+        }
+      } // else (normal sending)
+
+      // Detailed log:
+      if(a_originHost->logEnabled()) {
+        if (decodeMessage(true /* trust */)) {
+          std::string detail = usedServerSession ? usedServerSession->asString() : "<null server session>"; // shouldn't happen
+          a_originHost->writeLogFile(*a_messageCodec, (success ? "sent2c" : "send2cError"), detail);
+        }
       }
     }
+
   } catch(anna::RuntimeException &ex) {
     failReason = ex.asString();
   }
 
   // release msg
-  a_realmNode->releaseCommMessage(msg);
+  a_originHost->releaseCommMessage(msg);
 
   if (!success) {
     a_testCase->addDebugSummaryHint(failReason); // before report (when set Failed state);
@@ -297,22 +487,24 @@ bool TestStepSendxml::do_execute() throw() {
 void TestStepSendxml::do_reset() throw() {
   a_expired = false;
   //a_message.clear();
+  //a_messageAlreadyDecoded = false;
 }
 
 ////////////////////////////////////////////////////////////////////////////////////////////////////////
 // TestStepDelay
 ////////////////////////////////////////////////////////////////////////////////////////////////////////
-anna::xml::Node* TestStepDelay::asXML(anna::xml::Node* parent) const
+anna::xml::Node* TestStepDelay::asXML(anna::xml::Node* parent)
 throw() {
   anna::xml::Node* result = TestStep::asXML(parent);
   //parent->createChild("TestStepDelay");
 
-  result->createAttribute("Delay", a_delay.asString());
+  result->createAttribute("Delay", ((a_delay == 0) ? "dummy step, no delay" : a_delay.asString()));
 
   return result;
 }
 
 bool TestStepDelay::do_execute() throw() {
+  if (a_delay == 0) { complete(); return true; } // special case
   try {
     a_timer = TestManager::instantiate().createTimer((TestCaseStep*)this, a_delay, TestTimer::Type::Delay);
   }
@@ -326,11 +518,14 @@ bool TestStepDelay::do_execute() throw() {
 }
 
 void TestStepDelay::do_complete() throw() {
+  if (a_delay == 0) return; // special case
   a_timer = NULL;
   next(); // next() invoked here because execute() is always false for delay and never advance the iterator
+  // TODO, avoid this recursion
 }
 
 void TestStepDelay::do_reset() throw() {
+  if (a_delay == 0) return; // special case
   try {
     TestManager::instantiate().cancelTimer(a_timer);
   }
@@ -345,8 +540,9 @@ void TestStepDelay::do_reset() throw() {
 // TestStepWait
 ////////////////////////////////////////////////////////////////////////////////////////////////////////
 void TestStepWait::setCondition(bool fromEntity,
-                                  const std::string &code, const std::string &bitR, const std::string &resultCode, const std::string &sessionId,
-                                  const std::string &hopByHop, const std::string &msisdn, const std::string &imsi, const std::string &serviceContextId) throw() {
+    const std::string &code, const std::string &bitR, const std::string &hopByHop, const std::string &applicationId,
+    const std::string &sessionId, const std::string &resultCode,
+    const std::string &msisdn, const std::string &imsi, const std::string &serviceContextId) throw() {
 
   a_condition.setReceivedFromEntity(fromEntity);
   a_condition.setCode(code);
@@ -365,7 +561,7 @@ void TestStepWait::setCondition(bool fromEntity, const std::string &regexp) thro
   a_condition.setRegexp(regexp);
 }
 
-anna::xml::Node* TestStepWait::asXML(anna::xml::Node* parent) const
+anna::xml::Node* TestStepWait::asXML(anna::xml::Node* parent)
 throw() {
   anna::xml::Node* result = TestStep::asXML(parent);
   //parent->createChild("TestStepWait");
@@ -384,20 +580,19 @@ throw() {
     }
   }
 
-  if (!a_message.isEmpty()) {
-    try {
-      Launcher& my_app = static_cast <Launcher&>(anna::app::functions::getApp());
-      static anna::diameter::codec::Message codecMsg(my_app.getCodecEngine());
-      codecMsg.decode(a_message);
-      xmlmsg = "\n"; xmlmsg += codecMsg.asXMLString(); xmlmsg += "\n";
-    }
-    catch (anna::RuntimeException &ex) {
-      ex.trace();
-    }
+  if (decodeMessage()) {
+    xmlmsg = "\n";
+    xmlmsg += a_messageCodec->asXMLString();
+    xmlmsg += "\n";
+  }
+  else {
+    xmlmsg = "<unable to decode, check traces>"; 
   }
 
   if (msg != "") result->createAttribute("MatchedMessage", msg);
   if (xmlmsg != "") result->createAttribute("MatchedXMLMessage", xmlmsg);
+  if (a_clientSession) result->createAttribute("ClientSessionOrigin", anna::functions::asString("%p", a_clientSession));
+  if (a_serverSession) result->createAttribute("ServerSessionOrigin", anna::functions::asString("%p", a_serverSession));
 
   return result;
 }
@@ -407,7 +602,8 @@ bool TestStepWait::do_execute() throw() {
 }
 
 void TestStepWait::do_complete() throw() {
-  a_testCase->process(); // next() not invoked; we only want to reactivate the test case
+  //a_testCase->process(); // next() not invoked; we only want to reactivate the test case
+  // avoid stack overflow: we will process the test case externally when incoming message is fulfilled (TestCase.cpp), and TestManager is noticed
 }
 
 bool TestStepWait::fulfilled(const anna::DataBlock &db/*, bool matchSessionId*/) throw() {
@@ -429,29 +625,31 @@ void TestStepWait::do_reset() throw() {
 ////////////////////////////////////////////////////////////////////////////////////////////////////////
 // TestStepCmd
 ////////////////////////////////////////////////////////////////////////////////////////////////////////
-anna::xml::Node* TestStepCmd::asXML(anna::xml::Node* parent) const
+anna::xml::Node* TestStepCmd::asXML(anna::xml::Node* parent)
 throw() {
   anna::xml::Node* result = TestStep::asXML(parent);
   //parent->createChild("TestStepCmd");
 
   result->createAttribute("Script", (a_script != "") ? a_script:"<no script>");
-  result->createAttribute("Parameters", (a_parameters != "") ? a_parameters:"<no parameters>");
-  result->createAttribute("CommandInProgress", a_threadRunning ? "yes":"no");
   if (a_errorMsg != "") result->createAttribute("ErrorMessage", a_errorMsg);
-  if (!a_threadRunning && a_resultCode != -2) {
-    result->createAttribute("ResultCode", a_resultCode);
-    //if (a_output != "") result->createAttribute("Output", a_output);
+  if (a_threadRunning) {
+    if (a_childPid != -1)
+      result->createAttribute("ChildPid", a_childPid);
+  }
+  else {
+    if (a_resultCode != -2) {
+      result->createAttribute("ResultCode", a_resultCode);
+      //if (a_output != "") result->createAttribute("Output", a_output);
+    }
   }
 
   return result;
 }
 
 bool TestStepCmd::do_execute() throw() {
-  if (!a_threadRunning) {
+  if (!a_threadRunning /* || a_threadDeprecated DO NOT WANT TO OVERLAP ... */) {
     // Special tags to replace:
     std::string cmd = getScript();
-    cmd += " ";
-    cmd += getParameters();
     size_t index;
     while ((index = cmd.find(SH_COMMAND_TAG_FOR_REPLACE__CYCLE_ID)) != std::string::npos)
       cmd.replace(index, strlen(SH_COMMAND_TAG_FOR_REPLACE__CYCLE_ID), anna::functions::asString(TestManager::instantiate().getPoolCycle()));
@@ -461,10 +659,13 @@ bool TestStepCmd::do_execute() throw() {
       cmd.replace(index, strlen(SH_COMMAND_TAG_FOR_REPLACE__TESTSTEP_ID), anna::functions::asString(getNumber()));
 
     a_thread = std::thread(cmdRunOnThread, this, cmd);
+    //a_thread = std::thread(cmdRunOnThreadWithFork, this, cmd);
+
     a_thread.detach();
   }
 
-  return false; // don't go next (wait complete)
+  return false; // don't go next (wait complete): If system function on thread stucks, then the reset test case will stuck here forever.
+  // We must implement a interrupt procedure for the thread on reset call... TODO !
 }
 
 void TestStepCmd::do_complete() throw() {
@@ -472,6 +673,9 @@ void TestStepCmd::do_complete() throw() {
   a_threadRunning = false;
   if (a_threadDeprecated) {
     a_threadDeprecated = false;
+    do_reset();
+    setErrorMsg(anna::functions::asString("Step %d deprecated due to previous reset for Test Case %llu", getNumber(), a_testCase->getId()));
+    a_testCase->setState(TestCase::State::Failed);
     return; // ignore TODO: interrupt the thread to avoid execution of the script
   }
 
@@ -479,17 +683,25 @@ void TestStepCmd::do_complete() throw() {
     a_testCase->setState(TestCase::State::Failed);
   else
     next(); // next() invoked here because execute() is always false for delay and never advance the iterator
+  // TODO, avoid this recursion
 }
 
 void TestStepCmd::do_reset() throw() {
 
-  if (a_threadRunning) {
-    std::string s_warn = anna::functions::asString("Thread still in progress: deprecating step %d for Test Case %llu", getNumber(), a_testCase->getId());
-    LOGWARNING(anna::Logger::warning(s_warn, ANNA_FILE_LOCATION));
-    a_threadDeprecated = true;
-  }
+    if (a_threadRunning) {
+      std::string s_warn = anna::functions::asString("Thread still in progress: deprecating step %d for Test Case %llu", getNumber(), a_testCase->getId());
+      LOGWARNING(anna::Logger::warning(s_warn, ANNA_FILE_LOCATION));
+      a_threadDeprecated = true;
+    }
+//  if (a_threadRunning) {
+//    std::string s_warn = anna::functions::asString("Thread still in progress: killing child pid %d within step %d for Test Case %llu", a_childPid, getNumber(), a_testCase->getId());
+//    LOGWARNING(anna::Logger::warning(s_warn, ANNA_FILE_LOCATION));
+//    kill (a_childPid, SIGKILL);
+//  }
 
   a_resultCode = -2;
+  a_errorMsg = "";
   //a_output = "";
+  a_childPid = -1;
 }