Adding an early version of the 'engine debug' facility.

6 files changed, 27 insertions, 4 deletions

diff --git a/src/BString.cc b/src/BString.cc
index 0b4b428..74d033e 100644
--- a/src/BString.cc
+++ b/src/BString.cc
@@ -1,6 +1,7 @@
 #include <iconv.h>
 #include <ctype.h>
 
+#include "Printer.h"
 #include "BString.h"
 
 void Balau::String::set(const char * fmt, va_list ap) {
@@ -82,6 +83,7 @@ Balau::String & Balau::String::do_lower() {
 Balau::String & Balau::String::do_iconv(const char * from, const char * _to) {
     iconv_t cd;
     const String to = String(_to) + "//TRANSLIT";
+    Printer::elog(E_STRING, "Converting a string from %s to %s", from, _to);
 
     const char * inbuf;
     char * outbuf, * t;
diff --git a/src/Handle.cc b/src/Handle.cc
index 7bb6c19..b3458a8 100644
--- a/src/Handle.cc
+++ b/src/Handle.cc
@@ -4,6 +4,7 @@
 #include "Main.h"
 #include "TaskMan.h"
 #include "Handle.h"
+#include "Printer.h"
 
 class eioInterface : public Balau::AtStart {
   public:
@@ -29,6 +30,8 @@ void eioInterface::readyCB(ev::async & w, int revents) {
 }
 
 void eioInterface::doStart() {
+    Balau::Printer::elog(Balau::E_HANDLE, "Starting the eio interface");
+
     Balau::TaskMan * taskMan = Balau::TaskMan::getTaskMan();
     Assert(taskMan);
     struct ev_loop * loop = taskMan->getLoop();
diff --git a/src/Input.cc b/src/Input.cc
index 94cfe8f..8f16321 100644
--- a/src/Input.cc
+++ b/src/Input.cc
@@ -6,6 +6,7 @@
 #include "eio.h"
 #include "Input.h"
 #include "Task.h"
+#include "Printer.h"
 
 #ifdef _WIN32
 const char * strerror_r(int errorno, char * buf, size_t bufsize) {
@@ -49,6 +50,8 @@ static int eioStatsDone(eio_req * req) {
 Balau::Input::Input(const char * fname) throw (GeneralException) : m_fd(-1), m_size(-1), m_mtime(-1) {
     m_name.set("Input(%s)", fname);
 
+    Printer::elog(E_INPUT, "Opening file %s", fname);
+
     cbResults_t cbResults;
     eio_req * r = eio_open(fname, O_RDONLY, 0, 0, eioDone, &cbResults);
     Assert(r != 0);
diff --git a/src/Printer.cc b/src/Printer.cc
index ef0cbf5..3190663 100644
--- a/src/Printer.cc
+++ b/src/Printer.cc
@@ -12,9 +12,10 @@ static const char * prefixes[] = {
     "(WW) ",
     "(EE) ",
     "(AA) ",
+    "(**) ",
 };
 
-Balau::Printer::Printer() : m_verbosity(M_STATUS | M_WARNING | M_ERROR) {
+Balau::Printer::Printer() : m_verbosity(M_STATUS | M_WARNING | M_ERROR | M_ENGINE_DEBUG) {
     if (!localPrinter.getGlobal())
         localPrinter.setGlobal(this);
 }
@@ -37,9 +38,11 @@ void Balau::Printer::_log(uint32_t level, const char * fmt, va_list ap) {
 
     Printer * printer = getPrinter();
 
+    m_lock.enter();
     printer->_print(prefixes[i]);
     printer->_print(fmt, ap);
     printer->_print("\n");
+    m_lock.leave();
 }
 
 void Balau::Printer::_print(const char * fmt, va_list ap) {
diff --git a/src/Task.cc b/src/Task.cc
index 771063e..8ad5cb7 100644
--- a/src/Task.cc
+++ b/src/Task.cc
@@ -23,6 +23,8 @@ Balau::Task::Task() {
     m_status = STARTING;
     m_loop = NULL;
     m_okayToEAgain = false;
+
+    Printer::elog(E_TASK, "Created a Task at %p");
 }
 
 Balau::Task::~Task() {
@@ -35,23 +37,26 @@ Balau::Task::~Task() {
 void Balau::Task::coroutine(void * arg) {
     Task * task = reinterpret_cast<Task *>(arg);
     Assert(task);
+    Assert(task->m_status == STARTING);
     try {
         task->m_status = RUNNING;
         task->Do();
         task->m_status = STOPPED;
     }
     catch (GeneralException & e) {
-        Printer::log(M_WARNING, "Task %s caused an exception: `%s' - stopping.", task->getName(), e.getMsg());
+        Printer::log(M_WARNING, "Task %s at %p caused an exception: `%s' - stopping.", task->getName(), task, e.getMsg());
         task->m_status = FAULTED;
     }
     catch (...) {
-        Printer::log(M_WARNING, "Task %s caused an unknown exception - stopping.", task->getName());
+        Printer::log(M_WARNING, "Task %s at %p caused an unknown exception - stopping.", task->getName(), task);
         task->m_status = FAULTED;
     }
     coro_transfer(&task->m_ctx, &task->m_taskMan->m_returnContext);
 }
 
 void Balau::Task::switchTo() {
+    Printer::elog(E_TASK, "Switching to task %p - %s", this, getName());
+    Assert(m_status == IDLE || m_status == STARTING);
     void * oldTLS = g_tlsManager->getTLS();
     g_tlsManager->setTLS(m_tls);
     coro_transfer(&m_taskMan->m_returnContext, &m_ctx);
@@ -99,11 +104,14 @@ struct ev_loop * Balau::Task::getLoop() {
 }
 
 void Balau::Events::BaseEvent::doSignal() {
+    Printer::elog(E_TASK, "Event at %p (%s) is signaled with cb %p and task %p", this, ClassName(this).c_str(), m_cb, m_task);
     m_signal = true;
     if (m_cb)
         m_cb->gotEvent(this);
-    if (m_task)
+    if (m_task) {
+        Printer::elog(E_TASK, "Signaling task %p (%s - %s)", m_task, m_task->getName(), ClassName(m_task).c_str());
         m_task->getTaskMan()->signalTask(m_task);
+    }
 }
 
 Balau::Events::TaskEvent::TaskEvent(Task * taskWaited) : m_taskWaited(taskWaited) {
diff --git a/src/TaskMan.cc b/src/TaskMan.cc
index 5a0c1c1..aa8425d 100644
--- a/src/TaskMan.cc
+++ b/src/TaskMan.cc
@@ -45,6 +45,8 @@ void Balau::TaskMan::mainLoop() {
         Task * t;
         bool noWait = false;
 
+        Printer::elog(E_TASK, "TaskMan::mainLoop() with m_tasks.size = %i", m_tasks.size());
+
         // checking "STARTING" tasks, and running them once; also try to build the status of the noWait boolean.
         for (iH = m_tasks.begin(); iH != m_tasks.end(); iH++) {
             t = *iH;
@@ -69,6 +71,8 @@ void Balau::TaskMan::mainLoop() {
         // let's check who got signaled, and call them
         for (iH = m_signaledTasks.begin(); iH != m_signaledTasks.end(); iH++) {
             t = *iH;
+            Printer::elog(E_TASK, "Switching to task %p (%s - %s) that got signaled somehow.", t, t->getName(), ClassName(t).c_str());
+            Assert(t->getStatus() == Task::IDLE);
             t->switchTo();
         }