From 0062881a461dd6a0640725f3caf02c78d11e0fa2 Mon Sep 17 00:00:00 2001 From: Jonathan G Rennison Date: Thu, 25 Feb 2016 00:20:31 +0000 Subject: [PATCH 1/2] Avoid using malloc in scope guard logger. Use a temporary object with its own buffer, which lives on the stack. Reformat SCOPE_INFO_FMT to not be all on one line. Other minor reformatting. --- src/command.cpp | 6 ++++-- src/scope_info.cpp | 33 +++++++++++++++++---------------- src/scope_info.h | 27 ++++++++++++++++++++++----- src/vehicle.cpp | 4 ++-- 4 files changed, 45 insertions(+), 25 deletions(-) diff --git a/src/command.cpp b/src/command.cpp index b11306578d..b22edca681 100644 --- a/src/command.cpp +++ b/src/command.cpp @@ -456,7 +456,8 @@ CommandCost DoCommand(const CommandContainer *container, DoCommandFlag flags) */ CommandCost DoCommand(TileIndex tile, uint32 p1, uint32 p2, DoCommandFlag flags, uint32 cmd, const char *text) { - SCOPE_INFO_FMT([=], "DoCommand: tile: %dx%d, p1: 0x%X, p2: 0x%X, flags: 0x%X, company: %s, cmd: 0x%X (%s)", TileX(tile), TileY(tile), p1, p2, flags, DumpCompanyInfo(_current_company), cmd, GetCommandName(cmd)); + SCOPE_INFO_FMT([=], "DoCommand: tile: %dx%d, p1: 0x%X, p2: 0x%X, flags: 0x%X, company: %s, cmd: 0x%X (%s)", + TileX(tile), TileY(tile), p1, p2, flags, scope_dumper().CompanyInfo(_current_company), cmd, GetCommandName(cmd)); CommandCost res; @@ -551,7 +552,8 @@ bool DoCommandP(const CommandContainer *container, bool my_cmd) */ bool DoCommandP(TileIndex tile, uint32 p1, uint32 p2, uint32 cmd, CommandCallback *callback, const char *text, bool my_cmd) { - SCOPE_INFO_FMT([=], "DoCommandP: tile: %dx%d, p1: 0x%X, p2: 0x%X, company: %s, cmd: 0x%X (%s), my_cmd: %d", TileX(tile), TileY(tile), p1, p2, DumpCompanyInfo(_current_company), cmd, GetCommandName(cmd), my_cmd); + SCOPE_INFO_FMT([=], "DoCommandP: tile: %dx%d, p1: 0x%X, p2: 0x%X, company: %s, cmd: 0x%X (%s), my_cmd: %d", + TileX(tile), TileY(tile), p1, p2, scope_dumper().CompanyInfo(_current_company), cmd, GetCommandName(cmd), my_cmd); /* Cost estimation is generally only done when the * local user presses shift while doing somthing. diff --git a/src/scope_info.cpp b/src/scope_info.cpp index 7e5aa1cc23..fa7a14d628 100644 --- a/src/scope_info.cpp +++ b/src/scope_info.cpp @@ -39,34 +39,35 @@ int WriteScopeLog(char *buf, const char *last) } // helper functions -char *DumpCompanyInfo(int company_id) +const char *scope_dumper::CompanyInfo(int company_id) { - char buf[256]; - char *b = buf + seprintf(buf, lastof(buf), "%d (", company_id); + char *b = this->buffer; + const char *last = lastof(this->buffer); + b += seprintf(b, last, "%d (", company_id); SetDParam(0, company_id); - b = GetString(b, STR_COMPANY_NAME, lastof(buf)); - b += seprintf(b, lastof(buf), ")"); - return stredup(buf, lastof(buf)); + b = GetString(b, STR_COMPANY_NAME, last); + b += seprintf(b, last, ")"); + return buffer; } -char *DumpVehicleInfo(const Vehicle *v) +const char *scope_dumper::VehicleInfo(const Vehicle *v) { - char buf[256]; - char *b = buf; + char *b = this->buffer; + const char *last = lastof(this->buffer); if (v) { - b += seprintf(b, lastof(buf), "veh: %u: (", v->index); + b += seprintf(b, last, "veh: %u: (", v->index); SetDParam(0, v->index); - b = GetString(b, STR_VEHICLE_NAME, lastof(buf)); + b = GetString(b, STR_VEHICLE_NAME, last); if (v->First() && v->First() != v) { - b += seprintf(b, lastof(buf), "), front: %u: (", v->First()->index); + b += seprintf(b, last, "), front: %u: (", v->First()->index); SetDParam(0, v->First()->index); - b = GetString(b, STR_VEHICLE_NAME, lastof(buf)); + b = GetString(b, STR_VEHICLE_NAME, last); } - b += seprintf(b, lastof(buf), ")"); + b += seprintf(b, last, ")"); } else { - b += seprintf(b, lastof(buf), "veh: NULL"); + b += seprintf(b, last, "veh: NULL"); } - return stredup(buf, lastof(buf)); + return this->buffer; } #endif diff --git a/src/scope_info.h b/src/scope_info.h index cb6cb18dd4..89ed4f6571 100644 --- a/src/scope_info.h +++ b/src/scope_info.h @@ -43,15 +43,32 @@ int WriteScopeLog(char *buf, const char *last); * This lambda is then captured by reference in a std::function which is pushed onto the scope stack * The scope stack is popped at the end of the scope */ -#define SCOPE_INFO_FMT(capture, ...) auto SCOPE_INFO_PASTE(_sc_lm_, __LINE__) = capture (char *buf, const char *last) { return seprintf(buf, last, __VA_ARGS__); }; scope_info_func_obj SCOPE_INFO_PASTE(_sc_obj_, __LINE__) ([&](char *buf, const char *last) -> int { return SCOPE_INFO_PASTE(_sc_lm_, __LINE__) (buf, last); }); +#define SCOPE_INFO_FMT(capture, ...) \ + auto SCOPE_INFO_PASTE(_sc_lm_, __LINE__) = capture (char *buf, const char *last) { \ + return seprintf(buf, last, __VA_ARGS__); \ + }; \ + scope_info_func_obj SCOPE_INFO_PASTE(_sc_obj_, __LINE__) ([&](char *buf, const char *last) -> int { \ + return SCOPE_INFO_PASTE(_sc_lm_, __LINE__) (buf, last); \ + }); -// helper functions -char *DumpCompanyInfo(int company_id); -char *DumpVehicleInfo(const Vehicle *v); +/** + * This is a set of helper functions to print useful info from within a SCOPE_INFO_FMT statement. + * The use of a struct is so that when used as an argument to SCOPE_INFO_FMT/seprintf/etc, the buffer lives + * on the stack with a lifetime which lasts until the end of the statement. + * This avoids needing to call malloc(), which is technically unsafe within the crash logger signal handler, + * writing directly into the seprintf buffer, or the use of a separate static buffer. + */ +struct scope_dumper { + const char *CompanyInfo(int company_id); + const char *VehicleInfo(const Vehicle *v); + +private: + char buffer[256]; +}; #else /* USE_SCOPE_INFO */ -#define SCOPE_INFO_FMT(...) +#define SCOPE_INFO_FMT(...) { } #endif /* USE_SCOPE_INFO */ diff --git a/src/vehicle.cpp b/src/vehicle.cpp index 420761bb3d..99347d8620 100644 --- a/src/vehicle.cpp +++ b/src/vehicle.cpp @@ -852,7 +852,7 @@ static void RunVehicleDayProc() /* Run the day_proc for every DAY_TICKS vehicle starting at _date_fract. */ Vehicle *v = NULL; - SCOPE_INFO_FMT([&v], "RunVehicleDayProc: %s", DumpVehicleInfo(v)); + SCOPE_INFO_FMT([&v], "RunVehicleDayProc: %s", scope_dumper().VehicleInfo(v)); for (size_t i = _date_fract; i < Vehicle::GetPoolSize(); i += DAY_TICKS) { v = Vehicle::Get(i); if (v == NULL) continue; @@ -888,7 +888,7 @@ void CallVehicleTicks() FOR_ALL_STATIONS(st) LoadUnloadStation(st); Vehicle *v = NULL; - SCOPE_INFO_FMT([&v], "CallVehicleTicks: %s", DumpVehicleInfo(v)); + SCOPE_INFO_FMT([&v], "CallVehicleTicks: %s", scope_dumper().VehicleInfo(v)); FOR_ALL_VEHICLES(v) { /* Vehicle could be deleted in this tick */ if (!v->Tick()) { From cbc35e8aae666c8914ab1f4b198e38af381530b3 Mon Sep 17 00:00:00 2001 From: Jonathan G Rennison Date: Thu, 25 Feb 2016 19:21:06 +0000 Subject: [PATCH 2/2] Try to make scope info logging more robust. Add checks for validity of Vehicle ptrs in scope_dumper::VehicleInfo. In Unix mode, try to handle SIGSEGVs when dumping scope info. --- src/crashlog.cpp | 7 +++++++ src/crashlog.h | 10 ++++++++++ src/os/unix/crashlog_unix.cpp | 32 ++++++++++++++++++++++++++++++++ src/scope_info.cpp | 8 ++++++++ 4 files changed, 57 insertions(+) diff --git a/src/crashlog.cpp b/src/crashlog.cpp index a0ec4d26fb..ead0d96f3e 100644 --- a/src/crashlog.cpp +++ b/src/crashlog.cpp @@ -81,6 +81,13 @@ char *CrashLog::LogCompiler(char *buffer, const char *last) const return buffer; } +#ifdef USE_SCOPE_INFO +/* virtual */ char *CrashLog::LogScopeInfo(char *buffer, const char *last) const +{ + return buffer + WriteScopeLog(buffer, last); +} +#endif + /** * Writes OpenTTD's version to the buffer. * @param buffer The begin where to write at. diff --git a/src/crashlog.h b/src/crashlog.h index 6f7fb3c215..7894dea0ad 100644 --- a/src/crashlog.h +++ b/src/crashlog.h @@ -80,6 +80,16 @@ protected: */ virtual char *LogModules(char *buffer, const char *last) const; +#ifdef USE_SCOPE_INFO + /** + * Writes the scope info log to the buffer. + * This may only be called when IsMainThread() returns true + * @param buffer The begin where to write at. + * @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; +#endif char *LogOpenTTDVersion(char *buffer, const char *last) const; char *LogConfiguration(char *buffer, const char *last) const; diff --git a/src/os/unix/crashlog_unix.cpp b/src/os/unix/crashlog_unix.cpp index 7d04b641cb..60c8208785 100644 --- a/src/os/unix/crashlog_unix.cpp +++ b/src/os/unix/crashlog_unix.cpp @@ -251,6 +251,38 @@ class CrashLogUnix : public CrashLog { #endif 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 + { + logStacktraceSavedBuffer = buffer; + + 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"); + buffer += seprintf(buffer, last, "This is probably due to an invalid pointer or other corrupt data.\n\n"); + 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, NULL); + return buffer; + } +#endif + public: /** * A crash log is always generated by signal. diff --git a/src/scope_info.cpp b/src/scope_info.cpp index fa7a14d628..19fa67c905 100644 --- a/src/scope_info.cpp +++ b/src/scope_info.cpp @@ -56,10 +56,18 @@ const char *scope_dumper::VehicleInfo(const Vehicle *v) const char *last = lastof(this->buffer); if (v) { b += seprintf(b, last, "veh: %u: (", v->index); + if (Vehicle::GetIfValid(v->index) != v) { + b += seprintf(b, last, "INVALID PTR: %p)", v); + return this->buffer; + } SetDParam(0, v->index); b = GetString(b, STR_VEHICLE_NAME, last); if (v->First() && v->First() != v) { b += seprintf(b, last, "), front: %u: (", v->First()->index); + if (Vehicle::GetIfValid(v->First()->index) != v->First()) { + b += seprintf(b, last, "INVALID PTR: %p)", v->First()); + return this->buffer; + } SetDParam(0, v->First()->index); b = GetString(b, STR_VEHICLE_NAME, last); }