diff --git a/src/Makefile b/src/Makefile index 32e813d..b0d5367 100644 --- a/src/Makefile +++ b/src/Makefile @@ -20,6 +20,7 @@ BEES_OBJS = \ bees-resolve.o \ bees-roots.o \ bees-thread.o \ + bees-trace.o \ bees-types.o \ ALL_OBJS = $(BEES_OBJS) $(PROGRAM_OBJS) diff --git a/src/bees-trace.cc b/src/bees-trace.cc new file mode 100644 index 0000000..7d0d374 --- /dev/null +++ b/src/bees-trace.cc @@ -0,0 +1,154 @@ +#include "bees.h" + +// tracing ---------------------------------------- + +int bees_log_level = 8; + +thread_local BeesTracer *BeesTracer::tl_next_tracer = nullptr; +thread_local bool BeesTracer::tl_first = true; +thread_local bool BeesTracer::tl_silent = false; + +BeesTracer::~BeesTracer() +{ + if (!tl_silent && current_exception()) { + if (tl_first) { + BEESLOGNOTICE("--- BEGIN TRACE --- exception ---"); + tl_first = false; + } + try { + m_func(); + } catch (exception &e) { + BEESLOGNOTICE("Nested exception: " << e.what()); + } catch (...) { + BEESLOGNOTICE("Nested exception ..."); + } + if (!m_next_tracer) { + BEESLOGNOTICE("--- END TRACE --- exception ---"); + } + } + tl_next_tracer = m_next_tracer; + if (!m_next_tracer) { + tl_silent = false; + tl_first = true; + } +} + +BeesTracer::BeesTracer(function f, bool silent) : + m_func(f) +{ + m_next_tracer = tl_next_tracer; + tl_next_tracer = this; + tl_silent = silent; +} + +void +BeesTracer::trace_now() +{ + BeesTracer *tp = tl_next_tracer; + BEESLOGNOTICE("--- BEGIN TRACE ---"); + while (tp) { + tp->m_func(); + tp = tp->m_next_tracer; + } + BEESLOGNOTICE("--- END TRACE ---"); +} + +bool +BeesTracer::get_silent() +{ + return tl_silent; +} + +void +BeesTracer::set_silent() +{ + tl_silent = true; +} + +thread_local BeesNote *BeesNote::tl_next = nullptr; +mutex BeesNote::s_mutex; +map BeesNote::s_status; +thread_local string BeesNote::tl_name; + +BeesNote::~BeesNote() +{ + tl_next = m_prev; + unique_lock lock(s_mutex); + if (tl_next) { + s_status[crucible::gettid()] = tl_next; + } else { + s_status.erase(crucible::gettid()); + } +} + +BeesNote::BeesNote(function f) : + m_func(f) +{ + m_name = get_name(); + m_prev = tl_next; + tl_next = this; + unique_lock lock(s_mutex); + s_status[crucible::gettid()] = tl_next; +} + +void +BeesNote::set_name(const string &name) +{ + tl_name = name; + catch_all([&]() { + DIE_IF_MINUS_ERRNO(pthread_setname_np(pthread_self(), name.c_str())); + }); +} + +string +BeesNote::get_name() +{ + // Use explicit name if given + if (!tl_name.empty()) { + return tl_name; + } + + // Try a Task name. If there is one, return it, but do not + // remember it. Each output message may be a different Task. + // The current task is thread_local so we don't need to worry + // about it being destroyed under us. + auto current_task = Task::current_task(); + if (current_task) { + return current_task.title(); + } + + // OK try the pthread name next. + char buf[24]; + memset(buf, '\0', sizeof(buf)); + int err = pthread_getname_np(pthread_self(), buf, sizeof(buf)); + if (err) { + return string("pthread_getname_np: ") + strerror(err); + } + buf[sizeof(buf) - 1] = '\0'; + + // thread_getname_np returns process name + // ...by default? ...for the main thread? + // ...except during exception handling? + // ...randomly? + return buf; +} + +BeesNote::ThreadStatusMap +BeesNote::get_status() +{ + unique_lock lock(s_mutex); + ThreadStatusMap rv; + for (auto t : s_status) { + ostringstream oss; + if (!t.second->m_name.empty()) { + oss << t.second->m_name << ": "; + } + if (t.second->m_timer.age() > BEES_TOO_LONG) { + oss << "[" << t.second->m_timer << "s] "; + } + t.second->m_func(oss); + rv[t.first] = oss.str(); + } + return rv; +} + diff --git a/src/bees.cc b/src/bees.cc index d40a964..9bff140 100644 --- a/src/bees.cc +++ b/src/bees.cc @@ -31,164 +31,12 @@ using namespace crucible; using namespace std; -int bees_log_level = 8; - void do_cmd_help(char *argv[]) { fprintf(stderr, BEES_USAGE, argv[0]); } -// tracing ---------------------------------------- - -thread_local BeesTracer *BeesTracer::tl_next_tracer = nullptr; -thread_local bool BeesTracer::tl_first = true; -thread_local bool BeesTracer::tl_silent = false; - -BeesTracer::~BeesTracer() -{ - if (!tl_silent && current_exception()) { - if (tl_first) { - BEESLOGNOTICE("--- BEGIN TRACE --- exception ---"); - tl_first = false; - } - try { - m_func(); - } catch (exception &e) { - BEESLOGNOTICE("Nested exception: " << e.what()); - } catch (...) { - BEESLOGNOTICE("Nested exception ..."); - } - if (!m_next_tracer) { - BEESLOGNOTICE("--- END TRACE --- exception ---"); - } - } - tl_next_tracer = m_next_tracer; - if (!m_next_tracer) { - tl_silent = false; - tl_first = true; - } -} - -BeesTracer::BeesTracer(function f, bool silent) : - m_func(f) -{ - m_next_tracer = tl_next_tracer; - tl_next_tracer = this; - tl_silent = silent; -} - -void -BeesTracer::trace_now() -{ - BeesTracer *tp = tl_next_tracer; - BEESLOGNOTICE("--- BEGIN TRACE ---"); - while (tp) { - tp->m_func(); - tp = tp->m_next_tracer; - } - BEESLOGNOTICE("--- END TRACE ---"); -} - -bool -BeesTracer::get_silent() -{ - return tl_silent; -} - -void -BeesTracer::set_silent() -{ - tl_silent = true; -} - -thread_local BeesNote *BeesNote::tl_next = nullptr; -mutex BeesNote::s_mutex; -map BeesNote::s_status; -thread_local string BeesNote::tl_name; - -BeesNote::~BeesNote() -{ - tl_next = m_prev; - unique_lock lock(s_mutex); - if (tl_next) { - s_status[crucible::gettid()] = tl_next; - } else { - s_status.erase(crucible::gettid()); - } -} - -BeesNote::BeesNote(function f) : - m_func(f) -{ - m_name = get_name(); - m_prev = tl_next; - tl_next = this; - unique_lock lock(s_mutex); - s_status[crucible::gettid()] = tl_next; -} - -void -BeesNote::set_name(const string &name) -{ - tl_name = name; - catch_all([&]() { - DIE_IF_MINUS_ERRNO(pthread_setname_np(pthread_self(), name.c_str())); - }); -} - -string -BeesNote::get_name() -{ - // Use explicit name if given - if (!tl_name.empty()) { - return tl_name; - } - - // Try a Task name. If there is one, return it, but do not - // remember it. Each output message may be a different Task. - // The current task is thread_local so we don't need to worry - // about it being destroyed under us. - auto current_task = Task::current_task(); - if (current_task) { - return current_task.title(); - } - - // OK try the pthread name next. - char buf[24]; - memset(buf, '\0', sizeof(buf)); - int err = pthread_getname_np(pthread_self(), buf, sizeof(buf)); - if (err) { - return string("pthread_getname_np: ") + strerror(err); - } - buf[sizeof(buf) - 1] = '\0'; - - // thread_getname_np returns process name - // ...by default? ...for the main thread? - // ...except during exception handling? - // ...randomly? - return buf; -} - -BeesNote::ThreadStatusMap -BeesNote::get_status() -{ - unique_lock lock(s_mutex); - ThreadStatusMap rv; - for (auto t : s_status) { - ostringstream oss; - if (!t.second->m_name.empty()) { - oss << t.second->m_name << ": "; - } - if (t.second->m_timer.age() > BEES_TOO_LONG) { - oss << "[" << t.second->m_timer << "s] "; - } - t.second->m_func(oss); - rv[t.first] = oss.str(); - } - return rv; -} - // static inline helpers ---------------------------------------- string