Add backtrace to crash logs

Send crash information from the signal handler to traffic_crashlog. This
also adds a 30-second timeout around backtrace collection to prevent the
crashlog helper from hanging indefinitely if ptrace/waitpid blocks.

Author: bneradt

src/traffic_crashlog/backtrace.cc

@@ -105,57 +105,70 @@ backtrace_for_thread(pid_t threadid, TextBuffer &text)
   void            *ap     = nullptr;
   pid_t            target = -1;
   unsigned         level  = 0;
+  int              step_result;
 
   // First, attach to the child, causing it to stop.
   status = ptrace(PTRACE_ATTACH, threadid, 0, 0);
   if (status < 0) {
+    text.format("  [ptrace ATTACH failed: %s (%d)]\n", strerror(errno), errno);
     Dbg(dbg_ctl_backtrace, "ptrace(ATTACH, %ld) -> %s (%d)\n", (long)threadid, strerror(errno), errno);
     return;
   }
 
-  // Wait for it to stop (XXX should be a timed wait ...)
+  // Wait for it to stop. The caller uses alarm() to enforce a timeout.
   target = waitpid(threadid, &status, __WALL | WUNTRACED);
   Dbg(dbg_ctl_backtrace, "waited for target %ld, found PID %ld, %s\n", (long)threadid, (long)target,
       WIFSTOPPED(status) ? "STOPPED" : "???");
   if (target < 0) {
+    text.format("  [waitpid failed: %s (%d)]\n", strerror(errno), errno);
     goto done;
   }
 
   ap = _UPT_create(threadid);
   Dbg(dbg_ctl_backtrace, "created UPT %p", ap);
   if (ap == nullptr) {
+    text.format("  [_UPT_create failed]\n");
     goto done;
   }
 
   addr_space = unw_create_addr_space(&_UPT_accessors, 0 /* byteorder */);
   Dbg(dbg_ctl_backtrace, "created address space %p\n", addr_space);
   if (addr_space == nullptr) {
+    text.format("  [unw_create_addr_space failed]\n");
     goto done;
   }
 
   status = unw_init_remote(&cursor, addr_space, ap);
   Dbg(dbg_ctl_backtrace, "unw_init_remote(...) -> %d\n", status);
   if (status != 0) {
+    text.format("  [unw_init_remote failed: %d]\n", status);
     goto done;
   }
 
-  while (unw_step(&cursor) > 0) {
+  step_result = unw_step(&cursor);
+  if (step_result <= 0) {
+    text.format("  [unw_step returned %d on first call]\n", step_result);
+  }
+
+  while (step_result > 0) {
     unw_word_t ip;
-    unw_word_t offset;
+    unw_word_t offset = 0;
     char       buf[256];
 
     unw_get_reg(&cursor, UNW_REG_IP, &ip);
 
     if (unw_get_proc_name(&cursor, buf, sizeof(buf), &offset) == 0) {
-      int   status;
-      char *name = abi::__cxa_demangle(buf, nullptr, nullptr, &status);
-      text.format("%-4u 0x%016llx %s + %p\n", level, static_cast<unsigned long long>(ip), name ? name : buf, (void *)offset);
+      int   demangle_status;
+      char *name = abi::__cxa_demangle(buf, nullptr, nullptr, &demangle_status);
+      text.format("%-4u 0x%016llx %s + 0x%lx\n", level, static_cast<unsigned long long>(ip), name ? name : buf,
+                  static_cast<unsigned long>(offset));
       free(name);
     } else {
-      text.format("%-4u 0x%016llx 0x0 + %p\n", level, static_cast<unsigned long long>(ip), (void *)offset);
+      text.format("%-4u 0x%016llx <unknown>\n", level, static_cast<unsigned long long>(ip));
     }
 
     ++level;
+    step_result = unw_step(&cursor);
   }
 
 done:
@@ -167,8 +180,10 @@ backtrace_for_thread(pid_t threadid, TextBuffer &text)
     _UPT_destroy(ap);
   }
 
-  status = ptrace(PTRACE_DETACH, target, NULL, DATA_NULL);
-  Dbg(dbg_ctl_backtrace, "ptrace(DETACH, %ld) -> %d (errno %d)\n", (long)target, status, errno);
+  if (target > 0) {
+    status = ptrace(PTRACE_DETACH, target, NULL, DATA_NULL);
+    Dbg(dbg_ctl_backtrace, "ptrace(DETACH, %ld) -> %d (errno %d)\n", (long)target, status, errno);
+  }
 }
 } // namespace
 int

src/traffic_crashlog/traffic_crashlog.cc

@@ -32,8 +32,24 @@
 #include "tscore/BaseLogFile.h"
 #include "tscore/runroot.h"
 #include "iocore/eventsystem/RecProcess.h"
+#include <csignal>
 #include <unistd.h>
 
+namespace
+{
+// Timeout in seconds for backtrace collection. If ptrace/waitpid hangs, this
+// prevents the crashlog helper from blocking indefinitely.
+constexpr unsigned BACKTRACE_TIMEOUT_SECS = 10;
+
+volatile sig_atomic_t backtrace_timed_out = 0;
+
+void
+backtrace_alarm_handler(int /* sig */)
+{
+  backtrace_timed_out = 1;
+}
+} // namespace
+
 static int   syslog_mode  = false;
 static int   debug_mode   = false;
 static int   wait_mode    = false;
@@ -94,29 +110,58 @@ crashlog_open(const char *path)
 extern int ServerBacktrace(unsigned /* options */, int pid, char **trace);
 
 bool
-crashlog_write_backtrace(FILE *fp, pid_t pid, const crashlog_target &)
+crashlog_write_backtrace(FILE *fp, pid_t pid, const crashlog_target &target)
 {
-  char *trace = nullptr;
-  int   mgmterr;
+  char *trace   = nullptr;
+  int   mgmterr = -1;
+
+  // Set up a timeout to prevent indefinite hangs in ptrace/waitpid.
+  backtrace_timed_out = 0;
+  struct sigaction new_action;
+  struct sigaction old_action;
+  new_action.sa_handler = backtrace_alarm_handler;
+  sigemptyset(&new_action.sa_mask);
+  new_action.sa_flags = 0;
+  sigaction(SIGALRM, &new_action, &old_action);
+  alarm(BACKTRACE_TIMEOUT_SECS);
+
+  mgmterr = ServerBacktrace(0, static_cast<int>(pid), &trace);
+
+  // Cancel the alarm and restore the old handler.
+  alarm(0);
+  sigaction(SIGALRM, &old_action, nullptr);
+
+  if (backtrace_timed_out) {
+    fprintf(fp, "Backtrace collection timed out after %u seconds\n", BACKTRACE_TIMEOUT_SECS);
+    free(trace);
+    return false;
+  }
 
   // NOTE: sometimes we can't get a backtrace because the ptrace attach will fail with
   // EPERM. I've seen this happen when a debugger is attached, which makes sense, but it
   // can also happen without a debugger. Possibly in that case, there is a race with the
   // kernel locking the process information?
 
-  if ((mgmterr = ServerBacktrace(0, static_cast<int>(pid), &trace)) != 0) {
-    fprintf(fp, "Unable to retrieve backtrace: %d\n", mgmterr);
-    return false;
+  if (mgmterr == 0 && trace != nullptr) {
+    // ServerBacktrace succeeded - this gives us all threads' backtraces.
+    fprintf(fp, "%s", trace);
+    free(trace);
+    return true;
   }
 
-  if (trace == nullptr) {
-    fprintf(fp, "Unable to retrieve backtrace: trace is null\n");
-    return false;
+  // ServerBacktrace failed. Fall back to the in-process backtrace from the crashing thread.
+  if ((target.flags & CRASHLOG_HAVE_BACKTRACE) && !target.backtrace.empty()) {
+    fprintf(fp, "Crashing Thread Backtrace:\n%s", target.backtrace.c_str());
+    return true;
   }
 
-  fprintf(fp, "%s", trace);
-  free(trace);
-  return true;
+  // No backtrace available from either source.
+  if (mgmterr != 0) {
+    fprintf(fp, "Unable to retrieve backtrace: ServerBacktrace returned %d\n", mgmterr);
+  } else {
+    fprintf(fp, "Unable to retrieve backtrace: no backtrace data available\n");
+  }
+  return false;
 }
 
 void
@@ -200,11 +245,12 @@ main(int /* argc ATS_UNUSED */, const char **argv)
   Note("crashlog started, target=%ld, debug=%s syslog=%s, uid=%ld euid=%ld", static_cast<long>(target_pid),
        debug_mode ? "true" : "false", syslog_mode ? "true" : "false", (long)getuid(), (long)geteuid());
 
-  ink_zero(target);
   target.pid       = static_cast<pid_t>(target_pid);
   target.timestamp = timestamp();
 
-  if (host_triplet && strncmp(host_triplet, "x86_64-unknown-linux", sizeof("x86_64-unknown-linux") - 1) == 0) {
+  // Read crash context on Linux platforms. The siginfo_t and ucontext_t
+  // structures are platform-specific but defined for all Linux architectures.
+  if (host_triplet && (strstr(host_triplet, "linux") != nullptr || strstr(host_triplet, "Linux") != nullptr)) {
     ssize_t nbytes;
     target.flags |= CRASHLOG_HAVE_THREADINFO;
 
@@ -219,6 +265,21 @@ main(int /* argc ATS_UNUSED */, const char **argv)
       Warning("received %zd of %zu expected thread context bytes", nbytes, sizeof(target.ucontext));
       target.flags &= ~CRASHLOG_HAVE_THREADINFO;
     }
+
+    // Read the in-process backtrace from the crashing thread.
+    uint32_t bt_len = 0;
+    nbytes          = read(STDIN_FILENO, &bt_len, sizeof(bt_len));
+    if (nbytes == static_cast<ssize_t>(sizeof(bt_len)) && bt_len > 0 && bt_len < 1024 * 1024) {
+      target.backtrace.resize(bt_len);
+      nbytes = read(STDIN_FILENO, target.backtrace.data(), bt_len);
+      if (nbytes == static_cast<ssize_t>(bt_len)) {
+        target.flags |= CRASHLOG_HAVE_BACKTRACE;
+        Note("received %u bytes of in-process backtrace", bt_len);
+      } else {
+        Warning("received %zd of %u expected backtrace bytes", nbytes, bt_len);
+        target.backtrace.clear();
+      }
+    }
   }
 
   logname = crashlog_name();

src/traffic_crashlog/traffic_crashlog.h

@@ -28,6 +28,8 @@
 #include "tscore/Diags.h"
 #include "tscore/TextBuffer.h"
 
+#include <string>
+
 // ucontext.h is deprecated on Darwin, and we really only need it on Linux, so only
 // include it if we are planning to use it.
 #if defined(__linux__)
@@ -49,20 +51,25 @@
 #endif
 
 #define CRASHLOG_HAVE_THREADINFO 0x1u
+#define CRASHLOG_HAVE_BACKTRACE  0x2u
 
 struct crashlog_target {
-  pid_t     pid;
-  siginfo_t siginfo;
+  pid_t     pid{0};
+  siginfo_t siginfo{};
 #if defined(__linux__)
-  ucontext_t ucontext;
+  ucontext_t ucontext{};
 #else
-  char ucontext; // just a placeholder ...
+  char ucontext{}; // just a placeholder ...
 #endif
-  struct tm timestamp;
-  unsigned  flags;
+  struct tm timestamp {
+  };
+  unsigned flags{0};
+
+  // In-process backtrace from the crashing thread.
+  std::string backtrace;
 };
 
-bool crashlog_write_backtrace(FILE *, const crashlog_target &);
+bool crashlog_write_backtrace(FILE *, pid_t /* parent pid */, const crashlog_target &);
 bool crashlog_write_datime(FILE *, const crashlog_target &);
 bool crashlog_write_exename(FILE *, const crashlog_target &);
 bool crashlog_write_proclimits(FILE *, const crashlog_target &);

src/traffic_server/Crash.cc

@@ -28,6 +28,9 @@
 #include "tscore/Version.h"
 #include "tscore/signals.h"
 
+#include <string>
+#include <unistd.h>
+
 // ucontext.h is deprecated on Darwin, and we really only need it on Linux, so only
 // include it if we are planning to use it.
 #if defined(__linux__)
@@ -167,6 +170,13 @@ crash_logger_invoke(int signo, siginfo_t *info, void *ctx)
     // a single memory block that we can just puke out.
     ATS_UNUSED_RETURN(write(crash_logger_fd, info, sizeof(siginfo_t)));
     ATS_UNUSED_RETURN(write(crash_logger_fd, static_cast<ucontext_t *>(ctx), sizeof(ucontext_t)));
+
+    // Send zero-length backtrace. We cannot safely generate a backtrace here
+    // because backtrace() can acquire locks (e.g., in the dynamic linker) that
+    // the crashing thread might be holding, causing a deadlock. The crash
+    // logger will get the backtrace via ptrace from a separate process instead.
+    uint32_t bt_len = 0;
+    ATS_UNUSED_RETURN(write(crash_logger_fd, &bt_len, sizeof(bt_len)));
 #endif
 
     close(crash_logger_fd);

tests/CMakeLists.txt

@@ -39,6 +39,7 @@ add_subdirectory(tools/plugins)
 add_subdirectory(gold_tests/chunked_encoding)
 add_subdirectory(gold_tests/continuations/plugins)
 add_subdirectory(gold_tests/jsonrpc/plugins)
+add_subdirectory(gold_tests/pluginTest/crash_test)
 add_subdirectory(gold_tests/pluginTest/polite_hook_wait)
 add_subdirectory(gold_tests/pluginTest/tsapi)
 add_subdirectory(gold_tests/pluginTest/TSVConnFd)

tests/gold_tests/pluginTest/crash_test/CMakeLists.txt

@@ -0,0 +1,18 @@
+#######################
+#
+#  Licensed to the Apache Software Foundation (ASF) under one or more contributor license
+#  agreements.  See the NOTICE file distributed with this work for additional information regarding
+#  copyright ownership.  The ASF licenses this file to you under the Apache License, Version 2.0
+#  (the "License"); you may not use this file except in compliance with the License.  You may obtain
+#  a copy of the License at
+#
+#      http://www.apache.org/licenses/LICENSE-2.0
+#
+#  Unless required by applicable law or agreed to in writing, software distributed under the License
+#  is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express
+#  or implied. See the License for the specific language governing permissions and limitations under
+#  the License.
+#
+#######################
+
+add_autest_plugin(crash_test crash_test.cc)