From 2691b3a11a993f238b4890d984ca750a0b640794 Mon Sep 17 00:00:00 2001 From: Yuhong Guo Date: Sun, 2 Sep 2018 12:58:23 +0800 Subject: [PATCH] Add signal handlers to improve debuggability (#2757) * Add signal handlers to improve debuggability. * Fix Linux compiling * Fix Lint * Change SIGILL case that happens in both Linux and MaxOs * Add signal handler to main functions. * Change handler name. * Address comment * Address comment. * Fix Linux building failure * Introduce RAII mechanism to SignalHandlers. * Add InitShutdownWrapper to handle all RAII requirements * Change util_test to signal_test * Make sure shutdown is not nullptr. * Using google::InstallFailureSignalHandler() instead of our own signal handler * Refine code addording to comment * Fix valgrind test failure. * remove Shutdown template * consistency * linting --- .travis.yml | 1 + src/global_scheduler/global_scheduler.cc | 5 ++ src/local_scheduler/local_scheduler.cc | 13 ++-- src/local_scheduler/local_scheduler.h | 2 +- src/plasma/plasma_manager.cc | 5 ++ src/ray/raylet/main.cc | 6 +- src/ray/raylet/monitor_main.cc | 5 ++ src/ray/util/CMakeLists.txt | 1 + src/ray/util/logging.cc | 12 +++- src/ray/util/logging.h | 16 ++++- src/ray/util/signal_test.cc | 91 ++++++++++++++++++++++++ src/ray/util/util.h | 31 ++++++++ 12 files changed, 179 insertions(+), 9 deletions(-) create mode 100644 src/ray/util/signal_test.cc diff --git a/.travis.yml b/.travis.yml index 50a77933f..c2fe2a74e 100644 --- a/.travis.yml +++ b/.travis.yml @@ -183,6 +183,7 @@ install: - ./src/ray/raylet/task_dependency_manager_test - ./src/ray/raylet/reconstruction_policy_test - ./src/ray/util/logging_test --gtest_filter=PrintLogTest* + - ./src/ray/util/signal_test - bash ../src/common/test/run_tests.sh - bash ../src/plasma/test/run_tests.sh diff --git a/src/global_scheduler/global_scheduler.cc b/src/global_scheduler/global_scheduler.cc index 94dccf636..069ad6865 100644 --- a/src/global_scheduler/global_scheduler.cc +++ b/src/global_scheduler/global_scheduler.cc @@ -7,6 +7,7 @@ #include "global_scheduler.h" #include "global_scheduler_algorithm.h" #include "net.h" +#include "ray/util/util.h" #include "state/db_client_table.h" #include "state/local_scheduler_table.h" #include "state/object_table.h" @@ -453,6 +454,10 @@ void start_server(const char *node_ip_address, } int main(int argc, char *argv[]) { + InitShutdownRAII ray_log_shutdown_raii( + ray::RayLog::StartRayLog, ray::RayLog::ShutDownRayLog, argv[0], RAY_INFO, + /*log_dir=*/""); + ray::RayLog::InstallFailureSignalHandler(); signal(SIGTERM, signal_handler); /* IP address and port of the primary redis instance. */ char *redis_primary_addr_port = NULL; diff --git a/src/local_scheduler/local_scheduler.cc b/src/local_scheduler/local_scheduler.cc index 2f8a684f6..7bef00993 100644 --- a/src/local_scheduler/local_scheduler.cc +++ b/src/local_scheduler/local_scheduler.cc @@ -15,18 +15,19 @@ #include "event_loop.h" #include "format/local_scheduler_generated.h" #include "io.h" -#include "logging.h" -#include "local_scheduler_shared.h" #include "local_scheduler.h" #include "local_scheduler_algorithm.h" +#include "local_scheduler_shared.h" +#include "logging.h" #include "net.h" +#include "ray/util/util.h" #include "state/actor_notification_table.h" #include "state/db.h" #include "state/db_client_table.h" #include "state/driver_table.h" -#include "state/task_table.h" -#include "state/object_table.h" #include "state/error_table.h" +#include "state/object_table.h" +#include "state/task_table.h" using MessageType = ray::local_scheduler::protocol::MessageType; @@ -1421,6 +1422,10 @@ void start_server( * suite has its own declaration of main. */ #ifndef LOCAL_SCHEDULER_TEST int main(int argc, char *argv[]) { + InitShutdownRAII ray_log_shutdown_raii( + ray::RayLog::StartRayLog, ray::RayLog::ShutDownRayLog, argv[0], RAY_INFO, + /*log_dir=*/""); + ray::RayLog::InstallFailureSignalHandler(); signal(SIGTERM, signal_handler); /* Path of the listening socket of the local scheduler. */ char *scheduler_socket_name = NULL; diff --git a/src/local_scheduler/local_scheduler.h b/src/local_scheduler/local_scheduler.h index 0c2628931..39c7523fe 100644 --- a/src/local_scheduler/local_scheduler.h +++ b/src/local_scheduler/local_scheduler.h @@ -1,9 +1,9 @@ #ifndef LOCAL_SCHEDULER_H #define LOCAL_SCHEDULER_H +#include "event_loop.h" #include "local_scheduler_shared.h" #include "task.h" -#include "event_loop.h" /** * Establish a connection to a new client. diff --git a/src/plasma/plasma_manager.cc b/src/plasma/plasma_manager.cc index 91f74e528..51b18c572 100644 --- a/src/plasma/plasma_manager.cc +++ b/src/plasma/plasma_manager.cc @@ -36,6 +36,7 @@ #include "plasma/events.h" #include "plasma_manager.h" #include "ray/gcs/client.h" +#include "ray/util/util.h" #include "state/db.h" #include "state/db_client_table.h" #include "state/error_table.h" @@ -1624,6 +1625,10 @@ void signal_handler(int signal) { * suite has its own declaration of main. */ #ifndef PLASMA_TEST int main(int argc, char *argv[]) { + InitShutdownRAII ray_log_shutdown_raii( + ray::RayLog::StartRayLog, ray::RayLog::ShutDownRayLog, argv[0], RAY_INFO, + /*log_dir=*/""); + ray::RayLog::InstallFailureSignalHandler(); signal(SIGTERM, signal_handler); /* Socket name of the plasma store this manager is connected to. */ char *store_socket_name = NULL; diff --git a/src/ray/raylet/main.cc b/src/ray/raylet/main.cc index 171078cb2..23aa41f25 100644 --- a/src/ray/raylet/main.cc +++ b/src/ray/raylet/main.cc @@ -15,7 +15,10 @@ static std::vector parse_worker_command(std::string worker_command) } int main(int argc, char *argv[]) { - RayLog::StartRayLog(argv[0], RAY_INFO); + InitShutdownRAII ray_log_shutdown_raii(ray::RayLog::StartRayLog, + ray::RayLog::ShutDownRayLog, argv[0], RAY_INFO, + /*log_dir=*/""); + ray::RayLog::InstallFailureSignalHandler(); RAY_CHECK(argc == 11); const std::string raylet_socket_name = std::string(argv[1]); @@ -113,6 +116,5 @@ int main(int argc, char *argv[]) { signals.async_wait(handler); main_service.run(); - RayLog::ShutDownRayLog(); } #endif diff --git a/src/ray/raylet/monitor_main.cc b/src/ray/raylet/monitor_main.cc index c48588fbf..218faecd4 100644 --- a/src/ray/raylet/monitor_main.cc +++ b/src/ray/raylet/monitor_main.cc @@ -1,8 +1,13 @@ #include #include "ray/raylet/monitor.h" +#include "ray/util/util.h" int main(int argc, char *argv[]) { + InitShutdownRAII ray_log_shutdown_raii(ray::RayLog::StartRayLog, + ray::RayLog::ShutDownRayLog, argv[0], RAY_INFO, + /*log_dir=*/""); + ray::RayLog::InstallFailureSignalHandler(); RAY_CHECK(argc == 3); const std::string redis_address = std::string(argv[1]); diff --git a/src/ray/util/CMakeLists.txt b/src/ray/util/CMakeLists.txt index bc06d3126..2ce3c63f3 100644 --- a/src/ray/util/CMakeLists.txt +++ b/src/ray/util/CMakeLists.txt @@ -7,3 +7,4 @@ install(FILES ) ADD_RAY_TEST(logging_test STATIC_LINK_LIBS ray_static gtest pthread) +ADD_RAY_TEST(signal_test STATIC_LINK_LIBS ray_static gtest pthread ${Boost_SYSTEM_LIBRARY}) diff --git a/src/ray/util/logging.cc b/src/ray/util/logging.cc index 5a4066a11..ee42e7e3a 100644 --- a/src/ray/util/logging.cc +++ b/src/ray/util/logging.cc @@ -53,6 +53,7 @@ class CerrLog { }; int RayLog::severity_threshold_ = RAY_INFO; +std::string RayLog::app_name_ = ""; #ifdef RAY_USE_GLOG using namespace google; @@ -83,8 +84,9 @@ void RayLog::StartRayLog(const std::string &app_name, int severity_threshold, const std::string &log_dir) { #ifdef RAY_USE_GLOG severity_threshold_ = severity_threshold; + app_name_ = app_name; int mapped_severity_threshold = GetMappedSeverity(severity_threshold_); - google::InitGoogleLogging(app_name.c_str()); + google::InitGoogleLogging(app_name_.c_str()); google::SetStderrLogging(mapped_severity_threshold); // Enble log file if log_dir is not empty. if (!log_dir.empty()) { @@ -114,6 +116,14 @@ void RayLog::ShutDownRayLog() { #endif } +void RayLog::InstallFailureSignalHandler() { +#ifdef RAY_USE_GLOG + google::InstallFailureSignalHandler(); +#endif +} + +bool RayLog::IsLevelEnabled(int log_level) { return log_level >= severity_threshold_; } + RayLog::RayLog(const char *file_name, int line_number, int severity) // glog does not have DEBUG level, we can handle it here. : is_enabled_(severity >= severity_threshold_) { diff --git a/src/ray/util/logging.h b/src/ray/util/logging.h index 323ae5201..35bb9841d 100644 --- a/src/ray/util/logging.h +++ b/src/ray/util/logging.h @@ -87,7 +87,7 @@ class RayLog : public RayLogBase { virtual ~RayLog(); - /// Return whether or not logging is enabled. + /// Return whether or not current logging instance is enabled. /// /// \return True if logging is enabled and false otherwise. virtual bool IsEnabled() const; @@ -96,14 +96,28 @@ class RayLog : public RayLogBase { // If logDir is empty, the log won't output to file. static void StartRayLog(const std::string &appName, int severity_threshold = RAY_ERROR, const std::string &logDir = ""); + // The shutdown function of ray log which should be used with StartRayLog as a pair. static void ShutDownRayLog(); + /// Return whether or not the log level is enabled in current setting. + /// + /// \param log_level The input log level to test. + /// \return True if input log level is not lower than the threshold. + static bool IsLevelEnabled(int log_level); + + // Install the failure signal handler to output call stack when crash. + // If glog is not installed, this function won't do anything. + static void InstallFailureSignalHandler(); + private: std::unique_ptr logging_provider_; /// True if log messages should be logged and false if they should be ignored. bool is_enabled_; static int severity_threshold_; + // In InitGoogleLogging, it simply keeps the pointer. + // We need to make sure the app name passed to InitGoogleLogging exist. + static std::string app_name_; protected: virtual std::ostream &Stream(); diff --git a/src/ray/util/signal_test.cc b/src/ray/util/signal_test.cc new file mode 100644 index 000000000..a408681d8 --- /dev/null +++ b/src/ray/util/signal_test.cc @@ -0,0 +1,91 @@ +#include +#include +#include + +#include "gtest/gtest.h" +#include "ray/util/logging.h" +#include "ray/util/util.h" + +// This test just print some call stack information. +namespace ray { + +void Sleep() { usleep(100000); } + +void TestSendSignal(const std::string &test_name, int signal) { + pid_t pid; + pid = fork(); + ASSERT_TRUE(pid >= 0); + if (pid == 0) { + while (true) { + int n = 1000; + while (n--) + ; + } + } else { + Sleep(); + RAY_LOG(ERROR) << test_name << ": kill pid " << pid + << " with return value=" << kill(pid, signal); + Sleep(); + } +} + +TEST(SignalTest, SendTermSignalTest) { TestSendSignal("SendTermSignalTest", SIGTERM); } + +TEST(SignalTest, SendBusSignalTest) { TestSendSignal("SendBusSignalTest", SIGBUS); } + +TEST(SignalTest, SIGABRT_Test) { + pid_t pid; + pid = fork(); + ASSERT_TRUE(pid >= 0); + if (pid == 0) { + // This code will cause SIGABRT sent. + std::abort(); + } else { + Sleep(); + RAY_LOG(ERROR) << "SIGABRT_Test: kill pid " << pid + << " with return value=" << kill(pid, SIGKILL); + Sleep(); + } +} + +TEST(SignalTest, SIGSEGV_Test) { + pid_t pid; + pid = fork(); + ASSERT_TRUE(pid >= 0); + if (pid == 0) { + int *pointer = reinterpret_cast(0x1237896); + *pointer = 100; + } else { + Sleep(); + RAY_LOG(ERROR) << "SIGSEGV_Test: kill pid " << pid + << " with return value=" << kill(pid, SIGKILL); + Sleep(); + } +} + +TEST(SignalTest, SIGILL_Test) { + pid_t pid; + pid = fork(); + ASSERT_TRUE(pid >= 0); + if (pid == 0) { + // This code will cause SIGILL sent. + asm("ud2"); + } else { + Sleep(); + RAY_LOG(ERROR) << "SIGILL_Test: kill pid " << pid + << " with return value=" << kill(pid, SIGKILL); + Sleep(); + } +} + +} // namespace ray + +int main(int argc, char **argv) { + InitShutdownRAII ray_log_shutdown_raii(ray::RayLog::StartRayLog, + ray::RayLog::ShutDownRayLog, argv[0], RAY_INFO, + /*log_dir=*/""); + ray::RayLog::InstallFailureSignalHandler(); + ::testing::InitGoogleTest(&argc, argv); + int failed = RUN_ALL_TESTS(); + return failed; +} diff --git a/src/ray/util/util.h b/src/ray/util/util.h index 7e67210d7..1139b85e2 100644 --- a/src/ray/util/util.h +++ b/src/ray/util/util.h @@ -1,8 +1,11 @@ #ifndef RAY_UTIL_UTIL_H #define RAY_UTIL_UTIL_H +#include #include +#include "ray/status.h" + /// Return the number of milliseconds since the steady clock epoch. NOTE: The /// returned timestamp may be used for accurately measuring intervals but has /// no relation to wall clock time. It must not be used for synchronization @@ -35,4 +38,32 @@ inline ray::Status boost_to_ray_status(const boost::system::error_code &error) { } } +class InitShutdownRAII { + public: + /// Type of the Shutdown function. + using ShutdownFunc = void (*)(); + + /// Create an instance of InitShutdownRAII which will call shutdown + /// function when it is out of scope. + /// + /// \param init_func The init function. + /// \param shuntdown_func The shutdown function. + /// \param args The auguments for the init function. + template + InitShutdownRAII(InitFunc init_func, ShutdownFunc shuntdown_func, Args &&... args) + : shutdown_(shuntdown_func) { + init_func(args...); + } + + /// Destructor of InitShutdownRAII which will call the shutdown function. + ~InitShutdownRAII() { + if (shutdown_ != nullptr) { + shutdown_(); + } + } + + private: + ShutdownFunc shutdown_; +}; + #endif // RAY_UTIL_UTIL_H