Improve backtraces:

- Reduce noise.
- Trace through async callbacks.

c++/src/capnp/rpc.c++

@@ -116,6 +116,11 @@ void fromException(const kj::Exception& exception, rpc::Exception::Builder build
   //   transmit stack traces?
   builder.setReason(exception.getDescription());
   builder.setType(static_cast<rpc::Exception::Type>(exception.getType()));
+
+  if (exception.getType() == kj::Exception::Type::FAILED &&
+      !exception.getDescription().startsWith("remote exception:")) {
+    KJ_LOG(INFO, "returning failure over rpc", exception);
+  }
 }
 
 uint exceptionSizeHint(const kj::Exception& exception) {

c++/src/kj/async-inl.h

@@ -246,9 +246,84 @@ private:
 
 // -------------------------------------------------------------------
 
+class PtmfHelper {
+  // This class is a private helper for GetFunctorStartAddress. The class represents the internal
+  // representation of a pointer-to-member-function.
+
+  template <typename... ParamTypes>
+  friend struct GetFunctorStartAddress;
+
+#if __GNUG__
+  void* ptr;
+  ptrdiff_t adj;
+  // Layout of a pointer-to-member-function used by GCC and compatible compilers.
+#else
+#error "TODO(port): PTMF instruction address extraction"
+#endif
+
+#define BODY \
+    PtmfHelper result; \
+    static_assert(sizeof(p) == sizeof(result), "unknown ptmf layout"); \
+    memcpy(&result, &p, sizeof(result)); \
+    return result
+
+  template <typename R, typename C, typename... P, typename F>
+  static PtmfHelper from(F p) { BODY; }
+  // Create a PtmfHelper from some arbitrary pointer-to-member-function which is not
+  // overloaded nor a template. In this case the compiler is able to deduce the full function
+  // signature directly given the name since there is only one function with that name.
+
+  template <typename R, typename C, typename... P>
+  static PtmfHelper from(R (C::*p)(NoInfer<P>...)) { BODY; }
+  template <typename R, typename C, typename... P>
+  static PtmfHelper from(R (C::*p)(NoInfer<P>...) const) { BODY; }
+  // Create a PtmfHelper from some poniter-to-member-function which is a template. In this case
+  // the function must match exactly the containing type C, return type R, and parameter types P...
+  // GetFunctorStartAddress normally specifies exactly the correct C and R, but can only make a
+  // guess at P. Luckily, if the function parameters are template parameters then it's not
+  // necessary to be precise about P.
+#undef BODY
+
+  void* apply(void* obj) {
+    ptrdiff_t voff = (ptrdiff_t)ptr;
+    if (voff & 1) {
+      voff &= ~1;
+      return *(void**)(*(char**)obj + voff);
+    } else {
+      return ptr;
+    }
+  }
+};
+
+template <typename... ParamTypes>
+struct GetFunctorStartAddress {
+  // Given a functor (any object defining operator()), return the start address of the function,
+  // suitable for passing to addr2line to obtain a source file/line for debugging purposes.
+  //
+  // This turns out to be incredibly hard to implement in the presence of overloaded or templated
+  // functors. Therefore, we impose these specific restrictions, specific to our use case:
+  // - Overloading is not allowed, but templating is. (Generally we only intend to support lambdas
+  //   anyway.)
+  // - The template parameters to GetFunctorStartAddress specify a hint as to the expected
+  //   parameter types. If the functor is templated, its parameters must match exactly these types.
+  //   (If it's not templated, ParamTypes are ignored.)
+
+  template <typename Func>
+  static void* apply(Func&& func) {
+    typedef decltype(func(instance<ParamTypes>()...)) ReturnType;
+    return PtmfHelper::from<ReturnType, Decay<Func>, ParamTypes...>(
+        &Decay<Func>::operator()).apply(&func);
+  }
+};
+
+template <>
+struct GetFunctorStartAddress<Void&&>: public GetFunctorStartAddress<> {};
+// Hack for TransformPromiseNode use case: an input type of `Void` indicates that the function
+// actually has no parameters.
+
 class TransformPromiseNodeBase: public PromiseNode {
 public:
-  TransformPromiseNodeBase(Own<PromiseNode>&& dependency);
+  TransformPromiseNodeBase(Own<PromiseNode>&& dependency, void* continuationTracePtr);
 
   void onReady(Event& event) noexcept override;
   void get(ExceptionOrValue& output) noexcept override;
@@ -256,6 +331,7 @@ public:
 
 private:
   Own<PromiseNode> dependency;
+  void* continuationTracePtr;
 
   void dropDependency();
   void getDepResult(ExceptionOrValue& output);
@@ -273,7 +349,8 @@ class TransformPromiseNode final: public TransformPromiseNodeBase {
 
 public:
   TransformPromiseNode(Own<PromiseNode>&& dependency, Func&& func, ErrorFunc&& errorHandler)
-      : TransformPromiseNodeBase(kj::mv(dependency)),
+      : TransformPromiseNodeBase(kj::mv(dependency),
+            GetFunctorStartAddress<DepT&&>::apply(func)),
         func(kj::fwd<Func>(func)), errorHandler(kj::fwd<ErrorFunc>(errorHandler)) {}
 
   ~TransformPromiseNode() noexcept(false) {

c++/src/kj/async.c++

@@ -557,8 +557,9 @@ void AttachmentPromiseNodeBase::dropDependency() {
 
 // -------------------------------------------------------------------
 
-TransformPromiseNodeBase::TransformPromiseNodeBase(Own<PromiseNode>&& dependencyParam)
-    : dependency(kj::mv(dependencyParam)) {
+TransformPromiseNodeBase::TransformPromiseNodeBase(
+    Own<PromiseNode>&& dependencyParam, void* continuationTracePtr)
+    : dependency(kj::mv(dependencyParam)), continuationTracePtr(continuationTracePtr) {
   dependency->setSelfPointer(&dependency);
 }
 
@@ -590,6 +591,10 @@ void TransformPromiseNodeBase::getDepResult(ExceptionOrValue& output) {
   })) {
     output.addException(kj::mv(*exception));
   }
+
+  KJ_IF_MAYBE(e, output.exception) {
+    e->addTrace(continuationTracePtr);
+  }
 }
 
 // -------------------------------------------------------------------

c++/src/kj/common.h

@@ -156,6 +156,12 @@ typedef unsigned char byte;
 // Force a function to always be inlined.  Apply only to the prototype, not to the definition.
 #endif
 
+#if defined(_MSC_VER)
+#define KJ_NOINLINE __declspec(noinline)
+#else
+#define KJ_NOINLINE __attribute__((noinline))
+#endif
+
 #if defined(_MSC_VER)
 #define KJ_NORETURN(prototype) __declspec(noreturn) prototype
 #define KJ_UNUSED

c++/src/kj/debug.c++

@@ -276,7 +276,7 @@ Debug::Fault::~Fault() noexcept(false) {
   if (exception != nullptr) {
     Exception copy = mv(*exception);
     delete exception;
-    throwRecoverableException(mv(copy));
+    throwRecoverableException(mv(copy), 2);
   }
 }
 
@@ -284,7 +284,7 @@ void Debug::Fault::fatal() {
   Exception copy = mv(*exception);
   delete exception;
   exception = nullptr;
-  throwFatalException(mv(copy));
+  throwFatalException(mv(copy), 2);
   abort();
 }
 

c++/src/kj/debug.h

@@ -301,7 +301,7 @@ public:
           const char* condition, const char* macroArgs);
     ~Fault() noexcept(false);
 
-    KJ_NORETURN(void fatal());
+    KJ_NOINLINE KJ_NORETURN(void fatal());
     // Throw the exception.
 
   private:

c++/src/kj/exception.c++

@@ -55,15 +55,18 @@ StringPtr KJ_STRINGIFY(LogSeverity severity) {
   return SEVERITY_STRINGS[static_cast<uint>(severity)];
 }
 
-ArrayPtr<void* const> getStackTrace(ArrayPtr<void*> space) {
+ArrayPtr<void* const> getStackTrace(ArrayPtr<void*> space, uint ignoreCount) {
 #ifndef KJ_HAS_BACKTRACE
   return nullptr;
 #else
-  return space.slice(0, backtrace(space.begin(), space.size()));
+  size_t size = backtrace(space.begin(), space.size());
+  return space.slice(kj::min(ignoreCount + 1, size), size);
 #endif
 }
 
 String stringifyStackTrace(ArrayPtr<void* const> trace) {
+  if (trace.size() == 0) return nullptr;
+
 #if (__linux__ || __APPLE__) && !__ANDROID__ && defined(KJ_DEBUG)
   // We want to generate a human-readable stack trace.
 
@@ -115,20 +118,22 @@ String stringifyStackTrace(ArrayPtr<void* const> trace) {
   char line[512];
   size_t i = 0;
   while (i < kj::size(lines) && fgets(line, sizeof(line), p) != nullptr) {
-    // Don't include exception-handling infrastructure in stack trace.
+    // Don't include exception-handling infrastructure or promise infrastructure in stack trace.
     // addr2line output matches file names; atos output matches symbol names.
-    if (i == 0 &&
-        (strstr(line, "kj/common.c++") != nullptr ||
+    if (strstr(line, "kj/common.c++") != nullptr ||
         strstr(line, "kj/exception.") != nullptr ||
         strstr(line, "kj/debug.") != nullptr ||
+        strstr(line, "kj/async.") != nullptr ||
+        strstr(line, "kj/async-prelude.h") != nullptr ||
+        strstr(line, "kj/async-inl.h") != nullptr ||
         strstr(line, "kj::Exception") != nullptr ||
-         strstr(line, "kj::_::Debug") != nullptr)) {
+        strstr(line, "kj::_::Debug") != nullptr) {
       continue;
     }
 
     size_t len = strlen(line);
     if (len > 0 && line[len-1] == '\n') line[len-1] = '\0';
-    lines[i++] = str("\n    ", trimSourceFilename(line), ": called here");
+    lines[i++] = str("\n    ", trimSourceFilename(line), ": returning here");
   }
 
   // Skip remaining input.
@@ -146,12 +151,9 @@ namespace {
 
 void crashHandler(int signo, siginfo_t* info, void* context) {
   void* traceSpace[32];
-  auto trace = getStackTrace(traceSpace);
 
-  if (trace.size() >= 3) {
-    // Remove getStackTrace(), crashHandler() and signal trampoline from trace.
-    trace = trace.slice(3, trace.size());
-  }
+  // ignoreCount = 2 to ignore crashHandler() and signal trampoline.
+  auto trace = getStackTrace(traceSpace, 2);
 
   auto message = kj::str("*** Received signal #", signo, ": ", strsignal(signo),
                          "\nstack: ", strArray(trace, " "),
@@ -276,15 +278,12 @@ String KJ_STRINGIFY(const Exception& e) {
 }
 
 Exception::Exception(Type type, const char* file, int line, String description) noexcept
-    : file(trimSourceFilename(file).cStr()), line(line), type(type), description(mv(description)) {
-  traceCount = kj::getStackTrace(trace).size();
-}
+    : file(trimSourceFilename(file).cStr()), line(line), type(type), description(mv(description)),
+      traceCount(0) {}
 
 Exception::Exception(Type type, String file, int line, String description) noexcept
     : ownFile(kj::mv(file)), file(trimSourceFilename(ownFile).cStr()), line(line), type(type),
-      description(mv(description)) {
-  traceCount = kj::getStackTrace(trace).size();
-}
+      description(mv(description)), traceCount(0) {}
 
 Exception::Exception(const Exception& other) noexcept
     : file(other.file), line(other.line), type(other.type),
@@ -314,6 +313,64 @@ void Exception::wrapContext(const char* file, int line, String&& description) {
   context = heap<Context>(file, line, mv(description), mv(context));
 }
 
+void Exception::extendTrace(uint ignoreCount) {
+  KJ_STACK_ARRAY(void*, newTraceSpace, kj::size(trace) + ignoreCount + 1,
+      sizeof(trace)/sizeof(trace[0]) + 8, 128);
+
+  auto newTrace = kj::getStackTrace(newTraceSpace, ignoreCount + 1);
+  if (newTrace.size() > ignoreCount + 2) {
+    // Remove suffix that won't fit into our static-sized trace.
+    newTrace = newTrace.slice(0, kj::min(kj::size(trace) - traceCount, newTrace.size()));
+
+    // Copy the rest into our trace.
+    memcpy(trace + traceCount, newTrace.begin(), newTrace.asBytes().size());
+    traceCount += newTrace.size();
+  }
+}
+
+void Exception::truncateCommonTrace() {
+  if (traceCount > 0) {
+    // Create a "reference" stack trace that is a little bit deeper than the one in the exception.
+    void* refTraceSpace[sizeof(this->trace) / sizeof(this->trace[0]) + 4];
+    auto refTrace = kj::getStackTrace(refTraceSpace, 0);
+
+    // We expect that the deepest frame in the exception's stack trace should be somewhere in our
+    // own trace, since our own trace has a deeper limit. Search for it.
+    for (uint i = refTrace.size(); i > 0; i--) {
+      if (refTrace[i-1] == trace[traceCount-1]) {
+        // See how many frames match.
+        for (uint j = 0; j < i; j++) {
+          if (j >= traceCount) {
+            // We matched the whole trace, apparently?
+            traceCount = 0;
+            return;
+          } else if (refTrace[i-j-1] != trace[traceCount-j-1]) {
+            // Found mismatching entry.
+
+            // If we matched more than half of the reference trace, guess that this is in fact
+            // the prefix we're looking for.
+            if (j > refTrace.size() / 2) {
+              // Delete the matching suffix. Also delete one non-matched entry on the assumption
+              // that both traces contain that stack frame but are simply at different points in
+              // the function.
+              traceCount -= j + 1;
+              return;
+            }
+          }
+        }
+      }
+    }
+
+    // No match. Ignore.
+  }
+}
+
+void Exception::addTrace(void* ptr) {
+  if (traceCount < kj::size(trace)) {
+    trace[traceCount++] = ptr;
+  }
+}
+
 class ExceptionImpl: public Exception, public std::exception {
 public:
   inline ExceptionImpl(Exception&& other): Exception(mv(other)) {}
@@ -436,12 +493,14 @@ ExceptionCallback& getExceptionCallback() {
   return scoped != nullptr ? *scoped : defaultCallback;
 }
 
-void throwFatalException(kj::Exception&& exception) {
+void throwFatalException(kj::Exception&& exception, uint ignoreCount) {
+  exception.extendTrace(ignoreCount + 1);
   getExceptionCallback().onFatalException(kj::mv(exception));
   abort();
 }
 
-void throwRecoverableException(kj::Exception&& exception) {
+void throwRecoverableException(kj::Exception&& exception, uint ignoreCount) {
+  exception.extendTrace(ignoreCount + 1);
   getExceptionCallback().onRecoverableException(kj::mv(exception));
 }
 
@@ -549,12 +608,16 @@ Maybe<Exception> runCatchingExceptions(Runnable& runnable) noexcept {
 #if KJ_NO_EXCEPTIONS
   RecoverableExceptionCatcher catcher;
   runnable.run();
+  KJ_IF_MAYBE(e, catcher.caught) {
+    e->truncateCommonTrace();
+  }
   return mv(catcher.caught);
 #else
   try {
     runnable.run();
     return nullptr;
   } catch (Exception& e) {
+    e.truncateCommonTrace();
     return kj::mv(e);
   } catch (std::bad_alloc& e) {
     return Exception(Exception::Type::OVERLOADED,

c++/src/kj/exception.h

@@ -107,6 +107,19 @@ public:
   // is expected that contexts will be added in reverse order as the exception passes up the
   // callback stack.
 
+  KJ_NOINLINE void extendTrace(uint ignoreCount);
+  // Append the current stack trace to the exception's trace, ignoring the first `ignoreCount`
+  // frames (see `getStackTrace()` for discussion of `ignoreCount`).
+
+  KJ_NOINLINE void truncateCommonTrace();
+  // Remove the part of the stack trace which the exception shares with the caller of this method.
+  // This is used by the async library to remove the async infrastructure from the stack trace
+  // before replacing it with the async trace.
+
+  void addTrace(void* ptr);
+  // Append the given pointer to the backtrace, if it is not already full. This is used by the
+  // async library to trace through the promise chain that led to the exception.
+
 private:
   String ownFile;
   const char* file;
@@ -193,11 +206,11 @@ private:
 ExceptionCallback& getExceptionCallback();
 // Returns the current exception callback.
 
-KJ_NORETURN(void throwFatalException(kj::Exception&& exception));
+KJ_NOINLINE KJ_NORETURN(void throwFatalException(kj::Exception&& exception, uint ignoreCount = 0));
 // Invoke the exception callback to throw the given fatal exception.  If the exception callback
 // returns, abort.
 
-void throwRecoverableException(kj::Exception&& exception);
+KJ_NOINLINE void throwRecoverableException(kj::Exception&& exception, uint ignoreCount = 0);
 // Invoke the exception acllback to throw the given recoverable exception.  If the exception
 // callback returns, return normally.
 
@@ -293,10 +306,18 @@ void UnwindDetector::catchExceptionsIfUnwinding(Func&& func) const {
 
 // =======================================================================================
 
-ArrayPtr<void* const> getStackTrace(ArrayPtr<void*> space);
+KJ_NOINLINE ArrayPtr<void* const> getStackTrace(ArrayPtr<void*> space, uint ignoreCount);
 // Attempt to get the current stack trace, returning a list of pointers to instructions. The
 // returned array is a slice of `space`. Provide a larger `space` to get a deeper stack trace.
 // If the platform doesn't support stack traces, returns an empty array.
+//
+// `ignoreCount` items will be truncated from the front of the trace. This is useful for chopping
+// off a prefix of the trace that is uninteresting to the developer because it's just locations
+// inside the debug infrastructure that is requesting the trace. Be careful to mark functions as
+// KJ_NOINLINE if you intend to count them in `ignoreCount`. Note that, unfortunately, the
+// ignored entries will still waste space in the `space` array (and the returned array's `begin()`
+// is never exactly equal to `space.begin()` due to this effect, even if `ignoreCount` is zero
+// since `getStackTrace()` needs to ignore its own internal frames).
 
 String stringifyStackTrace(ArrayPtr<void* const>);
 // Convert the stack trace to a string with file names and line numbers. This may involve executing

c++/src/kj/test.c++

@@ -192,7 +192,7 @@ public:
   void logMessage(LogSeverity severity, const char* file, int line, int contextDepth,
                   String&& text) override {
     void* traceSpace[32];
-    auto trace = getStackTrace(traceSpace);
+    auto trace = getStackTrace(traceSpace, 2);
 
     if (text.size() == 0) {
       text = kj::heapString("expectation failed");