From dd57fc6ecff11e87d5a52257d7b3b5ed3e36411b Mon Sep 17 00:00:00 2001 From: Jonathan G Rennison Date: Mon, 12 Jun 2023 18:34:37 +0100 Subject: [PATCH] Unix crash log: Generalise crash log fault handling to all sections --- src/crashlog.cpp | 149 +++++++++++++++++++++++--------- src/crashlog.h | 9 +- src/os/unix/crashlog_unix.cpp | 158 +++++++++++++++++++++------------- 3 files changed, 213 insertions(+), 103 deletions(-) diff --git a/src/crashlog.cpp b/src/crashlog.cpp index b37d864976..ec3cd07402 100644 --- a/src/crashlog.cpp +++ b/src/crashlog.cpp @@ -138,6 +138,29 @@ char *CrashLog::LogCompiler(char *buffer, const char *last) const } #endif +/* virtual */ void CrashLog::StartCrashLogFaultHandler() +{ + /* Stub implementation; not all OSes support this. */ +} + +/* virtual */ void CrashLog::StopCrashLogFaultHandler() +{ + /* Stub implementation; not all OSes support this. */ +} + +/* virtual */ char *CrashLog::TryCrashLogFaultSection(char *buffer, const char *last, const char *section_name, CrashLogSectionWriter writer) +{ + /* Stub implementation; not all OSes support internal fault handling. */ + this->FlushCrashLogBuffer(); + return writer(this, buffer, last); +} + +/* virtual */ void CrashLog::CrashLogFaultSectionCheckpoint(char *buffer) const +{ + /* Stub implementation; not all OSes support this. */ + const_cast(this)->FlushCrashLogBuffer(); +} + /** * Writes OpenTTD's version to the buffer. * @param buffer The begin where to write at. @@ -223,6 +246,8 @@ char *CrashLog::LogConfiguration(char *buffer, const char *last) const pathfinder_name(_settings_game.pf.pathfinder_for_trains), pathfinder_name(_settings_game.pf.pathfinder_for_roadvehs), pathfinder_name(_settings_game.pf.pathfinder_for_ships) ); + this->CrashLogFaultSectionCheckpoint(buffer); + auto log_font = [&](FontSize fs) -> const char * { FontCache *fc = FontCache::Get(fs); if (fc != nullptr) { @@ -244,6 +269,8 @@ char *CrashLog::LogConfiguration(char *buffer, const char *last) const log_font(FS_MONO) ); + this->CrashLogFaultSectionCheckpoint(buffer); + buffer += seprintf(buffer, last, "Map size: 0x%X (%u x %u)%s\n\n", MapSize(), MapSizeX(), MapSizeY(), (!_m || !_me) ? ", NO MAP ALLOCATED" : ""); if (_settings_game.debug.chicken_bits != 0) { @@ -253,6 +280,8 @@ char *CrashLog::LogConfiguration(char *buffer, const char *last) const buffer += seprintf(buffer, last, "NewGRF optimiser flags: 0x%08X\n\n", _settings_game.debug.newgrf_optimiser_flags); } + this->CrashLogFaultSectionCheckpoint(buffer); + buffer += seprintf(buffer, last, "AI Configuration (local: %i) (current: %i):\n", (int)_local_company, (int)_current_company); for (const Company *c : Company::Iterate()) { if (c->ai_info == nullptr) { @@ -267,6 +296,8 @@ char *CrashLog::LogConfiguration(char *buffer, const char *last) const } buffer += seprintf(buffer, last, "\n"); + this->CrashLogFaultSectionCheckpoint(buffer); + if (_grfconfig_static != nullptr) { buffer += seprintf(buffer, last, "Static NewGRFs present:\n"); for (GRFConfig *c = _grfconfig_static; c != nullptr; c = c->next) { @@ -277,6 +308,8 @@ char *CrashLog::LogConfiguration(char *buffer, const char *last) const buffer += seprintf(buffer, last, "\n"); } + this->CrashLogFaultSectionCheckpoint(buffer); + if (_network_server) { extern char *NetworkServerDumpClients(char *buffer, const char *last); buffer += seprintf(buffer, last, "Clients:\n"); @@ -468,60 +501,94 @@ char *CrashLog::LogCommandLog(char *buffer, const char *last) const */ char *CrashLog::FillCrashLog(char *buffer, const char *last) { + this->StartCrashLogFaultHandler(); buffer += seprintf(buffer, last, "*** OpenTTD Crash Report ***\n\n"); - if (GamelogTestEmergency()) { - buffer += seprintf(buffer, last, "-=-=- As you loaded an emergency savegame no crash information would ordinarily be generated. -=-=-\n\n"); - } - if (SaveloadCrashWithMissingNewGRFs()) { - buffer += seprintf(buffer, last, "-=-=- As you loaded a savegame for which you do not have the required NewGRFs no crash information would ordinarily be generated. -=-=-\n\n"); - } + buffer = this->TryCrashLogFaultSection(buffer, last, "emergency test", [](CrashLog *self, char *buffer, const char *last) -> char * { + if (GamelogTestEmergency()) { + buffer += seprintf(buffer, last, "-=-=- As you loaded an emergency savegame no crash information would ordinarily be generated. -=-=-\n\n"); + } + if (SaveloadCrashWithMissingNewGRFs()) { + buffer += seprintf(buffer, last, "-=-=- As you loaded a savegame for which you do not have the required NewGRFs no crash information would ordinarily be generated. -=-=-\n\n"); + } + return buffer; + }); - buffer += UTCTime::Format(buffer, last, "Crash at: %Y-%m-%d %H:%M:%S (UTC)\n"); + buffer = this->TryCrashLogFaultSection(buffer, last, "times", [](CrashLog *self, char *buffer, const char *last) -> char * { + buffer += UTCTime::Format(buffer, last, "Crash at: %Y-%m-%d %H:%M:%S (UTC)\n"); + + buffer += seprintf(buffer, last, "In game date: %i-%02i-%02i (%i, %i) (DL: %u)\n", _cur_date_ymd.year, _cur_date_ymd.month + 1, _cur_date_ymd.day, _date_fract, _tick_skip_counter, _settings_game.economy.day_length_factor); + if (_game_load_time != 0) { + buffer += seprintf(buffer, last, "Game loaded at: %i-%02i-%02i (%i, %i), ", + _game_load_cur_date_ymd.year, _game_load_cur_date_ymd.month + 1, _game_load_cur_date_ymd.day, _game_load_date_fract, _game_load_tick_skip_counter); + buffer += UTCTime::Format(buffer, last, _game_load_time, "%Y-%m-%d %H:%M:%S"); + } + return buffer; + }); - buffer += seprintf(buffer, last, "In game date: %i-%02i-%02i (%i, %i) (DL: %u)\n", _cur_date_ymd.year, _cur_date_ymd.month + 1, _cur_date_ymd.day, _date_fract, _tick_skip_counter, _settings_game.economy.day_length_factor); - if (_game_load_time != 0) { - buffer += seprintf(buffer, last, "Game loaded at: %i-%02i-%02i (%i, %i), ", - _game_load_cur_date_ymd.year, _game_load_cur_date_ymd.month + 1, _game_load_cur_date_ymd.day, _game_load_date_fract, _game_load_tick_skip_counter); - buffer += UTCTime::Format(buffer, last, _game_load_time, "%Y-%m-%d %H:%M:%S"); - } buffer += seprintf(buffer, last, "\n"); - this->FlushCrashLogBuffer(); - - buffer = this->LogError(buffer, last, CrashLog::message); + buffer = this->TryCrashLogFaultSection(buffer, last, "message", [](CrashLog *self, char *buffer, const char *last) -> char * { + return self->LogError(buffer, last, CrashLog::message); + }); #ifdef USE_SCOPE_INFO - if (IsMainThread() || IsGameThread()) { - this->FlushCrashLogBuffer(); - buffer += WriteScopeLog(buffer, last); - } + buffer = this->TryCrashLogFaultSection(buffer, last, "scope", [](CrashLog *self, char *buffer, const char *last) -> char * { + if (IsMainThread() || IsGameThread()) { + buffer += WriteScopeLog(buffer, last); + } + return buffer; + }); #endif - if (IsNonMainThread()) { - buffer += seprintf(buffer, last, "Non-main thread ("); - buffer += GetCurrentThreadName(buffer, last); - buffer += seprintf(buffer, last, ")\n\n"); - } + buffer = this->TryCrashLogFaultSection(buffer, last, "thread", [](CrashLog *self, char *buffer, const char *last) -> char * { + if (IsNonMainThread()) { + buffer += seprintf(buffer, last, "Non-main thread ("); + buffer += GetCurrentThreadName(buffer, last); + buffer += seprintf(buffer, last, ")\n\n"); + } + return buffer; + }); - buffer = this->LogOpenTTDVersion(buffer, last); - this->FlushCrashLogBuffer(); - buffer = this->LogStacktrace(buffer, last); - this->FlushCrashLogBuffer(); - buffer = this->LogRegisters(buffer, last); - this->FlushCrashLogBuffer(); - buffer = this->LogOSVersion(buffer, last); - this->FlushCrashLogBuffer(); - buffer = this->LogCompiler(buffer, last); - buffer = this->LogOSVersionDetail(buffer, last); - buffer = this->LogConfiguration(buffer, last); - buffer = this->LogLibraries(buffer, last); - buffer = this->LogModules(buffer, last); - buffer = this->LogGamelog(buffer, last); - buffer = this->LogRecentNews(buffer, last); - buffer = this->LogCommandLog(buffer, last); + buffer = this->TryCrashLogFaultSection(buffer, last, "OpenTTD version", [](CrashLog *self, char *buffer, const char *last) -> char * { + return self->LogOpenTTDVersion(buffer, last); + }); + buffer = this->TryCrashLogFaultSection(buffer, last, "stacktrace", [](CrashLog *self, char *buffer, const char *last) -> char * { + return self->LogStacktrace(buffer, last); + }); + buffer = this->TryCrashLogFaultSection(buffer, last, "registers", [](CrashLog *self, char *buffer, const char *last) -> char * { + return self->LogRegisters(buffer, last); + }); + buffer = this->TryCrashLogFaultSection(buffer, last, "OS version", [](CrashLog *self, char *buffer, const char *last) -> char * { + return self->LogOSVersion(buffer, last); + }); + buffer = this->TryCrashLogFaultSection(buffer, last, "compiler", [](CrashLog *self, char *buffer, const char *last) -> char * { + return self->LogCompiler(buffer, last); + }); + buffer = this->TryCrashLogFaultSection(buffer, last, "OS version detail", [](CrashLog *self, char *buffer, const char *last) -> char * { + return self->LogOSVersionDetail(buffer, last); + }); + buffer = this->TryCrashLogFaultSection(buffer, last, "config", [](CrashLog *self, char *buffer, const char *last) -> char * { + return self->LogConfiguration(buffer, last); + }); + buffer = this->TryCrashLogFaultSection(buffer, last, "libraries", [](CrashLog *self, char *buffer, const char *last) -> char * { + return self->LogLibraries(buffer, last); + }); + buffer = this->TryCrashLogFaultSection(buffer, last, "modules", [](CrashLog *self, char *buffer, const char *last) -> char * { + return self->LogModules(buffer, last); + }); + buffer = this->TryCrashLogFaultSection(buffer, last, "gamelog", [](CrashLog *self, char *buffer, const char *last) -> char * { + return self->LogGamelog(buffer, last); + }); + buffer = this->TryCrashLogFaultSection(buffer, last, "news", [](CrashLog *self, char *buffer, const char *last) -> char * { + return self->LogRecentNews(buffer, last); + }); + buffer = this->TryCrashLogFaultSection(buffer, last, "command log", [](CrashLog *self, char *buffer, const char *last) -> char * { + return self->LogCommandLog(buffer, last); + }); buffer += seprintf(buffer, last, "*** End of OpenTTD Crash Report ***\n"); + this->StopCrashLogFaultHandler(); return buffer; } diff --git a/src/crashlog.h b/src/crashlog.h index 56240f0a4e..fd8f76fb10 100644 --- a/src/crashlog.h +++ b/src/crashlog.h @@ -125,7 +125,7 @@ protected: * @param last The last position in the buffer to write to. * @return the position of the \c '\0' character after the buffer. */ - virtual char *LogScopeInfo(char *buffer, const char *last) const; + char *LogScopeInfo(char *buffer, const char *last) const; #endif char *LogOpenTTDVersion(char *buffer, const char *last) const; @@ -135,6 +135,13 @@ protected: char *LogRecentNews(char *buffer, const char *list) const; char *LogCommandLog(char *buffer, const char *last) const; + virtual void StartCrashLogFaultHandler(); + virtual void StopCrashLogFaultHandler(); + + using CrashLogSectionWriter = char *(*)(CrashLog *self, char *buffer, const char *last); + virtual char *TryCrashLogFaultSection(char *buffer, const char *last, const char *section_name, CrashLogSectionWriter writer); + virtual void CrashLogFaultSectionCheckpoint(char *buffer) const; + public: /** Buffer for the filename name prefix */ char name_buffer[64]; diff --git a/src/os/unix/crashlog_unix.cpp b/src/os/unix/crashlog_unix.cpp index 41d3682f3c..dc47266bed 100644 --- a/src/os/unix/crashlog_unix.cpp +++ b/src/os/unix/crashlog_unix.cpp @@ -60,18 +60,25 @@ #include "../../safeguards.h" +/** The signals we want our crash handler to handle. */ +static const int _signals_to_handle[] = { SIGSEGV, SIGABRT, SIGFPE, SIGBUS, SIGILL, SIGQUIT }; + #if defined(__GLIBC__) && defined(__GNUC__) && (__GNUC__ > 4 || (__GNUC__ == 4 && __GNUC_MINOR__ >= 3)) #pragma GCC diagnostic ignored "-Wclobbered" #endif -#if defined(__GLIBC__) -static char *logStacktraceSavedBuffer; -static jmp_buf logStacktraceJmpBuf; +#if defined(__GLIBC__) && defined(WITH_SIGACTION) +static char *internal_fault_saved_buffer; +static jmp_buf internal_fault_jmp_buf; +sigset_t internal_fault_old_sig_proc_mask; -static void LogStacktraceSigSegvHandler(int sig) +static void InternalFaultSigHandler(int sig) { - signal(SIGSEGV, SIG_DFL); - longjmp(logStacktraceJmpBuf, 1); + longjmp(internal_fault_jmp_buf, sig); + if (internal_fault_saved_buffer == nullptr) { + /* if we get here, things are unrecoverable */ + _exit(43); + } } #endif @@ -318,6 +325,7 @@ class CrashLogUnix : public CrashLog { } } #endif + this->CrashLogFaultSectionCheckpoint(buffer); buffer += seprintf(buffer, last, " Message: %s\n\n", message == nullptr ? "" : message @@ -490,8 +498,6 @@ class CrashLogUnix : public CrashLog { * backtrace() is prone to crashing if the stack is invalid. * Also these functions freely use malloc which is not technically OK in a signal handler, as * malloc is not re-entrant. - * For that reason, set up another SIGSEGV handler to handle the case where we trigger a SIGSEGV - * during the course of getting the backtrace. * * If libdl is present, try to use that to get the section file name and possibly the symbol * name/address instead of using the string from backtrace_symbols(). @@ -500,32 +506,12 @@ class CrashLogUnix : public CrashLog { * and knows about more symbols than libdl does. * If demangling support is available, try to demangle whatever symbol name we got back. * If we could find a symbol address from libdl or libbfd, show the offset from that to the frame address. - * - * Note that GCC complains about 'buffer' being clobbered by the longjmp. - * This is not an issue as we save/restore it explicitly, so silence the warning. */ char *LogStacktrace(char *buffer, const char *last) const override { buffer += seprintf(buffer, last, "Stacktrace:\n"); #if defined(__GLIBC__) - logStacktraceSavedBuffer = buffer; - - if (setjmp(logStacktraceJmpBuf) != 0) { - buffer = logStacktraceSavedBuffer; - buffer += seprintf(buffer, last, "\nSomething went seriously wrong when attempting to decode the stacktrace (SIGSEGV in signal handler)\n"); - buffer += seprintf(buffer, last, "This is probably due to either: a crash caused by an attempt to call an invalid function\n"); - buffer += seprintf(buffer, last, "pointer, some form of stack corruption, or an attempt was made to call malloc recursively.\n\n"); - return buffer; - } - - signal(SIGSEGV, LogStacktraceSigSegvHandler); - sigset_t sigs; - sigset_t oldsigs; - sigemptyset(&sigs); - sigaddset(&sigs, SIGSEGV); - sigprocmask(SIG_UNBLOCK, &sigs, &oldsigs); - void *trace[64]; int trace_size = backtrace(trace, lengthof(trace)); @@ -637,9 +623,6 @@ class CrashLogUnix : public CrashLog { } free(messages); - signal(SIGSEGV, SIG_DFL); - sigprocmask(SIG_SETMASK, &oldsigs, nullptr); - /* end of __GLIBC__ */ #elif defined(SUNOS) ucontext_t uc; @@ -658,36 +641,92 @@ class CrashLogUnix : public CrashLog { return buffer + seprintf(buffer, last, "\n"); } -#if defined(USE_SCOPE_INFO) && defined(__GLIBC__) - /** - * This is a wrapper around the generic LogScopeInfo function which sets - * up a signal handler to catch any SIGSEGVs which may occur due to invalid data - */ - /* virtual */ char *LogScopeInfo(char *buffer, const char *last) const override +#if defined(__GLIBC__) && defined(WITH_SIGACTION) + /* virtual */ void StartCrashLogFaultHandler() override { - logStacktraceSavedBuffer = buffer; + internal_fault_saved_buffer = nullptr; - if (setjmp(logStacktraceJmpBuf) != 0) { - buffer = logStacktraceSavedBuffer; - buffer += seprintf(buffer, last, "\nSomething went seriously wrong when attempting to dump the scope info (SIGSEGV in signal handler).\n"); + sigset_t sigs; + sigemptyset(&sigs); + for (int signum : _signals_to_handle) { + sigaddset(&sigs, signum); + } + + struct sigaction sa; + memset(&sa, 0, sizeof(sa)); + sa.sa_flags = SA_RESTART; + sa.sa_handler = InternalFaultSigHandler; + sa.sa_mask = sigs; + + for (int signum : _signals_to_handle) { + sigaction(signum, &sa, nullptr); + } + sigprocmask(SIG_UNBLOCK, &sigs, &internal_fault_old_sig_proc_mask); + } + + /* virtual */ void StopCrashLogFaultHandler() override + { + internal_fault_saved_buffer = nullptr; + + for (int signum : _signals_to_handle) { + signal(signum, SIG_DFL); + } + sigprocmask(SIG_SETMASK, &internal_fault_old_sig_proc_mask, nullptr); + } + + /** + * Set up further signal handlers to handle the case where we trigger another fault signal + * during the course of calling the given log section writer. + * + * If a signal does occur, restore the buffer pointer to either the original value, or + * the value provided in any later checkpoint. + * Insert a message describing the problem and give up on the section. + * + * Note that GCC complains about 'buffer' being clobbered by the longjmp. + * This is not an issue as we save/restore it explicitly, so silence the warning. + */ + /* virtual */ char *TryCrashLogFaultSection(char *buffer, const char *last, const char *section_name, CrashLogSectionWriter writer) override + { + this->FlushCrashLogBuffer(); + internal_fault_saved_buffer = buffer; + + int signum = setjmp(internal_fault_jmp_buf); + if (signum != 0) { + if (internal_fault_saved_buffer == nullptr) { + /* if we get here, things are unrecoverable */ + _exit(43); + } + + buffer = internal_fault_saved_buffer; + internal_fault_saved_buffer = nullptr; + + buffer += seprintf(buffer, last, "\nSomething went seriously wrong when attempting to fill the '%s' section of the crash log: signal: %s (%d).\n", section_name, strsignal(signum), signum); buffer += seprintf(buffer, last, "This is probably due to an invalid pointer or other corrupt data.\n\n"); + + sigset_t sigs; + sigemptyset(&sigs); + for (int signum : _signals_to_handle) { + sigaddset(&sigs, signum); + } + sigprocmask(SIG_UNBLOCK, &sigs, nullptr); + return buffer; } - signal(SIGSEGV, LogStacktraceSigSegvHandler); - sigset_t sigs; - sigset_t oldsigs; - sigemptyset(&sigs); - sigaddset(&sigs, SIGSEGV); - sigprocmask(SIG_UNBLOCK, &sigs, &oldsigs); - - buffer = this->CrashLog::LogScopeInfo(buffer, last); - - signal(SIGSEGV, SIG_DFL); - sigprocmask(SIG_SETMASK, &oldsigs, nullptr); + buffer = writer(this, buffer, last); + internal_fault_saved_buffer = nullptr; return buffer; } -#endif + + /* virtual */ void CrashLogFaultSectionCheckpoint(char *buffer) const override + { + if (internal_fault_saved_buffer != nullptr && buffer > internal_fault_saved_buffer) { + internal_fault_saved_buffer = buffer; + } + + const_cast(this)->FlushCrashLogBuffer(); + } +#endif /* __GLIBC__ && WITH_SIGACTION */ public: struct DesyncTag {}; @@ -730,9 +769,6 @@ public: } }; -/** The signals we want our crash handler to handle. */ -static const int _signals_to_handle[] = { SIGSEGV, SIGABRT, SIGFPE, SIGBUS, SIGILL, SIGQUIT }; - /** * Entry point for the crash handler. * @note Not static so it shows up in the backtrace. @@ -745,8 +781,8 @@ static void CDECL HandleCrash(int signum) #endif { /* Disable all handling of signals by us, so we don't go into infinite loops. */ - for (const int *i = _signals_to_handle; i != endof(_signals_to_handle); i++) { - signal(*i, SIG_DFL); + for (int signum : _signals_to_handle) { + signal(signum, SIG_DFL); } const char *abort_reason = CrashLog::GetAbortCrashlogReason(); @@ -782,7 +818,7 @@ static void CDECL HandleCrash(int signum) ss.ss_flags = 0; sigaltstack(&ss, nullptr); #endif - for (const int *i = _signals_to_handle; i != endof(_signals_to_handle); i++) { + for (int signum : _signals_to_handle) { #ifdef WITH_SIGACTION struct sigaction sa; memset(&sa, 0, sizeof(sa)); @@ -792,9 +828,9 @@ static void CDECL HandleCrash(int signum) #endif sigemptyset(&sa.sa_mask); sa.sa_sigaction = HandleCrash; - sigaction(*i, &sa, nullptr); + sigaction(signum, &sa, nullptr); #else - signal(*i, HandleCrash); + signal(signum, HandleCrash); #endif } }