From a12c78a5552eac33ebfa7062f54d17f14fb5aba0 Mon Sep 17 00:00:00 2001 From: Jonathan G Rennison Date: Fri, 17 May 2019 18:55:45 +0100 Subject: [PATCH] Output a log, savegame and screenshot on desync events --- src/crashlog.cpp | 93 ++++++++++++++++++++++++++++++--- src/crashlog.h | 10 ++-- src/network/network_client.cpp | 3 ++ src/network/network_server.cpp | 3 ++ src/os/macosx/crashlog_osx.cpp | 15 ++++++ src/os/unix/crashlog_unix.cpp | 6 +++ src/os/windows/crashlog_win.cpp | 6 +++ 7 files changed, 127 insertions(+), 9 deletions(-) diff --git a/src/crashlog.cpp b/src/crashlog.cpp index 2928e97256..a78064dcf3 100644 --- a/src/crashlog.cpp +++ b/src/crashlog.cpp @@ -372,6 +372,36 @@ char *CrashLog::FillCrashLog(char *buffer, const char *last) const return buffer; } +/** + * Fill the crash log buffer with all data of a desync event. + * @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. + */ +char *CrashLog::FillDesyncCrashLog(char *buffer, const char *last) const +{ + time_t cur_time = time(nullptr); + buffer += seprintf(buffer, last, "*** OpenTTD Multiplayer %s Desync Report ***\n\n", _network_server ? "Server" : "Client"); + + buffer += seprintf(buffer, last, "Desync at: %s", asctime(gmtime(&cur_time))); + + YearMonthDay ymd; + ConvertDateToYMD(_date, &ymd); + buffer += seprintf(buffer, last, "In game date: %i-%02i-%02i (%i)\n\n", ymd.year, ymd.month + 1, ymd.day, _date_fract); + + buffer = this->LogOpenTTDVersion(buffer, last); + buffer = this->LogOSVersion(buffer, last); + buffer = this->LogCompiler(buffer, last); + buffer = this->LogConfiguration(buffer, last); + buffer = this->LogLibraries(buffer, last); + buffer = this->LogGamelog(buffer, last); + buffer = this->LogRecentNews(buffer, last); + buffer = this->LogRecentCommands(buffer, last); + + buffer += seprintf(buffer, last, "*** End of OpenTTD Multiplayer %s Desync Report ***\n", _network_server ? "Server" : "Client"); + return buffer; +} + /** * Write the crash log to a file. * @note On success the filename will be filled with the full path of the @@ -381,9 +411,9 @@ char *CrashLog::FillCrashLog(char *buffer, const char *last) const * @param filename_last The last position in the filename buffer. * @return true when the crash log was successfully written. */ -bool CrashLog::WriteCrashLog(const char *buffer, char *filename, const char *filename_last) const +bool CrashLog::WriteCrashLog(const char *buffer, char *filename, const char *filename_last, const char *name) const { - seprintf(filename, filename_last, "%scrash.log", _personal_dir); + seprintf(filename, filename_last, "%s%s.log", _personal_dir, name); FILE *file = FioFOpenFile(filename, "w", NO_DIRECTORY); if (file == nullptr) return false; @@ -409,7 +439,7 @@ bool CrashLog::WriteCrashLog(const char *buffer, char *filename, const char *fil * @param filename_last The last position in the filename buffer. * @return true when the crash save was successfully made. */ -bool CrashLog::WriteSavegame(char *filename, const char *filename_last) const +bool CrashLog::WriteSavegame(char *filename, const char *filename_last, const char *name) const { /* If the map array doesn't exist, saving will fail too. If the map got * initialised, there is a big chance the rest is initialised too. */ @@ -418,7 +448,7 @@ bool CrashLog::WriteSavegame(char *filename, const char *filename_last) const try { GamelogEmergency(); - seprintf(filename, filename_last, "%scrash.sav", _personal_dir); + seprintf(filename, filename_last, "%s%s.sav", _personal_dir, name); /* Don't do a threaded saveload. */ return SaveOrLoad(filename, SLO_SAVE, DFT_GAME_FILE, NO_DIRECTORY, false) == SL_OK; @@ -435,12 +465,12 @@ bool CrashLog::WriteSavegame(char *filename, const char *filename_last) const * @param filename_last The last position in the filename buffer. * @return true when the crash screenshot was successfully made. */ -bool CrashLog::WriteScreenshot(char *filename, const char *filename_last) const +bool CrashLog::WriteScreenshot(char *filename, const char *filename_last, const char *name) const { /* Don't draw when we have invalid screen size */ if (_screen.width < 1 || _screen.height < 1 || _screen.dst_ptr == nullptr) return false; - bool res = MakeScreenshot(SC_CRASHLOG, "crash"); + bool res = MakeScreenshot(SC_CRASHLOG, name); if (res) strecpy(filename, _full_screenshot_name, filename_last); return res; } @@ -506,6 +536,57 @@ bool CrashLog::MakeCrashLog() const return ret; } +/** + * Makes a desync crash log, writes it to a file and then subsequently tries + * to make a crash savegame. It uses DEBUG to write + * information like paths to the console. + * @return true when everything is made successfully. + */ +bool CrashLog::MakeDesyncCrashLog() const +{ + char filename[MAX_PATH]; + char buffer[65536 * 2]; + bool ret = true; + + const char *mode = _network_server ? "server" : "client"; + + char name_buffer[64]; + char *name_buffer_date = name_buffer + seprintf(name_buffer, lastof(name_buffer), "desync-%s-", mode); + time_t cur_time = time(nullptr); + strftime(name_buffer_date, lastof(name_buffer) - name_buffer_date, "%Y%m%dT%H%M%SZ", gmtime(&cur_time)); + + printf("Desync encountered (%s), generating desync log...\n", mode); + this->FillDesyncCrashLog(buffer, lastof(buffer)); + + bool bret = this->WriteCrashLog(buffer, filename, lastof(filename), name_buffer); + if (bret) { + printf("Desync log written to %s. Please add this file to any bug reports.\n\n", filename); + } else { + printf("Writing desync log failed.\n\n"); + ret = false; + } + + bret = this->WriteSavegame(filename, lastof(filename), name_buffer); + if (bret) { + printf("Desync savegame written to %s. Please add this file and the last (auto)save to any bug reports.\n\n", filename); + } else { + ret = false; + printf("Writing desync savegame failed. Please attach the last (auto)save to any bug reports.\n\n"); + } + + if (!(_screen.width < 1 || _screen.height < 1 || _screen.dst_ptr == nullptr)) { + bret = this->WriteScreenshot(filename, lastof(filename), name_buffer); + if (bret) { + printf("Desync screenshot written to %s. Please add this file to any bug reports.\n\n", filename); + } else { + ret = false; + printf("Writing desync screenshot failed.\n\n"); + } + } + + return ret; +} + /** * Sets a message for the error message handler. * @param message The error message of the error. diff --git a/src/crashlog.h b/src/crashlog.h index 5d68c01ab3..19952e73fb 100644 --- a/src/crashlog.h +++ b/src/crashlog.h @@ -91,7 +91,8 @@ public: virtual ~CrashLog() {} char *FillCrashLog(char *buffer, const char *last) const; - bool WriteCrashLog(const char *buffer, char *filename, const char *filename_last) const; + char *FillDesyncCrashLog(char *buffer, const char *last) const; + bool WriteCrashLog(const char *buffer, char *filename, const char *filename_last, const char *name = "crash") const; /** * Write the (crash) dump to a file. @@ -103,10 +104,11 @@ public: * was successful (not all OSes support dumping files). */ virtual int WriteCrashDump(char *filename, const char *filename_last) const; - bool WriteSavegame(char *filename, const char *filename_last) const; - bool WriteScreenshot(char *filename, const char *filename_last) const; + bool WriteSavegame(char *filename, const char *filename_last, const char *name = "crash") const; + bool WriteScreenshot(char *filename, const char *filename_last, const char *name = "crash") const; bool MakeCrashLog() const; + bool MakeDesyncCrashLog() const; /** * Initialiser for crash logs; do the appropriate things so crashes are @@ -115,6 +117,8 @@ public: */ static void InitialiseCrashLog(); + static void DesyncCrashLog(); + static void SetErrorMessage(const char *message); static void AfterCrashLogCleanup(); }; diff --git a/src/network/network_client.cpp b/src/network/network_client.cpp index 4eb638d722..9636b38641 100644 --- a/src/network/network_client.cpp +++ b/src/network/network_client.cpp @@ -28,6 +28,7 @@ #include "network_client.h" #include "../core/backup_type.hpp" #include "../thread.h" +#include "../crashlog.h" #include "table/strings.h" @@ -277,6 +278,8 @@ void ClientNetworkGameSocketHandler::ClientError(NetworkRecvStatus res) DEBUG(net, 0, "Sync error detected!"); my_client->ClientError(NETWORK_RECV_STATUS_DESYNC); + CrashLog::DesyncCrashLog(); + extern void CheckCaches(bool force_check); CheckCaches(true); return false; diff --git a/src/network/network_server.cpp b/src/network/network_server.cpp index 1175bf4bdd..dcc132c7b3 100644 --- a/src/network/network_server.cpp +++ b/src/network/network_server.cpp @@ -28,6 +28,7 @@ #include "../core/pool_func.hpp" #include "../core/random_func.hpp" #include "../rev.h" +#include "../crashlog.h" #include #include @@ -1159,6 +1160,8 @@ NetworkRecvStatus ServerNetworkGameSocketHandler::Receive_CLIENT_ERROR(Packet *p NetworkAdminClientError(this->client_id, errorno); if (errorno == NETWORK_ERROR_DESYNC) { + CrashLog::DesyncCrashLog(); + // have the server and all clients run some sanity checks NetworkSendCommand(0, 0, 0, CMD_DESYNC_CHECK, NULL, NULL, _local_company); } diff --git a/src/os/macosx/crashlog_osx.cpp b/src/os/macosx/crashlog_osx.cpp index a1470b6d63..f653e623e2 100644 --- a/src/os/macosx/crashlog_osx.cpp +++ b/src/os/macosx/crashlog_osx.cpp @@ -152,6 +152,8 @@ class CrashLogOSX : public CrashLog { } public: + struct DesyncTag {}; + /** * A crash log is always generated by signal. * @param signum the signal that was caused by the crash. @@ -163,6 +165,13 @@ public: filename_screenshot[0] = '\0'; } + CrashLogOSX(DesyncTag tag) : signum(0), si(nullptr), context(nullptr), signal_instruction_ptr_valid(false) + { + filename_log[0] = '\0'; + filename_save[0] = '\0'; + filename_screenshot[0] = '\0'; + } + /** Generate the crash log. */ bool MakeCrashLog() { @@ -257,3 +266,9 @@ void CDECL HandleCrash(int signum) signal(*i, HandleCrash); } } + +/* static */ void CrashLog::DesyncCrashLog() +{ + CrashLogOSX log(CrashLogOSX::DesyncTag{}); + log.MakeDesyncCrashLog(); +} diff --git a/src/os/unix/crashlog_unix.cpp b/src/os/unix/crashlog_unix.cpp index ee3f5823fd..994e9be954 100644 --- a/src/os/unix/crashlog_unix.cpp +++ b/src/os/unix/crashlog_unix.cpp @@ -181,3 +181,9 @@ static void CDECL HandleCrash(int signum) signal(*i, HandleCrash); } } + +/* static */ void CrashLog::DesyncCrashLog() +{ + CrashLogUnix log(0); + log.MakeDesyncCrashLog(); +} diff --git a/src/os/windows/crashlog_win.cpp b/src/os/windows/crashlog_win.cpp index 7a1a524aa5..2250df3d2e 100644 --- a/src/os/windows/crashlog_win.cpp +++ b/src/os/windows/crashlog_win.cpp @@ -633,6 +633,12 @@ static void CDECL CustomAbort(int signal) SetUnhandledExceptionFilter(ExceptionHandler); } +/* static */ void CrashLog::DesyncCrashLog() +{ + CrashLogWindows log(nullptr); + log.MakeDesyncCrashLog(); +} + /* The crash log GUI */ static bool _expanded;