Implement support for high-level stack traces.

Refs #5085

components/cluster/clusterlistener.cpp

@@ -29,6 +29,7 @@
 #include "base/zlibstream.h"
 #include "base/application.h"
 #include "base/convert.h"
+#include "base/context.h"
 #include <fstream>
 
 using namespace icinga;
@@ -358,6 +359,8 @@ void ClusterListener::LogGlobHandler(std::vector<int>& files, const String& file
 
 void ClusterListener::ReplayLog(const Endpoint::Ptr& endpoint, const Stream::Ptr& stream)
 {
+	CONTEXT("Replaying log for Endpoint '" + endpoint->GetName() + "'");
+
 	int count = -1;
 	double peer_ts = endpoint->GetLocalLogPosition();
 	bool last_sync = false;
@@ -495,6 +498,8 @@ void ClusterListener::ConfigGlobHandler(const Dictionary::Ptr& config, const Str
  */
 void ClusterListener::NewClientHandler(const Socket::Ptr& client, TlsRole role)
 {
+	CONTEXT("Handling new cluster client connection");
+
 	NetworkStream::Ptr netStream = make_shared<NetworkStream>(client);
 
 	TlsStream::Ptr tlsStream = make_shared<TlsStream>(netStream, role, m_SSLContext);
@@ -963,6 +968,8 @@ void ClusterListener::MessageExceptionHandler(boost::exception_ptr exp)
 
 void ClusterListener::MessageHandler(const Endpoint::Ptr& sender, const Dictionary::Ptr& message)
 {
+	CONTEXT("Processing cluster message of type '" + message->Get("method") + "'");
+
 	sender->SetSeen(Utility::GetTime());
 
 	if (message->Contains("ts")) {

components/db_ido_mysql/idomysqlconnection.cpp

@@ -122,6 +122,8 @@ void IdoMysqlConnection::Reconnect(void)
 {
 	AssertOnWorkQueue();
 
+	CONTEXT("Reconnecting to MySQL IDO database '" + GetName() + "'");
+
 	{
 		boost::mutex::scoped_lock lock(m_ConnectionMutex);
 

components/db_ido_pgsql/idopgsqlconnection.cpp

@@ -24,6 +24,7 @@
 #include "base/application.h"
 #include "base/dynamictype.h"
 #include "base/exception.h"
+#include "base/context.h"
 #include "db_ido/dbtype.h"
 #include "db_ido/dbvalue.h"
 #include "db_ido_pgsql/idopgsqlconnection.h"
@@ -121,6 +122,8 @@ void IdoPgsqlConnection::Reconnect(void)
 {
 	AssertOnWorkQueue();
 
+	CONTEXT("Reconnecting to PostgreSQL IDO database '" + GetName() + "'");
+
 	{
 		boost::mutex::scoped_lock lock(m_ConnectionMutex);
 

icinga-app/icinga.cpp

@@ -27,6 +27,7 @@
 #include "base/exception.h"
 #include "base/convert.h"
 #include "base/scriptvariable.h"
+#include "base/context.h"
 #include "config.h"
 #include <boost/program_options.hpp>
 #include <boost/tuple/tuple.hpp>
@@ -63,6 +64,8 @@ static String LoadAppType(const String& typeSpec)
 
 static bool LoadConfigFiles(const String& appType, bool validateOnly)
 {
+	CONTEXT("Loading configuration files");
+
 	ConfigCompilerContext::GetInstance()->Reset();
 
 	if (g_AppParams.count("config") > 0) {

lib/base/CMakeLists.txt

@@ -26,7 +26,7 @@ mkclass_target(sysloglogger.ti sysloglogger.th)
 
 add_library(base SHARED
   application.cpp application.th array.cpp bufferedstream.cpp consolelogger.cpp
-  consolelogger.th convert.cpp dictionary.cpp dynamicobject.cpp
+  consolelogger.th context.cpp convert.cpp dictionary.cpp dynamicobject.cpp
   dynamicobject.th dynamictype.cpp exception.cpp fifo.cpp filelogger.cpp
   filelogger.th logger.cpp logger.th netstring.cpp networkstream.cpp object.cpp
   objectlock.cpp process.cpp process-unix.cpp process-windows.cpp qstring.cpp

lib/base/application.cpp

@@ -363,6 +363,7 @@ void Application::SigAbrtHandler(int)
 	std::cerr << "Caught SIGABRT." << std::endl;
 
 	StackTrace trace;
+	std::cerr << "Stacktrace:" << std::endl;
 	trace.Print(std::cerr, 1);
 
 	DisplayBugMessage();
@@ -417,6 +418,7 @@ LONG CALLBACK Application::SEHUnhandledExceptionFilter(PEXCEPTION_POINTERS exi)
 	std::cerr << "Unhandled SEH exception." << std::endl;
 
 	StackTrace trace(exi);
+	std::cerr << "Stacktrace:" << std::endl;
 	trace.Print(std::cerr, 1);
 
 	DisplayBugMessage();

lib/base/context.cpp

@@ -0,0 +1,70 @@
+/******************************************************************************
+ * Icinga 2                                                                   *
+ * Copyright (C) 2012-2013 Icinga Development Team (http://www.icinga.org/)   *
+ *                                                                            *
+ * This program is free software; you can redistribute it and/or              *
+ * modify it under the terms of the GNU General Public License                *
+ * as published by the Free Software Foundation; either version 2             *
+ * of the License, or (at your option) any later version.                     *
+ *                                                                            *
+ * This program is distributed in the hope that it will be useful,            *
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of             *
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the              *
+ * GNU General Public License for more details.                               *
+ *                                                                            *
+ * You should have received a copy of the GNU General Public License          *
+ * along with this program; if not, write to the Free Software Foundation     *
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301, USA.             *
+ ******************************************************************************/
+
+#include "base/context.h"
+#include <boost/thread/tss.hpp>
+#include <boost/foreach.hpp>
+
+using namespace icinga;
+
+static boost::thread_specific_ptr<std::list<String> > l_Frames;
+
+ContextFrame::ContextFrame(const String& message)
+{
+	GetFrames().push_front(message);
+}
+
+ContextFrame::~ContextFrame(void)
+{
+	GetFrames().pop_front();
+}
+
+std::list<String>& ContextFrame::GetFrames(void)
+{
+	if (l_Frames.get() == NULL)
+		l_Frames.reset(new std::list<String>());
+
+	return *l_Frames;
+}
+
+ContextTrace::ContextTrace(void)
+	: m_Frames(ContextFrame::GetFrames())
+{ }
+
+void ContextTrace::Print(std::ostream& fp) const
+{
+	fp << std::endl;
+
+	int i = 0;
+	BOOST_FOREACH(const String& frame, m_Frames) {
+		fp << "\t(" << i << ") " << frame << std::endl;
+		i++;
+	}
+}
+
+size_t ContextTrace::GetLength(void) const
+{
+	return m_Frames.size();
+}
+
+std::ostream& icinga::operator<<(std::ostream& stream, const ContextTrace& trace)
+{
+	trace.Print(stream);
+	return stream;
+}

lib/base/context.h

@@ -0,0 +1,67 @@
+/******************************************************************************
+ * Icinga 2                                                                   *
+ * Copyright (C) 2012-2013 Icinga Development Team (http://www.icinga.org/)   *
+ *                                                                            *
+ * This program is free software; you can redistribute it and/or              *
+ * modify it under the terms of the GNU General Public License                *
+ * as published by the Free Software Foundation; either version 2             *
+ * of the License, or (at your option) any later version.                     *
+ *                                                                            *
+ * This program is distributed in the hope that it will be useful,            *
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of             *
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the              *
+ * GNU General Public License for more details.                               *
+ *                                                                            *
+ * You should have received a copy of the GNU General Public License          *
+ * along with this program; if not, write to the Free Software Foundation     *
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301, USA.             *
+ ******************************************************************************/
+
+#ifndef CONTEXT_H
+#define CONTEXT_H
+
+#include "base/i2-base.h"
+#include "base/qstring.h"
+#include <list>
+
+namespace icinga
+{
+
+class I2_BASE_API ContextTrace
+{
+public:
+	ContextTrace(void);
+
+	void Print(std::ostream& fp) const;
+
+	size_t GetLength(void) const;
+
+private:
+	std::list<String> m_Frames;
+};
+
+I2_BASE_API std::ostream& operator<<(std::ostream& stream, const ContextTrace& trace);
+
+/**
+ * A context frame.
+ *
+ * @ingroup base
+ */
+class I2_BASE_API ContextFrame
+{
+public:
+	ContextFrame(const String& message);
+	~ContextFrame(void);
+
+private:
+	static std::list<String>& GetFrames(void);
+
+	friend class ContextTrace;
+};
+
+/* The currentContextFrame variable has to be volatile in order to prevent
+ * the compiler from optimizing it away. */
+#define CONTEXT(message) volatile icinga::ContextFrame currentContextFrame(message)
+}
+
+#endif /* CONTEXT_H */

lib/base/exception.cpp

@@ -21,7 +21,8 @@
 
 using namespace icinga;
 
-static boost::thread_specific_ptr<StackTrace> l_LastStackTrace;
+static boost::thread_specific_ptr<StackTrace> l_LastExceptionStack;
+static boost::thread_specific_ptr<ContextTrace> l_LastExceptionContext;
 
 #ifndef _WIN32
 extern "C"
@@ -43,15 +44,22 @@ void __cxa_throw(void *obj, void *pvtinfo, void (*dest)(void *))
 		thrown_ptr = *(void **)thrown_ptr;
 #endif /* __APPLE__ */
 
-	StackTrace trace;
+	StackTrace stack;
-	SetLastExceptionStack(trace);
+	SetLastExceptionStack(stack);
+
+	ContextTrace context;
+	SetLastExceptionContext(context);
 
 #ifndef __APPLE__
 	/* Check if thrown_ptr inherits from boost::exception. */
 	if (boost_exc->__do_catch(tinfo, &thrown_ptr, 1)) {
 		boost::exception *ex = (boost::exception *)thrown_ptr;
 
-		*ex << StackTraceErrorInfo(trace);
+		if (boost::get_error_info<StackTraceErrorInfo>(*ex) == NULL)
+			*ex << StackTraceErrorInfo(stack);
+
+		if (boost::get_error_info<ContextTraceErrorInfo>(*ex) == NULL)
+			*ex << ContextTraceErrorInfo(context);
 	}
 #endif /* __APPLE__ */
 
@@ -61,28 +69,43 @@ void __cxa_throw(void *obj, void *pvtinfo, void (*dest)(void *))
 
 StackTrace *icinga::GetLastExceptionStack(void)
 {
-	return l_LastStackTrace.get();
+	return l_LastExceptionStack.get();
 }
 
 void icinga::SetLastExceptionStack(const StackTrace& trace)
 {
-	l_LastStackTrace.reset(new StackTrace(trace));
+	l_LastExceptionStack.reset(new StackTrace(trace));
+}
+
+ContextTrace *icinga::GetLastExceptionContext(void)
+{
+	return l_LastExceptionContext.get();
+}
+
+void icinga::SetLastExceptionContext(const ContextTrace& context)
+{
+	l_LastExceptionContext.reset(new ContextTrace(context));
 }
 
 String icinga::DiagnosticInformation(boost::exception_ptr eptr)
 {
 	StackTrace *pt = GetLastExceptionStack();
-	StackTrace trace;
+	StackTrace stack;
+
+	ContextTrace *pc = GetLastExceptionContext();
+	ContextTrace context;
 
 	if (pt)
-		trace = *pt;
+		stack = *pt;
+
+	if (pc)
+		context = *pc;
 
 	try {
 		boost::rethrow_exception(eptr);
 	} catch (const std::exception& ex) {
-		return DiagnosticInformation(ex, pt ? &trace : NULL);
+		return DiagnosticInformation(ex, pt ? &stack : NULL, pc ? &context : NULL);
 	}
 
 	return boost::diagnostic_information(eptr);
 }
-

lib/base/exception.h

@@ -23,6 +23,7 @@
 #include "base/i2-base.h"
 #include "base/qstring.h"
 #include "base/stacktrace.h"
+#include "base/context.h"
 #include <sstream>
 #include <boost/thread/tss.hpp>
 #include <boost/exception/errinfo_api_function.hpp>
@@ -41,10 +42,14 @@ namespace icinga
 I2_BASE_API StackTrace *GetLastExceptionStack(void);
 I2_BASE_API void SetLastExceptionStack(const StackTrace& trace);
 
+I2_BASE_API ContextTrace *GetLastExceptionContext(void);
+I2_BASE_API void SetLastExceptionContext(const ContextTrace& context);
+
 typedef boost::error_info<StackTrace, StackTrace> StackTraceErrorInfo;
+typedef boost::error_info<ContextTrace, ContextTrace> ContextTraceErrorInfo;
 
 template<typename T>
-String DiagnosticInformation(const T& ex, StackTrace *trace = NULL)
+String DiagnosticInformation(const T& ex, StackTrace *stack = NULL, ContextTrace *context = NULL)
 {
 	std::ostringstream result;
 
@@ -53,12 +58,21 @@ String DiagnosticInformation(const T& ex, StackTrace *trace = NULL)
 	if (boost::get_error_info<StackTraceErrorInfo>(ex) == NULL) {
 		result << std::endl;
 
-		if (trace)
+		if (stack)
-			result << *trace;
+			result << *stack;
 		else
 			result << *GetLastExceptionStack();
 	}
 
+	if (boost::get_error_info<ContextTraceErrorInfo>(ex) == NULL) {
+		result << std::endl;
+
+		if (context)
+			result << *context;
+		else
+			result << *GetLastExceptionContext();
+	}
+
 	return result.str();
 }
 

lib/base/logger.cpp

@@ -23,6 +23,8 @@
 #include "base/dynamictype.h"
 #include "base/utility.h"
 #include "base/objectlock.h"
+#include "base/context.h"
+#include "base/convert.h"
 #include <boost/make_shared.hpp>
 #include <boost/foreach.hpp>
 #include <iostream>
@@ -73,6 +75,16 @@ void icinga::Log(LogSeverity severity, const String& facility,
 	entry.Facility = facility;
 	entry.Message = message;
 
+	if (severity >= LogWarning) {
+		ContextTrace context;
+
+		if (context.GetLength() > 0) {
+			std::ostringstream trace;
+			trace << context;
+			entry.Message += "\nContext:" + trace.str();
+		}
+	}
+
 	bool processed = false;
 
 	BOOST_FOREACH(const Logger::Ptr& logger, Logger::GetLoggers()) {

lib/base/stacktrace.cpp

@@ -107,7 +107,7 @@ void StackTrace::Initialize(void)
  */
 void StackTrace::Print(std::ostream& fp, int ignoreFrames) const
 {
-	fp << std::endl << "Stacktrace:" << std::endl;
+	fp << std::endl;
 
 #ifndef _WIN32
 #	ifdef HAVE_BACKTRACE_SYMBOLS

lib/config/configcompiler.cpp

@@ -21,6 +21,7 @@
 #include "config/configitem.h"
 #include "base/logger_fwd.h"
 #include "base/utility.h"
+#include "base/context.h"
 #include <sstream>
 #include <fstream>
 #include <boost/foreach.hpp>
@@ -126,6 +127,8 @@ void ConfigCompiler::HandleLibrary(const String& library)
  */
 void ConfigCompiler::CompileStream(const String& path, std::istream *stream)
 {
+	CONTEXT("Compiling configuration stream with name '" + path + "'");
+
 	stream->exceptions(std::istream::badbit);
 
 	ConfigCompiler ctx(path, stream);
@@ -140,6 +143,8 @@ void ConfigCompiler::CompileStream(const String& path, std::istream *stream)
  */
 void ConfigCompiler::CompileFile(const String& path)
 {
+	CONTEXT("Compiling configuration file '" + path + "'");
+
 	std::ifstream stream;
 	stream.open(path.CStr(), std::ifstream::in);
 

lib/icinga/macroprocessor.cpp

@@ -23,6 +23,7 @@
 #include "base/array.h"
 #include "base/objectlock.h"
 #include "base/logger_fwd.h"
+#include "base/context.h"
 #include <boost/tuple/tuple.hpp>
 #include <boost/foreach.hpp>
 
@@ -60,6 +61,8 @@ Value MacroProcessor::ResolveMacros(const Value& str, const std::vector<MacroRes
 bool MacroProcessor::ResolveMacro(const String& macro, const std::vector<MacroResolver::Ptr>& resolvers,
     const CheckResult::Ptr& cr, String *result)
 {
+	CONTEXT("Resolving macro '" + macro + "'");
+
 	BOOST_FOREACH(const MacroResolver::Ptr& resolver, resolvers) {
 		if (resolver->ResolveMacro(macro, cr, result))
 			return true;
@@ -72,6 +75,8 @@ bool MacroProcessor::ResolveMacro(const String& macro, const std::vector<MacroRe
 String MacroProcessor::InternalResolveMacros(const String& str, const std::vector<MacroResolver::Ptr>& resolvers,
 	const CheckResult::Ptr& cr, const MacroProcessor::EscapeCallback& escapeFn, const Array::Ptr& escapeMacros)
 {
+	CONTEXT("Resolving macros for string '" + str + "'");
+
 	size_t offset, pos_first, pos_second;
 	offset = 0;
 

lib/icinga/service-check.cpp

@@ -27,6 +27,7 @@
 #include "base/convert.h"
 #include "base/utility.h"
 #include "base/exception.h"
+#include "base/context.h"
 #include <boost/foreach.hpp>
 #include <boost/algorithm/string/replace.hpp>
 
@@ -440,6 +441,8 @@ String Service::StateTypeToString(StateType type)
 
 void Service::ExecuteCheck(void)
 {
+	CONTEXT("Executing service check for service '" + GetShortName() + "' on host '" + GetHost()->GetName() + "'");
+
 	ASSERT(!OwnsLock());
 
 	bool reachable = IsReachable();

lib/icinga/service-event.cpp

@@ -20,6 +20,7 @@
 #include "icinga/service.h"
 #include "icinga/eventcommand.h"
 #include "icinga/icingaapplication.h"
+#include "base/context.h"
 
 using namespace icinga;
 
@@ -45,6 +46,8 @@ EventCommand::Ptr Service::GetEventCommand(void) const
 
 void Service::ExecuteEventHandler(void)
 {
+	CONTEXT("Executing event handler for service '" + GetShortName() + "' on host '" + GetHost()->GetName() + "'");
+
 	if (!IcingaApplication::GetInstance()->GetEnableEventHandlers() || !GetEnableEventHandler())
 		return;
 

lib/icinga/service-notification.cpp

@@ -25,6 +25,7 @@
 #include "base/timer.h"
 #include "base/utility.h"
 #include "base/exception.h"
+#include "base/context.h"
 #include "config/configitembuilder.h"
 #include <boost/tuple/tuple.hpp>
 #include <boost/foreach.hpp>
@@ -44,6 +45,8 @@ void Service::ResetNotificationNumbers(void)
 
 void Service::SendNotifications(NotificationType type, const CheckResult::Ptr& cr, const String& author, const String& text)
 {
+	CONTEXT("Sending notifications for service '" + GetShortName() + "' on host '" + GetHost()->GetName() + "'");
+
 	bool force = GetForceNextNotification();
 
 	if (!IcingaApplication::GetInstance()->GetEnableNotifications() || !GetEnableNotifications()) {