From 10d0f503fb68946c265bad18dd755fdc816075c1 Mon Sep 17 00:00:00 2001 From: Pixel Date: Mon, 17 Oct 2011 21:02:52 -0700 Subject: Adding an early version of the 'engine debug' facility. --- includes/Handle.h | 1 + includes/Printer.h | 22 +++++++++++++++++++++- includes/Task.h | 5 +++-- src/BString.cc | 2 ++ src/Handle.cc | 3 +++ src/Input.cc | 3 +++ src/Printer.cc | 5 ++++- src/Task.cc | 14 +++++++++++--- src/TaskMan.cc | 4 ++++ 9 files changed, 52 insertions(+), 7 deletions(-) diff --git a/includes/Handle.h b/includes/Handle.h index 9f1486a..0e19e50 100644 --- a/includes/Handle.h +++ b/includes/Handle.h @@ -1,6 +1,7 @@ #pragma once #include +#include namespace Balau { diff --git a/includes/Printer.h b/includes/Printer.h index d8ba9cf..cd24059 100644 --- a/includes/Printer.h +++ b/includes/Printer.h @@ -2,6 +2,7 @@ #include #include +#include namespace Balau { @@ -14,7 +15,19 @@ enum { M_ALERT = 32, M_ALL = M_DEBUG | M_INFO | M_STATUS | M_WARNING | M_ERROR | M_ALERT, - M_MAX = M_ALERT, + + M_ENGINE_DEBUG = 64, + M_MAX = M_ENGINE_DEBUG, +}; + +enum { + E_STRING = 1, + E_TASK = 2, + E_EVENT = 4, + E_HANDLE = 8, + E_INPUT = 16, + E_SOCKET = 32, + E_THREAD = 64, }; class Printer { @@ -25,6 +38,7 @@ class Printer { void _print(const char * fmt, ...); void _log(uint32_t level, const char * fmt, va_list ap); + Lock m_lock; public: Printer(); @@ -38,6 +52,12 @@ class Printer { static void print(const char * fmt, ...) { va_list ap; va_start(ap, fmt); vprint(fmt, ap); va_end(ap); } static void vprint(const char * fmt, va_list ap) { getPrinter()->_print(fmt, ap); } +#ifdef DEBUG + static void elog(uint32_t engine, const char * fmt, ...) { va_list ap; va_start(ap, fmt); getPrinter()->_log(M_ENGINE_DEBUG, fmt, ap); } +#else + static void elog(uint32_t engine, const char * fmt, ...) { } +#endif + static void enable(uint32_t levels = M_ALL) { getPrinter()->m_verbosity |= levels; } static void disable(uint32_t levels = M_ALL) { getPrinter()->m_verbosity &= ~levels; } diff --git a/includes/Task.h b/includes/Task.h index 3d99d26..691d47f 100644 --- a/includes/Task.h +++ b/includes/Task.h @@ -3,8 +3,9 @@ #include #include #include -#include #include +#include +#include namespace Balau { @@ -31,7 +32,7 @@ class Callback { class BaseEvent { public: - BaseEvent() : m_cb(NULL), m_signal(false), m_task(NULL) { } + BaseEvent() : m_cb(NULL), m_signal(false), m_task(NULL) { Printer::elog(E_TASK, "Creating event at %p", this); } virtual ~BaseEvent() { if (m_cb) delete m_cb; } bool gotSignal() { return m_signal; } void doSignal(); 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 #include +#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(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(); } -- cgit v1.2.3