Added Singe program tracing for tech support.

.gitignore

@@ -3,3 +3,4 @@
 **/.git-hidden/
 **/.github/
 cmake-build-debug/
+*.log

CMakeLists.txt

@@ -273,7 +273,31 @@ target_link_directories(${CMAKE_PROJECT_NAME} PUBLIC
 )
 
 
-if(WIN32)
+if(${KANGAROO_OS} STREQUAL "linux")
+	set(LIB_LIST
+		-lX11
+		-lvdpau
+	)
+endif()
+if(${KANGAROO_OS} STREQUAL "macos")
+	set(LIB_LIST
+		-Wl,-framework,CoreVideo
+		-Wl,-framework,Cocoa
+		-Wl,-framework,IOKit
+		-Wl,-framework,ForceFeedback
+		-Wl,-framework,Carbon
+		-Wl,-framework,CoreAudio
+		-Wl,-framework,AudioToolbox
+		-Wl,-framework,AVFoundation
+		-Wl,-framework,Foundation
+		-Wl,-weak_framework,GameController
+		-Wl,-weak_framework,Metal
+		-Wl,-weak_framework,QuartzCore
+		-Wl,-weak_framework,CoreHaptics
+		-liconv
+	)
+endif()
+if(${KANGAROO_OS} STREQUAL "windows")
 	set(LIB_LIST
 		-mwindows
 		-static
@@ -296,14 +320,8 @@ if(WIN32)
 		-lbcrypt
 		-lssp
 	)
-else()
-	set(LIB_LIST
-		-lX11
-		-lvdpau
-	)
 endif()
-target_link_libraries(${CMAKE_PROJECT_NAME}
+set(LIB_LIST
-	-Wl,--start-group
 	${LIB_LIST}
 	${BUILD_DIR}/lib/libavcodec.a
 	${BUILD_DIR}/lib/libavdevice.a
@@ -317,7 +335,7 @@ target_link_libraries(${CMAKE_PROJECT_NAME}
 #	${BUILD_DIR}/lib/libdav1d.a
 	${BUILD_DIR}/lib/libffms2.a
 	${BUILD_DIR}/lib/libfreetype.a
-	${BUILD_DIR}/lib/libharfbuzz.a
+#	${BUILD_DIR}/lib/libharfbuzz.a
 #	${BUILD_DIR}/lib/libhwy.a
 #	${BUILD_DIR}/lib/libjxl_dec.a
 	${BUILD_DIR}/lib/liblzma.a
@@ -339,6 +357,10 @@ target_link_libraries(${CMAKE_PROJECT_NAME}
 	${BUILD_DIR}/lib/libwebpdemux.a
 	${BUILD_DIR}/lib/libxmp.a
 	${BUILD_DIR}/lib/libz.a
+)
+target_link_libraries(${CMAKE_PROJECT_NAME}
+	-Wl,--start-group
+	${LIB_LIST}
 	-Wl,--end-group
 	-pthread
 	-lm

build-all.sh

@@ -29,81 +29,24 @@ G_GENERATED=
 function buildAll() {
 	local OS=$1
 	local ARCH=$2
-	local TRIPLE=
-	local SUFFIX=
-	local TOOLCHAIN=
 	local COMMON=
-	local CROSS_OS=
-	local OSXCROSS_LOCATION=
 
-
+	source <(../toolchains/toolchains.sh use ${ARCH} ${OS})
-	case "${OS}" in
-
-		linux)
-			case "${ARCH}" in
-				x86)
-					TRIPLE="i686-linux-gnu"
-					;;
-				x86_64)
-					TRIPLE="x86_64-linux-gnu"
-					;;
-			esac
-			CROSS_OS="linux"
-			;;
-
-		macos)
-			case "${ARCH}" in
-				aarch64)
-					TRIPLE="aarch64-apple-darwin22.4"
-					OSXCROSS_LOCATION=${G_BUILDROOT}/../toolchains/x-tools/aarch64-macos-apple
-					;;
-				x86)
-					TRIPLE="i386-apple-darwin17"
-					OSXCROSS_LOCATION=${G_BUILDROOT}/../toolchains/x-tools/x86_64-macos-apple
-					;;
-				x86_64)
-					TRIPLE="x86_64-apple-darwin17"
-					OSXCROSS_LOCATION=${G_BUILDROOT}/../toolchains/x-tools/x86_64-macos-apple
-					;;
-			esac
-			CROSS_OS="darwin"
-			source <("${OSXCROSS_LOCATION}/bin/osxcross-conf" 2>/dev/null)
-			export OSXCROSS_LOCATION
-			;;
-
-
-		windows)
-			case "${ARCH}" in
-				x86)
-					TRIPLE="i686-w64-mingw32"
-					;;
-				x86_64)
-					TRIPLE="x86_64-w64-mingw32"
-					;;
-			esac
-			export CC="${TRIPLE}-gcc-posix"
-			export CXX="${TRIPLE}-g++-posix"
-			SUFFIX=".exe"
-			CROSS_OS="mingw32"
-			;;
-
-	esac
 
 	G_TARGET=${G_BUILDROOT}/${G_BUILDDIR}/${OS}/${ARCH}
 	G_GENERATED=${G_TARGET}/generated
-	TOOLCHAIN=${G_BUILDROOT}/../toolchains/cmake/${TRIPLE}.cmake
+	COMMON="-DCMAKE_INSTALL_PREFIX=${G_TARGET} -DCMAKE_TOOLCHAIN_FILE=${TOOLCHAIN_FILE}"
-	COMMON="-DCMAKE_INSTALL_PREFIX=${G_TARGET} -DCMAKE_TOOLCHAIN_FILE=${TOOLCHAIN}"
 	# Add CMAKE_BUILD_TYPE to COMMON
 
+	export LDFLAGS="-L${G_TARGET}/lib ${LDFLAGS}"
+	export CFLAGS="-I${G_TARGET}/include ${CFLAGS}"
+	export CXXFLAGS="-I${G_TARGET}/include ${CXXFLAGS}"
+	export LD_LIBRARY_PATH="${G_TARGET}/lib"
+	export PKG_CONFIG_LIBDIR="${G_TARGET}/lib/pkgconfig"
+
 	mkdir -p ${G_GENERATED}
 
-	#export LD_FLAGS="-L ${G_TARGET}/lib"
+if [[ 0 == 1 ]]; then
-	#export C_FLAGS="-I ${G_TARGET}/include"
-	#export CXX_FLAGS=${C_FLAGS}
-	export LD_LIBRARY_PATH=${G_TARGET}
-	export PKG_CONFIG_LIBDIR=${G_TARGET}/lib/pkgconfig
-
-#:<<SKIP
 	pushd thirdparty/SDL2
 	clearAndEnterBuild
 	cmake ${COMMON} \
@@ -152,7 +95,7 @@ function buildAll() {
 	cmake ${COMMON} \
 		-DBUILD_SHARED_LIBS=off \
 		-DSDL2TTF_VENDORED=on \
-		-DSDL2TTF_HARFBUZZ=on \
+		-DSDL2TTF_HARFBUZZ=off \
 		-DSDL2TTF_SAMPLES=off \
 		-DSDL2_DIR=${G_TARGET}/lib/cmake/SDL2 \
 		..
@@ -180,7 +123,9 @@ function buildAll() {
 
 	pushd thirdparty/zlib
 	clearAndEnterBuild
-	cmake ${COMMON} ..
+	../configure \
+		--prefix=${G_TARGET} \
+		--static
 	make install
 	popd
 	if [[ "${OS}" == "windows" ]]; then
@@ -204,11 +149,15 @@ function buildAll() {
 		--disable-programs \
 		--enable-gpl \
 		--enable-version3 \
-		--extra-ldflags="-L${G_TARGET}/lib -l:libz.a -l:liblzma.a" \
+		--extra-ldflags="-L${G_TARGET}/lib" \
 		--prefix=${G_TARGET} \
 		--arch=${ARCH} \
 		--target-os=${CROSS_OS} \
-		--cross-prefix=${TRIPLE}-
+		--cross-prefix=${TRIPLE}- \
+		--cc="${CC}" \
+		--cxx="${CXX}" \
+		--ranlib="${RANLIB}"
+ #" -l:libz.a -l:liblzma.a" \
 	make install
 	popd
 
@@ -275,7 +224,7 @@ function buildAll() {
 	ffmpeg -f concat -safe 0 -i <(echo -e "file ${G_TARGET}/temp1.mkv\nfile ${G_TARGET}/temp2.mkv\n") -c copy ${G_TARGET}/menuBackground.mkv
 	createEmbeddedBinary ${G_TARGET}/menuBackground.mkv ${G_GENERATED}/menuBackground_mkv.h MENUBACKGROUND_MKV_H
 	rm ${G_TARGET}/temp1.mkv ${G_TARGET}/temp2.mkv ${G_TARGET}/menuBackground.mkv
-#SKIP
+fi
 
 :<<UNUSED
 	# === Singe Manual ===
@@ -290,8 +239,8 @@ UNUSED
 	clearAndEnterBuild
 	cmake ${COMMON} ${G_BUILDROOT}
 	make
-	upx -9 singe2${SUFFIX}
+	#upx -9 singe2${SUFFIX}
-	mv -f singe2${SUFFIX} ../Singe-v2.10-${OS}-${ARCH}${SUFFIX}
+	mv -f singe2${SUFFIX} ${G_BUILDROOT}/${G_BUILDDIR}/Singe-v2.10-${OS^}-${ARCH}${SUFFIX}
 	popd
 }
 
@@ -420,10 +369,16 @@ function outputLicense() {
 }
 
 
-buildAll linux x86
+#***TODO*** SDL2 needs a few dependencies on Linux to make its dynamic loading
-buildAll linux x86_64
+#           system happy.  No idea the complete list yet.
+#sudo apt-get install -y \
+#	libasound-dev
+
+
+#buildAll linux x86
+buildAll linux x86_64 2>&1 | tee linux-x86_64.log
 #buildAll macos aarch64
 #buildAll macos x86   #***TODO*** Needs older SDL2
 #buildAll macos x86_64   #***TODO*** Needs older SDL2
-buildAll windows x86
+#buildAll windows x86
-buildAll windows x86_64
+#buildAll windows x86_64

src/main.c

@@ -127,7 +127,8 @@ ConfigT *cloneConf(ConfigT *conf) {
 	c->showCalculated          = conf->showCalculated;
 	c->noConsole               = conf->noConsole;
 	c->noLogos                 = conf->noLogos;
-	c->tracing                 = conf->tracing;
+	c->programTracing          = conf->programTracing;
+	c->scriptTracing           = conf->scriptTracing;
 	c->bestRatioIndex          = conf->bestRatioIndex;
 	c->volumeVldp              = conf->volumeVldp;
 	c->volumeNonVldp           = conf->volumeNonVldp;
@@ -163,13 +164,14 @@ ConfigT *createConf(char *exeName, int argc, char *argv[]) {
 		{ 'd', "datadir",           ap_yes },
 		{ 'e', "volume_nonlvdp",    ap_yes },
 		{ 'f', "fullscreen",        ap_no  },
-		{ 'g', "sindengun",         ap_yes },
+//		{ 'g', "sindengun",         ap_yes },
 		{ 'h', "help",              ap_no  },
 		{ 'k', "nologos",           ap_no  },
 		{ 'l', "volume_vldp",       ap_yes },
 		{ 'm', "nomouse",           ap_no  },
 		{ 'n', "nocrosshair",       ap_no  },
-		{ 'o', "scalefactor",       ap_yes },
+//		{ 'o', "scalefactor",       ap_yes },
+		{ 'p', "program",           ap_no  },
 		{ 's', "nosound",           ap_no  },
 		{ 't', "trace",             ap_no  },
 		{ 'u', "stretch",           ap_no  },
@@ -278,14 +280,19 @@ ConfigT *createConf(char *exeName, int argc, char *argv[]) {
 				argCount++;
 				break;
 
+			// Program Tracing
+			case 'p':
+				conf->programTracing = true;
+				break;
+
 			// No Sound
 			case 's':
 				conf->noSound = true;
 				break;
 
-			// Trace
+			// Script Tracing
 			case 't':
-				conf->tracing = true;
+				conf->scriptTracing = true;
 				break;
 
 			// Ugly Stretched Video
@@ -510,12 +517,22 @@ void launcher(char *exeName, ConfigT *conf) {
 	SDL_Surface                *icon           =  NULL;
 	SDL_DisplayMode             mode;
 
+	// Do they want tracing of any kind?
+	if (conf->scriptTracing || conf->programTracing) {
+		temp = utilCreateString("%strace.txt", conf->dataDir);
+		utilTraceStart(temp);
+		free(temp);
+		temp = NULL;
+	}
+
 	// Init SDL
+	utilTrace("Starting SDL");
 	if (SDL_Init(SDL_INIT_EVERYTHING) != 0) utilDie("%s", SDL_GetError());
 	if (SDL_GetCurrentDisplayMode(0, &mode) < 0) utilDie("%s", SDL_GetError());
 
 	// Determine resolution if not specified
 	if ((conf->xResolution <= 0) || (conf->yResolution <= 0)) {
+		utilTrace("Determining resolution settings");
 		if (conf->bestRatioIndex < 0) {
 			// Find our current aspect ratio
 			x = 0;
@@ -529,6 +546,7 @@ void launcher(char *exeName, ConfigT *conf) {
 			}
 		}
 		if (conf->bestRatioIndex < 0) showUsage(exeName, "Unknown aspect ratio.");
+		utilTrace("Aspect ratio is %d:%d", _modes[conf->bestRatioIndex].ratio.aspectNum, _modes[conf->bestRatioIndex].ratio.aspectDom);
 		x = 0;
 		// Were both resolutions not specified?
 		if ((conf->xResolution <= 0) && (conf->yResolution <= 0)) {
@@ -576,37 +594,35 @@ void launcher(char *exeName, ConfigT *conf) {
 			}
 		}
 	}
+	utilTrace("Resolution is %dx%d", conf->xResolution, conf->yResolution);
 	// Did we end up with a valid resolution?
 	if (conf->xResolution <= 0) showUsage(exeName, "Unable to determine X resolution.  (Is the Y value sane?)");
 	if (conf->yResolution <= 0) showUsage(exeName, "Unable to determine Y resolution.  (Is the X value sane?)");
 	if ((conf->xResolution > mode.w) || (conf->yResolution > mode.h)) showUsage(exeName, "Specified resolution is larger than the display.");
 
-	// Do they want tracing?
-	if (conf->tracing) {
-		temp = utilCreateString("%strace.txt", conf->dataDir);
-		utilTraceStart(temp);
-		free(temp);
-		temp = NULL;
-	}
-
 	// Init SDL_mixer
+	utilTrace("Starting mixer");
 	flags = MIX_INIT_FLAC | MIX_INIT_MID | MIX_INIT_MOD | MIX_INIT_MP3 | MIX_INIT_OGG | MIX_INIT_OPUS | MIX_INIT_WAVPACK;
 	err = Mix_Init(flags);
 	if (err != flags) utilDie("%s", Mix_GetError());
 
 	// Init SDL_image
-	flags = IMG_INIT_AVIF | IMG_INIT_JPG | IMG_INIT_JXL | IMG_INIT_PNG | IMG_INIT_TIF | IMG_INIT_WEBP;
+	utilTrace("Starting image loader");
+	flags = /* IMG_INIT_AVIF | */ IMG_INIT_JPG | /* IMG_INIT_JXL | */ IMG_INIT_PNG | /* IMG_INIT_TIF | */ IMG_INIT_WEBP;
 	err = IMG_Init(flags);
 	if (err != flags) utilDie("%s", IMG_GetError());
 
 	// Init SDL_ttf
+	utilTrace("Starting fonts");
 	if (TTF_Init() < 0) utilDie("%s", TTF_GetError());
 
 	// Create Window
+	utilTrace("Creating window");
 	window = SDL_CreateWindow("SINGE", SDL_WINDOWPOS_UNDEFINED, SDL_WINDOWPOS_UNDEFINED, conf->xResolution, conf->yResolution, 0 /* SDL_WINDOW_RESIZABLE */);
 	if (window == NULL) utilDie("%s", SDL_GetError());
 
 	// Window Icon
+	utilTrace("Setting icon");
 	icon = IMG_LoadPNG_RW(SDL_RWFromMem(icon_png, icon_png_len));
 	if (icon == NULL) utilDie("%s", SDL_GetError());
 	SDL_SetWindowIcon(window, icon);
@@ -615,11 +631,13 @@ void launcher(char *exeName, ConfigT *conf) {
 
 	// Do we want full screen of some kind?
 	if (conf->fullScreen || conf->fullScreenWindow) {
+		utilTrace("Going fullscreen");
 		flags = conf->fullScreen ? SDL_WINDOW_FULLSCREEN : SDL_WINDOW_FULLSCREEN_DESKTOP;
 		SDL_SetWindowFullscreen(window, (Uint32)flags);
 	}
 
 	// Create an accelerated renderer.
+	utilTrace("Creating renderer");
 	renderer = SDL_CreateRenderer(window, -1, SDL_RENDERER_ACCELERATED);
 	if (renderer == NULL) utilDie("%s", SDL_GetError());
 
@@ -628,31 +646,47 @@ void launcher(char *exeName, ConfigT *conf) {
 	SDL_RenderClear(renderer);
 
 	// Create audio mixer device
+	utilTrace("Configuring mixer");
 	err = Mix_OpenAudio(44100, MIX_DEFAULT_FORMAT, 2, 44100 /* freq */ * 16  /* bits */ * 2 /* channels */ * 2 /* seconds */);
 	if (err != 0) utilDie("%s", Mix_GetError());
 	Mix_AllocateChannels(16);
 
 	// Start our video playback system
+	utilTrace("Initializing laserdisc framefile handler");
 	if (frameFileInit()) utilDie("Unable to initialize framefile handler.");
+	utilTrace("Initializing laserdisc video");
 	if (videoInit()) utilDie("Unable to initialize video player.");
 
 	// Finish our setup
+	utilTrace("Disabling screen saver");
 	SDL_DisableScreenSaver();
 
 	// Run Singe!
+	utilTrace("Starting Singe");
 	singe(window, renderer, conf);
 
 	// Shutdown
+	utilTrace("Shutting down laserdisc video");
 	videoQuit();
+	utilTrace("Shutting down laserdisc framefile handler");
 	frameFileQuit();
+	utilTrace("Stopping mixer");
 	Mix_CloseAudio();
+	utilTrace("Destroying renderer");
 	SDL_DestroyRenderer(renderer);
+	utilTrace("Destroying window");
 	SDL_DestroyWindow(window);
+	utilTrace("Re-enabling screen saver");
 	SDL_EnableScreenSaver();
+	utilTrace("Shutting down fonts");
 	TTF_Quit();
+	utilTrace("Shutting down image loader");
 	IMG_Quit();
+	utilTrace("Shutting down mixer");
 	Mix_Quit();
+	utilTrace("Shutting down SDL");
 	SDL_Quit();
+	utilTrace("Shutting down tracing");
 	utilTraceEnd();
 }
 

src/singe.c

@@ -351,6 +351,7 @@ int32_t  luaError(lua_State *L);
 void     luaPreload(lua_State *L, const char *name, lua_CFunction func);
 void     luaTrace(lua_State *L, char *method, char *fmt, ...);
 void     processKey(bool down, int keysym, int32_t scancode);
+void     progTrace(char *fmt, ...);
 void     putPixel(int32_t x, int32_t y, SDL_Color *c);
 void     startControllers(void);
 void     startLuaContext(lua_State *L);
@@ -952,7 +953,7 @@ int32_t apiFontSelect(lua_State *L) {
 			d = lua_tonumber(L, 1);
 			id = (int32_t)d;
 			HASH_FIND_INT(_global.fontList, &id, font);
-			if (!font) luaDie(L, "fontSelect", "No font at index %d in apiSpriteGetWidth.", id);
+			if (!font) luaDie(L, "fontSelect", "No font at index %d in apiFontSelect.", id);
 			_global.fontCurrent = font;
 			result = true;
 		}
@@ -1795,7 +1796,7 @@ int32_t apiSpriteDraw(lua_State *L) {
 						d = lua_tonumber(L, 3);  id     = (int32_t)d;
 					}
 					HASH_FIND_INT(_global.spriteList, &id, sprite);
-					if (!sprite) luaDie(L, "spriteDraw", "No sprite at index %d in apiSpriteGetWidth.", id);
+					if (!sprite) luaDie(L, "spriteDraw", "No sprite at index %d in apiSpriteDraw.", id);
 					if (n == 5) {
 						// Target is scaled
 						SDL_BlitScaled(sprite->surface, NULL, _global.overlay, &dest);
@@ -1832,7 +1833,7 @@ int32_t apiSpriteGetHeight(lua_State *L) {
 			d = lua_tonumber(L, 1);  id = (int32_t)d;
 			// Get our sprite structure
 			HASH_FIND_INT(_global.spriteList, &id, sprite);
-			if (!sprite) luaDie(L, "spriteGetHeight", "No sprite at index %d in apiSpriteGetWidth.", id);
+			if (!sprite) luaDie(L, "spriteGetHeight", "No sprite at index %d in apiSpriteGetHeight.", id);
 			result = sprite->surface->h;
 		}
 	}
@@ -2951,7 +2952,7 @@ void callLua(const char *func, const char *sig, ...) {
 		return;
 	}
 
-	utilTrace("%s", func);
+	if (_global.conf->scriptTracing) utilTrace("%s", func);
 
 	// Push Arguments
 	narg = 0;
@@ -3288,7 +3289,7 @@ void luaDie(lua_State *L, char *method, char *fmt, ...) {
 	string2 = utilCreateStringVArgs(fmt, args);
 	if (!string2) utilDie("Unable to allocate second trace string.");
 	va_end(args);
-	utilTrace("%s%s", string1, string2);
+	if (_global.conf->scriptTracing) utilTrace("%s%s", string1, string2);
 	utilDie("%s%s", string1, string2);
 	// Can't free strings - we never get here.
 }
@@ -3362,7 +3363,7 @@ void luaTrace(lua_State *L, char *method, char *fmt, ...) {
 	char      *string1 = NULL;
 	char      *string2 = NULL;
 
-	if (utilTraceGetFile()) {
+	if (_global.conf->scriptTracing) {
 		lua_getstack(L, 1, &ar);
 		lua_getinfo(L, "nSl", &ar);
 		string1 = utilCreateString("%d:%s:  ", ar.currentline, method);
@@ -3371,7 +3372,6 @@ void luaTrace(lua_State *L, char *method, char *fmt, ...) {
 		string2 = utilCreateStringVArgs(fmt, args);
 		if (!string2) utilDie("Unable to allocate second trace string.");
 		va_end(args);
-		utilSay("%s%s", string1, string2);
 		utilTrace("%s%s", string1, string2);
 		free(string2);
 		free(string1);
@@ -3431,6 +3431,16 @@ void processKey(bool down, int32_t keysym, int32_t scancode) {
 }
 
 
+void progTrace(char *fmt, ...) {
+	va_list args;
+	if (_global.conf->programTracing) {
+		va_start(args, fmt);
+		utilTraceVArgs(fmt, args);
+		va_end(args);
+	}
+}
+
+
 void putPixel(int32_t x, int32_t y, SDL_Color *c) {
 
 	SDL_Surface *surface = _global.overlay;
@@ -3560,33 +3570,49 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 	_global.renderer = renderer;
 
 	// Load controller mappings
+	progTrace("Creating Lua context for Singe setup");
 	_global.luaContext = luaL_newstate();
 	startLuaContext(_global.luaContext);
 	// Load framework
+	progTrace("Loading Singe framework");
 	if (luaL_loadbuffer(_global.luaContext, (char *)Framework_singe, Framework_singe_len, "Input Mappings") || lua_pcall(_global.luaContext, 0, 0, 0)) utilDie("%s", lua_tostring(_global.luaContext, -1));
 	// Load default mappings
+	progTrace("Loading default control mappings");
 	if (luaL_loadbuffer(_global.luaContext, (char *)controls_cfg, controls_cfg_len, "Input Mappings") || lua_pcall(_global.luaContext, 0, 0, 0)) utilDie("%s", lua_tostring(_global.luaContext, -1));
-	if (utilFileExists("controls.cfg") && luaL_dofile(_global.luaContext, "controls.cfg")) utilDie("%s", lua_tostring(_global.luaContext, -1));
+	if (utilFileExists("controls.cfg")) {
+		progTrace("Loading controls.cfg");
+		if (luaL_dofile(_global.luaContext, "controls.cfg")) utilDie("%s", lua_tostring(_global.luaContext, -1));
+	}
 	// Load mappings in main data dir
 	temp = utilCreateString("%s..%ccontrols.cfg", _global.conf->dataDir, utilGetPathSeparator());
-	if (utilFileExists(temp) && luaL_dofile(_global.luaContext, temp)) utilDie("%s", lua_tostring(_global.luaContext, -1));
+	if (utilFileExists(temp)) {
+		progTrace("Loading %s", temp);
+		if (luaL_dofile(_global.luaContext, temp)) utilDie("%s", lua_tostring(_global.luaContext, -1));
+	}
 	free(temp);
 	// Load mappings in game data dir
 	temp = utilCreateString("%scontrols.cfg", _global.conf->dataDir);
-	if (utilFileExists(temp) && luaL_dofile(_global.luaContext, temp)) utilDie("%s", lua_tostring(_global.luaContext, -1));
+	if (utilFileExists(temp)) {
+		progTrace("Loading %s", temp);
+		if (luaL_dofile(_global.luaContext, temp)) utilDie("%s", lua_tostring(_global.luaContext, -1));
+	}
 	free(temp);
 	// Load mappings in game script dir
 	temp = strdup(_global.conf->scriptFile);
 	temp2 = utilStrndup(temp, strlen(temp) - strlen(utilGetLastPathComponent(temp)));
 	free(temp);
 	temp = utilCreateString("%scontrols.cfg", temp2);
-	if (utilFileExists(temp) && luaL_dofile(_global.luaContext, temp)) utilDie("%s", lua_tostring(_global.luaContext, -1));
+	if (utilFileExists(temp)) {
+		progTrace("Loading %s", temp);
+		if (luaL_dofile(_global.luaContext, temp)) utilDie("%s", lua_tostring(_global.luaContext, -1));
+	}
 	free(temp);
 	free(temp2);
 	// Parse results
 	lua_getglobal(_global.luaContext, "DEAD_ZONE");
 	if (lua_isnumber(_global.luaContext, -1)) {
 		_global.controllerDeadZone = (int32_t)lua_tonumber(_global.luaContext, -1);
+		progTrace("Controller dead zone is %d", _global.controllerDeadZone);
 	}
 	lua_pop(_global.luaContext, 1);
 	for (x=0; x<INPUT_COUNT; x++) {
@@ -3635,10 +3661,12 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 
 	// Show splash screens
 	if (!_global.conf->noLogos) {
+		progTrace("Showing splash screens");
 		doLogos();
 	}
 
 	// Start Lua for game
+	progTrace("Creating Lua context for script");
 	_global.luaContext = luaL_newstate();
 	startLuaContext(_global.luaContext);
 
@@ -3752,6 +3780,7 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 	lua_register(_global.luaContext, "vldpSetVerbose",        apiVldpVerbose);
 
 	// Open main video file
+	progTrace("Opening main video file");
 	doIndexDisplay(-1);
 	videoSetIndexCallback(doIndexDisplay);
 	if (_global.conf->isFrameFile) {
@@ -3779,9 +3808,12 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 			changed = true;
 		}
 		if (changed) {
+			progTrace("Resizing window to %dx%d based on main video file", conf->xResolution, conf->yResolution);
 			SDL_SetWindowSize(_global.window, conf->xResolution, conf->yResolution);
+			progTrace("Destroying old renderer");
 			SDL_DestroyRenderer(_global.renderer);
 			// Recreate an accelerated renderer.
+			progTrace("Creating new renderer");
 			_global.renderer = SDL_CreateRenderer(_global.window, -1, SDL_RENDERER_ACCELERATED);
 			if (_global.renderer == NULL) utilDie("%s", SDL_GetError());
 			// Clear screen with black
@@ -3878,15 +3910,17 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 	_global.overlayScaleY = 0.5;
 	x = (int32_t)(videoGetWidth(_global.videoHandle) * _global.overlayScaleX);
 	y = (int32_t)(videoGetHeight(_global.videoHandle) * _global.overlayScaleY);
+	progTrace("Creating overlay of %dx%d", x, y);
 	_global.overlay = SDL_CreateRGBSurfaceWithFormat(0, x, y, 32, SDL_PIXELFORMAT_BGRA32);
 	if (_global.overlay == NULL) utilDie("%s", SDL_GetError());
 	SDL_SetSurfaceBlendMode(_global.overlay, SDL_BLENDMODE_BLEND);
 
 	// Mouse setup
 	_global.mouseEnabled = (bool)!_global.conf->noMouse;
+	progTrace("Initializing ManyMouse");
 	_global.mouseCount = ManyMouse_Init();
-	//utilSay("***DEBUG*** Mouse Driver:  %s", ManyMouse_DriverName());
+	progTrace("Mouse Driver:  %s", ManyMouse_DriverName());
-	//utilSay("***DEBUG*** Mice Found:  %d", _global.mouseCount);
+	progTrace("Mice Found:  %d", _global.mouseCount);
 	if ((_global.mouseCount < 1) && _global.mouseEnabled) utilDie("No mice detected.");
 	if (_global.mouseCount > MAX_MICE) {
 		_global.mouseCount = MAX_MICE;
@@ -3897,12 +3931,14 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 		_global.mice[x].name[sizeof(_global.mice[x].name) - 1] = 0;
 		_global.mice[x].x = (int32_t)(videoGetWidth(_global.videoHandle) * _global.overlayScaleX);
 		_global.mice[x].y = (int32_t)(videoGetHeight(_global.videoHandle) * _global.overlayScaleY);
-		//utilSay("***DEBUG*** Mouse %d:  %s", x, _global.mice[x].name);
+		progTrace("Mouse %d:  %s", x, _global.mice[x].name);
 	}
 
 	// Grab mouse
+	progTrace("Grabbing mouse");
 	_global.mouseGrabbed = true;
 	SDL_SetWindowGrab(_global.window, SDL_TRUE);
+	progTrace("Disabling mouse pointer");
 	SDL_ShowCursor(SDL_DISABLE);
 
 	// Clear axis caches
@@ -3915,12 +3951,14 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 
 	// Set volume
 	_global.effectsVolume = (int32_t)((float)AUDIO_MAX_VOLUME * (float)_global.conf->volumeNonVldp * (float)0.01);
+	progTrace("Setting up sound effects mixer");
 	Mix_Volume(-1, _global.effectsVolume * 2);
 
 	// Let us know when sounds end
 	Mix_ChannelFinished(channelFinished);
 
 	// Load overlay font
+	progTrace("Loading console font");
 	_global.consoleFontSurface = IMG_LoadPNG_RW(SDL_RWFromMem(font_png, font_png_len));
 	if (_global.consoleFontSurface == NULL) utilDie("%s", SDL_GetError());
 	_global.consoleFontWidth  = _global.consoleFontSurface->w / 256;
@@ -3928,13 +3966,16 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 	SDL_SetColorKey(_global.consoleFontSurface, true, _global.consoleFontSurface->format->Rmask | _global.consoleFontSurface->format->Bmask);
 
 	// Start video
+	progTrace("Starting laserdisc video in stopped state");
 	videoPlay(_global.videoHandle);
 	_global.discStopped = false;
 
 	// Start script
+	progTrace("Compiling %s", _global.conf->scriptFile);
 	if (luaL_dofile(_global.luaContext, _global.conf->scriptFile) != 0) utilDie("Error compiling script:  %s", lua_tostring(_global.luaContext, -1));
 
 	// Game Loop
+	progTrace("Script is running");
 	while (_global.running) {
 
 		// SDL Event Loop
@@ -3982,6 +4023,7 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 
 				case SDL_CONTROLLERDEVICEADDED:
 				case SDL_CONTROLLERDEVICEREMOVED:
+					progTrace("Updating connected controllers list");
 					stopControllers();
 					startControllers();
 					break;
@@ -4043,6 +4085,7 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 					break;
 
 				case SDL_QUIT:
+					progTrace("Quit requested");
 					_global.running = 0;
 					break;
 			}
@@ -4226,6 +4269,7 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 			// Save it?
 			if (_global.requestScreenShot) {
 				_global.requestScreenShot = false;
+				progTrace("Taking screenshot");
 				takeScreenshot();
 			}
 		}
@@ -4234,17 +4278,22 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 	}
 
 	// End game
+	progTrace("Script is shutting down");
 	callLua("onShutdown", "");
 
 	// Stop all sounds
+	progTrace("Stopping all audio");
 	Mix_HaltChannel(-1);
 	Mix_ChannelFinished(NULL);
 
 	// Stop Lua
+	progTrace("Stopping Lua");
 	lua_close(_global.luaContext);
 
 	// Free overlay & overlay font
+	progTrace("Destroying overlay");
 	SDL_FreeSurface(_global.overlay);
+	progTrace("Destroying console font");
 	SDL_FreeSurface(_global.consoleFontSurface);
 
 	// Unload fonts
@@ -4253,6 +4302,7 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 #pragma GCC diagnostic ignored "-Wcast-align"
 		HASH_DEL(_global.fontList, font);
 #pragma GCC diagnostic pop
+		progTrace("Unloading font handle %d", font->id);
 		TTF_CloseFont(font->font);
 		free(font);
 	}
@@ -4263,6 +4313,7 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 #pragma GCC diagnostic ignored "-Wcast-align"
 		HASH_DEL(_global.soundList, sound);
 #pragma GCC diagnostic pop
+		progTrace("Unloading sound handle %d", sound->id);
 		Mix_FreeChunk(sound->chunk);
 		free(sound);
 	}
@@ -4273,6 +4324,7 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 #pragma GCC diagnostic ignored "-Wcast-align"
 		HASH_DEL(_global.spriteList, sprite);
 #pragma GCC diagnostic pop
+		progTrace("Unloading sprite handle %d", sprite->id);
 		SDL_FreeSurface(sprite->surface);
 		free(sprite);
 	}
@@ -4280,11 +4332,13 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 	// Unload videos
 	HASH_ITER(hh, _global.videoList, video, videoTemp) {
 		HASH_DEL(_global.videoList, video);
+		progTrace("Unloading video handle %d", video->id);
 		if (video->surface) SDL_FreeSurface(video->surface);
 		free(video);
 	}
 
 	// Unload background video
+	progTrace("Unloading main video file");
 	if (_global.conf->isFrameFile) {
 		frameFileUnload(_global.frameFileHandle);
 	} else {
@@ -4292,10 +4346,13 @@ void singe(SDL_Window *window, SDL_Renderer *renderer, ConfigT *conf) {
 	}
 
 	// Stop controllers
+	progTrace("Stopping controllers");
 	stopControllers();
 
 	// Stop mice
+	progTrace("Re-enabling mouse pointer");
 	SDL_ShowCursor(SDL_ENABLE);
+	progTrace("Stopping ManyMouse");
 	ManyMouse_Quit();
 
 	// Release global conf memory
@@ -4322,15 +4379,13 @@ void startControllers(void) {
 		_global.controllers[x] = NULL;
 		if (SDL_IsGameController(x)) {
 			_global.controllers[x] = SDL_GameControllerOpen(x);
-			/*
+			if (_global.controllers[x]) {
-			if (_controllers[x]) {
+				progTrace("Found %d - %s", x, SDL_GameControllerName(_global.controllers[x]));
-				utilSay("Found #%d - %s\n", x, SDL_GameControllerName(_controllers[x]));
 			} else {
-				utilSay("Controller #%d not opened!\n", x);
+				progTrace("Controller %d not opened", x);
 			}
-			*/
 		} else {
-			//utilSay("Joystick #%d is not a controller!\n", x);
+			progTrace("Device %d is not a controller", x);
 		}
 	}
 

src/singe.h

@@ -61,7 +61,8 @@ typedef struct ConfigS {
 	bool     showCalculated;
 	bool     noConsole;
 	bool     noLogos;
-	bool     tracing;
+	bool     programTracing;
+	bool     scriptTracing;
 	int32_t  bestRatioIndex;
 	int32_t  volumeVldp;
 	int32_t  volumeNonVldp;

src/util.c

@@ -490,7 +490,17 @@ void utilTraceStart(char *filename) {
 
 __attribute__((__format__(__printf__, 1, 0)))
 void utilTraceVArgs(char *fmt, va_list args) {
+#if defined(va_copy)
+	va_list args2;
+#endif
+
 	if (_utilTraceFile) {
+#if defined(va_copy)
+		va_copy(args2, args);
+		vprintf(fmt, args2);
+		printf("\n");
+		va_end(args2);
+#endif
 		vfprintf(_utilTraceFile, fmt, args);
 		fprintf(_utilTraceFile, "\n");
 		fflush(_utilTraceFile);