towards logging the call stack on Segfault

src/3rd_party/ExceptionWithCallStack.cpp

@@ -0,0 +1,269 @@
+//
+// Copyright (c) Microsoft. All rights reserved.
+// Licensed under the MIT license. See LICENSE.md file in the project root for full license information.
+//
+// ExceptionWithCallStack.cpp : Defines the CNTK exception and stack utilities
+//
+
+//#define _CRT_SECURE_NO_WARNINGS // "secure" CRT not available on all platforms  --add this at the top of all CPP files that give "function or variable may be unsafe" warnings
+#ifdef _WIN32
+#pragma comment(lib, "Dbghelp.lib")
+#pragma warning(push)
+#pragma warning(disable: 4091) // 'typedef ': ignored on left of '' when no variable is declared
+#define NOMINMAX
+#include <Windows.h>
+#include "DbgHelp.h"
+#pragma warning(pop)
+#else
+#include <execinfo.h>
+#include <cxxabi.h>
+#endif
+
+#include "ExceptionWithCallStack.h"
+
+#include <algorithm>
+#include <iostream>
+#include <functional>
+#include <stdexcept>
+
+namespace Microsoft { namespace MSR { namespace CNTK {
+
+using namespace std;
+
+static string MakeFunctionNameStandOut(string name);
+static void CollectCallStack(size_t skipLevels, bool makeFunctionNamesStandOut, const function<void(string)>& write);
+
+namespace DebugUtil
+{
+    /// <summary>This function retrieves the call stack as a string</summary>
+    string GetCallStack(size_t skipLevels /*= 0*/, bool makeFunctionNamesStandOut /*= false*/)
+    {
+        try
+        {
+            string output;
+            CollectCallStack(skipLevels + 1/*skip this function*/, makeFunctionNamesStandOut, [&output](string stack)
+            {
+                output += stack;
+            });
+            return output;
+        }
+        catch (...) // since we run as part of error reporting, don't get hung up on our own error
+        {
+            return string();
+        }
+    }
+
+    /// <summary>This function outputs the call stack to the std err</summary>
+    void PrintCallStack(size_t skipLevels /*= 0*/, bool makeFunctionNamesStandOut /*= false*/)
+    {
+        CollectCallStack(skipLevels + 1/*skip this function*/, makeFunctionNamesStandOut, [](string stack)
+        {
+            cerr << stack;
+        });
+    }
+}
+
+// make the unmangled name a bit more readable
+// Insert spaces around the main function name for better visual parsability; and double-spaces between function arguments.
+// This uses some heuristics for C++ names that may be fragile, but that's OK since this only adds/removes spaces.
+static string MakeFunctionNameStandOut(string origName)
+{
+    try // guard against exception, since this is used for exception reporting
+    {
+        auto name = origName;
+        // strip off modifiers for parsing (will be put back at the end)
+        string modifiers;
+        auto pos = name.find_last_not_of(" abcdefghijklmnopqrstuvwxyz");
+        if (pos != string::npos)
+        {
+            modifiers = name.substr(pos + 1);
+            name = name.substr(0, pos + 1);
+        }
+        bool hasArgList = !name.empty() && name.back() == ')';
+        size_t angleDepth = 0;
+        size_t parenDepth = 0;
+        bool hitEnd = !hasArgList; // hit end of function name already?
+        bool hitStart = false;
+        // we parse the function name from the end; escape nested <> and ()
+        // We look for the end and start of the function name itself (without namespace qualifiers),
+        // and for commas separating function arguments.
+        for (size_t i = name.size(); i--> 0;)
+        {
+            // account for nested <> and ()
+            if (name[i] == '>')
+                angleDepth++;
+            else if (name[i] == '<')
+                angleDepth--;
+            else if (name[i] == ')')
+                parenDepth++;
+            else if (name[i] == '(')
+                parenDepth--;
+            // space before '>'
+            if (name[i] == ' ' && i + 1 < name.size() && name[i + 1] == '>')
+                name.erase(i, 1); // remove
+            // commas
+            if (name[i] == ',')
+            {
+                if (i + 1 < name.size() && name[i + 1] == ' ')
+                    name.erase(i + 1, 1);  // remove spaces after comma
+                if (!hitEnd && angleDepth == 0 && parenDepth == 1)
+                    name.insert(i + 1, "  "); // except for top-level arguments, we separate them by 2 spaces for better readability
+            }
+            // function name
+            if ((name[i] == '(' || name[i] == '<') &&
+                parenDepth == 0 && angleDepth == 0 &&
+                (i == 0 || name[i - 1] != '>') &&
+                !hitEnd && !hitStart) // we hit the start of the argument list
+            {
+                hitEnd = true;
+                name.insert(i, "  ");
+            }
+            else if ((name[i] == ' ' || name[i] == ':' || name[i] == '>') && hitEnd && !hitStart && i > 0) // we hit the start of the function name
+            {
+                if (name[i] != ' ')
+                    name.insert(i + 1, " ");
+                name.insert(i + 1, " "); // in total insert 2 spaces
+                hitStart = true;
+            }
+        }
+        return name + modifiers;
+    }
+    catch (...)
+    {
+        return origName;
+    }
+}
+
+/// <summary>This function collects the stack tracke and writes it through the provided write function
+/// <param name="write">Function for writing the text associated to a the callstack</param>
+/// <param name="newline">Function for writing and "end-of-line" / "newline"</param>
+/// </summary>
+static void CollectCallStack(size_t skipLevels, bool makeFunctionNamesStandOut, const function<void(string)>& write)
+{
+    static const int MAX_CALLERS = 62;
+    static const unsigned short MAX_CALL_STACK_DEPTH = 20;
+
+    write("\n[CALL STACK]\n");
+
+#ifdef _WIN32
+
+    // RtlCaptureStackBackTrace() is a kernel API without default binding, we must manually determine its function pointer.
+    typedef USHORT(WINAPI * CaptureStackBackTraceType)(__in ULONG, __in ULONG, __out PVOID*, __out_opt PULONG);
+    CaptureStackBackTraceType RtlCaptureStackBackTrace = (CaptureStackBackTraceType)(GetProcAddress(LoadLibrary(L"kernel32.dll"), "RtlCaptureStackBackTrace"));
+    if (RtlCaptureStackBackTrace == nullptr) // failed somehow
+        return write("Failed to generate CALL STACK. GetProcAddress(\"RtlCaptureStackBackTrace\") failed\n");
+
+    HANDLE process = GetCurrentProcess();
+    if (!SymInitialize(process, nullptr, TRUE))
+        return write("Failed to generate CALL STACK. SymInitialize() failed\n");
+
+    // get the call stack
+    void* callStack[MAX_CALLERS];
+    unsigned short frames;
+    frames = RtlCaptureStackBackTrace(0, MAX_CALLERS, callStack, nullptr);
+
+    SYMBOL_INFO* symbolInfo = (SYMBOL_INFO*)calloc(sizeof(SYMBOL_INFO) + 256 * sizeof(char), 1); // this is a variable-length structure, can't use vector easily
+    symbolInfo->MaxNameLen = 255;
+    symbolInfo->SizeOfStruct = sizeof(SYMBOL_INFO);
+    frames = min(frames, MAX_CALL_STACK_DEPTH);
+
+    // format and emit
+    size_t firstFrame = skipLevels + 1; // skip CollectCallStack()
+    for (size_t i = firstFrame; i < frames; i++)
+    {
+        if (i == firstFrame)
+            write("    > ");
+        else
+            write("    - ");
+
+        if (SymFromAddr(process, (DWORD64)(callStack[i]), 0, symbolInfo))
+        {
+            write(makeFunctionNamesStandOut ? MakeFunctionNameStandOut(symbolInfo->Name) : symbolInfo->Name);
+            write("\n");
+        }
+        else
+        {
+            char buf[17];
+            sprintf_s(buf, "%p", callStack[i]);
+            write(buf);
+            write(" (SymFromAddr() error)\n");
+        }
+    }
+
+    write("\n");
+
+    free(symbolInfo);
+
+    SymCleanup(process);
+
+#else // Linux
+
+    unsigned int MAX_NUM_FRAMES = 1024;
+    void* backtraceAddresses[MAX_NUM_FRAMES];
+    unsigned int numFrames = backtrace(backtraceAddresses, MAX_NUM_FRAMES);
+    char** symbolList = backtrace_symbols(backtraceAddresses, numFrames);
+
+    for (size_t i = skipLevels; i < numFrames; i++)
+    {
+        char* beginName    = NULL;
+        char* beginOffset  = NULL;
+        char* beginAddress = NULL;
+
+        // Find parentheses and +address offset surrounding the mangled name
+        for (char* p = symbolList[i]; *p; ++p)
+        {
+            if (*p == '(')      // function name begins here
+                beginName = p;
+            else if (*p == '+') // relative address ofset
+                beginOffset = p;
+            else if ((*p == ')') && (beginOffset || beginName)) // absolute address
+                beginAddress = p;
+        }
+        const int buf_size = 1024;
+        char buffer[buf_size];
+
+        if (beginName && beginAddress && (beginName < beginAddress))
+        {
+            *beginName++ = '\0';
+            *beginAddress++ = '\0';
+            if (beginOffset) // has relative address
+                *beginOffset++ = '\0';
+
+            // Mangled name is now in [beginName, beginOffset) and caller offset in [beginOffset, beginAddress).
+            int status = 0;
+            unsigned int MAX_FUNCNAME_SIZE = 4096;
+            size_t funcNameSize = MAX_FUNCNAME_SIZE;
+            char funcName[MAX_FUNCNAME_SIZE]; // working buffer
+            const char* ret = abi::__cxa_demangle(beginName, funcName, &funcNameSize, &status);
+            string fName;
+            if (status == 0)
+                fName = makeFunctionNamesStandOut ? MakeFunctionNameStandOut(ret) : ret; // make it a bit more readable
+            else
+                fName = beginName; // failed: fall back
+
+            // name of source file--not printing since it is not super-useful
+            //string sourceFile = symbolList[i];
+            //static const size_t sourceFileWidth = 20;
+            //if (sourceFile.size() > sourceFileWidth)
+            //    sourceFile = "..." + sourceFile.substr(sourceFile.size() - (sourceFileWidth-3));
+            while (*beginAddress == ' ') // eat unnecessary space
+                beginAddress++;
+            string pcOffset = beginOffset ? string(" + ") + beginOffset : string();
+            snprintf(buffer, buf_size, "%-20s%-50s%s\n", beginAddress, fName.c_str(), pcOffset.c_str());
+        }
+        else // Couldn't parse the line. Print the whole line as it came.
+            snprintf(buffer, buf_size, "%s\n", symbolList[i]);
+
+        write(buffer);
+    }
+
+    free(symbolList);
+
+#endif
+}
+
+template class ExceptionWithCallStack<std::runtime_error>;
+template class ExceptionWithCallStack<std::logic_error>;
+template class ExceptionWithCallStack<std::invalid_argument>;
+
+}}}

src/3rd_party/ExceptionWithCallStack.h

@@ -0,0 +1,42 @@
+//
+// Copyright (c) Microsoft. All rights reserved.
+// Licensed under the MIT license. See LICENSE.md file in the project root for full license information.
+//
+// ExceptionWithCallStack.h - debug util functions
+//
+
+#include <string>
+
+namespace Microsoft { namespace MSR { namespace CNTK {
+
+// base class that we can catch, independent of the type parameter
+struct /*interface*/ IExceptionWithCallStackBase
+{
+    virtual const char * CallStack() const = 0;
+    virtual ~IExceptionWithCallStackBase() noexcept = default;
+};
+
+// Exception wrapper to include native call stack string
+template <class E>
+class ExceptionWithCallStack : public E, public IExceptionWithCallStackBase
+{
+public:
+    ExceptionWithCallStack(const std::string& msg, const std::string& callstack) :
+        E(msg), m_callStack(callstack)
+    { }
+
+    virtual const char * CallStack() const override { return m_callStack.c_str(); }
+
+protected:
+    std::string m_callStack;
+};
+
+// some older code uses this namespace
+namespace DebugUtil
+{
+    void PrintCallStack(size_t skipLevels = 0, bool makeFunctionNamesStandOut = false);
+
+    std::string GetCallStack(size_t skipLevels = 0, bool makeFunctionNamesStandOut = false);
+};
+
+}}}

src/command/marian_conv.cpp

@@ -6,7 +6,7 @@
 int main(int argc, char** argv) {
   using namespace marian;
 
-  createLoggers();
+  createLoggers(); // @TODO: Most other main() do not call this directly. Needed here?
 
   namespace po = boost::program_options;
   po::options_description desc("Allowed options");

src/command/marian_vocab.cpp

@@ -8,7 +8,7 @@
 int main(int argc, char** argv) {
   using namespace marian;
 
-  createLoggers();
+  createLoggers(); // @TODO: Most other main() do not call this directly. Needed here?
 
   namespace po = boost::program_options;
   po::options_description desc("Allowed options");

src/common/logging.cpp

@@ -1,8 +1,12 @@
 #include "logging.h"
 #include "common/config.h"
 #include "spdlog/sinks/null_sink.h"
+#include "3rd_party/ExceptionWithCallStack.h"
 #include <time.h>
 #include <stdlib.h>
+#ifdef __unix__
+#include <signal.h>
+#endif
 
 std::shared_ptr<spdlog::logger> stderrLogger(
     const std::string& name,
@@ -53,6 +57,13 @@ bool setLoggingLevel(spdlog::logger& logger, std::string const level) {
   }
   return true;
 }
+
+#ifdef __unix__
+void segfault_sigaction(int signal, siginfo_t *si, void *arg)
+{
+  marian::logCallStack();
+}
+#endif
 
 void createLoggers(const marian::Config* options) {
   std::vector<std::string> generalLogs;
@@ -83,13 +94,34 @@ void createLoggers(const marian::Config* options) {
   }
 
   if (options && options->has("log-time-zone")) {
-      std::string timezone = options->get<std::string>("log-time-zone");
-      if (timezone != "") {
+    std::string timezone = options->get<std::string>("log-time-zone");
+    if (timezone != "") {
 #ifdef _WIN32
 #define setenv(var, val, over) SetEnvironmentVariableA(var, val) // ignoring over flag
 #endif
-        setenv("TZ", timezone.c_str(), true);
-        tzset();
-      }
+      setenv("TZ", timezone.c_str(), true);
+      tzset();
+    }
+  }
+
+#ifdef __unix__
+  // catch segfaults
+  struct sigaction sa;
+
+  memset(&sa, 0, sizeof(sa));
+  sigemptyset(&sa.sa_mask);
+  sa.sa_sigaction = segfault_sigaction;
+  sa.sa_flags = SA_SIGINFO;
+
+  sigaction(SIGSEGV, &sa, NULL);
+#endif
+}
+
+namespace marian {
+  void logCallStack()
+  {
+    using namespace ::Microsoft::MSR::CNTK::DebugUtil;
+    auto callStack = GetCallStack(/*skipLevels=*/ 1, /*makeFunctionNamesStandOut=*/true);
+    checkedLog("general", "critical", "Call stack:\n{}", callStack);
   }
 }

src/common/logging.h

@@ -4,6 +4,10 @@
 
 #include "spdlog/spdlog.h"
 
+namespace marian {
+  void logCallStack();
+}
+
 /**
  * Prints logging message into stderr and a file specified with `--log` option.
  *
@@ -45,6 +49,7 @@
 #define ABORT(...)                                                      \
   do {                                                                  \
     checkedLog("general", "critical", __VA_ARGS__);                     \
+    ::marian::logCallStack();                                           \
     std::cerr << "Aborted from " << FUNCTION_NAME << " in " << __FILE__ \
               << ": " << __LINE__ << std::endl;                         \
     std::abort();                                                       \

vs/Marian.vcxproj

@@ -112,8 +112,10 @@
     </Link>
   </ItemDefinitionGroup>
   <ItemGroup>
+    <ClCompile Include="..\src\3rd_party\ExceptionWithCallStack.cpp" />
     <ClCompile Include="..\src\3rd_party\yaml-cpp\binary_renamed.cpp" />
     <ClCompile Include="..\src\3rd_party\yaml-cpp\yaml-node.cpp" />
+    <ClInclude Include="..\src\3rd_party\ExceptionWithCallStack.h" />
     <ClInclude Include="..\src\command\marian.cpp" />
     <ClInclude Include="..\src\command\marian_decoder.cpp" />
     <ClInclude Include="..\src\command\marian_scorer.cpp" />

vs/Marian.vcxproj.filters

@@ -244,6 +244,9 @@
     <ClCompile Include="..\src\command\marian_main.cpp">
       <Filter>command</Filter>
     </ClCompile>
+    <ClCompile Include="..\src\3rd_party\ExceptionWithCallStack.cpp">
+      <Filter>3rd_party</Filter>
+    </ClCompile>
   </ItemGroup>
   <ItemGroup>
     <ClInclude Include="..\src\marian.h" />
@@ -1034,6 +1037,9 @@
       <Filter>command</Filter>
     </ClInclude>
     <ClInclude Include="..\src\command\marian_conv.cpp" />
+    <ClInclude Include="..\src\3rd_party\ExceptionWithCallStack.h">
+      <Filter>3rd_party</Filter>
+    </ClInclude>
   </ItemGroup>
   <ItemGroup>
     <Filter Include="3rd_party">