Add stack capture

Signed-off-by: Richard Chapman <[email protected]>
hpcc-systems · Oct 4, 2023 · 0062f82 · 0062f82
1 parent 6642430
commit 0062f82
Show file tree

Hide file tree

Showing 4 changed files with 74 additions and 13 deletions.
diff --git a/roxie/ccd/ccdkey.cpp b/roxie/ccd/ccdkey.cpp
@@ -691,10 +691,11 @@ class BufferedDirectReader : public CDirectReaderBase
         while (!_partNo && !thisPart && ++thisPartIdx < maxParts) // MORE
         {
             thisPart.setown(f->getFilePart(thisPartIdx, thisFileStartPos));
-            if (thisPart && _startPos >= thisPart->size())
+            offset_t thisPartSize = thisPart->size();
+            if (thisPart && _startPos >= thisPartSize)
             {
-                _startPos -= thisPart->size();
-                completedStreamsSize += thisPart->size();
+                _startPos -= thisPartSize;
+                completedStreamsSize += thisPartSize;
                 thisPart.clear();
             }
         }

diff --git a/system/jlib/jexcept.cpp b/system/jlib/jexcept.cpp
@@ -37,7 +37,7 @@
 #include <sys/types.h>
 #include <stddef.h>
 #include <errno.h>
-#ifdef __linux__
+#if defined(__linux__) || defined(__APPLE__)
 #include <execinfo.h> // comment out if not present
 #endif
 #ifdef __APPLE__
@@ -1702,7 +1702,7 @@ void printStackReport(__int64 startIP)
 #ifdef _WIN32
     unsigned onstack=1234;
     doPrintStackReport(0, 0,(unsigned)&onstack);
-#elif defined(__linux__)
+#elif defined(__linux__) || defined(__APPLE__)
     DBGLOG("Backtrace:");
     void *btarray[100];
     unsigned btn = backtrace (btarray, 100);

diff --git a/system/jlib/jmutex.cpp b/system/jlib/jmutex.cpp
@@ -132,14 +132,18 @@ MODULE_EXIT()
     qsort(critBlocks, numCritBlocks, sizeof(CriticalBlockInstrumentation*), compareCI);
     for (unsigned i = 0; i < numCritBlocks; i++)
     {
-        StringBuffer s;
-        DBGLOG("%s", critBlocks[i]->describe(s).str());
+        critBlocks[i]->describe(i < 10);
     }
 }
 
 static SpinLock sl;
 thread_local CriticalBlockInstrumentation *__cbinst = nullptr;
 
+std::size_t CriticalBlockInstrumentation::StackHash::operator()(const Stack& k) const
+{
+    return hashc((const byte *) k.stack, sizeof(k.stack), 0);
+}
+
 std::string humanTime(unsigned long cycles)
 {
     if (!cycles)
@@ -163,6 +167,17 @@ CriticalBlockInstrumentation::CriticalBlockInstrumentation(const char *_file, co
 
 void CriticalBlockInstrumentation::addStat(cycle_t wait, cycle_t hold, bool wasContended)
 {
+    // most of these should be atomic OR we should use some sort of lock, to be safe. A member object Spin might make the most sense
+    // 
+#ifdef HAS_BACKTRACE
+    void *lbtBuff[numStackEntries+3];
+    unsigned nFrames = backtrace(lbtBuff, numStackEntries+3);
+    if (nFrames == numStackEntries+3)
+    {
+        Stack *a = (Stack *) (lbtBuff+3);
+        stacks[*a]++;
+    }
+#endif
     if (wasContended)
         contended++;
     else
@@ -175,9 +190,26 @@ CriticalBlockInstrumentation::~CriticalBlockInstrumentation()
 {
 }
 
-StringBuffer &CriticalBlockInstrumentation::describe(StringBuffer &ret) const
+void CriticalBlockInstrumentation::describe(bool includeStack) const
 {
-    return ret.appendf("CritBlock %s (%s:%u): wait %s hold %s, entered %u times", func, strrchr(file, PATHSEPCHAR)+1, line, humanTime(waitCycles).c_str(), humanTime(holdCycles).c_str(), contended+uncontended);
+    DBGLOG("CritBlock %s (%s:%u): wait %s hold %s, entered %u times, contended %u times", func, strrchr(file, PATHSEPCHAR)+1, line, humanTime(waitCycles).c_str(), humanTime(holdCycles).c_str(), contended+uncontended, contended);
+    if (includeStack)
+    {
+        std::vector<std::pair<Stack, int>> sorted_stacks(stacks.begin(), stacks.end());
+        std::sort(sorted_stacks.begin(), sorted_stacks.end(), [](auto &left, auto &right) { return left.second > right.second; });
+        unsigned printed = 0;
+        for (auto &stack: sorted_stacks)
+        {
+            if (printed == 3)
+                break;
+            DBGLOG("Stack appeared %u times:", stack.second);
+            char** strs = backtrace_symbols(stack.first.stack, 4);
+            for (unsigned i = 0; i < 4; ++i)
+                DBGLOG("%s", strs[i]);
+            free(strs);
+            printed++;
+        }
+    }
 }
 
 int CriticalBlockInstrumentation::compare(const CriticalBlockInstrumentation *other) const
@@ -212,9 +244,9 @@ InstrumentedCriticalBlock::InstrumentedCriticalBlock(InstrumentedCriticalSection
 
 InstrumentedCriticalBlock::~InstrumentedCriticalBlock()
 {
-    crit.leave();
+    bool wasContended = crit.leave();
     cycle_t out = get_cycles_now();
-    inst->addStat(in-start, out-in, false);
+    inst->addStat(in-start, out-in, wasContended);
 }
 
 void InstrumentedCriticalSection::reportContended(bool destructor)

diff --git a/system/jlib/jmutex.hpp b/system/jlib/jmutex.hpp
@@ -26,6 +26,12 @@
 #include "jiface.hpp"
 #include "jsem.hpp"
 #include "jtiming.hpp"
+#include <unordered_map>
+
+#if defined (__linux__) || defined(__FreeBSD__)  || defined(__APPLE__)
+#include <execinfo.h> // comment out if not present
+#define HAS_BACKTRACE
+#endif
 
 extern jlib_decl void ThreadYield();
 extern jlib_decl void spinUntilReady(std::atomic_uint &value);
@@ -396,7 +402,7 @@ class InstrumentedCriticalSection
 #endif
     }
 
-    inline void leave()
+    inline bool leave()
     {
         bool isContended = false;
         if (depth==1)
@@ -411,6 +417,7 @@ class InstrumentedCriticalSection
         pthread_mutex_unlock(&mutex);
         if (isContended)
             reportContended(false);
+        return isContended;
     }
     inline void assertLocked()
     {
@@ -441,11 +448,29 @@ typedef CriticalBlockOf<UninstrumentedCriticalSection> UninstrumentedCriticalBlo
 
 class CriticalBlockInstrumentation
 {
+#ifdef HAS_BACKTRACE
+    static constexpr unsigned numStackEntries = 8;
+    class Stack
+    {
+    public:
+        void *stack[numStackEntries];
+        bool operator==(const Stack &other) const
+        {
+            return memcmp(stack, other.stack, sizeof(stack)) == 0;
+        }
+    };
+
+    struct StackHash
+    {
+        std::size_t operator()(const Stack& k) const;
+    };
+#endif
+
 public:
     CriticalBlockInstrumentation(const char *file, const char *func, unsigned line);
     ~CriticalBlockInstrumentation();
     void addStat(cycle_t wait, cycle_t hold, bool wasContended);
-    StringBuffer &describe(StringBuffer &ret) const;
+    void describe(bool withStack) const;
     int compare(const CriticalBlockInstrumentation *other) const;
 private:
     const char *file;
@@ -455,6 +480,9 @@ class CriticalBlockInstrumentation
     cycle_t holdCycles;
     unsigned uncontended;
     unsigned contended;
+#ifdef HAS_BACKTRACE
+    std::unordered_map<Stack, unsigned, StackHash> stacks;
+#endif
 };
 
 class InstrumentedCriticalBlock