| // 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. |
| |
| #include <signal.h> // For sigaction(), sigemptyset(). |
| #include <string.h> // For strsignal(). |
| |
| #ifdef __WINDOWS__ |
| #include <windows.h> |
| #include <dbghelp.h> |
| #endif |
| |
| #include <glog/logging.h> |
| #include <glog/raw_logging.h> |
| |
| #ifdef __WINDOWS__ |
| #include <atomic> |
| #include <cstdio> |
| #endif |
| #include <string> |
| |
| #include <process/once.hpp> |
| |
| #include <stout/error.hpp> |
| #include <stout/exit.hpp> |
| #include <stout/os.hpp> |
| #include <stout/path.hpp> |
| #include <stout/stringify.hpp> |
| #include <stout/try.hpp> |
| #include <stout/unreachable.hpp> |
| |
| #include <stout/os/signals.hpp> |
| |
| #include "logging/logging.hpp" |
| |
| #ifdef __linux__ |
| // Declare FLAGS_drop_log_memory flag for glog. This declaration is based on the |
| // the DECLARE_XXX macros from glog/logging.h. |
| namespace fLB { |
| extern GOOGLE_GLOG_DLL_DECL bool FLAGS_drop_log_memory; |
| } |
| using fLB::FLAGS_drop_log_memory; |
| #endif |
| |
| using process::Once; |
| |
| using std::cerr; |
| using std::endl; |
| using std::string; |
| |
| // Captures the stack trace and exits when a pure virtual method is |
| // called. |
| // This interface is part of C++ ABI. |
| // -Linux c++abi: |
| // http://refspecs.linuxbase.org/cxxabi-1.83.html#vcall |
| // "This routine will only be called if the user calls a |
| // non-overridden pure virtual function, which has undefined |
| // behavior according to the C++ Standard". |
| // -OSX libc++abi: |
| // http://libcxxabi.llvm.org/spec.html |
| // This usage has been tested on Linux & OSX and on gcc & clang. |
| extern "C" void __cxa_pure_virtual() |
| { |
| RAW_LOG(FATAL, "Pure virtual method called"); |
| UNREACHABLE(); |
| } |
| |
| |
| namespace mesos { |
| namespace internal { |
| namespace logging { |
| |
| // Persistent copy of argv0 since InitGoogleLogging requires the |
| // string we pass to it to be accessible indefinitely. |
| string argv0; |
| |
| |
| // NOTE: We use RAW_LOG instead of LOG because RAW_LOG doesn't |
| // allocate any memory or grab locks. And according to |
| // https://code.google.com/p/google-glog/issues/detail?id=161 |
| // it should work in 'most' cases in signal handlers. |
| #ifndef __WINDOWS__ |
| inline void handler(int signal, siginfo_t *siginfo, void *context) |
| { |
| if (signal == SIGTERM) { |
| if (siginfo->si_code == SI_USER || |
| siginfo->si_code == SI_QUEUE || |
| siginfo->si_code <= 0) { |
| RAW_LOG(WARNING, "Received signal SIGTERM from process %d of user %d; " |
| "exiting", siginfo->si_pid, siginfo->si_uid); |
| } else { |
| RAW_LOG(WARNING, "Received signal SIGTERM; exiting"); |
| } |
| |
| // Setup the default handler for SIGTERM so that we don't print |
| // a stack trace. |
| os::signals::reset(signal); |
| raise(signal); |
| } else { |
| RAW_LOG(FATAL, "Unexpected signal in signal handler: %d", signal); |
| } |
| } |
| #endif // __WINDOWS__ |
| |
| |
| #ifdef __WINDOWS__ |
| // We use a lock to protect dbghelp.h methods, since they are not |
| // thread safe and need to be synchronized. |
| std::atomic_flag dbghelpLock = ATOMIC_FLAG_INIT; |
| |
| // Fills in the stack trace from the provided exception context. |
| // NOTE: Do not allocate memory or do anything else that might |
| // obtain a lock acquired by code running outside of the exception |
| // filter, since that lock may still be held since the stack is |
| // unwound. (See POSIX async-signal-safety to better understand |
| // the importance of this). |
| // |
| // NOTE: Rather than returning the number of filled in entries, |
| // this returns the number of frames in the stack trace, which may be |
| // larger than the provided trace array (in which case, the caller |
| // needs to be careful not to index past the end!). This enables |
| // the caller to detect that there were more frames that this |
| // function was not able to fill in. |
| // |
| // This code is adapted from Chromium's implementation: |
| // |
| // https://github.com/chromium/chromium/blob/3771ffb16f922cf9ddc40b733498cc88f82f8fcf/base/debug/stack_trace_win.cc#L295-L339 // NOLINT |
| size_t stackTraceFromExceptionContext( |
| const CONTEXT* context, void** trace, size_t size) |
| { |
| size_t traceCount = 0; |
| |
| // StackWalk64 modifies the context in place; we supply it with a copy |
| // so that downstream exception handlers get the right context. |
| CONTEXT contextCopy; |
| memcpy(&contextCopy, context, sizeof(contextCopy)); |
| contextCopy.ContextFlags = CONTEXT_INTEGER | CONTEXT_CONTROL; |
| |
| STACKFRAME64 frame; |
| memset(&frame, 0, sizeof(frame)); |
| #if defined(_M_X64) || defined(__x86_64__) |
| int machineType = IMAGE_FILE_MACHINE_AMD64; |
| frame.AddrPC.Offset = context->Rip; |
| frame.AddrFrame.Offset = context->Rbp; |
| frame.AddrStack.Offset = context->Rsp; |
| #elif defined(__aarch64__) |
| int machineType = IMAGE_FILE_MACHINE_ARM64; |
| frame.AddrPC.Offset = context->Pc; |
| frame.AddrFrame.Offset = context->Fp; |
| frame.AddrStack.Offset = context->Sp; |
| #elif defined(_M_IX86) || defined(__i386__) |
| int machineType = IMAGE_FILE_MACHINE_I386; |
| frame.AddrPC.Offset = context->Eip; |
| frame.AddrFrame.Offset = context->Ebp; |
| frame.AddrStack.Offset = context->Esp; |
| #else |
| #error Unsupported Windows Architecture |
| #endif |
| frame.AddrPC.Mode = AddrModeFlat; |
| frame.AddrFrame.Mode = AddrModeFlat; |
| frame.AddrStack.Mode = AddrModeFlat; |
| |
| // Acquire the lock to protect StackWalk64. |
| while (dbghelpLock.test_and_set(std::memory_order_acquire)); |
| |
| while (StackWalk64(machineType, GetCurrentProcess(), GetCurrentThread(), |
| &frame, &contextCopy, NULL, |
| &SymFunctionTableAccess64, &SymGetModuleBase64, NULL)) { |
| if (traceCount < size) { |
| trace[traceCount] = reinterpret_cast<void*>(frame.AddrPC.Offset); |
| } |
| ++traceCount; |
| } |
| |
| // Release the lock protecting StackWalk64. |
| dbghelpLock.clear(std::memory_order_release); |
| |
| for (size_t i = traceCount; i < size; ++i) { |
| trace[i] = NULL; |
| } |
| |
| return traceCount; |
| } |
| |
| |
| // This code is inspired from the Chromium and Glog projects, as well |
| // as the MSDN documentation and examples: |
| // |
| // https://github.com/chromium/chromium/blob/3771ffb16f922cf9ddc40b733498cc88f82f8fcf/base/debug/stack_trace_win.cc#L197-L256 // NOLINT |
| // https://github.com/google/glog/blob/130a3e10de248344cdaeda54aed4c8a5ad7cedac/src/symbolize.cc#L908-L933 // NOLINT |
| // https://docs.microsoft.com/en-us/windows/win32/debug/retrieving-symbol-information-by-address // NOLINT |
| void Symbolize(void* pc, char* out, size_t size) |
| { |
| char buffer[sizeof(SYMBOL_INFO) + MAX_SYM_NAME * sizeof(TCHAR)]; |
| |
| DWORD64 symbolDisplacement = 0; |
| SYMBOL_INFO* symbol = reinterpret_cast<SYMBOL_INFO*>(buffer); |
| symbol->SizeOfStruct = sizeof(SYMBOL_INFO); |
| symbol->MaxNameLen = MAX_SYM_NAME - 1; |
| |
| // Acquire the lock to protect SymFromAddr and SymGetLineFromAddr64. |
| while (dbghelpLock.test_and_set(std::memory_order_acquire)); |
| |
| BOOL symbolFound = SymFromAddr( |
| GetCurrentProcess(), |
| reinterpret_cast<DWORD64>(pc), |
| &symbolDisplacement, |
| symbol); |
| |
| DWORD lineDisplacement = 0; |
| IMAGEHLP_LINE64 line = {}; |
| line.SizeOfStruct = sizeof(IMAGEHLP_LINE64); |
| |
| BOOL lineFound = SymGetLineFromAddr64( |
| GetCurrentProcess(), |
| reinterpret_cast<DWORD64>(pc), |
| &lineDisplacement, |
| &line); |
| |
| // Release the lock protecting SymFromAddr and SymGetLineFromAddr64. |
| dbghelpLock.clear(std::memory_order_release); |
| |
| // We handle each case individually here since it winds up being |
| // simpler than dealing with offsets into the output buffer and |
| // error handling, and it's easier to see what the output looks like. |
| if (symbolFound) { |
| if (lineFound) { |
| snprintf(out, size, "\t%s [%p+%llu] (%s:%u)", |
| symbol->Name, |
| pc, symbolDisplacement, |
| line.FileName, line.LineNumber); |
| } else { |
| snprintf(out, size, "\t%s [%p+%llu]", |
| symbol->Name, |
| pc, symbolDisplacement); |
| } |
| } else { |
| if (lineFound) { |
| snprintf(out, size, "\t(No symbol) [%p+%llu] (%s:%u)", |
| pc, symbolDisplacement, |
| line.FileName, line.LineNumber); |
| } else { |
| snprintf(out, size, "\t(No symbol) [%p+%llu]", |
| pc, symbolDisplacement); |
| } |
| } |
| } |
| |
| |
| long WINAPI UnhandledExceptionFilter(EXCEPTION_POINTERS* info) |
| { |
| // At this point the stack has already been unwound so we have to walk |
| // the exception's stack information from the provided `info` (i.e. we |
| // can't just RAW_LOG(FATAL) like we do on POSIX. |
| // |
| // Use raw logging since the stack has been unwound and locks may be |
| // held (see `handler(...)` above). Log as error even though this is |
| // fatal since we don't want to crash here. |
| // |
| // It appears there is no simple way to convert the error code into |
| // a string, so we hard code the names. |
| |
| DWORD code = info->ExceptionRecord->ExceptionCode; |
| |
| RAW_LOG(ERROR, "Received fatal exception %#x %s", code, [code]() { |
| switch (code) { |
| case EXCEPTION_ACCESS_VIOLATION: |
| return "EXCEPTION_ACCESS_VIOLATION"; |
| case EXCEPTION_ARRAY_BOUNDS_EXCEEDED: |
| return "EXCEPTION_ARRAY_BOUNDS_EXCEEDED"; |
| case EXCEPTION_BREAKPOINT: |
| return "EXCEPTION_BREAKPOINT"; |
| case EXCEPTION_DATATYPE_MISALIGNMENT: |
| return "EXCEPTION_DATATYPE_MISALIGNMENT"; |
| case EXCEPTION_FLT_DENORMAL_OPERAND: |
| return "EXCEPTION_FLT_DENORMAL_OPERAND"; |
| case EXCEPTION_FLT_DIVIDE_BY_ZERO: |
| return "EXCEPTION_FLT_DIVIDE_BY_ZERO"; |
| case EXCEPTION_FLT_INEXACT_RESULT: |
| return "EXCEPTION_FLT_INEXACT_RESULT"; |
| case EXCEPTION_FLT_INVALID_OPERATION: |
| return "EXCEPTION_FLT_INVALID_OPERATION"; |
| case EXCEPTION_FLT_OVERFLOW: |
| return "EXCEPTION_FLT_OVERFLOW"; |
| case EXCEPTION_FLT_STACK_CHECK: |
| return "EXCEPTION_FLT_STACK_CHECK"; |
| case EXCEPTION_FLT_UNDERFLOW: |
| return "EXCEPTION_FLT_UNDERFLOW"; |
| case EXCEPTION_ILLEGAL_INSTRUCTION: |
| return "EXCEPTION_ILLEGAL_INSTRUCTION"; |
| case EXCEPTION_IN_PAGE_ERROR: |
| return "EXCEPTION_IN_PAGE_ERROR"; |
| case EXCEPTION_INT_DIVIDE_BY_ZERO: |
| return "EXCEPTION_INT_DIVIDE_BY_ZERO"; |
| case EXCEPTION_INT_OVERFLOW: |
| return "EXCEPTION_INT_OVERFLOW"; |
| case EXCEPTION_INVALID_DISPOSITION: |
| return "EXCEPTION_INVALID_DISPOSITION"; |
| case EXCEPTION_NONCONTINUABLE_EXCEPTION: |
| return "EXCEPTION_NONCONTINUABLE_EXCEPTION"; |
| case EXCEPTION_PRIV_INSTRUCTION: |
| return "EXCEPTION_PRIV_INSTRUCTION"; |
| case EXCEPTION_SINGLE_STEP: |
| return "EXCEPTION_SINGLE_STEP"; |
| case EXCEPTION_STACK_OVERFLOW: |
| return "EXCEPTION_STACK_OVERFLOW"; |
| default: |
| return "UNKNOWN"; |
| }}()); |
| |
| // Acquire the lock to protect SymSetOptions and SymInitialize. |
| while (dbghelpLock.test_and_set(std::memory_order_acquire)); |
| |
| SymSetOptions(SYMOPT_DEFERRED_LOADS | |
| SYMOPT_UNDNAME | |
| SYMOPT_LOAD_LINES); |
| |
| BOOL initialized = SymInitialize(GetCurrentProcess(), NULL, TRUE); |
| |
| // Release the lock protecting SymSetOptions and SymInitialize. |
| dbghelpLock.clear(std::memory_order_release); |
| |
| if (!initialized) { |
| DWORD error = GetLastError(); |
| char buffer[64]; |
| strerror_s(buffer, sizeof(buffer), error); |
| RAW_LOG(ERROR, "Unable to print exception stack trace:" |
| " Failed to SymInitialize: %s", buffer); |
| return EXCEPTION_CONTINUE_SEARCH; |
| } |
| |
| const size_t MAX_TRACE_SIZE = 250; |
| |
| void* trace[MAX_TRACE_SIZE]; |
| |
| size_t traceCount = stackTraceFromExceptionContext( |
| info->ContextRecord, trace, MAX_TRACE_SIZE); |
| |
| for (size_t i = 0; i < std::min(traceCount, MAX_TRACE_SIZE); ++i) { |
| char buffer[sizeof(SYMBOL_INFO) + MAX_SYM_NAME * sizeof(TCHAR) + 16]; |
| |
| Symbolize(trace[i], buffer, sizeof(buffer)); |
| |
| RAW_LOG(ERROR, "%s", buffer); |
| } |
| |
| if (traceCount > MAX_TRACE_SIZE) { |
| RAW_LOG(ERROR, "\t< %u additional frames clipped >", |
| traceCount - MAX_TRACE_SIZE); |
| } |
| |
| return EXCEPTION_CONTINUE_SEARCH; |
| } |
| #endif |
| |
| |
| google::LogSeverity getLogSeverity(const string& logging_level) |
| { |
| if (logging_level == "INFO") { |
| return google::INFO; |
| } else if (logging_level == "WARNING") { |
| return google::WARNING; |
| } else if (logging_level == "ERROR") { |
| return google::ERROR; |
| } else { |
| // TODO(bmahler): Consider an error here. |
| return google::INFO; |
| } |
| } |
| |
| |
| void initialize( |
| const string& _argv0, |
| bool installFailureSignalHandler, |
| const Option<Flags>& _flags) |
| { |
| static Once* initialized = new Once(); |
| |
| if (initialized->once()) { |
| return; |
| } |
| |
| argv0 = _argv0; |
| |
| // Use the default flags if not specified. |
| Flags flags; |
| if (_flags.isSome()) { |
| flags = _flags.get(); |
| |
| FLAGS_minloglevel = getLogSeverity(flags.logging_level); |
| FLAGS_logbufsecs = flags.logbufsecs; |
| } |
| |
| if (flags.logging_level != "INFO" && |
| flags.logging_level != "WARNING" && |
| flags.logging_level != "ERROR") { |
| cerr << "'" << flags.logging_level << "' is not a valid logging level." |
| << " Possible values for 'logging_level' flag are:" |
| << " 'INFO', 'WARNING', 'ERROR'." << endl; |
| exit(EXIT_FAILURE); |
| } |
| |
| if (flags.log_dir.isSome()) { |
| Try<Nothing> mkdir = os::mkdir(flags.log_dir.get()); |
| if (mkdir.isError()) { |
| cerr << "Could not initialize logging: Failed to create directory " |
| << flags.log_dir.get() << ": " << mkdir.error() << endl; |
| exit(EXIT_FAILURE); |
| } |
| FLAGS_log_dir = flags.log_dir.get(); |
| // Do not log to stderr instead of log files. |
| FLAGS_logtostderr = false; |
| } else { |
| // Log to stderr instead of log files. |
| FLAGS_logtostderr = true; |
| } |
| |
| // Log everything to stderr IN ADDITION to log files unless |
| // otherwise specified. |
| if (flags.quiet) { |
| FLAGS_stderrthreshold = 3; // FATAL. |
| |
| // FLAGS_stderrthreshold is ignored when logging to stderr instead |
| // of log files. Setting the minimum log level gets around this issue. |
| if (FLAGS_logtostderr) { |
| FLAGS_minloglevel = 3; // FATAL. |
| } |
| } else { |
| FLAGS_stderrthreshold = FLAGS_minloglevel; |
| } |
| |
| #ifdef __linux__ |
| // Do not drop in-memory buffers of log contents. When set to true, this flag |
| // can significantly slow down the master. The slow down is attributed to |
| // several hundred `posix_fadvise(..., POSIX_FADV_DONTNEED)` calls per second |
| // to advise the kernel to drop in-memory buffers related to log contents. |
| // We set this flag to 'false' only if the corresponding environment variable |
| // is not set. |
| if (os::getenv("GLOG_drop_log_memory").isNone()) { |
| FLAGS_drop_log_memory = false; |
| } |
| #endif |
| |
| google::InitGoogleLogging(argv0.c_str()); |
| if (flags.log_dir.isSome()) { |
| // Log this message in order to create the log file; this is because GLOG |
| // creates the log file once the first log message occurs; also recreate |
| // the file if it has been created on a previous run. |
| LOG_AT_LEVEL(FLAGS_minloglevel) |
| << google::GetLogSeverityName(FLAGS_minloglevel) |
| << " level logging started!"; |
| } |
| |
| VLOG(1) << "Logging to " << |
| (flags.log_dir.isSome() ? flags.log_dir.get() : "STDERR"); |
| |
| if (installFailureSignalHandler) { |
| #ifdef __WINDOWS__ |
| // Glog on windows now supports InstallFailureSignalHandler(), |
| // but it is of little utility since windows handles failures |
| // via structured exception handling (SEH) instead. While some |
| // signals may get mapped by the c runtime library (CRT) [1], when |
| // we tested this out it worked for SIGABRT but it did not work |
| // for SIGSEGV. So, we just use an unhandled exception filter to |
| // catch these exceptions and dump a stack trace. |
| // |
| // [1] https://docs.oracle.com/en/java/javase/13/troubleshoot/handle-signals-and-exceptions.html#GUID-43732853-4FDD-4FED-99A0-56B79B44B3AD // NOLINT |
| // |
| // See the following issues for having glog provide this: |
| // |
| // https://github.com/google/glog/issues/535 |
| // https://github.com/google/glog/issues/534 |
| // |
| // TODO(bmahler): Does it make sense to use AddVectoredContinueHandler |
| // (and push to back of list), this appears to execute after vectored |
| // exception handlers and SEH, which seems like the last chance to |
| // look at the exception. |
| SetUnhandledExceptionFilter(&UnhandledExceptionFilter); |
| #else |
| // Handles SIGSEGV, SIGILL, SIGFPE, SIGABRT, SIGBUS, SIGTERM |
| // by default. |
| google::InstallFailureSignalHandler(); |
| |
| // Set up our custom signal handlers. |
| // |
| // NOTE: The code below sets the SIGTERM signal handler to the `handle` |
| // function declared above. While this is useful on POSIX systems, SIGTERM |
| // is generated and handled differently on Windows[1], so this code would |
| // not work. |
| // |
| // [1] https://msdn.microsoft.com/en-us/library/xdkz3x12.aspx |
| struct sigaction action; |
| action.sa_sigaction = handler; |
| |
| // Do not block additional signals while in the handler. |
| sigemptyset(&action.sa_mask); |
| |
| // The SA_SIGINFO flag tells sigaction() to use |
| // the sa_sigaction field, not sa_handler. |
| action.sa_flags = SA_SIGINFO; |
| |
| // We also do not want SIGTERM to dump a stacktrace, as this |
| // can imply that we crashed, when we were in fact terminated |
| // by user request. |
| if (sigaction(SIGTERM, &action, nullptr) < 0) { |
| PLOG(FATAL) << "Failed to set sigaction"; |
| } |
| #endif // __WINDOWS__ |
| } |
| |
| initialized->done(); |
| } |
| |
| |
| Try<string> getLogFile(google::LogSeverity severity) |
| { |
| if (FLAGS_log_dir.empty()) { |
| return Error("The 'log_dir' option was not specified"); |
| } |
| |
| if (severity < 0 || google::NUM_SEVERITIES <= severity) { |
| return Error("Unknown log severity: " + stringify(severity)); |
| } |
| |
| return path::join(FLAGS_log_dir, Path(argv0).basename()) + "." + |
| google::GetLogSeverityName(severity); |
| } |
| |
| } // namespace logging { |
| } // namespace internal { |
| } // namespace mesos { |