Working crash log

This was SVN commit r760.

source/lib/sysdep/sysdep.h

@@ -34,7 +34,7 @@ extern void debug_break();
 
 extern int debug_assert_failed(const char* source_file, int line, const char* expr);
 
-extern int debug_write_crashlog(const char* file);
+extern int debug_write_crashlog(const char* file, wchar_t* header, void* context);
 
 
 extern void check_heap();

source/lib/sysdep/win/wdbg.cpp

@@ -61,6 +61,7 @@ typedef enum
 }
 BasicType;
 
+static void DumpMiniDump(HANDLE hFile, PEXCEPTION_POINTERS excpInfo);
 
 // function pointers
 //
@@ -99,7 +100,6 @@ static void dbg_cleanup(void)
 	_SymCleanup(hProcess);
 }
 
-
 static void dbg_init()
 {
 	/* already initialized */
@@ -261,19 +261,27 @@ next_element:
 /* print sym name; if not a basic type, recurse for each child */
 static void dump_sym(u32 type_idx, uint level, u64 addr)
 {
-	u32 num_children = 0;
-	_SymGetTypeInfo(hProcess, mod_base, type_idx, TI_GET_CHILDRENCOUNT, &num_children);
-
 	/* print type name / member name */
 	WCHAR* type_name;
 	if(_SymGetTypeInfo(hProcess, mod_base, type_idx, TI_GET_SYMNAME, &type_name))
 	{
+		/* HACK: ignore things that look like member functions */
+		if (wcsstr(type_name, L"::"))
+			return;
+
+		/* indent */
+		for(uint i = 0; i < level+2; i++)
+			out(L"  ");
+
 		out(L"%ls ", type_name);
 		LocalFree(type_name);
 	}
 
+	u32 num_children = 0;
+
 	/* built-in type? yes - show its value, terminate recursion */
-	if(!num_children)
+	if (! _SymGetTypeInfo(hProcess, mod_base, type_idx, TI_GET_CHILDRENCOUNT, &num_children)
+		|| num_children == 0)
 	{
 		print_var(type_idx, level, addr);
 		return;
@@ -297,10 +305,6 @@ static void dump_sym(u32 type_idx, uint level, u64 addr)
 	{
 		u32 child_id = children->ChildId[child_idx];
 
-		/* indent */
-		for(uint i = 0; i < level+3; i++)
-			out(L"  ");
-
 		u32 member_ofs;
 		_SymGetTypeInfo(hProcess, mod_base, child_id, TI_GET_OFFSET, &member_ofs);
 
@@ -368,7 +372,7 @@ static BOOL CALLBACK sym_callback(SYMBOL_INFO* sym, ULONG /* SymbolSize */, void
  * most recent <skip> stack frames will be skipped
  * (we don't want to show e.g. GetThreadContext / this call)
  */
-static void walk_stack(int skip, wchar_t* out_buf)
+static void walk_stack(int skip, wchar_t* out_buf, CONTEXT* override_context = NULL)
 {
 	dbg_init();
 
@@ -383,9 +387,16 @@ static void walk_stack(int skip, wchar_t* out_buf)
 	HANDLE hThread = GetCurrentThread();
 
 	CONTEXT context;
-	memset(&context, 0, sizeof(context));
-	context.ContextFlags = CONTEXT_FULL;
-	GetThreadContext(hThread, &context);
+	if(override_context)
+	{
+		memcpy(&context, override_context, sizeof(CONTEXT));
+	}
+	else
+	{
+		memset(&context, 0, sizeof(context));
+		context.ContextFlags = CONTEXT_FULL;
+		GetThreadContext(hThread, &context);
+	}
 
 	STACKFRAME64 frame;
 	memset(&frame, 0, sizeof(frame));
@@ -413,7 +424,7 @@ static void walk_stack(int skip, wchar_t* out_buf)
 	IMAGEHLP_LINE64 line = { sizeof(IMAGEHLP_LINE64) };
 	IMAGEHLP_STACK_FRAME imghlp_frame;
 
-    for(;;)
+	for(;;)
     {
         if(!_StackWalk64(machine, hProcess, hThread, &frame, &context, 0, _SymFunctionTableAccess64, _SymGetModuleBase64, 0))
             break;
@@ -452,7 +463,6 @@ static void walk_stack(int skip, wchar_t* out_buf)
 
 		out(L"\r\n");
     }
-	
 }
 
 
@@ -544,7 +554,6 @@ static int dialog(DLG_TYPE type)
 
 static PTOP_LEVEL_EXCEPTION_FILTER prev_except_filter;
 
-
 static long CALLBACK except_filter(EXCEPTION_POINTERS* except)
 {
 	PEXCEPTION_RECORD except_record = except->ExceptionRecord;
@@ -611,6 +620,104 @@ static void set_exception_handler()
 }
 
 
+// PT: Alternate version of the exception handler, which makes
+// the crash log more useful, and takes the responsibility of
+// suiciding away from main.cpp.
+
+int debug_main_exception_filter(unsigned int code, struct _EXCEPTION_POINTERS *ep)
+{
+	const wchar_t* error = NULL;
+
+	// C++ exceptions put a pointer to the exception object
+	// into ExceptionInformation[1] -- so see if it looks like
+	// a PSERROR*, and use the relevant message if it is.
+	try
+	{
+		if (ep->ExceptionRecord->NumberParameters == 3)
+		{
+			PSERROR* err = (PSERROR*) ep->ExceptionRecord->ExceptionInformation[1];
+			if (err->magic == 0x50534552)
+			{
+				int code = err->code;
+				error = GetErrorString(code);
+			}
+		}
+	}
+	catch (...) {
+		// Presumably it wasn't a PSERROR and resulted in
+		// accessing some invalid pointers.
+	}
+
+	// Try getting nice names for other types of error:
+	if (! error)
+	{
+		switch (ep->ExceptionRecord->ExceptionCode)
+		{
+		case EXCEPTION_ACCESS_VIOLATION:		error = L"Access Violation"; break;
+		case EXCEPTION_DATATYPE_MISALIGNMENT:	error = L"Datatype Misalignment"; break;
+		case EXCEPTION_BREAKPOINT:				error = L"Breakpoint"; break;
+		case EXCEPTION_SINGLE_STEP:				error = L"Single Step"; break;
+		case EXCEPTION_ARRAY_BOUNDS_EXCEEDED:	error = L"Array Bounds Exceeded"; break;
+		case EXCEPTION_FLT_DENORMAL_OPERAND:	error = L"Float Denormal Operand"; break;
+		case EXCEPTION_FLT_DIVIDE_BY_ZERO:		error = L"Float Divide By Zero"; break;
+		case EXCEPTION_FLT_INEXACT_RESULT:		error = L"Float Inexact Result"; break;
+		case EXCEPTION_FLT_INVALID_OPERATION:	error = L"Float Invalid Operation"; break;
+		case EXCEPTION_FLT_OVERFLOW:			error = L"Float Overflow"; break;
+		case EXCEPTION_FLT_STACK_CHECK:			error = L"Float Stack Check"; break;
+		case EXCEPTION_FLT_UNDERFLOW:			error = L"Float Underflow"; break;
+		case EXCEPTION_INT_DIVIDE_BY_ZERO:		error = L"Integer Divide By Zero"; break;
+		case EXCEPTION_INT_OVERFLOW:			error = L"Integer Overflow"; break;
+		case EXCEPTION_PRIV_INSTRUCTION:		error = L"Private Instruction"; break;
+		case EXCEPTION_IN_PAGE_ERROR:			error = L"In Page Error"; break;
+		case EXCEPTION_ILLEGAL_INSTRUCTION:		error = L"Illegal Instruction"; break;
+		case EXCEPTION_NONCONTINUABLE_EXCEPTION:error = L"Noncontinuable Exception"; break;
+		case EXCEPTION_STACK_OVERFLOW:			error = L"Stack Overflow"; break;
+		case EXCEPTION_INVALID_DISPOSITION:		error = L"Invalid Disposition"; break;
+		case EXCEPTION_GUARD_PAGE:				error = L"Guard Page"; break;
+		case EXCEPTION_INVALID_HANDLE:			error = L"Invalid Handle"; break;
+		default: error = L"[unknown exception]";
+		}
+	}
+
+	wchar_t* errortext = (wchar_t*) error;
+
+	// Handle access violations specially, because we can see
+	// whether and where they were reading/writing.
+	if (ep->ExceptionRecord->ExceptionCode == EXCEPTION_ACCESS_VIOLATION)
+	{
+		errortext = new wchar_t[256];
+		if (ep->ExceptionRecord->ExceptionInformation[0])
+			swprintf(errortext, 256, L"Access violation writing 0x%08X", ep->ExceptionRecord->ExceptionInformation[1]);
+		else
+			swprintf(errortext, 256, L"Access violation reading 0x%08X", ep->ExceptionRecord->ExceptionInformation[1]);
+	}
+
+	wchar_t message[1024];
+	swprintf(message, 1024, L"A fatal error has occurred: %ls.\nPlease report this to http://bugs.wildfiregames.com/ and attach the crashlog.txt and crashlog.dmp files from your 'data' folder.", errortext);
+	message[1023] = 0;
+
+	wdisplay_msg(L"0 A.D. failure", message);
+
+	debug_write_crashlog("crashlog.txt", errortext, ep->ContextRecord);
+
+
+	HANDLE hFile = CreateFile("crashlog.dmp", GENERIC_WRITE, FILE_SHARE_WRITE, 0, CREATE_ALWAYS, 0, 0);
+	DumpMiniDump(hFile, ep);
+	CloseHandle(hFile);
+
+	// Disable memory-leak reporting, because it's going to
+	// leak like an upside-down bucket when it crashes.
+#ifdef HAVE_DEBUGALLOC
+	_CrtSetDbgFlag( _CrtSetDbgFlag(_CRTDBG_REPORT_FLAG) & ~_CRTDBG_LEAK_CHECK_DF );
+#endif
+
+	exit(EXIT_FAILURE);
+	return EXCEPTION_EXECUTE_HANDLER;
+}
+
+
+
+
 static void init()
 {
 	ONCE(dbg_init());
@@ -677,24 +784,36 @@ static void DumpMiniDump(HANDLE hFile, PEXCEPTION_POINTERS excpInfo)
 //	}
 }
 
-int debug_write_crashlog(const char* file)
+const int MICROLOG_SIZE = 16384;
+int MicroBuffer_size = MICROLOG_SIZE;
+wchar_t MicroBuffer[MICROLOG_SIZE];
+int MicroBuffer_off = 0;
+
+int debug_write_crashlog(const char* file, wchar_t* header, void* context)
 {
 	init();
 
 	int len = swprintf(buf, 1000, L"Undefined state reached.\r\n");
-	walk_stack(2, buf+len);
+
+	if (context)
+		walk_stack(0, buf+len, (CONTEXT*)context);
+	else
+		walk_stack(2, buf+len);
 
 	FILE* f = fopen(file, "wb");
 	int BOM = 0xFEFF;
 	fwrite(&BOM, 2, 1, f);
+	if (header)
+	{
+		fwrite(header, wcslen(header), sizeof(wchar_t), f);
+		fwrite(L"\r\n\r\n", 4, sizeof(wchar_t), f);
+	}
 	fwrite(buf, pos-buf, 2, f);
+	
+	const wchar_t* footer = L"\r\n\r\nLast known activity:\r\n\r\n";
+	fwrite(footer, wcslen(footer), sizeof(wchar_t), f);
+	fwrite(MicroBuffer, MicroBuffer_off, sizeof(wchar_t), f);
 	fclose(f);
 
-	char dmp_file[MAX_PATH];
-	strcpy(dmp_file, file);
-	strcat(dmp_file, ".mdmp");
-	HANDLE hFile = CreateFile(dmp_file, GENERIC_WRITE, FILE_SHARE_WRITE, 0, CREATE_ALWAYS, 0, 0);
-	DumpMiniDump(hFile, 0);
-
 	return 0;
 }

source/lib/sysdep/win/wdbg.h

@@ -3,6 +3,8 @@
 
 #include "win.h"
 
+int debug_main_exception_filter(unsigned int code, struct _EXCEPTION_POINTERS *ep);
+
 #ifdef __cplusplus
 extern "C" {
 #endif

source/main.cpp

@@ -155,7 +155,6 @@ static int write_sys_info();
 // TODO: load from language file
 // these will need to be variables; better to make an index into string table
 // (as with errors)? if it's a string, what happens if lang file load failed?
-#define STR_UNHANDLED_EXCEPTION L"unhandled exception. crash log has been written; please report at bugs.wildfiregames.com"
 #define STR_SDL_INIT_FAILED     L"SDL library initialization failed: %hs\n"
 #define STR_SET_VMODE_FAILED    L"could not set %dx%d graphics mode: %hs\n"
 #define STR_OGL_EXT_MISSING     L"required ARB_multitexture or ARB_texture_env_combine extension not available"
@@ -179,19 +178,14 @@ void Die(int err, const wchar_t* fmt, ...)
 	wdisplay_msg(L"0ad", buf);
 
 	write_sys_info();
-	debug_write_crashlog("crashlog.txt");
+
+	debug_write_crashlog("crashlog.txt", NULL, NULL);
 
 	exit(EXIT_FAILURE);
 }
 
 
 
-
-
-
-
-
-
 void Testing (void)
 {
 	g_Console->InsertMessage(L"Testing Function Registration");
@@ -455,14 +449,19 @@ void RenderNoCull()
 
 static void Render()
 {
+	MICROLOG(L"begin frame");
+
 	// start new frame
 	g_Renderer.BeginFrame();
 	g_Renderer.SetCamera(g_Camera);
 
 	// switch on wireframe for terrain if we want it
 	//g_Renderer.SetTerrainRenderMode( SOLID ); // (PT: If this is done here, the W key doesn't work)
+	MICROLOG(L"render terrain");
 	RenderTerrain();
+	MICROLOG(L"render models");
 	RenderModels();
+	MICROLOG(L"flush frame");
 	g_Renderer.FlushFrame();
 
 	if( g_EntGraph )
@@ -473,11 +472,13 @@ static void Render()
 		glDisable( GL_DEPTH_TEST );
 		glColor3f( 1.0f, 0.0f, 1.0f );
 
+		MICROLOG(L"render entities");
 		g_EntityManager.renderAll(); // <-- collision outlines, pathing routes
 
 		glPopAttrib();
 	}
 
+	MICROLOG(L"render fonts");
 	// overlay mode
 	glPushAttrib(GL_ENABLE_BIT);
 	glEnable(GL_TEXTURE_2D);
@@ -514,11 +515,13 @@ static void Render()
 	glwprintf( L"%hs", g_GUI.TEMPmessage.c_str() );
 
 	glLoadIdentity();
+	MICROLOG(L"render GUI");
 	g_GUI.Draw();
 #endif
 
 	unifont_bind(g_Font_Console);
 	glLoadIdentity();
+	MICROLOG(L"render console");
 	g_Console->Render();
 
 	// restore
@@ -528,6 +531,7 @@ static void Render()
 	glPopMatrix();
 	glPopAttrib();
 
+	MICROLOG(L"end frame");
 	g_Renderer.EndFrame();
 }
 
@@ -753,6 +757,8 @@ static void Init(int argc, char* argv[])
 sle(1134);
 #endif
 
+	MICROLOG(L"In init");
+
 	// If you ever want to catch a particular allocation:
 	//_CrtSetBreakAlloc(4128);
 
@@ -766,6 +772,7 @@ PREVTSC=TSC;
 #endif
 
 
+	MICROLOG(L"init lib");
 	lib_init();
 
 	// set 24 bit (float) FPU precision for faster divides / sqrts
@@ -778,10 +785,13 @@ PREVTSC=TSC;
 	// and fonts are set later in psInit())
 	g_Console = new CConsole();
 
+	MICROLOG(L"detect");
 	detect();
 
+	MICROLOG(L"init vfs");
 	InitVfs(argv[0]);
 
+	MICROLOG(L"init sdl");
 	// init SDL
 	if(SDL_Init(SDL_INIT_VIDEO|SDL_INIT_TIMER|SDL_INIT_NOPARACHUTE) < 0)
 		Die(0, STR_SDL_INIT_FAILED, SDL_GetError());
@@ -792,9 +802,10 @@ PREVTSC=TSC;
 	// (command line params may override these)
 	get_cur_vmode(&g_xres, &g_yres, &g_bpp, &g_freq);
 
-
+	MICROLOG(L"init scripting");
 	InitScripting();	// before GUI
 	
+	MICROLOG(L"init config");
 	new CConfigDB;
 	g_ConfigDB.SetConfigFile(CFG_SYSTEM, false, "config/system.cfg");
 	g_ConfigDB.Reload(CFG_SYSTEM);
@@ -827,6 +838,8 @@ PREVTSC=TSC;
 sle(11340106);
 #endif
 
+	MICROLOG(L"set vmode");
+
 	if(set_vmode(g_xres, g_yres, 32, !windowed) < 0)
 		Die(0, STR_SET_VMODE_FAILED, g_xres, g_yres, SDL_GetError());
 
@@ -850,7 +863,7 @@ debug_out(
 PREVTSC=CURTSC;
 #endif
 
-
+	MICROLOG(L"init ps");
 	psInit();
 
 	// create renderer
@@ -869,6 +882,7 @@ PREVTSC=CURTSC;
 	new CObjectManager;
 	new CUnitManager;
 
+	MICROLOG(L"init renderer");
 	g_Renderer.Open(g_xres,g_yres,g_bpp);
 
 	// terr_init loads a bunch of resources as well as setting up the terrain
@@ -888,6 +902,7 @@ PREVTSC=CURTSC;
 if(!g_MapFile)
 	g_MapFile = "test01.pmp";
 
+	MICROLOG(L"init map");
 
 	// load a map if we were given one
 	if (g_MapFile) {
@@ -914,6 +929,7 @@ if(!g_MapFile)
 
 	in_add_handler(conInputHandler);
 
+	MICROLOG(L"render blank");
 	// render everything to a blank frame to force renderer to load everything
 	RenderNoCull();
 
@@ -955,6 +971,8 @@ PREVTSC=CURTSC;
 
 static void Frame()
 {
+	MICROLOG(L"In frame");
+
 	static double last_time;
 	const double time = get_time();
 	const float TimeSinceLastFrame = (float)(time-last_time);
@@ -963,6 +981,8 @@ static void Frame()
 		// first call: set last_time and return
 	assert(TimeSinceLastFrame >= 0.0f);
 
+	MICROLOG(L"reload files");
+
 	res_reload_changed_files();
 
 // TODO: limiter in case simulation can't keep up?
@@ -979,6 +999,8 @@ static void Frame()
 	}
 #endif
 
+	MICROLOG(L"input");
+
 	// ugly, but necessary. these are one-shot events, have to be reset.
 	mouseButtons[SDL_BUTTON_WHEELUP] = false;
 	mouseButtons[SDL_BUTTON_WHEELDOWN] = false;
@@ -986,6 +1008,8 @@ static void Frame()
 
 	if(TimeSinceLastFrame > 0.0f)
 	{
+		MICROLOG(L"update world");
+
 		UpdateWorld(TimeSinceLastFrame);
 		if (!g_FixedFrameTiming)
 			terr_update(float(TimeSinceLastFrame));
@@ -994,8 +1018,11 @@ static void Frame()
 
 	if(g_active)
 	{
+		MICROLOG(L"render");
 		Render();
+		MICROLOG(L"swap buffers");
 		SDL_GL_SwapBuffers();
+		MICROLOG(L"finished render");
 	}
 	// inactive; relinquish CPU for a little while
 	// don't use SDL_WaitEvent: don't want the main loop to freeze until app focus is restored
@@ -1007,25 +1034,41 @@ static void Frame()
 	if (g_FixedFrameTiming && frameCount==100) quit=true;
 }
 
+
+#ifdef _WIN32
+// Define/undefine this as desired:
+#  define CUSTOM_EXCEPTION_HANDLER
+#endif
+
+#ifdef CUSTOM_EXCEPTION_HANDLER
+#include <excpt.h>
+#endif
+
 int main(int argc, char* argv[])
 {
-	try
+	MICROLOG(L"In main");
+
+#ifdef CUSTOM_EXCEPTION_HANDLER
+	__try
 	{
+#endif
+		MICROLOG(L"Init");
 		Init(argc, argv);
 
 		while(!quit)
+		{
+			MICROLOG(L"Frame");
 			Frame();
+		}
 
+		MICROLOG(L"Shutdown");
 		Shutdown();
+#ifdef CUSTOM_EXCEPTION_HANDLER
 	}
-	catch(...)
+	__except(debug_main_exception_filter(GetExceptionCode(), GetExceptionInformation()))
 	{
-// debug build: let debugger display it (more convenient)
-#ifndef NDEBUG
-		throw;
-#endif
-		Die(0, STR_UNHANDLED_EXCEPTION);
 	}
+#endif
 
 	exit(0);
 	return 0;