Merge pull request ceph#63673 from Matan-B/wip-matanb-crimson-signals-aborts

crimson/common/fatal_signal: Rework signals

Reviewed-by: Yingxin Cheng <[email protected]>

Author: Matan-B

src/crimson/common/assert.cc

@@ -8,6 +8,8 @@
 
 #include "crimson/common/log.h"
 
+SET_SUBSYS(osd);
+
 namespace ceph {
   [[gnu::cold]] void __ceph_assert_fail(const ceph::assert_data &ctx)
   {
@@ -18,12 +20,8 @@ namespace ceph {
                                         const char* file, int line,
                                         const char* func)
   {
-    seastar::logger& logger = crimson::get_logger(0);
-    logger.error("{}:{} : In function '{}', ceph_assert(%s)\n"
-                 "{}",
-                 file, line, func, assertion,
-                 seastar::current_backtrace());
-    std::cout << std::flush;
+    GENERIC_ERROR("{}:{} : In function '{}', ceph_assert({})\n",
+                  file, line, func, assertion);
     abort();
   }
   [[gnu::cold]] void __ceph_assertf_fail(const char *assertion,
@@ -37,25 +35,15 @@ namespace ceph {
     std::vsnprintf(buf, sizeof(buf), msg, args);
     va_end(args);
 
-    seastar::logger& logger = crimson::get_logger(0);
-    logger.error("{}:{} : In function '{}', ceph_assert(%s)\n"
-                 "{}\n{}\n",
-                 file, line, func, assertion,
-                 buf,
-                 seastar::current_backtrace());
-    std::cout << std::flush;
+    GENERIC_ERROR("{}:{} : In function '{}', ceph_assert({})\n {}\n",
+                 file, line, func, assertion, buf);
     abort();
   }
 
   [[gnu::cold]] void __ceph_abort(const char* file, int line,
                                   const char* func, const std::string& msg)
   {
-    seastar::logger& logger = crimson::get_logger(0);
-    logger.error("{}:{} : In function '{}', abort(%s)\n"
-                 "{}",
-                 file, line, func, msg,
-                 seastar::current_backtrace());
-    std::cout << std::flush;
+    GENERIC_ERROR("{}:{} : In function '{}', abort({})\n", file, line, func, msg);
     abort();
   }
 
@@ -69,12 +57,8 @@ namespace ceph {
     std::vsnprintf(buf, sizeof(buf), fmt, args);
     va_end(args);
 
-    seastar::logger& logger = crimson::get_logger(0);
-    logger.error("{}:{} : In function '{}', abort()\n"
-                 "{}\n{}\n",
-                 file, line, func,
-                 buf,
-                 seastar::current_backtrace());
+    GENERIC_ERROR("{}:{} : In function '{}', abort()\n {}\n",
+                  file, line, func, buf);
     std::cout << std::flush;
     abort();
   }

src/crimson/common/fatal_signal.cc

@@ -7,13 +7,23 @@
 #include <iostream>
 #include <string_view>
 
+// boost is able to translate addresses
+// to lines with the following definition.
+// Similar to Seastar's seastar-addr2line
 #define BOOST_STACKTRACE_USE_ADDR2LINE
+
+// Consider std once C++23 is available
 #include <boost/stacktrace.hpp>
+
 #include <seastar/core/reactor.hh>
 
+#include "crimson/common/log.h"
+
 #include "common/safe_io.h"
 #include "include/scope_guard.h"
 
+SET_SUBSYS(osd);
+
 FatalSignal::FatalSignal()
 {
   install_oneshot_signals_handler<SIGSEGV,
@@ -78,27 +88,40 @@ void FatalSignal::install_oneshot_signal_handler()
   assert(r == 0);
 }
 
-
 [[gnu::noinline]] static void print_backtrace(std::string_view cause) {
-  std::cerr << cause;
-  if (seastar::engine_is_ready()) {
-    std::cerr << " on shard " << seastar::this_shard_id();
-  }
   // nobody wants to see things like `FatalSignal::signaled()` or
   // `print_backtrace()` in our backtraces. `+ 1` is for the extra
   // frame created by kernel (signal trampoline, it will take care
   // about e.g. sigreturn(2) calling; see the man page).
-  constexpr std::size_t FRAMES_TO_SKIP = 3 + 1;
-  std::cerr << ".\nBacktrace:\n";
-  std::cerr << boost::stacktrace::stacktrace(
+  constexpr std::size_t FRAMES_TO_SKIP = 2 + 1;
+
+  // Let's inform regarding the abort before getting the stacktrace
+   std::string pre_backtrace = fmt::format(
+    "Aborting {} on shard {} - Stopping all shards",
+    cause,
+    seastar::engine_is_ready() ? std::to_string(seastar::this_shard_id()) : "no shard");
+
+  GENERIC_ERROR("{}", pre_backtrace);
+  std::cerr << pre_backtrace << std::flush;
+
+  seastar::engine().exit(1);
+
+  std::string backtrace = fmt::format("{} on shard {}  \nBacktrace:\n {}",
+    cause,
+    seastar::engine_is_ready() ? std::to_string(seastar::this_shard_id()) : "no shard",
+    boost::stacktrace::to_string(boost::stacktrace::stacktrace(
     FRAMES_TO_SKIP,
-    static_cast<std::size_t>(-1)/* max depth same as the default one */);
-  std::cerr << std::flush;
+    static_cast<std::size_t>(-1)/* max depth same as the default one */)));
+
+  // Print backtrace in log and in std out
+  GENERIC_ERROR("{}", backtrace);
+  std::cerr << backtrace << std::flush;
+
   // TODO: dump crash related meta data to $crash_dir
   //       see handle_fatal_signal()
 }
 
-static void print_segv_info(const siginfo_t& siginfo)
+[[maybe_unused]] static void print_segv_info(const siginfo_t& siginfo)
 {
   std::cerr \
      << "Dump of siginfo:" << std::endl
@@ -127,7 +150,7 @@ static void print_segv_info(const siginfo_t& siginfo)
   std::cerr << std::flush;
 }
 
-static void print_proc_maps()
+[[maybe_unused]] static void print_proc_maps()
 {
   const int fd = ::open("/proc/self/maps", O_RDONLY);
   if (fd < 0) {
@@ -156,17 +179,20 @@ static void print_proc_maps()
 [[gnu::noinline]] void FatalSignal::signaled(const int signum,
                                              const siginfo_t& siginfo)
 {
+  // Commented out for clean backtrace logs,
+  // can be used if needed:
+  // print_proc_maps();
+  // print_segv_info(siginfo);
+
   switch (signum) {
   case SIGSEGV:
-    print_backtrace("Segmentation fault");
-    print_segv_info(siginfo);
+    print_backtrace("Got SIGSEGV");
     break;
   case SIGABRT:
-    print_backtrace("Aborting");
+    print_backtrace("Got SIGABRT");
     break;
   default:
-    print_backtrace(fmt::format("Signal {}", signum));
+    print_backtrace(fmt::format("Got signal {}", signum));
     break;
   }
-  print_proc_maps();
 }

src/crimson/common/log.h

@@ -48,6 +48,8 @@ static inline seastar::log_level to_log_level(int level) {
 #define LOGGER(subname_) crimson::get_logger(ceph_subsys_##subname_)
 #define LOG_PREFIX(x) constexpr auto FNAME = #x
 
+#define GENERIC_LOG(level_, MSG, ...) \
+  LOCAL_LOGGER.log(level_, MSG , ##__VA_ARGS__)
 #define LOG(level_, MSG, ...) \
   LOCAL_LOGGER.log(level_, "{}: " MSG, FNAME , ##__VA_ARGS__)
 #define SUBLOG(subname_, level_, MSG, ...) \
@@ -80,6 +82,7 @@ static inline seastar::log_level to_log_level(int level) {
 #define SUBWARNI(subname_, ...) SUBLOGI(subname_, seastar::log_level::warn, __VA_ARGS__)
 
 #define ERROR(...) LOG(seastar::log_level::error, __VA_ARGS__)
+#define GENERIC_ERROR(...) GENERIC_LOG(seastar::log_level::error, __VA_ARGS__)
 #define ERRORI(...) LOGI(seastar::log_level::error, __VA_ARGS__)
 #define SUBERROR(subname_, ...) SUBLOG(subname_, seastar::log_level::error, __VA_ARGS__)
 #define SUBERRORI(subname_, ...) SUBLOGI(subname_, seastar::log_level::error, __VA_ARGS__)