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 3fdd553a08
commit fa55a1c002
7 changed files with 139 additions and 9 deletions

View File

@ -433,6 +433,37 @@ 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, %i)\n\n", _cur_date_ymd.year, _cur_date_ymd.month + 1, _cur_date_ymd.day, _date_fract, _tick_skip_counter);
buffer = this->LogOpenTTDVersion(buffer, last);
buffer = this->LogOSVersion(buffer, last);
buffer = this->LogCompiler(buffer, last);
buffer = this->LogOSVersionDetail(buffer, last);
buffer = this->LogConfiguration(buffer, last);
buffer = this->LogLibraries(buffer, last);
buffer = this->LogGamelog(buffer, last);
buffer = this->LogRecentNews(buffer, last);
buffer = this->LogCommandLog(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
@ -442,9 +473,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;
@ -470,7 +501,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. */
@ -479,7 +510,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;
@ -496,12 +527,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;
}
@ -561,6 +592,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;
}
/**
* Makes a crash dump and crash savegame. It uses DEBUG to write
* information like paths to the console.

View File

@ -111,7 +111,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.
@ -123,10 +124,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;
bool MakeCrashSavegameAndScreenshot() const;
/**
@ -136,6 +138,8 @@ public:
*/
static void InitialiseCrashLog();
static void DesyncCrashLog();
static void SetErrorMessage(const char *message);
static void AfterCrashLogCleanup();

View File

@ -31,6 +31,7 @@
#include "network_client.h"
#include "../core/backup_type.hpp"
#include "../thread.h"
#include "../crashlog.h"
#include "table/strings.h"
@ -282,6 +283,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;

View File

@ -30,6 +30,7 @@
#include "../core/pool_func.hpp"
#include "../core/random_func.hpp"
#include "../rev.h"
#include "../crashlog.h"
#include <mutex>
#include <condition_variable>
#if defined(__MINGW32__)
@ -1170,6 +1171,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, nullptr, nullptr, _local_company, 0);
}

View File

@ -375,6 +375,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.
@ -399,6 +401,13 @@ public:
#endif /* WITH_UCONTEXT */
}
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()
{
@ -502,3 +511,9 @@ void CDECL HandleCrash(int signum, siginfo_t *si, void *context)
sigaction(*i, &sa, nullptr);
}
}
/* static */ void CrashLog::DesyncCrashLog()
{
CrashLogOSX log(CrashLogOSX::DesyncTag{});
log.MakeDesyncCrashLog();
}

View File

@ -517,6 +517,8 @@ class CrashLogUnix : public CrashLog {
#endif
public:
struct DesyncTag {};
/**
* A crash log is always generated by signal.
* @param signum the signal that was caused by the crash.
@ -544,6 +546,15 @@ public:
{
}
#endif /* WITH_SIGACTION */
CrashLogUnix(DesyncTag tag) : signum(0)
{
#ifdef WITH_SIGACTION
this->si = nullptr;
this->context = nullptr;
this->signal_instruction_ptr_valid = false;
#endif
}
};
/** The signals we want our crash handler to handle. */
@ -608,3 +619,9 @@ static void CDECL HandleCrash(int signum)
#endif
}
}
/* static */ void CrashLog::DesyncCrashLog()
{
CrashLogUnix log(CrashLogUnix::DesyncTag{});
log.MakeDesyncCrashLog();
}

View File

@ -609,6 +609,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;