Output a log, savegame and screenshot on desync events

This commit is contained in:
Jonathan G Rennison 2019-05-17 18:55:45 +01:00
parent 1106a55be4
commit a12c78a555
7 changed files with 127 additions and 9 deletions

View File

@ -372,6 +372,36 @@ char *CrashLog::FillCrashLog(char *buffer, const char *last) const
return buffer; 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. * Write the crash log to a file.
* @note On success the filename will be filled with the full path of the * @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. * @param filename_last The last position in the filename buffer.
* @return true when the crash log was successfully written. * @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); FILE *file = FioFOpenFile(filename, "w", NO_DIRECTORY);
if (file == nullptr) return false; 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. * @param filename_last The last position in the filename buffer.
* @return true when the crash save was successfully made. * @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 /* 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. */ * 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 { try {
GamelogEmergency(); 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. */ /* Don't do a threaded saveload. */
return SaveOrLoad(filename, SLO_SAVE, DFT_GAME_FILE, NO_DIRECTORY, false) == SL_OK; 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. * @param filename_last The last position in the filename buffer.
* @return true when the crash screenshot was successfully made. * @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 */ /* Don't draw when we have invalid screen size */
if (_screen.width < 1 || _screen.height < 1 || _screen.dst_ptr == nullptr) return false; 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); if (res) strecpy(filename, _full_screenshot_name, filename_last);
return res; return res;
} }
@ -506,6 +536,57 @@ bool CrashLog::MakeCrashLog() const
return ret; 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. * Sets a message for the error message handler.
* @param message The error message of the error. * @param message The error message of the error.

View File

@ -91,7 +91,8 @@ public:
virtual ~CrashLog() {} virtual ~CrashLog() {}
char *FillCrashLog(char *buffer, const char *last) const; 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. * Write the (crash) dump to a file.
@ -103,10 +104,11 @@ public:
* was successful (not all OSes support dumping files). * was successful (not all OSes support dumping files).
*/ */
virtual int WriteCrashDump(char *filename, const char *filename_last) const; virtual int WriteCrashDump(char *filename, const char *filename_last) const;
bool WriteSavegame(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; bool WriteScreenshot(char *filename, const char *filename_last, const char *name = "crash") const;
bool MakeCrashLog() const; bool MakeCrashLog() const;
bool MakeDesyncCrashLog() const;
/** /**
* Initialiser for crash logs; do the appropriate things so crashes are * Initialiser for crash logs; do the appropriate things so crashes are
@ -115,6 +117,8 @@ public:
*/ */
static void InitialiseCrashLog(); static void InitialiseCrashLog();
static void DesyncCrashLog();
static void SetErrorMessage(const char *message); static void SetErrorMessage(const char *message);
static void AfterCrashLogCleanup(); static void AfterCrashLogCleanup();
}; };

View File

@ -28,6 +28,7 @@
#include "network_client.h" #include "network_client.h"
#include "../core/backup_type.hpp" #include "../core/backup_type.hpp"
#include "../thread.h" #include "../thread.h"
#include "../crashlog.h"
#include "table/strings.h" #include "table/strings.h"
@ -277,6 +278,8 @@ void ClientNetworkGameSocketHandler::ClientError(NetworkRecvStatus res)
DEBUG(net, 0, "Sync error detected!"); DEBUG(net, 0, "Sync error detected!");
my_client->ClientError(NETWORK_RECV_STATUS_DESYNC); my_client->ClientError(NETWORK_RECV_STATUS_DESYNC);
CrashLog::DesyncCrashLog();
extern void CheckCaches(bool force_check); extern void CheckCaches(bool force_check);
CheckCaches(true); CheckCaches(true);
return false; return false;

View File

@ -28,6 +28,7 @@
#include "../core/pool_func.hpp" #include "../core/pool_func.hpp"
#include "../core/random_func.hpp" #include "../core/random_func.hpp"
#include "../rev.h" #include "../rev.h"
#include "../crashlog.h"
#include <mutex> #include <mutex>
#include <condition_variable> #include <condition_variable>
@ -1159,6 +1160,8 @@ NetworkRecvStatus ServerNetworkGameSocketHandler::Receive_CLIENT_ERROR(Packet *p
NetworkAdminClientError(this->client_id, errorno); NetworkAdminClientError(this->client_id, errorno);
if (errorno == NETWORK_ERROR_DESYNC) { if (errorno == NETWORK_ERROR_DESYNC) {
CrashLog::DesyncCrashLog();
// have the server and all clients run some sanity checks // have the server and all clients run some sanity checks
NetworkSendCommand(0, 0, 0, CMD_DESYNC_CHECK, NULL, NULL, _local_company); NetworkSendCommand(0, 0, 0, CMD_DESYNC_CHECK, NULL, NULL, _local_company);
} }

View File

@ -152,6 +152,8 @@ class CrashLogOSX : public CrashLog {
} }
public: public:
struct DesyncTag {};
/** /**
* A crash log is always generated by signal. * A crash log is always generated by signal.
* @param signum the signal that was caused by the crash. * @param signum the signal that was caused by the crash.
@ -163,6 +165,13 @@ public:
filename_screenshot[0] = '\0'; 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. */ /** Generate the crash log. */
bool MakeCrashLog() bool MakeCrashLog()
{ {
@ -257,3 +266,9 @@ void CDECL HandleCrash(int signum)
signal(*i, HandleCrash); signal(*i, HandleCrash);
} }
} }
/* static */ void CrashLog::DesyncCrashLog()
{
CrashLogOSX log(CrashLogOSX::DesyncTag{});
log.MakeDesyncCrashLog();
}

View File

@ -181,3 +181,9 @@ static void CDECL HandleCrash(int signum)
signal(*i, HandleCrash); signal(*i, HandleCrash);
} }
} }
/* static */ void CrashLog::DesyncCrashLog()
{
CrashLogUnix log(0);
log.MakeDesyncCrashLog();
}

View File

@ -633,6 +633,12 @@ static void CDECL CustomAbort(int signal)
SetUnhandledExceptionFilter(ExceptionHandler); SetUnhandledExceptionFilter(ExceptionHandler);
} }
/* static */ void CrashLog::DesyncCrashLog()
{
CrashLogWindows log(nullptr);
log.MakeDesyncCrashLog();
}
/* The crash log GUI */ /* The crash log GUI */
static bool _expanded; static bool _expanded;