diff options
-rw-r--r-- | config.lib | 5 | ||||
-rw-r--r-- | readme.txt | 52 | ||||
-rw-r--r-- | src/command.cpp | 2 | ||||
-rw-r--r-- | src/date.cpp | 14 | ||||
-rw-r--r-- | src/debug.cpp | 28 | ||||
-rw-r--r-- | src/debug.h | 13 | ||||
-rw-r--r-- | src/genworld.cpp | 7 | ||||
-rw-r--r-- | src/network/network.cpp | 8 | ||||
-rw-r--r-- | src/network/network_data.cpp | 2 | ||||
-rw-r--r-- | src/openttd.cpp | 74 | ||||
-rw-r--r-- | src/saveload.cpp | 3 |
11 files changed, 121 insertions, 87 deletions
diff --git a/config.lib b/config.lib index 143c4967e..918e5cad1 100644 --- a/config.lib +++ b/config.lib @@ -1357,10 +1357,7 @@ make_cflags_and_ldflags() { CFLAGS="$CFLAGS -DNDEBUG" fi - if [ "$enable_desync_debug" = "1" ]; then - CFLAGS="$CFLAGS -DDEBUG_DUMP_COMMANDS" - fi - if [ "$enable_desync_debug" = "2" ]; then + if [ "$enable_desync_debug" != "0" ]; then CFLAGS="$CFLAGS -DRANDOM_DEBUG" fi diff --git a/readme.txt b/readme.txt index bdb894027..78a3da179 100644 --- a/readme.txt +++ b/readme.txt @@ -66,6 +66,58 @@ Please include the following information in your bug report: the bug. That way we can fix it quicker by looking at the changes made. +2.2) Reporting Desyncs: +---- ------------------ +As desyncs are hard to make reproducable OpenTTD has the ability to log all +actions done by clients so we can replay the whole game in an effort to make +desyncs better reproducable. You need to turn this ability on. When turned +on an automatic savegame will be made once the map has been constructed in +the 'save/autosave' directory, see OpenTTD directories to know where to find +this directory. Furthermore the log file 'commands-out.log' will be created +and all actions will be written to there. + +To enable the desync debugging you need to set the debug level for 'desync' +to at least 1. You do this by starting OpenTTD with '-d desync=<level>' as +parameter or by typing 'debug_level desync=<level>' in OpenTTD's internal +console. +The desync debug levels are: + 0: nothing. + 1: dumping of commands to 'commands-out.log'. + 2: same as 1 plus checking vehicle caches and dumping that too. + 3: same as 2 plus monthly saves in autosave. + 4 and higher: same as 3 + +Restarting OpenTTD will overwrite 'commands-out.log'. OpenTTD will not remove +the savegames (dmp_cmds_*.sav) made by the desync debugging system, so you +have to occasionally remove them yourself! + +The naming format of the desync savegames is as follows: +dmp_cmds_XXXXXXXX_YYYYYYYY.sav. The XXXXXXXX is the hexadecimal representation +of the generation seed of the game and YYYYYYYY is the hexadecimal +representation of the date of the game. This sorts the savegames by game and +then by date making it easier to find the right savegames. + +When a desync has occurred with the desync debugging turned on you should file +a bug report with the following files attached: + - commands-out.log as it contains all the commands that were done + - the last saved savegame (search for the last line beginning with + 'save: dmp_cmds_' in commands-out.log). We use this savegame to check + whether we can quickly reproduce the desync. Otherwise we will need... + - the first saved savegame (search for the first line beginning with 'save' + where the first part, up to the last underscore '_', is the same). We need + this savegame to be able to reproduce the bug when the last savegame is not + old enough. If you loaded a scenario or savegame you need to attach that. + - optionally you can attach the savegames from around 50%, 75%, 85%, 90% and + 95% of the game's progression. We can use these savegames to speed up the + reproduction of the desync, but we should be able to reproduce these + savegames based on the first savegame and commands-out.log. + - in case you use any NewGRFs you should attach the ones you used unless + we can easily find them ourselves via e.g. grfcrawler or when they are + in the OpenTTDCoop pack. + +Do NOT remove the dmp_cmds savegames of a desync you have reported until the +desync has been fixed; if you, by accident, send us the wrong savegames we +will not be able to reproduce the desync and thus will be unable to fix it. 3.0) Supported Platforms: ---- -------------------- diff --git a/src/command.cpp b/src/command.cpp index f91bc4319..8a21f9d60 100644 --- a/src/command.cpp +++ b/src/command.cpp @@ -583,7 +583,7 @@ bool DoCommandP(TileIndex tile, uint32 p1, uint32 p2, uint32 cmd, CommandCallbac return true; } #endif /* ENABLE_NETWORK */ - DebugDumpCommands("ddc:cmd:%d;%d;%d;%d;%d;%d;%d;%s\n", _date, _date_fract, (int)_current_company, tile, p1, p2, cmd, text); + DEBUG(desync, 1, "cmd: %08x; %08x; %1x; %06x; %08x; %08x; %04x; %s\n", _date, _date_fract, (int)_current_company, tile, p1, p2, cmd & ~CMD_NETWORK_COMMAND, text); /* update last build coordinate of company. */ if (tile != 0 && IsValidCompanyID(_current_company)) { diff --git a/src/date.cpp b/src/date.cpp index 2b0e6ff09..5827cbc05 100644 --- a/src/date.cpp +++ b/src/date.cpp @@ -15,9 +15,7 @@ #include "vehicle_base.h" #include "debug.h" #include "rail_gui.h" -#ifdef DEBUG_DUMP_COMMANDS #include "saveload.h" -#endif Year _cur_year; Month _cur_month; @@ -244,12 +242,12 @@ void IncreaseDate() /* yes, call various monthly loops */ if (_game_mode != GM_MENU) { -#ifdef DEBUG_DUMP_COMMANDS - char name[MAX_PATH]; - snprintf(name, lengthof(name), "dmp_cmds_%d.sav", _date); - SaveOrLoad(name, SL_SAVE, AUTOSAVE_DIR); - DebugDumpCommands("ddc:save:%s\n", name); -#endif /* DUMP_COMMANDS */ + if (_debug_desync_level > 2) { + char name[MAX_PATH]; + snprintf(name, lengthof(name), "dmp_cmds_%08x_%08x.sav", _settings_game.game_creation.generation_seed, _date); + SaveOrLoad(name, SL_SAVE, AUTOSAVE_DIR); + } + if (_settings_client.gui.autosave != 0 && (_cur_month % _autosave_months[_settings_client.gui.autosave]) == 0) { _do_autosave = true; RedrawAutosave(); diff --git a/src/debug.cpp b/src/debug.cpp index 10c43cf9c..62f75e157 100644 --- a/src/debug.cpp +++ b/src/debug.cpp @@ -10,6 +10,7 @@ #include "debug.h" #include "string_func.h" #include "network/core/core.h" +#include "fileio_func.h" #if defined(ENABLE_NETWORK) SOCKET _debug_socket = INVALID_SOCKET; @@ -31,6 +32,7 @@ int _debug_freetype_level; int _debug_sl_level; int _debug_station_level; int _debug_gamelog_level; +int _debug_desync_level; struct DebugLevel { @@ -56,6 +58,7 @@ struct DebugLevel { DEBUG_LEVEL(sl), DEBUG_LEVEL(station), DEBUG_LEVEL(gamelog), + DEBUG_LEVEL(desync), }; #undef DEBUG_LEVEL @@ -71,7 +74,7 @@ static void debug_print(const char *dbg, const char *buf) send(_debug_socket, buf2, (int)strlen(buf2), 0); } else #endif /* ENABLE_NETWORK */ - { + if (strcmp(dbg, "desync") != 0) { #if defined(WINCE) /* We need to do OTTD2FS twice, but as it uses a static buffer, we need to store one temporary */ TCHAR tbuf[512]; @@ -81,6 +84,12 @@ static void debug_print(const char *dbg, const char *buf) fprintf(stderr, "dbg: [%s] %s\n", dbg, buf); #endif IConsoleDebug(dbg, buf); + } else { + static FILE *f = FioFOpenFile("commands-out.log", "wb", AUTOSAVE_DIR); + if (f == NULL) return; + + fprintf(f, "%s", buf); + fflush(f); } } @@ -168,20 +177,3 @@ const char *GetDebugString() return dbgstr; } - -#ifdef DEBUG_DUMP_COMMANDS -#include "fileio_func.h" - -void CDECL DebugDumpCommands(const char *s, ...) -{ - static FILE *f = FioFOpenFile("commands-out.log", "wb", AUTOSAVE_DIR); - if (f == NULL) return; - - va_list va; - va_start(va, s); - vfprintf(f, s, va); - va_end(va); - - fflush(f); -} -#endif /* DEBUG_DUMP_COMMANDS */ diff --git a/src/debug.h b/src/debug.h index 8ab897b2e..c7a71c67a 100644 --- a/src/debug.h +++ b/src/debug.h @@ -48,6 +48,7 @@ extern int _debug_sl_level; extern int _debug_station_level; extern int _debug_gamelog_level; + extern int _debug_desync_level; void CDECL debug(const char *dbg, ...); #endif /* NO_DEBUG_MESSAGES */ @@ -101,16 +102,4 @@ const char *GetDebugString(); void ShowInfo(const char *str); void CDECL ShowInfoF(const char *str, ...); -#ifdef DEBUG_DUMP_COMMANDS - void CDECL DebugDumpCommands(const char *s, ...); -#else /* DEBUG_DUMP_COMMANDS */ - /* when defined as an empty function with variable argument list, - * it can't be inlined - so define it as an empty macro */ - #if defined(__GNUC__) && (__GNUC__ < 3) - #define DebugDumpCommands(s, args...) - #else - #define DebugDumpCommands(s, ...) - #endif -#endif /* DEBUG_DUMP_COMMANDS */ - #endif /* DEBUG_H */ diff --git a/src/genworld.cpp b/src/genworld.cpp index 0a2b49d5b..23a978272 100644 --- a/src/genworld.cpp +++ b/src/genworld.cpp @@ -26,6 +26,7 @@ #include "newgrf_storage.h" #include "water.h" #include "tilehighlight_func.h" +#include "saveload.h" #include "table/sprites.h" @@ -163,8 +164,14 @@ static void _GenerateWorld(void *arg) MarkWholeScreenDirty(); if (_network_dedicated) DEBUG(net, 0, "Map generated, starting game"); + DEBUG(desync, 1, "new_map: %i\n", _settings_game.game_creation.generation_seed); if (_settings_client.gui.pause_on_newgame && _game_mode == GM_NORMAL) DoCommandP(0, 1, 0, CMD_PAUSE); + if (_debug_desync_level > 0) { + char name[MAX_PATH]; + snprintf(name, lengthof(name), "dmp_cmds_%08x_%08x.sav", _settings_game.game_creation.generation_seed, _date); + SaveOrLoad(name, SL_SAVE, AUTOSAVE_DIR); + } } catch (...) { _generating_world = false; throw; diff --git a/src/network/network.cpp b/src/network/network.cpp index c6935638a..7bc562a86 100644 --- a/src/network/network.cpp +++ b/src/network/network.cpp @@ -213,7 +213,7 @@ void NetworkTextMessage(NetworkAction action, ConsoleColour color, bool self_sen SetDParam(2, data); GetString(message, strid, lastof(message)); - DebugDumpCommands("ddc:cmsg:%d;%d;%s\n", _date, _date_fract, message); + DEBUG(desync, 1, "msg: %d; %d; %s\n", _date, _date_fract, message); IConsolePrintF(color, "%s", message); NetworkAddChatMessage(color, duration, "%s", message); } @@ -964,7 +964,7 @@ static bool NetworkDoClientLoop() if (_sync_seed_1 != _random.state[0]) { #endif NetworkError(STR_NETWORK_ERR_DESYNC); - DebugDumpCommands("ddc:serr:%d;%d\n", _date, _date_fract); + DEBUG(desync, 1, "sync_err: %d; %d\n", _date, _date_fract); DEBUG(net, 0, "Sync error detected!"); NetworkClientError(NETWORK_RECV_STATUS_DESYNC, GetNetworkClientSocket(0)); return false; @@ -1032,10 +1032,10 @@ void NetworkGameLoop() char buff[4096]; if (fgets(buff, lengthof(buff), f) == NULL) break; - if (strncmp(buff, "ddc:cmd:", 8) != 0) continue; + if (strncmp(buff, "cmd: ", 8) != 0) continue; cp = MallocT<CommandPacket>(1); int company; - sscanf(&buff[8], "%d;%d;%d;%d;%d;%d;%d;%s", &next_date, &next_date_fract, &company, &cp->tile, &cp->p1, &cp->p2, &cp->cmd, cp->text); + sscanf(&buff[8], "%d; %d; %d; %d; %d; %d; %d; %s", &next_date, &next_date_fract, &company, &cp->tile, &cp->p1, &cp->p2, &cp->cmd, cp->text); cp->company = (CompanyID)company; } #endif /* DEBUG_DUMP_COMMANDS */ diff --git a/src/network/network_data.cpp b/src/network/network_data.cpp index 42358f284..cdcf0ba39 100644 --- a/src/network/network_data.cpp +++ b/src/network/network_data.cpp @@ -102,8 +102,6 @@ void NetworkExecuteCommand(CommandPacket *cp) cp->callback = 0; } - DebugDumpCommands("ddc:cmd:%d;%d;%d;%d;%d;%d;%d;%s\n", _date, _date_fract, (int)cp->company, cp->tile, cp->p1, cp->p2, cp->cmd, cp->text); - DoCommandP(cp->tile, cp->p1, cp->p2, cp->cmd | CMD_NETWORK_COMMAND, _callback_table[cp->callback], cp->text, cp->my_cmd); } diff --git a/src/openttd.cpp b/src/openttd.cpp index 06b343309..cf4709c5d 100644 --- a/src/openttd.cpp +++ b/src/openttd.cpp @@ -1029,53 +1029,53 @@ void StateGameLoop() CallWindowTickEvent(); NewsLoop(); } else { -#ifdef DEBUG_DUMP_COMMANDS - Vehicle *v; - FOR_ALL_VEHICLES(v) { - if (v != v->First()) continue; - - switch (v->type) { - case VEH_ROAD: { - extern byte GetRoadVehLength(const Vehicle *v); - if (GetRoadVehLength(v) != v->u.road.cached_veh_length) { - printf("cache mismatch: vehicle %i, company %i, unit number %i\n", v->index, (int)v->owner, v->unitnumber); - } - } break; + if (_debug_desync_level > 1) { + Vehicle *v; + FOR_ALL_VEHICLES(v) { + if (v != v->First()) continue; + + switch (v->type) { + case VEH_ROAD: { + extern byte GetRoadVehLength(const Vehicle *v); + if (GetRoadVehLength(v) != v->u.road.cached_veh_length) { + DEBUG(desync, 2, "cache mismatch: vehicle %i, company %i, unit number %i\n", v->index, (int)v->owner, v->unitnumber); + } + } break; - case VEH_TRAIN: { - uint length = 0; - for (Vehicle *u = v; u != NULL; u = u->Next()) length++; + case VEH_TRAIN: { + uint length = 0; + for (Vehicle *u = v; u != NULL; u = u->Next()) length++; - VehicleRail *wagons = MallocT<VehicleRail>(length); - length = 0; - for (Vehicle *u = v; u != NULL; u = u->Next()) wagons[length++] = u->u.rail; + VehicleRail *wagons = MallocT<VehicleRail>(length); + length = 0; + for (Vehicle *u = v; u != NULL; u = u->Next()) wagons[length++] = u->u.rail; - TrainConsistChanged(v, true); + TrainConsistChanged(v, true); - length = 0; - for (Vehicle *u = v; u != NULL; u = u->Next()) { - if (memcmp(&wagons[length], &u->u.rail, sizeof(VehicleRail)) != 0) { - printf("cache mismatch: vehicle %i, company %i, unit number %i, wagon %i\n", v->index, (int)v->owner, v->unitnumber, length); + length = 0; + for (Vehicle *u = v; u != NULL; u = u->Next()) { + if (memcmp(&wagons[length], &u->u.rail, sizeof(VehicleRail)) != 0) { + DEBUG(desync, 2, "cache mismatch: vehicle %i, company %i, unit number %i, wagon %i\n", v->index, (int)v->owner, v->unitnumber, length); + } + length++; } - length++; - } - free(wagons); - } break; + free(wagons); + } break; - case VEH_AIRCRAFT: { - uint speed = v->u.air.cached_max_speed; - UpdateAircraftCache(v); - if (speed != v->u.air.cached_max_speed) { - printf("cache mismatch: vehicle %i, company %i, unit number %i\n", v->index, (int)v->owner, v->unitnumber); - } - } break; + case VEH_AIRCRAFT: { + uint speed = v->u.air.cached_max_speed; + UpdateAircraftCache(v); + if (speed != v->u.air.cached_max_speed) { + DEBUG(desync, 2, "cache mismatch: vehicle %i, company %i, unit number %i\n", v->index, (int)v->owner, v->unitnumber); + } + } break; - default: - break; + default: + break; + } } } -#endif /* All these actions has to be done from OWNER_NONE * for multiplayer compatibility */ diff --git a/src/saveload.cpp b/src/saveload.cpp index 06789e8b0..968e48911 100644 --- a/src/saveload.cpp +++ b/src/saveload.cpp @@ -1687,6 +1687,7 @@ SaveOrLoadResult SaveOrLoad(const char *filename, int mode, Subdirectory sb) /* General tactic is to first save the game to memory, then use an available writer * to write it to file, either in threaded mode if possible, or single-threaded */ if (mode == SL_SAVE) { /* SAVE game */ + DEBUG(desync, 1, "save: %s\n", filename); fmt = GetSavegameFormat("memory"); // write to memory _sl.write_bytes = fmt->writer; @@ -1714,7 +1715,7 @@ SaveOrLoadResult SaveOrLoad(const char *filename, int mode, Subdirectory sb) } } else { /* LOAD game */ assert(mode == SL_LOAD); - DebugDumpCommands("ddc:load:%s\n", filename); + DEBUG(desync, 1, "load: %s\n", filename); if (fread(hdr, sizeof(hdr), 1, _sl.fh) != 1) SlError(STR_GAME_SAVELOAD_ERROR_FILE_NOT_READABLE); |