Changeset - r10515:c73815918fba
[Not reviewed]
master
0 11 0
rubidium - 16 years ago 2008-12-29 21:50:25
rubidium@openttd.org
(svn r14772) -Codechange: make the "dump log of game to reproduce" desync debug stuff a runtime configurable debug option instead of a compile time option.
11 files changed with 86 insertions and 52 deletions:
0 comments (0 inline, 0 general)
config.lib
Show inline comments
 
@@ -1354,16 +1354,13 @@ make_cflags_and_ldflags() {
 
	fi
 

	
 
	if [ "$enable_assert" = "0" ]; then
 
		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
 

	
 
	if [ "$enable_osx_g5" != "0" ]; then
 
		CFLAGS="$CFLAGS -mtune=970 -mcpu=970 -mpowerpc-gpopt"
 
	fi
readme.txt
Show inline comments
 
@@ -63,12 +63,64 @@ Please include the following information
 
        - Attach a saved game *and* a screenshot if possible
 
        - If this bug only occurred recently please note the last
 
          version without the bug and the first version including
 
          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:
 
---- --------------------
 
OpenTTD has been ported to several platforms and operating systems. It shouldn't
 
be very difficult to port it to a new platform. The currently working platforms
 
are:
src/command.cpp
Show inline comments
 
@@ -580,13 +580,13 @@ bool DoCommandP(TileIndex tile, uint32 p
 
		if (_network_dedicated || (_network_server && bck == COMPANY_SPECTATOR)) _local_company = bck;
 
		_docommand_recursive = 0;
 
		ClearStorageChanges(false);
 
		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)) {
 
		GetCompany(_current_company)->last_build_coordinate = tile;
 
	}
 

	
src/date.cpp
Show inline comments
 
@@ -12,15 +12,13 @@
 
#include "window_func.h"
 
#include "functions.h"
 
#include "date_func.h"
 
#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;
 
Date      _date;
 
DateFract _date_fract;
 

	
 
@@ -241,18 +239,18 @@ void IncreaseDate()
 
	ConvertDateToYMD(_date, &ymd);
 
	if (ymd.month == _cur_month) return;
 
	_cur_month = ymd.month;
 

	
 
	/* yes, call various monthly loops */
 
	if (_game_mode != GM_MENU) {
 
#ifdef DEBUG_DUMP_COMMANDS
 
		if (_debug_desync_level > 2) {
 
		char name[MAX_PATH];
 
		snprintf(name, lengthof(name), "dmp_cmds_%d.sav", _date);
 
			snprintf(name, lengthof(name), "dmp_cmds_%08x_%08x.sav", _settings_game.game_creation.generation_seed, _date);
 
		SaveOrLoad(name, SL_SAVE, AUTOSAVE_DIR);
 
		DebugDumpCommands("ddc:save:%s\n", name);
 
#endif /* DUMP_COMMANDS */
 
		}
 

	
 
		if (_settings_client.gui.autosave != 0 && (_cur_month % _autosave_months[_settings_client.gui.autosave]) == 0) {
 
			_do_autosave = true;
 
			RedrawAutosave();
 
		}
 

	
 
		InvalidateWindowClasses(WC_CHEATS);
src/debug.cpp
Show inline comments
 
@@ -7,12 +7,13 @@
 
#include <stdarg.h>
 
#include "openttd.h"
 
#include "console_func.h"
 
#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;
 
#endif /* ENABLE_NETWORK */
 

	
 
int _debug_ai_level;
 
@@ -28,12 +29,13 @@ int _debug_ntp_level;
 
int _debug_npf_level;
 
int _debug_yapf_level;
 
int _debug_freetype_level;
 
int _debug_sl_level;
 
int _debug_station_level;
 
int _debug_gamelog_level;
 
int _debug_desync_level;
 

	
 

	
 
struct DebugLevel {
 
	const char *name;
 
	int *level;
 
};
 
@@ -53,12 +55,13 @@ struct DebugLevel {
 
	DEBUG_LEVEL(npf),
 
	DEBUG_LEVEL(yapf),
 
	DEBUG_LEVEL(freetype),
 
	DEBUG_LEVEL(sl),
 
	DEBUG_LEVEL(station),
 
	DEBUG_LEVEL(gamelog),
 
	DEBUG_LEVEL(desync),
 
	};
 
#undef DEBUG_LEVEL
 

	
 
#if !defined(NO_DEBUG_MESSAGES)
 

	
 
static void debug_print(const char *dbg, const char *buf)
 
@@ -68,22 +71,28 @@ static void debug_print(const char *dbg,
 
		char buf2[1024 + 32];
 

	
 
		snprintf(buf2, lengthof(buf2), "dbg: [%s] %s\n", dbg, 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];
 
		_sntprintf(tbuf, sizeof(tbuf), _T("%s"), OTTD2FS(dbg));
 
		NKDbgPrintfW(_T("dbg: [%s] %s\n"), tbuf, OTTD2FS(buf));
 
#else
 
		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);
 
	}
 
}
 

	
 
void CDECL debug(const char *dbg, ...)
 
{
 
	va_list va;
 
@@ -165,23 +174,6 @@ const char *GetDebugString()
 
		snprintf(dbgval, sizeof(dbgval), ", %s=%d", i->name, *i->level);
 
		strecat(dbgstr, dbgval, lastof(dbgstr));
 
	}
 

	
 
	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 */
src/debug.h
Show inline comments
 
@@ -45,12 +45,13 @@
 
	extern int _debug_npf_level;
 
	extern int _debug_yapf_level;
 
	extern int _debug_freetype_level;
 
	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 */
 

	
 
void SetDebugString(const char *s);
 
const char *GetDebugString();
 
@@ -98,19 +99,7 @@ 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 */
src/genworld.cpp
Show inline comments
 
@@ -23,12 +23,13 @@
 
#include "core/random_func.hpp"
 
#include "engine_func.h"
 
#include "settings_type.h"
 
#include "newgrf_storage.h"
 
#include "water.h"
 
#include "tilehighlight_func.h"
 
#include "saveload.h"
 

	
 
#include "table/sprites.h"
 

	
 
void GenerateClearTile();
 
void GenerateIndustries();
 
void GenerateUnmovables();
 
@@ -160,14 +161,20 @@ static void _GenerateWorld(void *arg)
 
		_gw.threaded = false;
 

	
 
		DeleteWindowById(WC_GENERATE_PROGRESS_WINDOW, 0);
 
		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;
 
	}
 
}
 

	
src/network/network.cpp
Show inline comments
 
@@ -210,13 +210,13 @@ void NetworkTextMessage(NetworkAction ac
 
	char message[1024];
 
	SetDParamStr(0, name);
 
	SetDParamStr(1, str);
 
	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);
 
}
 

	
 
// Calculate the frame-lag of a client
 
uint NetworkCalculateLag(const NetworkClientSocket *cs)
 
@@ -961,13 +961,13 @@ static bool NetworkDoClientLoop()
 
#ifdef NETWORK_SEND_DOUBLE_SEED
 
			if (_sync_seed_1 != _random.state[0] || _sync_seed_2 != _random.state[1]) {
 
#else
 
			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;
 
			}
 

	
 
			// If this is the first time we have a sync-frame, we
 
@@ -1029,13 +1029,13 @@ void NetworkGameLoop()
 
			}
 

	
 
			if (cp != NULL) break;
 

	
 
			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);
 
			cp->company = (CompanyID)company;
 
		}
 
#endif /* DEBUG_DUMP_COMMANDS */
src/network/network_data.cpp
Show inline comments
 
@@ -99,12 +99,10 @@ void NetworkExecuteCommand(CommandPacket
 
	/* cp->callback is unsigned. so we don't need to do lower bounds checking. */
 
	if (cp->callback > _callback_table_count) {
 
		DEBUG(net, 0, "Received out-of-bounds callback (%d)", cp->callback);
 
		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);
 
}
 

	
 
#endif /* ENABLE_NETWORK */
src/openttd.cpp
Show inline comments
 
@@ -1026,22 +1026,22 @@ void StateGameLoop()
 
		CallLandscapeTick();
 
		ClearStorageChanges(true);
 

	
 
		CallWindowTickEvent();
 
		NewsLoop();
 
	} else {
 
#ifdef DEBUG_DUMP_COMMANDS
 
		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) {
 
						printf("cache mismatch: vehicle %i, company %i, unit number %i\n", v->index, (int)v->owner, v->unitnumber);
 
							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++;
 
@@ -1052,33 +1052,33 @@ void StateGameLoop()
 

	
 
					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);
 
								DEBUG(desync, 2, "cache mismatch: vehicle %i, company %i, unit number %i, wagon %i\n", v->index, (int)v->owner, v->unitnumber, length);
 
						}
 
						length++;
 
					}
 

	
 
					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);
 
							DEBUG(desync, 2, "cache mismatch: vehicle %i, company %i, unit number %i\n", v->index, (int)v->owner, v->unitnumber);
 
					}
 
				} break;
 

	
 
				default:
 
					break;
 
			}
 
		}
 
#endif
 
		}
 

	
 
		/* All these actions has to be done from OWNER_NONE
 
		 *  for multiplayer compatibility */
 
		CompanyID old_company = _current_company;
 
		_current_company = OWNER_NONE;
 

	
src/saveload.cpp
Show inline comments
 
@@ -1684,12 +1684,13 @@ SaveOrLoadResult SaveOrLoad(const char *
 
		_sl.save = (mode != 0);
 
		_sl.chs = _chunk_handlers;
 

	
 
		/* 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;
 
			_sl.excpt_uninit = fmt->uninit_write;
 
			if (!fmt->init_write()) {
 
				DEBUG(sl, 0, "Initializing writer '%s' failed.", fmt->name);
 
@@ -1711,13 +1712,13 @@ SaveOrLoadResult SaveOrLoad(const char *
 
				SaveFileDone();
 

	
 
				return result;
 
			}
 
		} 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);
 

	
 
			/* see if we have any loader for this type. */
 
			for (fmt = _saveload_formats; ; fmt++) {
 
				/* No loader found, treat as version 0 and use LZO format */
0 comments (0 inline, 0 general)