diff --git a/.gitignore b/.gitignore index 53c59cff8..fb3756c01 100644 --- a/.gitignore +++ b/.gitignore @@ -5,3 +5,4 @@ CMakeUserPresets.json .devcontainer/ compat/config.mk /.vs +*.log diff --git a/CMakeLists.txt b/CMakeLists.txt index 924d470fa..48746cc78 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -95,6 +95,7 @@ if(PLATFORM STREQUAL "web-meta") set(SOURCES src/data_win.c src/binary_reader.c + src/log.c ) else() file(GLOB SOURCES src/*.c) diff --git a/README.md b/README.md index ef4d7e23c..987b51e79 100644 --- a/README.md +++ b/README.md @@ -10,7 +10,7 @@

-> [!IMPORTANT] +> [!IMPORTANT] > Butterscotch is still VERY early in development and it is NOT that good yet. When you create a game in GameMaker: Studio and export it, GameMaker: Studio exports the game code as bytecode instead of native compiled code, and that bytecode is compatible with any other GameMaker: Studio runner (also known as YoYo runner), as long as they have matching GameMaker: Studio versions. This is similar to how Java applications work. @@ -52,7 +52,7 @@ However, that doesn't mean that a game that uses a compatible version WILL run! Of course, there are exceptions that break game compatibility altogether: -* Games compiled with YYC, because they use native code instead of bytecode. +* Games compiled with YYC, because they use native code instead of bytecode. * Games compiled with the new [GMRT](https://github.com/YoYoGames/GMRT-Beta/tree/main), because they use native code instead of bytecode. ## Supported Platforms @@ -152,7 +152,10 @@ The desktop target has a lot of nifty CLI parameters that you can use to trace a --profile-opcodes - Rank which GML opcodes were executed the most --lazy-textures - Load textures into VRAM on first use, improving startup times --load-type - Specify how data.win is loaded, per-chunk or all at once -``` +--disable-file-log - Disable logging to a file +--log-file - File to log to +--disable-log-colours - Disable colours for warning, error, and debug logs +--disable-log-colors - Same as --disable-log-colours, but different spelling ## Debug Features @@ -172,7 +175,7 @@ Performance is pretty good on any modern computer, but when running on low end t ## Then why not have a transpiler? -The issue with a transpiler is that, if you try transpiling the game in the "naive" way, that is, emitting VM calls like it was the original bytecode, you won't get any +The issue with a transpiler is that, if you try transpiling the game in the "naive" way, that is, emitting VM calls like it was the original bytecode, you won't get any *improvement* from it, you would need to create a *good* transpiler that actually transpiles it into *good* code, and that's way harder. Having a transpiler also have other disadvantages: diff --git a/src/android/main.c b/src/android/main.c index 741eb4df9..0bca9a4ad 100644 --- a/src/android/main.c +++ b/src/android/main.c @@ -16,6 +16,8 @@ #include "gl/gl_renderer.h" #include "stb_ds.h" +#include "log.h" + #define LOG_TAG "Butterscotch" #define LOGI(...) __android_log_print(ANDROID_LOG_INFO, LOG_TAG, __VA_ARGS__) #define LOGW(...) __android_log_print(ANDROID_LOG_WARN, LOG_TAG, __VA_ARGS__) @@ -40,6 +42,31 @@ static float gNormalizedCursorY = 0.0f; // We don't need to worry about game changes because the profiler will be automatically disabled then static int32_t gProfilerStartedAtFrame = 0; +void platformLog(const logType type, const char *format, va_list va) { + const char* prefix = ""; + switch (type) { + case LOG_TYPE_NORMAL: + break; + case LOG_TYPE_WARNING: + prefix = "Warning: "; + break; + case LOG_TYPE_ERROR: + prefix = "Error: "; + break; + case LOG_TYPE_DEBUG: + prefix = "Debug: "; + break; + } + + const int newFormatSize = strlen(format) + strlen(prefix) + 1; + const char* newFormat = (char*)safeMalloc(newFormatSize); + snprintf(newFormat, newFormatSize, "%s%s", prefix, format); + + __android_log_vprint(type == LOG_TYPE_NORMAL ? ANDROID_LOG_INFO : (type == LOG_TYPE_WARNING ? ANDROID_LOG_WARN : ANDROID_LOG_ERROR), LOG_TAG, newFormat, va); + + free(newFormat); +} + // Android has no platformGetWindowSize like the desktop, so we cache the EGL surface size the host // passes into stepAndDraw and expose it through the getWindowSize hook below. static int32_t gWindowW = 0; @@ -633,7 +660,7 @@ static bool performGameChange(const char* workingDirectory, char* launchParamete } if (dataWinFilename == nullptr) { - fprintf(stderr, "Runner: Launch parameters '%s' did not contain a '-game ' entry! Shutting down...\n", launchParameters); + logError("Runner: Launch parameters '%s' did not contain a '-game ' entry! Shutting down...\n", launchParameters); repeat(arrlen(newArguments), i) { free(newArguments[i]); } diff --git a/src/audio/miniaudio/ma_audio_system.c b/src/audio/miniaudio/ma_audio_system.c index 3ec79ec7c..c44f613b8 100644 --- a/src/audio/miniaudio/ma_audio_system.c +++ b/src/audio/miniaudio/ma_audio_system.c @@ -109,14 +109,14 @@ static void maInit(AudioSystem* audio, DataWin* dataWin, FileSystem* fileSystem) deviceConfig.pUserData = &ma->engine; ma_result deviceResult = ma_device_init(NULL, &deviceConfig, &ma->device); if (deviceResult != MA_SUCCESS) { - fprintf(stderr, "Audio: Failed to initialize playback device (error %d)\n", deviceResult); + logError("Audio: Failed to initialize playback device (error %d)\n", deviceResult); return; } ma_engine_config config = ma_engine_config_init(); config.pDevice = &ma->device; ma_result result = ma_engine_init(&config, &ma->engine); if (result != MA_SUCCESS) { - fprintf(stderr, "Audio: Failed to initialize miniaudio engine (error %d)\n", result); + logError("Audio: Failed to initialize miniaudio engine (error %d)\n", result); ma_device_uninit(&ma->device); return; } @@ -130,7 +130,7 @@ static void maInit(AudioSystem* audio, DataWin* dataWin, FileSystem* fileSystem) ma->listenerGains[i] = 1.0f; } - fprintf(stderr, "Audio: miniaudio engine initialized\n"); + logInfo("Audio: miniaudio engine initialized\n"); } static void maDestroy(AudioSystem* audio) { @@ -215,7 +215,7 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior if (isStream) { int32_t streamSlot = soundIndex - AUDIO_STREAM_INDEX_BASE; if (0 > streamSlot || streamSlot >= MAX_AUDIO_STREAMS || !ma->streams[streamSlot].active) { - fprintf(stderr, "Audio: Invalid stream index %d\n", soundIndex); + logWarn("Audio: Invalid stream index %d\n", soundIndex); return -1; } AudioStreamEntry* stream = &ma->streams[streamSlot]; @@ -225,7 +225,7 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior } else { DataWin* dw = ma->base.audioGroups[0]; // Audio Group 0 should always be data.win if (0 > soundIndex || (uint32_t) soundIndex >= dw->sond.count) { - fprintf(stderr, "Audio: Invalid sound index %d\n", soundIndex); + logWarn("Audio: Invalid sound index %d\n", soundIndex); return -1; } sound = &dw->sond.sounds[soundIndex]; @@ -233,7 +233,7 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior SoundInstance* slot = findFreeSlot(ma); if (slot == nullptr) { - fprintf(stderr, "Audio: No free sound slots for sound %d\n", soundIndex); + logWarn("Audio: No free sound slots for sound %d\n", soundIndex); return -1; } @@ -244,7 +244,7 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior // Stream audio: load from file path stored in stream entry result = ma_sound_init_from_file(&ma->engine, streamPath, MA_SOUND_FLAG_ASYNC, &ma->listenerGroups[0], nullptr, &slot->maSound); if (result != MA_SUCCESS) { - fprintf(stderr, "Audio: Failed to load stream file '%s' (error %d)\n", streamPath, result); + logWarn("Audio: Failed to load stream file '%s' (error %d)\n", streamPath, result); return -1; } slot->ownsDecoder = false; @@ -257,7 +257,7 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior if (inAudo) { // Embedded audio: decode from AUDO chunk memory if (0 > sound->audioFile || (uint32_t) sound->audioFile >= ma->base.audioGroups[sound->audioGroup]->audo.count) { - fprintf(stderr, "Audio: Invalid audio file index %d for sound '%s'\n", sound->audioFile, sound->name); + logWarn("Audio: Invalid audio file index %d for sound '%s'\n", sound->audioFile, sound->name); return -1; } @@ -266,14 +266,14 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior ma_decoder_config decoderConfig = ma_decoder_config_init_default(); result = ma_decoder_init_memory(entry->data, entry->dataSize, &decoderConfig, &slot->decoder); if (result != MA_SUCCESS) { - fprintf(stderr, "Audio: Failed to init decoder for '%s' (error %d)\n", sound->name, result); + logWarn("Audio: Failed to init decoder for '%s' (error %d)\n", sound->name, result); return -1; } slot->ownsDecoder = true; result = ma_sound_init_from_data_source(&ma->engine, &slot->decoder, 0, &ma->listenerGroups[0], &slot->maSound); if (result != MA_SUCCESS) { - fprintf(stderr, "Audio: Failed to init sound from decoder for '%s' (error %d)\n", sound->name, result); + logWarn("Audio: Failed to init sound from decoder for '%s' (error %d)\n", sound->name, result); ma_decoder_uninit(&slot->decoder); return -1; } @@ -281,13 +281,13 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior // External audio: load from file char* path = resolveExternalPath(ma, sound); if (path == nullptr) { - fprintf(stderr, "Audio: Could not resolve path for sound '%s'\n", sound->name); + logWarn("Audio: Could not resolve path for sound '%s'\n", sound->name); return -1; } result = ma_sound_init_from_file(&ma->engine, path, MA_SOUND_FLAG_ASYNC, &ma->listenerGroups[0], nullptr, &slot->maSound); if (result != MA_SUCCESS) { - fprintf(stderr, "Audio: Failed to load file for '%s' at '%s' (error %d)\n", sound->name, path, result); + logWarn("Audio: Failed to load file for '%s' at '%s' (error %d)\n", sound->name, path, result); free(path); return -1; } @@ -741,7 +741,7 @@ static void maGroupLoad(AudioSystem* audio, int32_t groupIndex) { // The original runner does not care if the file doesn't exist (this may happen if someone uses "audio_group_load" on a non-existent group) FileSystem* fileSystem = ((MaAudioSystem*)audio)->fileSystem; if (!fileSystem->vtable->fileExists(fileSystem, buf)) { - fprintf(stderr, "Audio: Wanted to load Audio Group %d, but Audio Group %d does not exist in the file system!\n", groupIndex, groupIndex); + logWarn("Audio: Wanted to load Audio Group %d, but Audio Group %d does not exist in the file system!\n", groupIndex, groupIndex); free(buf); DataWin* dw = (DataWin *)safeCalloc(1, sizeof(DataWin)); arrput(audio->audioGroups, dw); @@ -754,7 +754,7 @@ static void maGroupLoad(AudioSystem* audio, int32_t groupIndex) { arrput(audio->audioGroups, audioGroup); free(buf); } else { - fprintf(stderr, "Audio: Wanted to load Audio Group %d, but Audio Group %d does not exist in the AGPR!\n", groupIndex, groupIndex); + logWarn("Audio: Wanted to load Audio Group %d, but Audio Group %d does not exist in the AGPR!\n", groupIndex, groupIndex); } } @@ -777,13 +777,13 @@ static int32_t maCreateStream(AudioSystem* audio, const char* filename) { } if (0 > freeSlot) { - fprintf(stderr, "Audio: No free stream slots for '%s'\n", filename); + logWarn("Audio: No free stream slots for '%s'\n", filename); return -1; } char* resolved = ma->fileSystem->vtable->resolvePath(ma->fileSystem, filename); if (resolved == nullptr) { - fprintf(stderr, "Audio: Could not resolve path for stream '%s'\n", filename); + logWarn("Audio: Could not resolve path for stream '%s'\n", filename); return -1; } @@ -793,7 +793,7 @@ static int32_t maCreateStream(AudioSystem* audio, const char* filename) { ma->streams[freeSlot].initialPitch = 1.0f; int32_t streamIndex = AUDIO_STREAM_INDEX_BASE + freeSlot; - fprintf(stderr, "Audio: Created stream %d for '%s' -> '%s'\n", streamIndex, filename, resolved); + logInfo("Audio: Created stream %d for '%s' -> '%s'\n", streamIndex, filename, resolved); return streamIndex; } @@ -802,7 +802,7 @@ static bool maDestroyStream(AudioSystem* audio, int32_t streamIndex) { int32_t slotIndex = streamIndex - AUDIO_STREAM_INDEX_BASE; if (0 > slotIndex || slotIndex >= MAX_AUDIO_STREAMS) { - fprintf(stderr, "Audio: Invalid stream index %d for destroy\n", streamIndex); + logWarn("Audio: Invalid stream index %d for destroy\n", streamIndex); return false; } @@ -825,7 +825,7 @@ static bool maDestroyStream(AudioSystem* audio, int32_t streamIndex) { free(entry->filePath); entry->filePath = nullptr; entry->active = false; - fprintf(stderr, "Audio: Destroyed stream %d\n", streamIndex); + logInfo("Audio: Destroyed stream %d\n", streamIndex); return true; } diff --git a/src/audio/openal/al_audio_system.c b/src/audio/openal/al_audio_system.c index a2223b03f..2bc43f805 100644 --- a/src/audio/openal/al_audio_system.c +++ b/src/audio/openal/al_audio_system.c @@ -170,14 +170,14 @@ static void maInit(AudioSystem* audio, DataWin* dataWin, FileSystem* fileSystem) ma->alContext = alcCreateContext(ma->alDevice, nullptr); alcMakeContextCurrent(ma->alContext); if (ma->alDevice == nullptr || ma->alContext == nullptr) { - fprintf(stderr, "Audio: Failed to initialize OpenAL engine (error %d)\n", alGetError()); + logError("Audio: Failed to initialize OpenAL engine (error %d)\n", alGetError()); return; } memset(ma->instances, 0, sizeof(ma->instances)); ma->nextInstanceCounter = 0; - fprintf(stderr, "Audio: OpenAL engine initialized\n"); + logInfo("Audio: OpenAL engine initialized\n"); } static void maDestroy(AudioSystem* audio) { @@ -289,14 +289,14 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior if (isStream) { int32_t streamSlot = soundIndex - AUDIO_STREAM_INDEX_BASE; if (0 > streamSlot || streamSlot >= MAX_AUDIO_STREAMS || !ma->streams[streamSlot].active) { - fprintf(stderr, "Audio: Invalid stream index %d\n", soundIndex); + logWarn("Audio: Invalid stream index %d\n", soundIndex); return -1; } streamPath = ma->streams[streamSlot].filePath; } else { DataWin* dw = ma->base.audioGroups[0]; // Audio Group 0 should always be data.win if (0 > soundIndex || (uint32_t) soundIndex >= dw->sond.count) { - fprintf(stderr, "Audio: Invalid sound index %d\n", soundIndex); + logWarn("Audio: Invalid sound index %d\n", soundIndex); return -1; } sound = &dw->sond.sounds[soundIndex]; @@ -304,7 +304,7 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior SoundInstance* slot = findFreeSlot(ma); if (slot == nullptr) { - fprintf(stderr, "Audio: No free sound slots for sound %d\n", soundIndex); + logWarn("Audio: No free sound slots for sound %d\n", soundIndex); return -1; } @@ -322,7 +322,7 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior int err = 0; stb_vorbis* v = stb_vorbis_open_filename(streamPath, &err, nullptr); if (v == nullptr) { - fprintf(stderr, "Audio: Failed to open stream '%s' (stb_vorbis err %d)\n", streamPath, err); + logWarn("Audio: Failed to open stream '%s' (stb_vorbis err %d)\n", streamPath, err); return -1; } stb_vorbis_info info = stb_vorbis_get_info(v); @@ -368,7 +368,7 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior if (inAudo) { // Embedded audio: decode from AUDO chunk memory if (0 > sound->audioFile || (uint32_t) sound->audioFile >= ma->base.audioGroups[sound->audioGroup]->audo.count) { - fprintf(stderr, "Audio: Invalid audio file index %d for sound '%s'\n", sound->audioFile, sound->name); + logWarn("Audio: Invalid audio file index %d for sound '%s'\n", sound->audioFile, sound->name); return -1; } @@ -380,7 +380,7 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior { if (wav.header.bits_per_sample == 8) format = AL_FORMAT_MONO8; - else + else format = AL_FORMAT_MONO16; } else { @@ -390,10 +390,10 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior format = AL_FORMAT_STEREO16; } alBufferData( - slot->alBuffer, - format, - wav.data, - wav.data_length, + slot->alBuffer, + format, + wav.data, + wav.data_length, wav.header.sample_rate ); alSourcei(slot->alSource, AL_BUFFER, slot->alBuffer); @@ -402,7 +402,7 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior // External audio: load from file char* path = resolveExternalPath(ma, sound); if (path == nullptr) { - fprintf(stderr, "Audio: Could not resolve path for sound '%s'\n", sound->name); + logWarn("Audio: Could not resolve path for sound '%s'\n", sound->name); return -1; } @@ -411,10 +411,10 @@ static int32_t maPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prior short* data = NULL; int len = stb_vorbis_decode_filename(path, &channels, &sample_rate, &data); alBufferData( - slot->alBuffer, - (channels == 2) ? AL_FORMAT_STEREO16 : AL_FORMAT_MONO16, - (void*)data, - len*channels*sizeof(uint16_t), + slot->alBuffer, + (channels == 2) ? AL_FORMAT_STEREO16 : AL_FORMAT_MONO16, + (void*)data, + len*channels*sizeof(uint16_t), sample_rate ); alSourcei(slot->alSource, AL_BUFFER, slot->alBuffer); @@ -684,7 +684,7 @@ static float maGetSoundPitch(AudioSystem* audio, int32_t soundOrInstance) { static float streamCursorSeconds(SoundInstance* inst) { if (0 >= inst->streamSampleRate) return 0.0f; - + ALint sampleOffset = 0; alGetSourcei(inst->alSource, AL_SAMPLE_OFFSET, &sampleOffset); uint64_t total = inst->playedSamples + (uint64_t) sampleOffset; @@ -817,7 +817,7 @@ static void maGroupLoad(AudioSystem* audio, int32_t groupIndex) { FileSystem* fileSystem = ((AlAudioSystem*)audio)->fileSystem; char* resolvedPath = (((AlAudioSystem*)audio)->fileSystem->vtable->resolvePath(((AlAudioSystem*)audio)->fileSystem, buf)); if (!fileSystem->vtable->fileExists(fileSystem, resolvedPath)) { - fprintf(stderr, "Audio: Wanted to load Audio Group %d, but Audio Group %d does not exist!\n", groupIndex, groupIndex); + logWarn("Audio: Wanted to load Audio Group %d, but Audio Group %d does not exist!\n", groupIndex, groupIndex); free(buf); return; } @@ -849,13 +849,13 @@ static int32_t maCreateStream(AudioSystem* audio, const char* filename) { } if (0 > freeSlot) { - fprintf(stderr, "Audio: No free stream slots for '%s'\n", filename); + logWarn("Audio: No free stream slots for '%s'\n", filename); return -1; } char* resolved = ma->fileSystem->vtable->resolvePath(ma->fileSystem, filename); if (resolved == nullptr) { - fprintf(stderr, "Audio: Could not resolve path for stream '%s'\n", filename); + logWarn("Audio: Could not resolve path for stream '%s'\n", filename); return -1; } @@ -863,7 +863,7 @@ static int32_t maCreateStream(AudioSystem* audio, const char* filename) { ma->streams[freeSlot].filePath = resolved; int32_t streamIndex = AUDIO_STREAM_INDEX_BASE + freeSlot; - fprintf(stderr, "Audio: Created stream %d for '%s' -> '%s'\n", streamIndex, filename, resolved); + logInfo("Audio: Created stream %d for '%s' -> '%s'\n", streamIndex, filename, resolved); return streamIndex; } @@ -872,7 +872,7 @@ static bool maDestroyStream(AudioSystem* audio, int32_t streamIndex) { int32_t slotIndex = streamIndex - AUDIO_STREAM_INDEX_BASE; if (0 > slotIndex || slotIndex >= MAX_AUDIO_STREAMS) { - fprintf(stderr, "Audio: Invalid stream index %d for destroy\n", streamIndex); + logWarn("Audio: Invalid stream index %d for destroy\n", streamIndex); return false; } @@ -890,7 +890,7 @@ static bool maDestroyStream(AudioSystem* audio, int32_t streamIndex) { free(entry->filePath); entry->filePath = nullptr; entry->active = false; - fprintf(stderr, "Audio: Destroyed stream %d\n", streamIndex); + logInfo("Audio: Destroyed stream %d\n", streamIndex); return true; } diff --git a/src/audio/ps2/ps2_audio_system.c b/src/audio/ps2/ps2_audio_system.c index 29bf9fa7f..0fbd0d712 100644 --- a/src/audio/ps2/ps2_audio_system.c +++ b/src/audio/ps2/ps2_audio_system.c @@ -82,7 +82,7 @@ static void parseSoundBank(Ps2AudioSystem* ps2) { FILE* f = fopen(path, "rb"); free(path); if (f == nullptr) { - fprintf(stderr, "PS2AudioSystem: Could not open SOUNDBNK.BIN\n"); + logWarn("PS2AudioSystem: Could not open SOUNDBNK.BIN\n"); return; } @@ -93,7 +93,7 @@ static void parseSoundBank(Ps2AudioSystem* ps2) { fread(&ps2->audoEntryCount, 2, 1, f); fread(&ps2->musEntryCount, 2, 1, f); - fprintf(stderr, "PS2AudioSystem: SOUNDBNK v%d, %d SOND entries, %d AUDO entries, %d MUS entries\n", version, ps2->sondEntryCount, ps2->audoEntryCount, ps2->musEntryCount); + logInfo("PS2AudioSystem: SOUNDBNK v%d, %d SOND entries, %d AUDO entries, %d MUS entries\n", version, ps2->sondEntryCount, ps2->audoEntryCount, ps2->musEntryCount); // Parse SOND entries (12 bytes each) ps2->sondEntries = safeMalloc(ps2->sondEntryCount * sizeof(Ps2SondEntry)); @@ -148,7 +148,7 @@ static void parseSoundBank(Ps2AudioSystem* ps2) { } if (ps2->musEntryCount > 0) { - fprintf(stderr, "PS2AudioSystem: Loaded %d MUS entries\n", ps2->musEntryCount); + logInfo("PS2AudioSystem: Loaded %d MUS entries\n", ps2->musEntryCount); } fclose(f); @@ -163,12 +163,12 @@ static void openSoundsBin(Ps2AudioSystem* ps2) { ps2->soundsFile = fopen(path, "rb"); if (ps2->soundsFile == nullptr) { - fprintf(stderr, "PS2AudioSystem: Could not open SOUNDS.BIN at %s\n", path); + logWarn("PS2AudioSystem: Could not open SOUNDS.BIN at %s\n", path); free(path); return; } - fprintf(stderr, "PS2AudioSystem: Opened SOUNDS.BIN for streaming (%s)\n", path); + logInfo("PS2AudioSystem: Opened SOUNDS.BIN for streaming (%s)\n", path); free(path); } @@ -221,7 +221,7 @@ static DecodedPcmEntry* cacheInsert(Ps2AudioSystem* ps2, int32_t audoIndex) { } if (slot == nullptr) { - // fprintf(stderr, "PS2AudioSystem: Cache full, all entries in use! Cannot decode audoIndex %" PRId32 "\n", audoIndex); + // logWarn("PS2AudioSystem: Cache full, all entries in use! Cannot decode audoIndex %" PRId32 "\n", audoIndex); return nullptr; } @@ -533,14 +533,14 @@ static void ps2Init(AudioSystem* audio, MAYBE_UNUSED DataWin* dataWin, MAYBE_UNU // Parse sound bank index parseSoundBank(ps2); if (ps2->sondEntries == nullptr || ps2->audoEntries == nullptr) { - fprintf(stderr, "PS2AudioSystem: Failed to parse SOUNDBNK.BIN, audio disabled\n"); + logWarn("PS2AudioSystem: Failed to parse SOUNDBNK.BIN, audio disabled\n"); return; } // Open SOUNDS.BIN for streaming (kept open for on-demand reads) openSoundsBin(ps2); if (ps2->soundsFile == nullptr) { - fprintf(stderr, "PS2AudioSystem: Failed to open SOUNDS.BIN, audio disabled\n"); + logWarn("PS2AudioSystem: Failed to open SOUNDS.BIN, audio disabled\n"); return; } @@ -559,7 +559,7 @@ static void ps2Init(AudioSystem* audio, MAYBE_UNUSED DataWin* dataWin, MAYBE_UNU // Initialize audsrv int ret = audsrv_init(); if (ret != 0) { - fprintf(stderr, "PS2AudioSystem: audsrv_init failed (%d)\n", ret); + logWarn("PS2AudioSystem: audsrv_init failed (%d)\n", ret); return; } @@ -570,7 +570,7 @@ static void ps2Init(AudioSystem* audio, MAYBE_UNUSED DataWin* dataWin, MAYBE_UNU ret = audsrv_set_format(&format); if (ret != 0) { - fprintf(stderr, "PS2AudioSystem: audsrv_set_format failed (%d)\n", ret); + logWarn("PS2AudioSystem: audsrv_set_format failed (%d)\n", ret); audsrv_quit(); return; } @@ -578,7 +578,7 @@ static void ps2Init(AudioSystem* audio, MAYBE_UNUSED DataWin* dataWin, MAYBE_UNU audsrv_set_volume(MAX_VOLUME); ps2->initialized = true; - fprintf(stderr, "PS2AudioSystem: Initialized (output: %d Hz, 16-bit, stereo)\n", AUDSRV_OUTPUT_FREQ); + logInfo("PS2AudioSystem: Initialized (output: %d Hz, 16-bit, stereo)\n", AUDSRV_OUTPUT_FREQ); } static void ps2Destroy(AudioSystem* audio) { @@ -657,7 +657,7 @@ static void ps2Update(AudioSystem* audio, float deltaTime) { repeat(MAX_MUSIC_STREAMS, i) { Ps2MusicStream* stream = &ps2->musicStreams[i]; if (!stream->active || !stream->needsRefill) continue; - // fprintf(stderr, "PS2AudioSystem: Filling music stream %d back buffers...\n", stream->soundIndex); + // logInfo("PS2AudioSystem: Filling music stream %d back buffers...\n", stream->soundIndex); int backBuffer = stream->activeBuffer ^ 1; streamFillBuffer(ps2, stream, backBuffer); @@ -667,16 +667,16 @@ static void ps2Update(AudioSystem* audio, float deltaTime) { // Fill audsrv ring buffer int32_t chunkBytes = MIX_BUFFER_SAMPLES * 2 * (int32_t) sizeof(int16_t); while (audsrv_available() >= chunkBytes) { - // fprintf(stderr, "PS2AudioSystem: Filling audsrv ring buffer... audsrv_available: %d, chunkBytes: %d\n", audsrv_available(), chunkBytes); + // logInfo("PS2AudioSystem: Filling audsrv ring buffer... audsrv_available: %d, chunkBytes: %d\n", audsrv_available(), chunkBytes); mixAudio(ps2, ps2->mixBuffer, MIX_BUFFER_SAMPLES); audsrv_play_audio((char*) ps2->mixBuffer, chunkBytes); } - // fprintf(stderr, "PS2AudioSystem: Finished ticking the audio system\n"); + // logInfo("PS2AudioSystem: Finished ticking the audio system\n"); } static int32_t ps2PlaySound(AudioSystem* audio, int32_t soundIndex, int32_t priority, bool loop) { - // fprintf(stderr, "PS2AudioSystem: Attempting to play sound index %d with priority %d, should loop? %d\n", soundIndex, priority, loop); + // logInfo("PS2AudioSystem: Attempting to play sound index %d with priority %d, should loop? %d\n", soundIndex, priority, loop); Ps2AudioSystem* ps2 = (Ps2AudioSystem*) audio; if (!ps2->initialized) return -1; @@ -732,13 +732,13 @@ static int32_t ps2PlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prio stream->readPosition = 0; stream->needsRefill = false; - // fprintf(stderr, "PS2AudioSystem: Streaming MUS '%s', size=%" PRIu32 " bytes, instanceId=%" PRId32 "\n", mus->name, mus->dataSize, instanceId); + // logInfo("PS2AudioSystem: Streaming MUS '%s', size=%" PRIu32 " bytes, instanceId=%" PRId32 "\n", mus->name, mus->dataSize, instanceId); return instanceId; } if (0 > soundIndex || (uint16_t) soundIndex >= ps2->sondEntryCount) { - // fprintf(stderr, "PS2AudioSystem: Invalid sound index %" PRId32 "\n", soundIndex); + // logWarn("PS2AudioSystem: Invalid sound index %" PRId32 "\n", soundIndex); return -1; } @@ -750,7 +750,7 @@ static int32_t ps2PlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prio } if (sond->audoIndex >= ps2->audoEntryCount) { - // fprintf(stderr, "PS2AudioSystem: Invalid audo index %d for sound %" PRId32 "\n", sond->audoIndex, soundIndex); + // logWarn("PS2AudioSystem: Invalid audo index %d for sound %" PRId32 "\n", sond->audoIndex, soundIndex); return -1; } @@ -767,7 +767,7 @@ static int32_t ps2PlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prio Ps2AudoEntry* audoForSize = &ps2->audoEntries[sond->audoIndex]; uint32_t decodedPcmBytes = audoForSize->dataSize * 2 * (uint32_t) sizeof(int16_t); if ((isEmbedded || isCompressed) && decodedPcmBytes > PS2_SFX_CACHE_MAX_BYTES) { - fprintf(stderr, "PS2AudioSystem: Sound %" PRId32 " (audo %d) would need %" PRIu32 " bytes of PCM in the cache! isEmbedded? %s; isCompressed? %s; Streaming instead...\n", soundIndex, sond->audoIndex, decodedPcmBytes, isEmbedded ? "true" : "false", isCompressed ? "true" : "false"); + logWarn("PS2AudioSystem: Sound %" PRId32 " (audo %d) would need %" PRIu32 " bytes of PCM in the cache! isEmbedded? %s; isCompressed? %s; Streaming instead...\n", soundIndex, sond->audoIndex, decodedPcmBytes, isEmbedded ? "true" : "false", isCompressed ? "true" : "false"); isEmbedded = false; isCompressed = false; } @@ -786,7 +786,7 @@ static int32_t ps2PlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prio } if (stream == nullptr) { - // fprintf(stderr, "PS2AudioSystem: No free music stream slots for sound %" PRId32 "\n", soundIndex); + // logWarn("PS2AudioSystem: No free music stream slots for sound %" PRId32 "\n", soundIndex); return -1; } @@ -825,7 +825,7 @@ static int32_t ps2PlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prio stream->readPosition = 0; stream->needsRefill = false; - // fprintf(stderr, "PS2AudioSystem: Streaming music soundIndex=%" PRId32 " audoIndex=%d, size=%" PRIu32 " bytes, instanceId=%" PRId32 "\n", soundIndex, sond->audoIndex, audo->dataSize, instanceId); + // logInfo("PS2AudioSystem: Streaming music soundIndex=%" PRId32 " audoIndex=%d, size=%" PRIu32 " bytes, instanceId=%" PRId32 "\n", soundIndex, sond->audoIndex, audo->dataSize, instanceId); return instanceId; } @@ -836,7 +836,7 @@ static int32_t ps2PlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prio if (cached == nullptr) { cached = cacheInsert(ps2, sond->audoIndex); if (cached == nullptr) { - // fprintf(stderr, "PS2AudioSystem: Failed to cache decoded audio for sound %" PRId32 "\n", soundIndex); + // logWarn("PS2AudioSystem: Failed to cache decoded audio for sound %" PRId32 "\n", soundIndex); return -1; } } @@ -844,7 +844,7 @@ static int32_t ps2PlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prio // Find a free SFX instance slot Ps2SoundInstance* slot = findFreeSlot(ps2); if (slot == nullptr) { - // fprintf(stderr, "PS2AudioSystem: No free sound slots for sound %" PRId32 "\n", soundIndex); + // logWarn("PS2AudioSystem: No free sound slots for sound %" PRId32 "\n", soundIndex); return -1; } @@ -978,12 +978,12 @@ static void actionSetPitch(Ps2SoundInstance* sfx, Ps2MusicStream* music, void* u // ===[ Vtable: Stop/Pause/Resume/Gain/Pitch ]=== static void ps2StopSound(AudioSystem* audio, int32_t soundOrInstance) { - // fprintf(stderr, "PS2AudioSystem: Stopping sound %d\n", soundOrInstance); + // logInfo("PS2AudioSystem: Stopping sound %d\n", soundOrInstance); forEachInstance((Ps2AudioSystem*) audio, soundOrInstance, actionStop, nullptr); } static void ps2StopAll(AudioSystem* audio) { - // fprintf(stderr, "PS2AudioSystem: Stopping all audios!\n"); + // logInfo("PS2AudioSystem: Stopping all audios!\n"); Ps2AudioSystem* ps2 = (Ps2AudioSystem*) audio; repeat(MAX_PS2_SOUND_INSTANCES, i) { ps2->instances[i].active = false; @@ -1023,17 +1023,17 @@ static bool ps2IsPlaying(AudioSystem* audio, int32_t soundOrInstance) { } static void ps2PauseSound(AudioSystem* audio, int32_t soundOrInstance) { - // fprintf(stderr, "PS2AudioSystem: Pausing sound %d\n", soundOrInstance); + // logInfo("PS2AudioSystem: Pausing sound %d\n", soundOrInstance); forEachInstance((Ps2AudioSystem*) audio, soundOrInstance, actionPause, nullptr); } static void ps2ResumeSound(AudioSystem* audio, int32_t soundOrInstance) { - // fprintf(stderr, "PS2AudioSystem: Resuming sound %d\n", soundOrInstance); + // logInfo("PS2AudioSystem: Resuming sound %d\n", soundOrInstance); forEachInstance((Ps2AudioSystem*) audio, soundOrInstance, actionResume, nullptr); } static void ps2PauseAll(AudioSystem* audio) { - // fprintf(stderr, "PS2AudioSystem: Pausing all sounds!\n"); + // logInfo("PS2AudioSystem: Pausing all sounds!\n"); Ps2AudioSystem* ps2 = (Ps2AudioSystem*) audio; repeat(MAX_PS2_SOUND_INSTANCES, i) { if (ps2->instances[i].active) ps2->instances[i].paused = true; @@ -1044,7 +1044,7 @@ static void ps2PauseAll(AudioSystem* audio) { } static void ps2ResumeAll(AudioSystem* audio) { - // fprintf(stderr, "PS2AudioSystem: Resuming all sounds!\n"); + // logInfo("PS2AudioSystem: Resuming all sounds!\n"); Ps2AudioSystem* ps2 = (Ps2AudioSystem*) audio; repeat(MAX_PS2_SOUND_INSTANCES, i) { if (ps2->instances[i].active) ps2->instances[i].paused = false; @@ -1082,7 +1082,7 @@ static float ps2GetSoundGain(AudioSystem* audio, int32_t soundOrInstance) { } static void ps2SetSoundPitch(AudioSystem* audio, int32_t soundOrInstance, float pitch) { - // fprintf(stderr, "PS2AudioSystem: Setting pitch of sound %d to %f\n", soundOrInstance, pitch); + // logInfo("PS2AudioSystem: Setting pitch of sound %d to %f\n", soundOrInstance, pitch); forEachInstance((Ps2AudioSystem*) audio, soundOrInstance, actionSetPitch, &pitch); } @@ -1175,7 +1175,7 @@ static void seekMusicStream(Ps2AudioSystem* ps2, Ps2MusicStream* music, float po } static void ps2SetTrackPosition(AudioSystem* audio, int32_t soundOrInstance, float positionSeconds) { - // fprintf(stderr, "PS2AudioSystem: Setting track position of sound %d to %f\n", soundOrInstance, positionSeconds); + // logInfo("PS2AudioSystem: Setting track position of sound %d to %f\n", soundOrInstance, positionSeconds); Ps2AudioSystem* ps2 = (Ps2AudioSystem*) audio; if (soundOrInstance >= PS2_AUDIO_STREAM_INDEX_BASE) { @@ -1264,7 +1264,7 @@ static float ps2GetSoundLength(AudioSystem* audio, int32_t soundOrInstance) { } static void ps2SetMasterGain(AudioSystem* audio, float gain) { - // fprintf(stderr, "PS2AudioSystem: Setting master gain to %f\n", gain); + // logInfo("PS2AudioSystem: Setting master gain to %f\n", gain); Ps2AudioSystem* ps2 = (Ps2AudioSystem*) audio; ps2->masterGain = gain; } @@ -1295,12 +1295,12 @@ static int32_t ps2CreateStream(AudioSystem* audio, const char* filename) { for (int i = 0; ps2->musEntryCount > i; i++) { if (strcmp(ps2->musEntries[i].name, filename) == 0) { int32_t streamIndex = PS2_AUDIO_STREAM_INDEX_BASE + i; - fprintf(stderr, "PS2AudioSystem: Created stream %" PRId32 " for '%s'\n", streamIndex, filename); + logInfo("PS2AudioSystem: Created stream %" PRId32 " for '%s'\n", streamIndex, filename); return streamIndex; } } - fprintf(stderr, "PS2AudioSystem: audio_create_stream: '%s' not found in MUS entries\n", filename); + logWarn("PS2AudioSystem: audio_create_stream: '%s' not found in MUS entries\n", filename); return -1; } diff --git a/src/audio/web/web_audio_system.c b/src/audio/web/web_audio_system.c index 479913222..914b325d1 100644 --- a/src/audio/web/web_audio_system.c +++ b/src/audio/web/web_audio_system.c @@ -79,7 +79,7 @@ static void webInit(AudioSystem* audio, DataWin* dataWin, FileSystem* fileSystem ma_result result = ma_engine_init(&config, &ma->engine); if (result != MA_SUCCESS) { - fprintf(stderr, "Audio: Failed to initialize miniaudio engine in noDevice mode (error %d)\n", result); + logError("Audio: Failed to initialize miniaudio engine in noDevice mode (error %d)\n", result); ma->engineReady = false; return; } @@ -88,7 +88,7 @@ static void webInit(AudioSystem* audio, DataWin* dataWin, FileSystem* fileSystem memset(ma->instances, 0, sizeof(ma->instances)); ma->nextInstanceCounter = 0; - fprintf(stderr, "Audio: web miniaudio engine initialized (noDevice, %d Hz, 2 ch)\n", ma->sampleRate); + logInfo("Audio: web miniaudio engine initialized (noDevice, %d Hz, 2 ch)\n", ma->sampleRate); } static void webDestroy(AudioSystem* audio) { @@ -166,14 +166,14 @@ static int32_t webPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prio if (isStream) { int32_t streamSlot = soundIndex - WEB_AUDIO_STREAM_INDEX_BASE; if (0 > streamSlot || streamSlot >= WEB_MAX_AUDIO_STREAMS || !ma->streams[streamSlot].active) { - fprintf(stderr, "Audio: Invalid stream index %d\n", soundIndex); + logWarn("Audio: Invalid stream index %d\n", soundIndex); return -1; } streamPath = ma->streams[streamSlot].filePath; } else { DataWin* dw = ma->base.audioGroups[0]; if (0 > soundIndex || (uint32_t) soundIndex >= dw->sond.count) { - fprintf(stderr, "Audio: Invalid sound index %d\n", soundIndex); + logWarn("Audio: Invalid sound index %d\n", soundIndex); return -1; } sound = &dw->sond.sounds[soundIndex]; @@ -181,7 +181,7 @@ static int32_t webPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prio WebSoundInstance* slot = findFreeSlot(ma); if (slot == nullptr) { - fprintf(stderr, "Audio: No free sound slots for sound %d\n", soundIndex); + logWarn("Audio: No free sound slots for sound %d\n", soundIndex); return -1; } @@ -191,7 +191,7 @@ static int32_t webPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prio if (isStream) { result = ma_sound_init_from_file(&ma->engine, streamPath, MA_SOUND_FLAG_ASYNC, nullptr, nullptr, &slot->maSound); if (result != MA_SUCCESS) { - fprintf(stderr, "Audio: Failed to load stream file '%s' (error %d)\n", streamPath, result); + logWarn("Audio: Failed to load stream file '%s' (error %d)\n", streamPath, result); return -1; } slot->ownsDecoder = false; @@ -203,7 +203,7 @@ static int32_t webPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prio if (inAudo) { if (0 > sound->audioFile || (uint32_t) sound->audioFile >= ma->base.audioGroups[sound->audioGroup]->audo.count) { - fprintf(stderr, "Audio: Invalid audio file index %d for sound '%s'\n", sound->audioFile, sound->name); + logWarn("Audio: Invalid audio file index %d for sound '%s'\n", sound->audioFile, sound->name); return -1; } @@ -212,27 +212,27 @@ static int32_t webPlaySound(AudioSystem* audio, int32_t soundIndex, int32_t prio ma_decoder_config decoderConfig = ma_decoder_config_init_default(); result = ma_decoder_init_memory(entry->data, entry->dataSize, &decoderConfig, &slot->decoder); if (result != MA_SUCCESS) { - fprintf(stderr, "Audio: Failed to init decoder for '%s' (error %d)\n", sound->name, result); + logWarn("Audio: Failed to init decoder for '%s' (error %d)\n", sound->name, result); return -1; } slot->ownsDecoder = true; result = ma_sound_init_from_data_source(&ma->engine, &slot->decoder, 0, nullptr, &slot->maSound); if (result != MA_SUCCESS) { - fprintf(stderr, "Audio: Failed to init sound from decoder for '%s' (error %d)\n", sound->name, result); + logWarn("Audio: Failed to init sound from decoder for '%s' (error %d)\n", sound->name, result); ma_decoder_uninit(&slot->decoder); return -1; } } else { char* path = resolveExternalPath(ma, sound); if (path == nullptr) { - fprintf(stderr, "Audio: Could not resolve path for sound '%s'\n", sound->name); + logWarn("Audio: Could not resolve path for sound '%s'\n", sound->name); return -1; } result = ma_sound_init_from_file(&ma->engine, path, MA_SOUND_FLAG_ASYNC, nullptr, nullptr, &slot->maSound); if (result != MA_SUCCESS) { - fprintf(stderr, "Audio: Failed to load file for '%s' at '%s' (error %d)\n", sound->name, path, result); + logWarn("Audio: Failed to load file for '%s' at '%s' (error %d)\n", sound->name, path, result); free(path); return -1; } @@ -605,7 +605,7 @@ static void webGroupLoad(AudioSystem* audio, int32_t groupIndex) { // The original runner does not care if the file doesn't exist (this may happen if someone uses "audio_group_load" on a non-existent group) FileSystem* fileSystem = ((WebAudioSystem*)audio)->fileSystem; if (!fileSystem->vtable->fileExists(fileSystem, buf)) { - fprintf(stderr, "Audio: Wanted to load Audio Group %d, but Audio Group %d does not exist in the file system!\n", groupIndex, groupIndex); + logWarn("Audio: Wanted to load Audio Group %d, but Audio Group %d does not exist in the file system!\n", groupIndex, groupIndex); free(buf); return; } @@ -634,13 +634,13 @@ static int32_t webCreateStream(AudioSystem* audio, const char* filename) { } if (0 > freeSlot) { - fprintf(stderr, "Audio: No free stream slots for '%s'\n", filename); + logWarn("Audio: No free stream slots for '%s'\n", filename); return -1; } char* resolved = ma->fileSystem->vtable->resolvePath(ma->fileSystem, filename); if (resolved == nullptr) { - fprintf(stderr, "Audio: Could not resolve path for stream '%s'\n", filename); + logWarn("Audio: Could not resolve path for stream '%s'\n", filename); return -1; } @@ -648,7 +648,7 @@ static int32_t webCreateStream(AudioSystem* audio, const char* filename) { ma->streams[freeSlot].filePath = resolved; int32_t streamIndex = WEB_AUDIO_STREAM_INDEX_BASE + freeSlot; - fprintf(stderr, "Audio: Created stream %d for '%s' -> '%s'\n", streamIndex, filename, resolved); + logInfo("Audio: Created stream %d for '%s' -> '%s'\n", streamIndex, filename, resolved); return streamIndex; } @@ -658,7 +658,7 @@ static bool webDestroyStream(AudioSystem* audio, int32_t streamIndex) { int32_t slotIndex = streamIndex - WEB_AUDIO_STREAM_INDEX_BASE; if (0 > slotIndex || slotIndex >= WEB_MAX_AUDIO_STREAMS) { - fprintf(stderr, "Audio: Invalid stream index %d for destroy\n", streamIndex); + logWarn("Audio: Invalid stream index %d for destroy\n", streamIndex); return false; } diff --git a/src/binary_reader.c b/src/binary_reader.c index 6490c0884..9ced421bd 100644 --- a/src/binary_reader.c +++ b/src/binary_reader.c @@ -30,7 +30,7 @@ static void readCheck(BinaryReader* reader, void* dest, size_t bytes) { if (reader->buffer != nullptr) { if (reader->bufferPos + bytes > reader->bufferSize) { size_t absPos = reader->bufferBase + reader->bufferPos; - fprintf(stderr, "BinaryReader: buffer read error at position 0x%zX (requested %zu bytes, buffer has %zu remaining)\n", absPos, bytes, reader->bufferSize - reader->bufferPos); + logError("BinaryReader: buffer read error at position 0x%zX (requested %zu bytes, buffer has %zu remaining)\n", absPos, bytes, reader->bufferSize - reader->bufferPos); abort(); } memcpy(dest, reader->buffer + reader->bufferPos, bytes); @@ -41,7 +41,7 @@ static void readCheck(BinaryReader* reader, void* dest, size_t bytes) { size_t read = fread(dest, 1, bytes, reader->file); if (read != bytes) { long pos = ftell(reader->file) - (long) read; - fprintf(stderr, "BinaryReader: read error at position 0x%lX (requested %zu bytes, got %zu, file size 0x%zX)\n", pos, bytes, read, reader->fileSize); + logError("BinaryReader: read error at position 0x%lX (requested %zu bytes, got %zu, file size 0x%zX)\n", pos, bytes, read, reader->fileSize); abort(); } } @@ -110,7 +110,7 @@ uint8_t* BinaryReader_readBytesAt(BinaryReader* reader, size_t offset, size_t co if (reader->buffer != nullptr) { if (offset < reader->bufferBase || offset + count > reader->bufferBase + reader->bufferSize) { - fprintf(stderr, "BinaryReader: readBytesAt offset 0x%zX+%zu out of buffer range [0x%zX, 0x%zX)\n", offset, count, reader->bufferBase, reader->bufferBase + reader->bufferSize); + logError("BinaryReader: readBytesAt offset 0x%zX+%zu out of buffer range [0x%zX, 0x%zX)\n", offset, count, reader->bufferBase, reader->bufferBase + reader->bufferSize); abort(); } size_t savedPos = reader->bufferPos; @@ -137,7 +137,7 @@ void BinaryReader_skip(BinaryReader* reader, size_t bytes) { void BinaryReader_seek(BinaryReader* reader, size_t position) { if (reader->buffer != nullptr) { if (position < reader->bufferBase || position > reader->bufferBase + reader->bufferSize) { - fprintf(stderr, "BinaryReader: buffer seek to 0x%zX out of buffer range [0x%zX, 0x%zX]\n", position, reader->bufferBase, reader->bufferBase + reader->bufferSize); + logError("BinaryReader: buffer seek to 0x%zX out of buffer range [0x%zX, 0x%zX]\n", position, reader->bufferBase, reader->bufferBase + reader->bufferSize); abort(); } reader->bufferPos = position - reader->bufferBase; @@ -145,7 +145,7 @@ void BinaryReader_seek(BinaryReader* reader, size_t position) { } if (position > reader->fileSize) { - fprintf(stderr, "BinaryReader: seek to 0x%zX out of bounds (file size 0x%zX)\n", position, reader->fileSize); + logError("BinaryReader: seek to 0x%zX out of bounds (file size 0x%zX)\n", position, reader->fileSize); abort(); } fseek(reader->file, (long) position, SEEK_SET); diff --git a/src/data_win.c b/src/data_win.c index 23e9e4839..b0fc801da 100644 --- a/src/data_win.c +++ b/src/data_win.c @@ -822,7 +822,7 @@ static void parseSPRT(BinaryReader* reader, DataWin* dw, bool skipLoadingPrecise check = 0; } } else { - fprintf(stderr, "DataWin: Detected special sprite type %u (%s), but we don't support it yet!\n", spr->sSpriteType, spr->sSpriteType == 2 ? "Spine" : spr->sSpriteType == 1 ? "SWF" : "Unknown"); + logWarn("DataWin: Detected special sprite type %u (%s), but we don't support it yet!\n", spr->sSpriteType, spr->sSpriteType == 2 ? "Spine" : spr->sSpriteType == 1 ? "SWF" : "Unknown"); spr->textureCount = 0; spr->tpagIndices = nullptr; spr->maskCount = 0; @@ -1077,7 +1077,7 @@ static void parseACRV(BinaryReader* reader, DataWin* dw) { uint32_t version = BinaryReader_readUint32(reader); if (version != 1) { - fprintf(stderr, "ACRV: unexpected version %u (expected 1)\n", version); + logWarn("ACRV: unexpected version %u (expected 1)\n", version); return; } @@ -1858,7 +1858,7 @@ static void readRoomLayers(BinaryReader* reader, DataWin* dw, Room* room, uint32 break; } default: { - fprintf(stderr, "Unsupported Room Layer Type %u\n", layer->type); + logError("Unsupported Room Layer Type %u\n", layer->type); exit(0); } } @@ -2114,7 +2114,7 @@ static void parseROOM(BinaryReader* reader, DataWin* dw, bool lazyLoadRooms, Str static int32_t parseTexturePageItem(BinaryReader* reader, DataWin* dw, int32_t i) { int32_t position = i; if (i == -1) { - fprintf(stderr, "DataWin: Allocated new TPAG! Was the WAD built with WinPack? (TranslaTale)\n"); + logWarn("DataWin: Allocated new TPAG! Was the WAD built with WinPack? (TranslaTale)\n"); uint32_t newCount = dw->tpag.count + 1; TexturePageItem* newItems = (TexturePageItem *)safeCalloc(newCount, sizeof(TexturePageItem)); memcpy(newItems, dw->tpag.items, dw->tpag.count * sizeof(TexturePageItem)); @@ -2552,7 +2552,7 @@ void DataWin_loadTxtrIfNeeded(DataWin* dw, uint32_t textureId) { if (tex->blobData != nullptr) return; if (!dw->lazyLoadFile) { - fprintf(stderr, "loadTxtrIfNeeded: called without a lazy load file.\n"); + logWarn("loadTxtrIfNeeded: called without a lazy load file.\n"); return; } @@ -2565,7 +2565,7 @@ void DataWin_loadTxtrIfNeeded(DataWin* dw, uint32_t textureId) { fseek(dw->lazyLoadFile, old_seek, SEEK_SET); if (read != tex->blobSize) { - fprintf(stderr, "loadTxtrIfNeeded: couldn't read %u bytes to load a texture.\n", tex->blobSize); + logWarn("loadTxtrIfNeeded: couldn't read %u bytes to load a texture.\n", tex->blobSize); } } @@ -2603,7 +2603,7 @@ static void parseAUDO(BinaryReader* reader, DataWin* dw) { DataWin* DataWin_parse(const char* filePath, DataWinParserOptions options) { FILE* file = fopen(filePath, "rb"); if (!file) { - fprintf(stderr, "Failed to open file: %s\n", filePath); + logError("Failed to open file: %s\n", filePath); exit(1); } @@ -2617,7 +2617,7 @@ DataWin* DataWin_parse(const char* filePath, DataWinParserOptions options) { fseek(file, 0, SEEK_SET); if (0 >= fileSizeRaw) { - fprintf(stderr, "Invalid file size: %ld\n", fileSizeRaw); + logError("Invalid file size: %ld\n", fileSizeRaw); fclose(file); exit(1); } @@ -2639,7 +2639,7 @@ DataWin* DataWin_parse(const char* filePath, DataWinParserOptions options) { } else if (options.loadType == DATAWINLOADTYPE_MAP_FILE) { wholeFileData = mapFile(file, fileSize); if (!wholeFileData) { - fprintf(stderr, "Failed to map file\n"); + logError("Failed to map file\n"); fclose(file); exit(1); } @@ -2653,7 +2653,7 @@ DataWin* DataWin_parse(const char* filePath, DataWinParserOptions options) { // Some games may purposely corrupt the magic value so that UndertaleModTool doesn't open it // The native runner does not care about verifying the magic value, so we'll validate it and warn, but we won't exit if (memcmp(formMagic, "FORM", 4) != 0) { - fprintf(stderr, "The file does not have the expected FORM magic, got '%.4s'. The file may not be a WAD or it may have been tampered with!\n", formMagic); + logWarn("The file does not have the expected FORM magic, got '%.4s'. The file may not be a WAD or it may have been tampered with!\n", formMagic); } uint32_t formLength = BinaryReader_readUint32(&reader); @@ -2700,7 +2700,7 @@ DataWin* DataWin_parse(const char* filePath, DataWinParserOptions options) { } if (chunkDataStart + chunkLength > fileSize) { - fprintf(stderr, "Chunk data extends beyond file size: chunkDataStart=%zu, chunkLength=%u, fileSize=%zu! Are you running a GameMaker Raspberry Pi game? Skipping bytes out of bounds...\n", chunkDataStart, chunkLength, fileSize); + logWarn("Chunk data extends beyond file size: chunkDataStart=%zu, chunkLength=%u, fileSize=%zu! Are you running a GameMaker Raspberry Pi game? Skipping bytes out of bounds...\n", chunkDataStart, chunkLength, fileSize); break; } @@ -2709,7 +2709,7 @@ DataWin* DataWin_parse(const char* filePath, DataWinParserOptions options) { } if (!codeExists && options.parseCode) { - fprintf(stderr, "CODE chunk does not exist or is empty! This usually means you're loading a YYC game.\n"); + logError("CODE chunk does not exist or is empty! This usually means you're loading a YYC game.\n"); fclose(file); exit(1); } @@ -2767,7 +2767,7 @@ DataWin* DataWin_parse(const char* filePath, DataWinParserOptions options) { if (chunkBuffer) { size_t read = fread(chunkBuffer, 1, chunkLength, reader.file); if (read != chunkLength) { - fprintf(stderr, "DataWin: short read on chunk %.4s (expected %u, got %zu)\n", chunkName, chunkLength, read); + logError("DataWin: short read on chunk %.4s (expected %u, got %zu)\n", chunkName, chunkLength, read); exit(1); } BinaryReader_setBuffer(&reader, chunkBuffer, chunkDataStart, chunkLength); @@ -2840,7 +2840,7 @@ DataWin* DataWin_parse(const char* filePath, DataWinParserOptions options) { } else if (options.parseAudo && memcmp(chunkName, "AUDO", 4) == 0) { parseAUDO(&reader, dw); } else { - printf("Unknown chunk: %.4s (length %u at offset 0x%zX)\n", chunkName, chunkLength, chunkDataStart - 8); + logInfo("Unknown chunk: %.4s (length %u at offset 0x%zX)\n", chunkName, chunkLength, chunkDataStart - 8); } // Free the chunk buffer and revert to FILE*-based reads for the next header diff --git a/src/data_win_print.c b/src/data_win_print.c index fc357e198..28c78a96b 100644 --- a/src/data_win_print.c +++ b/src/data_win_print.c @@ -6,139 +6,139 @@ #include "utils.h" void DataWin_printDebugSummary(DataWin* dataWin) { - printf("===== data.win Summary =====\n\n"); + logInfo("===== data.win Summary =====\n\n"); // GEN8 Gen8* g = &dataWin->gen8; - printf("-- GEN8 (General Info) --\n"); - printf(" Game Name: %s\n", g->name ? g->name : "(null)"); - printf(" Display Name: %s\n", g->displayName ? g->displayName : "(null)"); - printf(" File Name: %s\n", g->fileName ? g->fileName : "(null)"); - printf(" Config: %s\n", g->config ? g->config : "(null)"); - printf(" WAD Version: %u\n", g->wadVersion); - printf(" Game ID: %u\n", g->gameID); - printf(" Version: %u.%u.%u.%u\n", g->major, g->minor, g->release, g->build); - printf(" Window Size: %ux%u\n", g->defaultWindowWidth, g->defaultWindowHeight); - printf(" Steam App ID: %d\n", g->steamAppID); - printf(" Room Order: %u rooms\n", g->roomOrderCount); - printf("\n"); + logInfo("-- GEN8 (General Info) --\n"); + logInfo(" Game Name: %s\n", g->name ? g->name : "(null)"); + logInfo(" Display Name: %s\n", g->displayName ? g->displayName : "(null)"); + logInfo(" File Name: %s\n", g->fileName ? g->fileName : "(null)"); + logInfo(" Config: %s\n", g->config ? g->config : "(null)"); + logInfo(" WAD Version: %u\n", g->wadVersion); + logInfo(" Game ID: %u\n", g->gameID); + logInfo(" Version: %u.%u.%u.%u\n", g->major, g->minor, g->release, g->build); + logInfo(" Window Size: %ux%u\n", g->defaultWindowWidth, g->defaultWindowHeight); + logInfo(" Steam App ID: %d\n", g->steamAppID); + logInfo(" Room Order: %u rooms\n", g->roomOrderCount); + logInfo("\n"); // OPTN - printf("-- OPTN (Options) --\n"); - printf(" Constants: %u\n", dataWin->optn.constantCount); + logInfo("-- OPTN (Options) --\n"); + logInfo(" Constants: %u\n", dataWin->optn.constantCount); if (dataWin->optn.constantCount > 0) { uint32_t show = dataWin->optn.constantCount < 3 ? dataWin->optn.constantCount : 3; forEachIndexed(OptnConstant, constant, idx, dataWin->optn.constants, show) { - printf(" [%u] %s = %s\n", (unsigned int)idx, constant->name ? constant->name : "?", constant->value ? constant->value : "?"); + logInfo(" [%u] %s = %s\n", (unsigned int)idx, constant->name ? constant->name : "?", constant->value ? constant->value : "?"); } - if (dataWin->optn.constantCount > 3) printf(" ... and %u more\n", dataWin->optn.constantCount - 3); + if (dataWin->optn.constantCount > 3) logInfo(" ... and %u more\n", dataWin->optn.constantCount - 3); } - printf("\n"); + logInfo("\n"); // LANG - printf("-- LANG (Languages) --\n"); - printf(" Languages: %u\n", dataWin->lang.languageCount); - printf(" Entries: %u\n", dataWin->lang.entryCount); - printf("\n"); + logInfo("-- LANG (Languages) --\n"); + logInfo(" Languages: %u\n", dataWin->lang.languageCount); + logInfo(" Entries: %u\n", dataWin->lang.entryCount); + logInfo("\n"); // EXTN - printf("-- EXTN (Extensions) --\n"); - printf(" Extensions: %u\n", dataWin->extn.count); + logInfo("-- EXTN (Extensions) --\n"); + logInfo(" Extensions: %u\n", dataWin->extn.count); forEachIndexed(Extension, ext, idx, dataWin->extn.extensions, dataWin->extn.count) { - printf(" [%u] %s (%u files)\n", (unsigned int)idx, ext->name ? ext->name : "?", ext->fileCount); + logInfo(" [%u] %s (%u files)\n", (unsigned int)idx, ext->name ? ext->name : "?", ext->fileCount); } - printf("\n"); + logInfo("\n"); // SOND - printf("-- SOND (Sounds) --\n"); - printf(" Sounds: %u\n", dataWin->sond.count); + logInfo("-- SOND (Sounds) --\n"); + logInfo(" Sounds: %u\n", dataWin->sond.count); if (dataWin->sond.count > 0) { uint32_t show = dataWin->sond.count < 3 ? dataWin->sond.count : 3; forEachIndexed(Sound, snd, idx, dataWin->sond.sounds, show) { - printf(" [%u] %s (%s)\n", (unsigned int)idx, snd->name ? snd->name : "?", snd->type ? snd->type : "?"); + logInfo(" [%u] %s (%s)\n", (unsigned int)idx, snd->name ? snd->name : "?", snd->type ? snd->type : "?"); } - if (dataWin->sond.count > 3) printf(" ... and %u more\n", dataWin->sond.count - 3); + if (dataWin->sond.count > 3) logInfo(" ... and %u more\n", dataWin->sond.count - 3); } - printf("\n"); + logInfo("\n"); // AGRP - printf("-- AGRP (Audio Groups) --\n"); - printf(" Audio Groups: %u\n", dataWin->agrp.count); + logInfo("-- AGRP (Audio Groups) --\n"); + logInfo(" Audio Groups: %u\n", dataWin->agrp.count); forEachIndexed(AudioGroup, ag, idx, dataWin->agrp.audioGroups, dataWin->agrp.count) { - printf(" [%u] %s\n", (unsigned int)idx, ag->name ? ag->name : "?"); + logInfo(" [%u] %s\n", (unsigned int)idx, ag->name ? ag->name : "?"); } - printf("\n"); + logInfo("\n"); // SPRT - printf("-- SPRT (Sprites) --\n"); - printf(" Sprites: %u\n", dataWin->sprt.count); + logInfo("-- SPRT (Sprites) --\n"); + logInfo(" Sprites: %u\n", dataWin->sprt.count); if (dataWin->sprt.count > 0) { uint32_t show = dataWin->sprt.count < 3 ? dataWin->sprt.count : 3; forEachIndexed(Sprite, spr, idx, dataWin->sprt.sprites, show) { - printf(" [%u] %s (%ux%u, %u frames)\n", (unsigned int)idx, spr->name ? spr->name : "?", spr->width, spr->height, spr->textureCount); + logInfo(" [%u] %s (%ux%u, %u frames)\n", (unsigned int)idx, spr->name ? spr->name : "?", spr->width, spr->height, spr->textureCount); } - if (dataWin->sprt.count > 3) printf(" ... and %u more\n", dataWin->sprt.count - 3); + if (dataWin->sprt.count > 3) logInfo(" ... and %u more\n", dataWin->sprt.count - 3); } - printf("\n"); + logInfo("\n"); // BGND - printf("-- BGND (Backgrounds) --\n"); - printf(" Backgrounds: %u\n", dataWin->bgnd.count); + logInfo("-- BGND (Backgrounds) --\n"); + logInfo(" Backgrounds: %u\n", dataWin->bgnd.count); if (dataWin->bgnd.count > 0) { uint32_t show = dataWin->bgnd.count < 3 ? dataWin->bgnd.count : 3; forEachIndexed(Background, bg, idx, dataWin->bgnd.backgrounds, show) { - printf(" [%u] %s\n", (unsigned int)idx, bg->name ? bg->name : "?"); + logInfo(" [%u] %s\n", (unsigned int)idx, bg->name ? bg->name : "?"); } - if (dataWin->bgnd.count > 3) printf(" ... and %u more\n", dataWin->bgnd.count - 3); + if (dataWin->bgnd.count > 3) logInfo(" ... and %u more\n", dataWin->bgnd.count - 3); } - printf("\n"); + logInfo("\n"); // PATH - printf("-- PATH (Paths) --\n"); - printf(" Paths: %u\n", dataWin->path.count); - printf("\n"); + logInfo("-- PATH (Paths) --\n"); + logInfo(" Paths: %u\n", dataWin->path.count); + logInfo("\n"); // SCPT - printf("-- SCPT (Scripts) --\n"); - printf(" Scripts: %u\n", dataWin->scpt.count); + logInfo("-- SCPT (Scripts) --\n"); + logInfo(" Scripts: %u\n", dataWin->scpt.count); if (dataWin->scpt.count > 0) { uint32_t show = dataWin->scpt.count < 3 ? dataWin->scpt.count : 3; forEachIndexed(Script, scr, idx, dataWin->scpt.scripts, show) { - printf(" [%u] %s -> code[%d]\n", (unsigned int)idx, scr->name ? scr->name : "?", scr->codeId); + logInfo(" [%u] %s -> code[%d]\n", (unsigned int)idx, scr->name ? scr->name : "?", scr->codeId); } - if (dataWin->scpt.count > 3) printf(" ... and %u more\n", dataWin->scpt.count - 3); + if (dataWin->scpt.count > 3) logInfo(" ... and %u more\n", dataWin->scpt.count - 3); } - printf("\n"); + logInfo("\n"); // GLOB - printf("-- GLOB (Global Init Scripts) --\n"); - printf(" Init Scripts: %u\n", dataWin->glob.count); - printf("\n"); + logInfo("-- GLOB (Global Init Scripts) --\n"); + logInfo(" Init Scripts: %u\n", dataWin->glob.count); + logInfo("\n"); // SHDR - printf("-- SHDR (Shaders) --\n"); - printf(" Shaders: %u\n", dataWin->shdr.count); + logInfo("-- SHDR (Shaders) --\n"); + logInfo(" Shaders: %u\n", dataWin->shdr.count); forEachIndexed(Shader, shdr, idx, dataWin->shdr.shaders, dataWin->shdr.count) { - printf(" [%u] %s (version %d)\n", (unsigned int)idx, shdr->name ? shdr->name : "?", shdr->version); + logInfo(" [%u] %s (version %d)\n", (unsigned int)idx, shdr->name ? shdr->name : "?", shdr->version); } - printf("\n"); + logInfo("\n"); // FONT - printf("-- FONT (Fonts) --\n"); - printf(" Fonts: %u\n", dataWin->font.count); + logInfo("-- FONT (Fonts) --\n"); + logInfo(" Fonts: %u\n", dataWin->font.count); forEachIndexed(Font, fnt, idx, dataWin->font.fonts, dataWin->font.count) { - printf(" [%u] %s (%s, em=%u, %u glyphs)\n", (unsigned int)idx, fnt->name ? fnt->name : "?", fnt->displayName ? fnt->displayName : "?", fnt->emSize, fnt->glyphCount); + logInfo(" [%u] %s (%s, em=%u, %u glyphs)\n", (unsigned int)idx, fnt->name ? fnt->name : "?", fnt->displayName ? fnt->displayName : "?", fnt->emSize, fnt->glyphCount); } - printf("\n"); + logInfo("\n"); // TMLN - printf("-- TMLN (Timelines) --\n"); - printf(" Timelines: %u\n", dataWin->tmln.count); - printf("\n"); + logInfo("-- TMLN (Timelines) --\n"); + logInfo(" Timelines: %u\n", dataWin->tmln.count); + logInfo("\n"); // OBJT - printf("-- OBJT (Game Objects) --\n"); - printf(" Objects: %u\n", dataWin->objt.count); + logInfo("-- OBJT (Game Objects) --\n"); + logInfo(" Objects: %u\n", dataWin->objt.count); if (dataWin->objt.count > 0) { uint32_t show = dataWin->objt.count < 3 ? dataWin->objt.count : 3; forEachIndexed(GameObject, obj, idx, dataWin->objt.objects, show) { @@ -146,75 +146,75 @@ void DataWin_printDebugSummary(DataWin* dataWin) { repeat(OBJT_EVENT_TYPE_COUNT, e) { totalEvents += obj->eventLists[e].eventCount; } - printf(" [%u] %s (sprite=%d, depth=%d, %u events)\n", (unsigned int)idx, obj->name ? obj->name : "?", obj->spriteId, obj->depth, totalEvents); + logInfo(" [%u] %s (sprite=%d, depth=%d, %u events)\n", (unsigned int)idx, obj->name ? obj->name : "?", obj->spriteId, obj->depth, totalEvents); } - if (dataWin->objt.count > 3) printf(" ... and %u more\n", dataWin->objt.count - 3); + if (dataWin->objt.count > 3) logInfo(" ... and %u more\n", dataWin->objt.count - 3); } - printf("\n"); + logInfo("\n"); // ROOM - printf("-- ROOM (Rooms) --\n"); - printf(" Rooms: %u\n", dataWin->room.count); + logInfo("-- ROOM (Rooms) --\n"); + logInfo(" Rooms: %u\n", dataWin->room.count); if (dataWin->room.count > 0) { uint32_t show = dataWin->room.count < 3 ? dataWin->room.count : 3; forEachIndexed(Room, rm, idx, dataWin->room.rooms, show) { if (rm->payloadLoaded) { - printf(" [%u] %s (%ux%u, %u objects, %u tiles)\n", (unsigned int)idx, rm->name ? rm->name : "?", rm->width, rm->height, rm->gameObjectCount, rm->tileCount); + logInfo(" [%u] %s (%ux%u, %u objects, %u tiles)\n", (unsigned int)idx, rm->name ? rm->name : "?", rm->width, rm->height, rm->gameObjectCount, rm->tileCount); } else { // Lazy room with payload not yet loaded: gameObjectCount/tileCount would be 0 and misleading. - printf(" [%u] %s (%ux%u, payload not loaded)\n", (unsigned int)idx, rm->name ? rm->name : "?", rm->width, rm->height); + logInfo(" [%u] %s (%ux%u, payload not loaded)\n", (unsigned int)idx, rm->name ? rm->name : "?", rm->width, rm->height); } } - if (dataWin->room.count > 3) printf(" ... and %u more\n", dataWin->room.count - 3); + if (dataWin->room.count > 3) logInfo(" ... and %u more\n", dataWin->room.count - 3); } - printf("\n"); + logInfo("\n"); // TPAG - printf("-- TPAG (Texture Page Items) --\n"); - printf(" Items: %u\n", dataWin->tpag.count); - printf("\n"); + logInfo("-- TPAG (Texture Page Items) --\n"); + logInfo(" Items: %u\n", dataWin->tpag.count); + logInfo("\n"); // CODE - printf("-- CODE (Code Entries) --\n"); - printf(" Entries: %u\n", dataWin->code.count); + logInfo("-- CODE (Code Entries) --\n"); + logInfo(" Entries: %u\n", dataWin->code.count); if (dataWin->code.count > 0) { uint32_t show = dataWin->code.count < 3 ? dataWin->code.count : 3; forEachIndexed(CodeEntry, entry, idx, dataWin->code.entries, show) { - printf(" [%u] %s (%u bytes, %u locals, %u args)\n", (unsigned int)idx, entry->name ? entry->name : "?", entry->length, entry->localsCount, entry->argumentsCount); + logInfo(" [%u] %s (%u bytes, %u locals, %u args)\n", (unsigned int)idx, entry->name ? entry->name : "?", entry->length, entry->localsCount, entry->argumentsCount); } - if (dataWin->code.count > 3) printf(" ... and %u more\n", dataWin->code.count - 3); + if (dataWin->code.count > 3) logInfo(" ... and %u more\n", dataWin->code.count - 3); } - printf("\n"); + logInfo("\n"); // VARI - printf("-- VARI (Variables) --\n"); - printf(" Variables: %u\n", dataWin->vari.variableCount); - printf(" Max Locals: %u\n", dataWin->vari.maxLocalVarCount); + logInfo("-- VARI (Variables) --\n"); + logInfo(" Variables: %u\n", dataWin->vari.variableCount); + logInfo(" Max Locals: %u\n", dataWin->vari.maxLocalVarCount); if (dataWin->vari.variableCount > 0) { uint32_t show = dataWin->vari.variableCount < 3 ? dataWin->vari.variableCount : 3; forEachIndexed(Variable, var, idx, dataWin->vari.variables, show) { - printf(" [%u] %s (type=%d, id=%d, %u refs)\n", (unsigned int)idx, var->name ? var->name : "?", var->instanceType, var->varID, var->occurrences); + logInfo(" [%u] %s (type=%d, id=%d, %u refs)\n", (unsigned int)idx, var->name ? var->name : "?", var->instanceType, var->varID, var->occurrences); } - if (dataWin->vari.variableCount > 3) printf(" ... and %u more\n", dataWin->vari.variableCount - 3); + if (dataWin->vari.variableCount > 3) logInfo(" ... and %u more\n", dataWin->vari.variableCount - 3); } - printf("\n"); + logInfo("\n"); // FUNC - printf("-- FUNC (Functions) --\n"); - printf(" Functions: %u\n", dataWin->func.functionCount); - printf(" Code Locals: %u\n", dataWin->func.codeLocalsCount); + logInfo("-- FUNC (Functions) --\n"); + logInfo(" Functions: %u\n", dataWin->func.functionCount); + logInfo(" Code Locals: %u\n", dataWin->func.codeLocalsCount); if (dataWin->func.functionCount > 0) { uint32_t show = dataWin->func.functionCount < 3 ? dataWin->func.functionCount : 3; forEachIndexed(Function, fn, idx, dataWin->func.functions, show) { - printf(" [%u] %s (%u refs)\n", (unsigned int)idx, fn->name ? fn->name : "?", fn->occurrences); + logInfo(" [%u] %s (%u refs)\n", (unsigned int)idx, fn->name ? fn->name : "?", fn->occurrences); } - if (dataWin->func.functionCount > 3) printf(" ... and %u more\n", dataWin->func.functionCount - 3); + if (dataWin->func.functionCount > 3) logInfo(" ... and %u more\n", dataWin->func.functionCount - 3); } - printf("\n"); + logInfo("\n"); // STRG - printf("-- STRG (Strings) --\n"); - printf(" Strings: %u\n", dataWin->strg.count); + logInfo("-- STRG (Strings) --\n"); + logInfo(" Strings: %u\n", dataWin->strg.count); if (dataWin->strg.count > 0) { uint32_t show = dataWin->strg.count < 5 ? dataWin->strg.count : 5; repeat(show, i) { @@ -223,56 +223,56 @@ void DataWin_printDebugSummary(DataWin* dataWin) { if (str) { size_t len = strlen(str); if (len > 60) { - printf(" [%u] \"%.60s...\" (%zu chars)\n", (unsigned int)i, str, len); + logInfo(" [%u] \"%.60s...\" (%zu chars)\n", (unsigned int)i, str, len); } else { - printf(" [%u] \"%s\"\n", (unsigned int)i, str); + logInfo(" [%u] \"%s\"\n", (unsigned int)i, str); } } else { - printf(" [%u] (null)\n", (unsigned int)i); + logInfo(" [%u] (null)\n", (unsigned int)i); } } - if (dataWin->strg.count > 5) printf(" ... and %u more\n", dataWin->strg.count - 5); + if (dataWin->strg.count > 5) logInfo(" ... and %u more\n", dataWin->strg.count - 5); } - printf("\n"); + logInfo("\n"); // TXTR - printf("-- TXTR (Textures) --\n"); - printf(" Textures: %u\n", dataWin->txtr.count); + logInfo("-- TXTR (Textures) --\n"); + logInfo(" Textures: %u\n", dataWin->txtr.count); if (dataWin->txtr.count > 0) { forEachIndexed(Texture, tex, idx, dataWin->txtr.textures, dataWin->txtr.count) { - printf(" [%u] offset=0x%08X size=%u bytes\n", (unsigned int)idx, tex->blobOffset, tex->blobSize); + logInfo(" [%u] offset=0x%08X size=%u bytes\n", (unsigned int)idx, tex->blobOffset, tex->blobSize); } } - printf("\n"); + logInfo("\n"); // AUDO - printf("-- AUDO (Audio) --\n"); - printf(" Audio Entries: %u\n", dataWin->audo.count); + logInfo("-- AUDO (Audio) --\n"); + logInfo(" Audio Entries: %u\n", dataWin->audo.count); if (dataWin->audo.count > 0) { uint32_t show = dataWin->audo.count < 3 ? dataWin->audo.count : 3; forEachIndexed(AudioEntry, ae, idx, dataWin->audo.entries, show) { - printf(" [%u] offset=0x%08X size=%u bytes\n", (unsigned int)idx, ae->dataOffset, ae->dataSize); + logInfo(" [%u] offset=0x%08X size=%u bytes\n", (unsigned int)idx, ae->dataOffset, ae->dataSize); } - if (dataWin->audo.count > 3) printf(" ... and %u more\n", dataWin->audo.count - 3); + if (dataWin->audo.count > 3) logInfo(" ... and %u more\n", dataWin->audo.count - 3); } - printf("\n"); + logInfo("\n"); - printf("-- Room Instances --\n"); + logInfo("-- Room Instances --\n"); forEach(Room, room, dataWin->room.rooms, dataWin->room.count) { - printf("Room %s\n", room->name); + logInfo("Room %s\n", room->name); if (!room->payloadLoaded) { - printf(" (payload not loaded)\n"); + logInfo(" (payload not loaded)\n"); continue; } forEachIndexed(RoomGameObject, roomGameObject, idx, room->gameObjects, room->gameObjectCount) { int32_t objectDefinitionId = roomGameObject->objectDefinition; GameObject* objectDefinition = &dataWin->objt.objects[objectDefinitionId]; - printf(" Object %d (%s, x=%d, y=%d)\n", objectDefinitionId, objectDefinition->name, roomGameObject->x, roomGameObject->y); + logInfo(" Object %d (%s, x=%d, y=%d)\n", objectDefinitionId, objectDefinition->name, roomGameObject->x, roomGameObject->y); } } // Overall summary - printf("===== DataWin parse complete =====\n"); + logInfo("===== DataWin parse complete =====\n"); } diff --git a/src/desktop/backends/glfw2.c b/src/desktop/backends/glfw2.c index b97b41764..9a0181f9c 100644 --- a/src/desktop/backends/glfw2.c +++ b/src/desktop/backends/glfw2.c @@ -29,7 +29,7 @@ static bool tryOpenWindow(int reqW, int reqH) { for (size_t i = 0; i < sizeof(GLCommon_versions)/sizeof(GLCommon_versions[0]); i++) { glfwOpenWindowHint(GLFW_OPENGL_VERSION_MAJOR, GLCommon_versions[i].major); glfwOpenWindowHint(GLFW_OPENGL_VERSION_MINOR, GLCommon_versions[i].minor); - + if (GLCommon_versions[i].major >= 3) { glfwOpenWindowHint(GLFW_OPENGL_PROFILE, GLFW_OPENGL_COMPAT_PROFILE); if (GLCommon_versions[i].major == 3 && GLCommon_versions[i].minor == 2) { @@ -186,18 +186,18 @@ static void GLFWCALL scrollCallback(int pos) { bool platformInit(int32_t reqW, int32_t reqH, const char *title, bool headless) { if (headless) { - fprintf(stderr, "Headless mode is not supported with GLFW 2\n"); + logError("Headless mode is not supported with GLFW 2\n"); return false; } // Init GLFW if (!glfwInit()) { - fprintf(stderr, "Failed to initialize GLFW\n"); + logError("Failed to initialize GLFW\n"); return false; } if (!tryOpenWindow(reqW, reqH)) { - fprintf(stderr, "Failed to create GLFW window\n"); + logError("Failed to create GLFW window\n"); glfwTerminate(); return false; } diff --git a/src/desktop/backends/glfw3.c b/src/desktop/backends/glfw3.c index 28cba4c2b..bb4b4bd74 100644 --- a/src/desktop/backends/glfw3.c +++ b/src/desktop/backends/glfw3.c @@ -33,11 +33,11 @@ static GLFWwindow *tryOpenWindow(int reqW, int reqH, const char* title) { glfwDefaultWindowHints(); glfwWindowHint(GLFW_CONTEXT_VERSION_MAJOR, 1); glfwWindowHint(GLFW_CONTEXT_VERSION_MINOR, (gfx == SOFTWARE) ? 0 : 1); - + #ifndef NDEBUG glfwWindowHint(GLFW_OPENGL_DEBUG_CONTEXT, GL_TRUE); #endif - + return glfwCreateWindow(reqW, reqH, title, NULL, NULL); } @@ -127,7 +127,7 @@ static bool platformGetWindowFocus(void) { } static void glfwErrorCallback(int code, const char* description) { - fprintf(stderr, "GLFW error 0x%x: %s\n", code, description); + logWarn("GLFW error 0x%x: %s\n", code, description); } static int32_t glfwKeyToGml(int glfwKey) { @@ -224,7 +224,7 @@ bool platformInit(int32_t reqW, int32_t reqH, const char *title, bool headless) // Init GLFW glfwSetErrorCallback(glfwErrorCallback); if (!glfwInit()) { - fprintf(stderr, "Failed to initialize GLFW\n"); + logError("Failed to initialize GLFW\n"); return false; } @@ -241,23 +241,23 @@ bool platformInit(int32_t reqW, int32_t reqH, const char *title, bool headless) buffer[len] = '\0'; if (buffer[0] != '\0') { if (glfwUpdateGamepadMappings(buffer)) { - fprintf(stderr, "Gamepad: Loaded SDL gamecontroller mappings successfully\n"); + logInfo("Gamepad: Loaded SDL gamecontroller mappings successfully\n"); } else { - fprintf(stderr, "Gamepad: Failed to load SDL gamecontroller mappings\n"); + logWarn("Gamepad: Failed to load SDL gamecontroller mappings\n"); } } free(buffer); } fclose(f); } else - fprintf(stderr, "Gamepad: SDL gamecontrollerdb.txt not found at %s, using defaults\n", dbPath); + logWarn("Gamepad: SDL gamecontrollerdb.txt not found at %s, using defaults\n", dbPath); if (headless) glfwWindowHint(GLFW_VISIBLE, GLFW_FALSE); window = tryOpenWindow(reqW, reqH, title); if (!window) { - fprintf(stderr, "Failed to create GLFW window\n"); + logError("Failed to create GLFW window\n"); glfwTerminate(); return false; } diff --git a/src/desktop/backends/sdl1.c b/src/desktop/backends/sdl1.c index ad9beba10..fd57c8851 100644 --- a/src/desktop/backends/sdl1.c +++ b/src/desktop/backends/sdl1.c @@ -137,7 +137,7 @@ static void loadGamepadMappings(void) { const char* dbPath = "gamecontrollerdb.txt"; FILE* f = fopen(dbPath, "rb"); if (!f) { - fprintf(stderr, "Gamepad: SDL gamecontrollerdb.txt not found at %s, ignoring mappings\n", dbPath); + logWarn("Gamepad: SDL gamecontrollerdb.txt not found at %s, ignoring mappings\n", dbPath); return; } @@ -194,7 +194,7 @@ static void loadGamepadMappings(void) { const char* jname = SDL_JoystickName(i); if (jname && strcasecmp(jname, name) == 0) { joystickMappings[i] = temp; - fprintf(stderr, "Gamepad: Mapped '%s' (slot %d)\n", jname, i); + logInfo("Gamepad: Mapped '%s' (slot %d)\n", jname, i); } } } @@ -240,13 +240,13 @@ static bool platformGetWindowFocus(void) { bool platformInit(int32_t reqW, int32_t reqH, const char *title, bool headless) { if (headless && gfx != SOFTWARE) { - fprintf(stderr, "Headless mode on SDL 1.2 requires the software renderer!\n"); + logError("Headless mode on SDL 1.2 requires the software renderer!\n"); return false; } // Init SDL if (SDL_Init(SDL_INIT_VIDEO|SDL_INIT_TIMER|SDL_INIT_JOYSTICK)) { - fprintf(stderr, "Failed to initialize SDL\n"); + logError("Failed to initialize SDL\n"); return false; } @@ -271,7 +271,7 @@ bool platformInit(int32_t reqW, int32_t reqH, const char *title, bool headless) if (!scr && gfx == SOFTWARE) { SDL_Rect** modes = SDL_ListModes(NULL, SDL_FULLSCREEN); if (modes && modes != (SDL_Rect**) -1 && modes[0]) { - fprintf(stderr, "Warning: %dx%d unavailable, falling back to %dx%d: %s\n", + logWarn("%dx%d unavailable, falling back to %dx%d: %s\n", reqW, reqH, modes[0]->w, modes[0]->h, SDL_GetError()); scr = SDL_SetVideoMode(modes[0]->w, modes[0]->h, 0, 0); fbWidth = modes[0]->w; @@ -279,7 +279,7 @@ bool platformInit(int32_t reqW, int32_t reqH, const char *title, bool headless) } } if (!scr) { - fprintf(stderr, "Fatal: Could not set any video mode: %s\n", SDL_GetError()); + logError("Fatal: Could not set any video mode: %s\n", SDL_GetError()); return false; } } @@ -416,11 +416,11 @@ static void platformResetJoysticks(void) { openJoysticks[i] = NULL; } } - + SDL_QuitSubSystem(SDL_INIT_JOYSTICK); SDL_InitSubSystem(SDL_INIT_JOYSTICK); SDL_JoystickEventState(SDL_IGNORE); - + int numJoysticks = SDL_NumJoysticks(); bool needsRemap = false; for (int i = 0; i < numJoysticks && i < MAX_GAMEPADS; i++) { @@ -432,11 +432,11 @@ static void platformResetJoysticks(void) { needsRemap = true; } } - + for (int i = numJoysticks; i < MAX_GAMEPADS; i++) { joystickMappings[i].valid = false; } - + if (needsRemap) { loadGamepadMappings(); } @@ -502,7 +502,7 @@ bool platformHandleEvents(void) { float norm = val / 32767.0f; if (map->axis_button_sign[btn] < 0) norm = -norm; if (norm < 0.0f) norm = 0.0f; - + if (norm > slot->buttonValue[btn]) { slot->buttonValue[btn] = norm; } diff --git a/src/desktop/backends/sdl2.c b/src/desktop/backends/sdl2.c index c677ffd8d..baacf199e 100644 --- a/src/desktop/backends/sdl2.c +++ b/src/desktop/backends/sdl2.c @@ -28,7 +28,7 @@ static SDL_Window *tryOpenWindow(int reqW, int reqH, const char* title, Uint32 f SDL_GL_SetAttribute(SDL_GL_CONTEXT_MAJOR_VERSION, 1); SDL_GL_SetAttribute(SDL_GL_CONTEXT_MINOR_VERSION, 1); SDL_GL_SetAttribute(SDL_GL_CONTEXT_PROFILE_MASK, 0); - + SDL_Window *newWindow = SDL_CreateWindow( title, SDL_WINDOWPOS_UNDEFINED, @@ -45,7 +45,7 @@ static SDL_Window *tryOpenWindow(int reqW, int reqH, const char* title, Uint32 f } return NULL; } - for (size_t i = 0; i < sizeof(GLCommon_versions)/sizeof(GLCommon_versions[0]); i++) { + for (size_t i = 0; i < sizeof(GLCommon_versions)/sizeof(GLCommon_versions[0]); i++) { SDL_Window *newWindow; int contextFlags = 0; @@ -60,16 +60,16 @@ static SDL_Window *tryOpenWindow(int reqW, int reqH, const char* title, Uint32 f if (GLCommon_versions[i].gles) { SDL_GL_SetAttribute(SDL_GL_CONTEXT_PROFILE_MASK, SDL_GL_CONTEXT_PROFILE_ES); - } else { + } else { if (GLCommon_versions[i].major >= 3) { if (GLCommon_versions[i].major == 3 && GLCommon_versions[i].minor == 2) { contextFlags |= SDL_GL_CONTEXT_FORWARD_COMPATIBLE_FLAG; } } else { - SDL_GL_SetAttribute(SDL_GL_CONTEXT_PROFILE_MASK, 0); + SDL_GL_SetAttribute(SDL_GL_CONTEXT_PROFILE_MASK, 0); } } - + SDL_GL_SetAttribute(SDL_GL_CONTEXT_FLAGS, contextFlags); newWindow = SDL_CreateWindow( @@ -86,7 +86,7 @@ static SDL_Window *tryOpenWindow(int reqW, int reqH, const char* title, Uint32 f } SDL_DestroyWindow(newWindow); } - + } return NULL; } @@ -167,14 +167,14 @@ static bool platformGetWindowFocus(void) { bool platformInit(int reqW, int reqH, const char *title, bool headless) { // Init SDL if (SDL_Init(SDL_INIT_VIDEO|SDL_INIT_TIMER|SDL_INIT_GAMECONTROLLER)) { - fprintf(stderr, "Failed to initialize SDL\n"); + logError("Failed to initialize SDL\n"); return false; } for (int i = 0; i < MAX_GAMEPADS; i++) { openControllers[i] = NULL; } - + Uint32 flags; if (headless) flags = (gfx == SOFTWARE ? 0 : SDL_WINDOW_OPENGL) | SDL_WINDOW_HIDDEN; @@ -183,18 +183,18 @@ bool platformInit(int reqW, int reqH, const char *title, bool headless) { #if SDL_VERSION_ATLEAST(2, 0, 1) flags |= SDL_WINDOW_ALLOW_HIGHDPI; #endif - + window = tryOpenWindow(reqW, reqH, title, flags); - + if (!window && gfx != SOFTWARE) { - fprintf(stderr, "Fatal: Could not open window: %s\n", SDL_GetError()); + logError("Fatal: Could not open window: %s\n", SDL_GetError()); return false; } - + if (!window && gfx == SOFTWARE) { SDL_DisplayMode mode; if (SDL_GetDisplayMode(0, 0, &mode) == 0) { - fprintf(stderr, "Warning: %dx%d unavailable, falling back to %dx%d: %s\n", + logWarn("%dx%d unavailable, falling back to %dx%d: %s\n", reqW, reqH, mode.w, mode.h, SDL_GetError()); reqW = mode.w; reqH = mode.h; @@ -208,7 +208,7 @@ bool platformInit(int reqW, int reqH, const char *title, bool headless) { } } if (!window) { - fprintf(stderr, "Fatal: Could not set any video mode: %s\n", SDL_GetError()); + logError("Fatal: Could not set any video mode: %s\n", SDL_GetError()); return false; } if (gfx != SOFTWARE) { @@ -222,9 +222,9 @@ bool platformInit(int reqW, int reqH, const char *title, bool headless) { // init gamepad mappings const char* dbPath = "gamecontrollerdb.txt"; if (SDL_GameControllerAddMappingsFromFile(dbPath) >= 0) { - fprintf(stderr, "Gamepad: Loaded SDL gamecontroller mappings successfully\n"); + logInfo("Gamepad: Loaded SDL gamecontroller mappings successfully\n"); } else { - fprintf(stderr, "Gamepad: SDL gamecontrollerdb.txt not found at %s or failed to load, using defaults\n", dbPath); + logWarn("Gamepad: SDL gamecontrollerdb.txt not found at %s or failed to load, using defaults\n", dbPath); } return true; diff --git a/src/desktop/backends/sdl3.c b/src/desktop/backends/sdl3.c index 7cf229eb8..19a99914e 100644 --- a/src/desktop/backends/sdl3.c +++ b/src/desktop/backends/sdl3.c @@ -48,7 +48,7 @@ static SDL_Window *tryOpenWindow(int reqW, int reqH, const char* title, Uint32 f SDL_GL_SetAttribute(SDL_GL_CONTEXT_MAJOR_VERSION, 1); SDL_GL_SetAttribute(SDL_GL_CONTEXT_MINOR_VERSION, 1); SDL_GL_SetAttribute(SDL_GL_CONTEXT_PROFILE_MASK, 0); - + SDL_Window *newWindow = SDL_CreateWindow( title, reqW, @@ -78,16 +78,16 @@ static SDL_Window *tryOpenWindow(int reqW, int reqH, const char* title, Uint32 f if (GLCommon_versions[i].gles) { SDL_GL_SetAttribute(SDL_GL_CONTEXT_PROFILE_MASK, SDL_GL_CONTEXT_PROFILE_ES); - } else { + } else { if (GLCommon_versions[i].major >= 3) { if (GLCommon_versions[i].major == 3 && GLCommon_versions[i].minor == 2) { contextFlags |= SDL_GL_CONTEXT_FORWARD_COMPATIBLE_FLAG; } } else { - SDL_GL_SetAttribute(SDL_GL_CONTEXT_PROFILE_MASK, 0); + SDL_GL_SetAttribute(SDL_GL_CONTEXT_PROFILE_MASK, 0); } } - + SDL_GL_SetAttribute(SDL_GL_CONTEXT_FLAGS, contextFlags); newWindow = SDL_CreateWindow( @@ -103,7 +103,7 @@ static SDL_Window *tryOpenWindow(int reqW, int reqH, const char* title, Uint32 f } SDL_DestroyWindow(newWindow); } - + } return NULL; } @@ -149,7 +149,7 @@ static bool platformGetWindowFocus(void) { bool platformInit(int reqW, int reqH, const char *title, bool headless) { // Init SDL if (!SDL_Init(SDL_INIT_VIDEO|SDL_INIT_GAMEPAD)) { - fprintf(stderr, "Failed to initialize SDL\n"); + logError("Failed to initialize SDL\n"); return false; } @@ -162,27 +162,27 @@ bool platformInit(int reqW, int reqH, const char *title, bool headless) { fbHeight = reqH; window = tryOpenWindow(fbWidth, fbHeight, title, flags); - + if (!window && gfx != SOFTWARE) { - fprintf(stderr, "Fatal: Could not open window: %s\n", SDL_GetError()); + logError("Fatal: Could not open window: %s\n", SDL_GetError()); return false; } - + if (!window && gfx == SOFTWARE) { const SDL_DisplayMode *mode = SDL_GetDesktopDisplayMode(SDL_GetPrimaryDisplay()); if (mode != NULL) { - SDL_LogWarn(SDL_LOG_CATEGORY_APPLICATION, - "Warning: %dx%d unavailable, falling back to %dx%d: %s", + SDL_LogWarn(SDL_LOG_CATEGORY_APPLICATION, + "%dx%d unavailable, falling back to %dx%d: %s", fbWidth, fbHeight, mode->w, mode->h, SDL_GetError()); - + fbWidth = mode->w; fbHeight = mode->h; - + window = SDL_CreateWindow(title, fbWidth, fbHeight, flags); } } if (!window) { - fprintf(stderr, "Fatal: Could not set any video mode: %s\n", SDL_GetError()); + logError("Fatal: Could not set any video mode: %s\n", SDL_GetError()); return false; } if (gfx != SOFTWARE) { diff --git a/src/desktop/main.c b/src/desktop/main.c index d55cb3bc1..91b25b005 100644 --- a/src/desktop/main.c +++ b/src/desktop/main.c @@ -5,6 +5,7 @@ #include "platformdefs.h" #include +#include #include #include #include @@ -114,7 +115,7 @@ static bool platformInitGlad(void) { if (!glGetString) return 0; - fprintf(stderr, "OpenGL Version: %s\n", (const char*)glGetString(GL_VERSION)); + logInfo("OpenGL Version: %s\n", (const char*)glGetString(GL_VERSION)); GLVer ver = GLCommon_getGLVersion(); if (ver.isGLES) { @@ -164,7 +165,7 @@ static void APIENTRY glDebugCallback(GLenum source, GLenum type, GLuint id, GLen default: severityStr = "Unknown"; break; } - fprintf(stderr, "[OpenGL %s] id=%u Type: %s; Severity: %s; Message: %.*s\n", sourceStr, id, typeStr, severityStr, (int) length, message); + logInfo("[OpenGL %s] id=%u Type: %s; Severity: %s; Message: %.*s\n", sourceStr, id, typeStr, severityStr, (int) length, message); } static void installGLDebugCallback(void) { @@ -254,6 +255,9 @@ typedef struct { #ifdef ENABLE_VM_OPCODE_PROFILER bool opcodeProfiler; #endif + bool disableFileLog; + const char* logFile; + bool disableLogColours; } CommandLineArgs; typedef struct { const char* name; YoYoOperatingSystem value; } OsTypeNameEntry; @@ -302,6 +306,55 @@ static void printOsTypeNames(FILE* out) { } } +static bool logToFile = false; +static FILE* logFileHandle = nullptr; + +static bool logColour; + +#ifndef va_copy +#define va_copy(d, s) ((d) = (s)) +#endif + +void platformLog(const logType type, const char *format, va_list va) { + FILE *out = stderr; + const char* colourPrefix = ANSI_COLOUR_CODE_RESET; + const char* textPrefix = ""; + switch (type) { + case LOG_TYPE_NORMAL: + out = stdout; + break; + case LOG_TYPE_WARNING: + colourPrefix = ANSI_COLOUR_CODE_BOLD_YELLOW; + textPrefix = "Warning: "; + break; + case LOG_TYPE_ERROR: + colourPrefix = ANSI_COLOUR_CODE_BOLD_RED; + textPrefix = "Error: "; + break; + case LOG_TYPE_DEBUG: + colourPrefix = ANSI_COLOUR_CODE_BOLD_PURPLE; + textPrefix = "Debug: "; + break; + } + + va_list va2; + va_copy(va2, va); + + print: + if (logColour) fputs(colourPrefix, out); + fputs(textPrefix, out); + vfprintf(out, format, va2); + if (logColour) fputs(ANSI_COLOUR_CODE_RESET, out); + + if (logToFile && out != logFileHandle && logFileHandle) { + out = logFileHandle; + va_copy(va2, va); + goto print; + } + + va_end(va2); +} + // Resolves the window size for the specified operating system. // The "--window-size" argument takes precedence over the default resolution for each platform. static void resolveWindowSize(const CommandLineArgs* args, uint32_t gen8Width, uint32_t gen8Height, int32_t* outW, int32_t* outH) { @@ -383,8 +436,7 @@ static char** extractRunnerArguments(char* rawArguments) { } static void printUsage(const char *argv0) { - fprintf( - stderr, + logInfo( "Usage: %s \n" " --help - Show this message\n" " --screenshot - Specify the filename for screenshots\n" @@ -436,6 +488,10 @@ static void printUsage(const char *argv0) { " --game-args - Arguments to pass to the game\n" " --lazy-textures - Load textures into VRAM on first use, improving startup times\n" " --load-type - Specify how data.win is loaded, per-chunk or all at once\n" + " --disable-file-log - Disable logging to a file\n" + " --log-file - File to log to\n" + " --disable-log-colours - Disable colours for warning, error, and debug logs\n" + " --disable-log-colors - Same as --disable-log-colours, but different spelling\n" #ifdef EABLE_VM_OPCODE_PROFILER " --profile-opcodes - Rank which GML opcodes were executed the most\n" #endif @@ -495,6 +551,10 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) {"game-args", required_argument, nullptr, 'N'}, {"lazy-textures", no_argument, nullptr, 'L'}, {"load-type", required_argument, nullptr, 999}, + {"disable-file-log", no_argument, nullptr, 1001}, + {"log-file", required_argument, nullptr, 1002}, + {"disable-log-colours", no_argument, nullptr, 1003}, + {"disable-log-colors", no_argument, nullptr, 1003}, #ifdef ENABLE_VM_OPCODE_PROFILER {"profile-opcodes", no_argument, nullptr, 'Q'}, #endif @@ -532,7 +592,7 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) char* endPtr; int frame = strtol(optarg, &endPtr, 10); if (*endPtr != '\0' || 0 > frame) { - fprintf(stderr, "Error: Invalid frame number '%s'\n", optarg); + logError("Invalid frame number '%s'\n", optarg); exit(1); } @@ -546,7 +606,7 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) char* endPtr; int frame = strtol(optarg, &endPtr, 10); if (*endPtr != '\0' || 0 > frame) { - fprintf(stderr, "Error: Invalid frame number '%s' for --screenshot-surfaces-at-frame\n", optarg); + logError("Invalid frame number '%s' for --screenshot-surfaces-at-frame\n", optarg); exit(1); } hmput(args->screenshotSurfacesFrames, frame, true); @@ -614,7 +674,7 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) char* endPtr; int frame = strtol(optarg, &endPtr, 10); if (*endPtr != '\0' || 0 > frame) { - fprintf(stderr, "Error: Invalid frame number '%s' for --exit-at-frame\n", optarg); + logError("Invalid frame number '%s' for --exit-at-frame\n", optarg); exit(1); } args->exitAtFrame = frame; @@ -624,7 +684,7 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) char* endPtr; int frame = strtol(optarg, &endPtr, 10); if (*endPtr != '\0' || 0 > frame) { - fprintf(stderr, "Error: Invalid frame number '%s' for --trace-bytecode-after-frame\n", optarg); + logError("Invalid frame number '%s' for --trace-bytecode-after-frame\n", optarg); exit(1); } args->traceBytecodeAfterFrame = frame; @@ -634,7 +694,7 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) char* endPtr; int frame = strtol(optarg, &endPtr, 10); if (*endPtr != '\0' || 0 > frame) { - fprintf(stderr, "Error: Invalid frame number '%s' for --dump-frame\n", optarg); + logError("Invalid frame number '%s' for --dump-frame\n", optarg); exit(1); } hmput(args->dumpFrames, frame, true); @@ -644,7 +704,7 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) char* endPtr; int frame = strtol(optarg, &endPtr, 10); if (*endPtr != '\0' || 0 > frame) { - fprintf(stderr, "Error: Invalid frame number '%s' for --dump-frame-json\n", optarg); + logError("Invalid frame number '%s' for --dump-frame-json\n", optarg); exit(1); } hmput(args->dumpJsonFrames, frame, true); @@ -657,7 +717,7 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) char* endPtr; double speed = strtod(optarg, &endPtr); if (*endPtr != '\0' || speed <= 0.0) { - fprintf(stderr, "Error: Invalid speed multiplier '%s' for --speed (must be > 0)\n", optarg); + logError("Invalid speed multiplier '%s' for --speed (must be > 0)\n", optarg); exit(1); } args->speedMultiplier = speed; @@ -667,7 +727,7 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) char* endPtr; double speed = strtod(optarg, &endPtr); if (*endPtr != '\0' || speed <= 0.0) { - fprintf(stderr, "Error: Invalid speed '%s' for --fast-forward-speed (must be > 0)\n", optarg); + logError("Invalid speed '%s' for --fast-forward-speed (must be > 0)\n", optarg); exit(1); } args->fastForwardSpeed = speed; @@ -698,7 +758,7 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) char* endPtr; int seedVal = strtol(optarg, &endPtr, 10); if (*endPtr != '\0') { - fprintf(stderr, "Error: Invalid seed value '%s' for --seed\n", optarg); + logError("Invalid seed value '%s' for --seed\n", optarg); exit(1); } args->seed = seedVal; @@ -715,7 +775,7 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) char* endPtr; int framesBetween = strtol(optarg, &endPtr, 10); if (*endPtr != '\0' || framesBetween <= 0) { - fprintf(stderr, "Error: Invalid frame count '%s' for --profile-gml-scripts (must be > 0)\n", optarg); + logError("Invalid frame count '%s' for --profile-gml-scripts (must be > 0)\n", optarg); exit(1); } args->profilerFramesBetween = framesBetween; @@ -739,16 +799,16 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) #endif case 'O': if (!parseOsTypeArg(optarg, &args->osType)) { - fprintf(stderr, "Error: Invalid --os-type value '%s' (expected: ", optarg); + logError("Invalid --os-type value '%s' (expected: ", optarg); printOsTypeNames(stderr); - fprintf(stderr, ")\n"); + logError(")\n"); exit(1); } break; case 'w': { int32_t w = 0, h = 0; if (sscanf(optarg, "%dx%d", &w, &h) != 2 || 0 >= w || 0 >= h) { - fprintf(stderr, "Error: Invalid --window-size value '%s' (expected WxH, e.g. 960x544)\n", optarg); + logError("Invalid --window-size value '%s' (expected WxH, e.g. 960x544)\n", optarg); exit(1); } args->windowWidth = w; @@ -763,7 +823,7 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) } else if (strcmp(optarg, "load-per-chunk") == 0) { args->loadType = DATAWINLOADTYPE_LOAD_PER_CHUNK; } else { - fprintf(stderr, "Error: Unknown load type '%s'\n", optarg); + logError("Unknown load type '%s'\n", optarg); exit(1); } break; @@ -781,11 +841,20 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) } else if ((ratio = strtod(optarg, &endPtr)), *endPtr == '\0' && ratio > 0.0) { args->widescreenAspect = (float) ratio; } else { - fprintf(stderr, "Error: Invalid --widescreen-hack value '%s' (expected W:H like 16:9, or a decimal like 1.7778)\n", optarg); + logError("Invalid --widescreen-hack value '%s' (expected W:H like 16:9, or a decimal like 1.7778)\n", optarg); exit(1); } break; } + case 1001: + args->disableFileLog = true; + break; + case 1002: + args->logFile = optarg; + break; + case 1003: + args->disableLogColours = true; + break; default: printUsage(argv[0]); exit(1); @@ -793,24 +862,24 @@ static void parseCommandLineArgs(CommandLineArgs* args, int argc, char* argv[]) } if (optind >= argc) { - fprintf(stderr, "Usage: %s \n", argv[0]); + printUsage(argv[0]); exit(1); } args->dataWinPath = argv[optind]; if (hmlen(args->screenshotFrames) > 0 && args->screenshotPattern == nullptr) { - fprintf(stderr, "Error: --screenshot-at-frame requires --screenshot to be set\n"); + logError("--screenshot-at-frame requires --screenshot to be set\n"); exit(1); } if (hmlen(args->screenshotSurfacesFrames) > 0 && args->screenshotSurfacesPattern == nullptr) { - fprintf(stderr, "Error: --screenshot-surfaces-at-frame requires --screenshot-surfaces to be set\n"); + logError("--screenshot-surfaces-at-frame requires --screenshot-surfaces to be set\n"); exit(1); } if (args->headless && args->speedMultiplier != 1.0) { - fprintf(stderr, "You can't set the speed multiplier while running in headless mode! Headless mode always run in real time\n"); + logError("You can't set the speed multiplier while running in headless mode! Headless mode always run in real time\n"); exit(1); } } @@ -846,7 +915,7 @@ static void writeFramebufferAsPng(GLuint fbo, int width, int height, const char* int stride = width * 4; unsigned char* pixels = (unsigned char *)safeMalloc(stride * height); if (pixels == nullptr) { - fprintf(stderr, "Error: Failed to allocate memory for %s (%dx%d)\n", logPrefix, width, height); + logWarn("Failed to allocate memory for %s (%dx%d)\n", logPrefix, width, height); return; } @@ -866,7 +935,7 @@ static void writeFramebufferAsPng(GLuint fbo, int width, int height, const char* } free(pixels); - fprintf(stderr, "%s: %s (%dx%d)\n", logPrefix, filename, width, height); + logInfo("%s: %s (%dx%d)\n", logPrefix, filename, width, height); } static void captureScreenshot(GLuint fbo, const char* filenamePattern, int frameNumber, int width, int height, bool flipY) { @@ -1006,6 +1075,16 @@ int main(int argc, char* argv[]) { CommandLineArgs args; parseCommandLineArgs(&args, argc, argv); + logToFile = !args.disableFileLog; + if (logToFile) { + logFileHandle = fopen(args.logFile ? args.logFile : "./butterscotch.log", "w"); + if (logFileHandle) { + setbuf(logFileHandle, NULL); + } + } + + logColour = !args.disableLogColours; + char* currentDataWinPath = safeStrdup(args.dataWinPath); char** currentGameArgs = args.gameArgs; repeat(arrlen(args.gameArgs), i) { @@ -1018,7 +1097,7 @@ int main(int argc, char* argv[]) { int32_t inputFrameCount = 0; while (true) { - fprintf(stderr, "Loading %s...\n", args.dataWinPath); + logInfo("Loading %s...\n", args.dataWinPath); DataWinParserOptions options = {0}; options.parseGen8 = true; @@ -1055,12 +1134,12 @@ int main(int argc, char* argv[]) { DataWin* dataWin = DataWin_parse(currentDataWinPath, options); Gen8* gen8 = &dataWin->gen8; - fprintf(stderr, "Loaded \"%s\" (%d) successfully! [WAD Version %u / GameMaker version %u.%u.%u.%u]\n", gen8->name, gen8->gameID, gen8->wadVersion, dataWin->detectedFormat.major, dataWin->detectedFormat.minor, dataWin->detectedFormat.release, dataWin->detectedFormat.build); + logInfo("Loaded \"%s\" (%d) successfully! [WAD Version %u / GameMaker version %u.%u.%u.%u]\n", gen8->name, gen8->gameID, gen8->wadVersion, dataWin->detectedFormat.major, dataWin->detectedFormat.minor, dataWin->detectedFormat.release, dataWin->detectedFormat.build); #ifdef HAVE_MALLINFO2 { struct mallinfo2 mi = mallinfo2(); - fprintf(stderr, "Memory after data.win parsing: used=%zu bytes (%.1f KB)\n", mi.uordblks, mi.uordblks / 1024.0f); + logInfo("Memory after data.win parsing: used=%zu bytes (%.1f KB)\n", mi.uordblks, mi.uordblks / 1024.0f); } #endif @@ -1083,7 +1162,7 @@ int main(int argc, char* argv[]) { if (args.hasSeed) { srand((unsigned int) args.seed); vm->hasFixedSeed = true; - fprintf(stderr, "Using fixed RNG seed: %d\n", args.seed); + logInfo("Using fixed RNG seed: %d\n", args.seed); } if (args.printRooms) { @@ -1091,7 +1170,7 @@ int main(int argc, char* argv[]) { // reflects what each room contains without keeping all of them resident simultaneously. forEachIndexed(Room, room, idx, dataWin->room.rooms, dataWin->room.count) { if (!room->present) { - printf("[%d] \n", (int)idx); + logInfo("[%d] \n", (int)idx); continue; } bool loadedHere = false; @@ -1100,15 +1179,15 @@ int main(int argc, char* argv[]) { loadedHere = true; } - printf("[%d] %s ()\n", (int)idx, room->name); + logInfo("[%d] %s ()\n", (int)idx, room->name); forEachIndexed(RoomGameObject, roomGameObject, idx2, room->gameObjects, room->gameObjectCount) { if (roomGameObject->objectDefinition < 0 || (uint32_t) roomGameObject->objectDefinition >= dataWin->objt.count) { - printf(" [%d] (x=%d,y=%d)\n", (int)idx2, roomGameObject->x, roomGameObject->y); + logInfo(" [%d] (x=%d,y=%d)\n", (int)idx2, roomGameObject->x, roomGameObject->y); continue; } GameObject* gameObject = &dataWin->objt.objects[roomGameObject->objectDefinition]; - printf( + logInfo( " [%d] %s (x=%d,y=%d,persistent=%d,solid=%d,spriteId=%d,preCreateCode=%d,creationCode=%d)\n", (int)idx2, gameObject->name, @@ -1137,22 +1216,22 @@ int main(int argc, char* argv[]) { repeat(OBJT_EVENT_TYPE_COUNT, e) { totalEvents += obj->eventLists[e].eventCount; } - printf("[%u] %s:\n", (unsigned int)idx, obj->name); + logInfo("[%u] %s:\n", (unsigned int)idx, obj->name); if (obj->parentId >= 0 && (uint32_t) obj->parentId < dataWin->objt.count) { - printf(" Parent: %s (%d)\n", dataWin->objt.objects[obj->parentId].name, obj->parentId); + logInfo(" Parent: %s (%d)\n", dataWin->objt.objects[obj->parentId].name, obj->parentId); } else { - printf(" Parent: none\n"); + logInfo(" Parent: none\n"); } if (obj->spriteId >= 0 && (uint32_t) obj->spriteId < dataWin->sprt.count) { - printf(" Sprite: %s (%d)\n", dataWin->sprt.sprites[obj->spriteId].name, obj->spriteId); + logInfo(" Sprite: %s (%d)\n", dataWin->sprt.sprites[obj->spriteId].name, obj->spriteId); } else { - printf(" Sprite: none\n"); + logInfo(" Sprite: none\n"); } - printf(" Solid: %d\n", obj->solid); - printf(" Persistent: %d\n", obj->persistent); - printf(" Visible: %d\n", obj->visible); - printf(" Depth: %d\n", obj->depth); - printf(" Events (%u):\n", totalEvents); + logInfo(" Solid: %d\n", obj->solid); + logInfo(" Persistent: %d\n", obj->persistent); + logInfo(" Visible: %d\n", obj->visible); + logInfo(" Depth: %d\n", obj->depth); + logInfo(" Events (%u):\n", totalEvents); repeat(OBJT_EVENT_TYPE_COUNT, e) { ObjectEventList* list = &obj->eventLists[e]; repeat(list->eventCount, eIdx) { @@ -1160,10 +1239,10 @@ int main(int argc, char* argv[]) { const char* eventName = Runner_getEventName((int32_t) e, (int32_t) event->eventSubtype); int32_t codeId = -1; if (event->actionCount > 0) codeId = event->actions[0].codeId; - printf(" %s:\n", eventName); - printf(" Sub Type: %u\n", event->eventSubtype); - printf(" Code ID: %d\n", codeId); - printf(" Actions: %u\n", event->actionCount); + logInfo(" %s:\n", eventName); + logInfo(" Sub Type: %u\n", event->eventSubtype); + logInfo(" Code ID: %d\n", codeId); + logInfo(" Actions: %u\n", event->actionCount); } } } @@ -1174,25 +1253,25 @@ int main(int argc, char* argv[]) { if (args.printShaders) { forEachIndexed(Shader, shader, idx, dataWin->shdr.shaders, dataWin->shdr.count) { - printf("[%u] %s:\n", (unsigned int)idx, shader->name); - printf("GLSL Vertex Shader:\n"); + logInfo("[%u] %s:\n", (unsigned int)idx, shader->name); + logInfo("GLSL Vertex Shader:\n"); char* glslVertex = collapseNewlines(shader->glsl_Vertex); - printf("%s\n", glslVertex); + logInfo("%s\n", glslVertex); free(glslVertex); - printf("GLSL Fragment Shader:\n"); + logInfo("GLSL Fragment Shader:\n"); char* glslFragment = collapseNewlines(shader->glsl_Fragment); - printf("%s\n", glslFragment); + logInfo("%s\n", glslFragment); free(glslFragment); - printf("GLSL ES Vertex Shader:\n"); + logInfo("GLSL ES Vertex Shader:\n"); char* glslESVertex = collapseNewlines(shader->glslES_Vertex); - printf("%s\n", glslESVertex); + logInfo("%s\n", glslESVertex); free(glslESVertex); - printf("GLSL ES Fragment Shader:\n"); + logInfo("GLSL ES Fragment Shader:\n"); char* glslESFragment = collapseNewlines(shader->glslES_Fragment); - printf("%s\n", glslESFragment); + logInfo("%s\n", glslESFragment); free(glslESFragment); } VM_free(vm); @@ -1202,7 +1281,7 @@ int main(int argc, char* argv[]) { if (args.printDeclaredFunctions) { repeat(hmlen(vm->codeIndexByName), i) { - printf("[%d] %s\n", vm->codeIndexByName[i].value, vm->codeIndexByName[i].key); + logInfo("[%d] %s\n", vm->codeIndexByName[i].value, vm->codeIndexByName[i].key); } VM_free(vm); DataWin_free(dataWin); @@ -1211,7 +1290,7 @@ int main(int argc, char* argv[]) { if (args.printUnknownFunctions) { uint32_t unimplementedCount = 0; - fprintf(stderr, "Unknown Functions:\n"); + logInfo("Unknown Functions:\n"); repeat(dataWin->func.functionCount, i) { const char* name = dataWin->func.functions[i].name; if (name == nullptr) @@ -1225,14 +1304,14 @@ int main(int argc, char* argv[]) { if (VM_findBuiltin(vm, name) != nullptr) continue; - fprintf(stderr, "- %s\n", name); + logInfo("- %s\n", name); unimplementedCount++; } if (unimplementedCount == 0) { - fprintf(stderr, "All %u referenced functions are implemented! :3\n", dataWin->func.functionCount); + logInfo("All %u referenced functions are implemented! :3\n", dataWin->func.functionCount); } else { - fprintf(stderr, "%u unknown function(s) out of %u referenced\n", unimplementedCount, dataWin->func.functionCount); + logInfo("%u unknown function(s) out of %u referenced\n", unimplementedCount, dataWin->func.functionCount); } VM_free(vm); DataWin_free(dataWin); @@ -1252,7 +1331,7 @@ int main(int argc, char* argv[]) { if (idx >= 0) { VM_disassemble(vm, vm->codeIndexByName[idx].value); } else { - fprintf(stderr, "Error: Script '%s' not found in funcMap\n", name); + logWarn("Script '%s' not found in funcMap\n", name); } } } @@ -1289,31 +1368,31 @@ int main(int argc, char* argv[]) { else if (strcmp(args.renderer, "software") == 0) gfx = SOFTWARE; else { - fprintf(stderr, "Unknown renderer: %s!\n", args.renderer); + logError("Unknown renderer: %s!\n", args.renderer); return 1; } #ifndef ENABLE_LEGACY_GL if (gfx == LEGACY_GL) { - fprintf(stderr, "The legacy gl renderer is not available in this build!\n"); + logError("The legacy gl renderer is not available in this build!\n"); return 0; } #endif #ifndef ENABLE_MODERN_GL if (gfx == MODERN_GL) { - fprintf(stderr, "The modern gl renderer is not available in this build!\n"); + logError("The modern gl renderer is not available in this build!\n"); return 0; } #endif #ifndef ENABLE_SW_RENDERER if (gfx == SOFTWARE) { - fprintf(stderr, "The software renderer is not available in this build!\n"); + logError("The software renderer is not available in this build!\n"); return 0; } #endif if (gfx != MODERN_GL && hmlen(args.screenshotSurfacesFrames)) { - fprintf(stderr, "You can only use --screenshot-surfaces with the modern gl renderer!\n"); + logError("You can only use --screenshot-surfaces with the modern gl renderer!\n"); return 0; } @@ -1335,7 +1414,7 @@ int main(int argc, char* argv[]) { if (gfx == LEGACY_GL || gfx == MODERN_GL) { #endif if (!platformInitGlad()) { - fprintf(stderr, "Failed to initialize GLAD\n"); + logError("Failed to initialize GLAD\n"); platformExit(); DataWin_free(dataWin); freeCommandLineArgs(&args); @@ -1377,7 +1456,7 @@ int main(int argc, char* argv[]) { } #endif if (!renderer) { - fprintf(stderr, "Failed to initialize a renderer\n"); + logError("Failed to initialize a renderer\n"); platformExit(); DataWin_free(dataWin); freeCommandLineArgs(&args); @@ -1504,7 +1583,7 @@ int main(int argc, char* argv[]) { // Pause if (RunnerKeyboard_checkPressed(runner->keyboard, 'P')) { debugPaused = !debugPaused; - fprintf(stderr, "Debug: %s\n", debugPaused ? "Paused" : "Resumed"); + logDebug("%s\n", debugPaused ? "Paused" : "Resumed"); } } @@ -1512,7 +1591,7 @@ int main(int argc, char* argv[]) { bool shouldStep = true; if (runner->debugMode && debugPaused) { shouldStep = RunnerKeyboard_checkPressed(runner->keyboard, 'O'); - if (shouldStep) fprintf(stderr, "Debug: Frame advance (frame %d)\n", runner->frameCount); + if (shouldStep) logDebug("Frame advance (frame %d)\n", runner->frameCount); } uint64_t frameStartTime = 0; @@ -1520,7 +1599,7 @@ int main(int argc, char* argv[]) { if (shouldStep) { if (args.traceFrames) { frameStartTime = nowNanos(); - fprintf(stderr, "Frame %d (Start)\n", runner->frameCount); + logInfo("Frame %d (Start)\n", runner->frameCount); } // Process input recording/playback (must happen after platformHandleEvents, before Runner_step) @@ -1533,7 +1612,7 @@ int main(int argc, char* argv[]) { int32_t nextIdx = dw->gen8.roomOrder[runner->currentRoomOrderPosition + 1]; runner->pendingRoom = nextIdx; runner->audioSystem->vtable->stopAll(runner->audioSystem); - fprintf(stderr, "Debug: Going to next room -> %s\n", dw->room.rooms[nextIdx].name); + logDebug("Going to next room -> %s\n", dw->room.rooms[nextIdx].name); } } @@ -1544,18 +1623,18 @@ int main(int argc, char* argv[]) { int32_t prevIdx = dw->gen8.roomOrder[runner->currentRoomOrderPosition - 1]; runner->pendingRoom = prevIdx; runner->audioSystem->vtable->stopAll(runner->audioSystem); - fprintf(stderr, "Debug: Going to previous room -> %s\n", dw->room.rooms[prevIdx].name); + logDebug("Going to previous room -> %s\n", dw->room.rooms[prevIdx].name); } } // Dump runner state to console if (RunnerKeyboard_checkPressed(runner->keyboard, VK_F12)) { - fprintf(stderr, "Debug: Dumping runner state at frame %d\n", runner->frameCount); + logDebug("Dumping runner state at frame %d\n", runner->frameCount); Runner_dumpState(runner); } if (RunnerKeyboard_checkPressed(runner->keyboard, VK_F11)) { - fprintf(stderr, "Debug: Dumping runner state at frame %d\n", runner->frameCount); + logDebug("Dumping runner state at frame %d\n", runner->frameCount); char* json = Runner_dumpStateJson(runner); if (args.dumpJsonFilePattern != nullptr) { @@ -1566,12 +1645,12 @@ int main(int argc, char* argv[]) { fwrite(json, 1, strlen(json), f); fputc('\n', f); fclose(f); - printf("JSON dump saved: %s\n", filename); + logInfo("JSON dump saved: %s\n", filename); } else { - fprintf(stderr, "Error: Could not write JSON dump to '%s'\n", filename); + logWarn("Could not write JSON dump to '%s'\n", filename); } } else { - printf("%s\n", json); + logInfo("%s\n", json); } free(json); @@ -1580,7 +1659,7 @@ int main(int argc, char* argv[]) { // Toggle the collision mask debug overlay if (RunnerKeyboard_checkPressed(runner->keyboard, VK_F2)) { debugShowCollisionMasks = !debugShowCollisionMasks; - fprintf(stderr, "Debug: Collision mask overlay %s!\n", debugShowCollisionMasks ? "enabled" : "disabled"); + logDebug("Collision mask overlay %s!\n", debugShowCollisionMasks ? "enabled" : "disabled"); } // Enable free cam @@ -1590,7 +1669,7 @@ int main(int argc, char* argv[]) { runner->freeCamZoom = 1.0f; freeCamActive = !freeCamActive; - fprintf(stderr, "Debug: Free cam %s!\n", freeCamActive ? "enabled" : "disabled"); + logDebug("Free cam %s!\n", freeCamActive ? "enabled" : "disabled"); } if (freeCamActive) { @@ -1616,7 +1695,7 @@ int main(int argc, char* argv[]) { int32_t interactVarId = shget(runner->vmContext->varNameMap, "interact"); Instance_setSelfVar(runner->vmContext->globalScopeInstance, interactVarId, RValue_makeInt32(0)); - printf("Changed global.interact [%d] value!\n", interactVarId); + logInfo("Changed global.interact [%d] value!\n", interactVarId); } bool currentKeyDown[GML_KEY_COUNT]; @@ -1646,7 +1725,7 @@ int main(int argc, char* argv[]) { if (args.profilerFramesBetween > 0 && runner->frameCount > 0 && runner->frameCount % args.profilerFramesBetween == 0) { char* profilerReport = Profiler_createReport(vm->profiler, 20, args.profilerFramesBetween); if (profilerReport != nullptr) { - fprintf(stderr, "%s\n", profilerReport); + logInfo("%s\n", profilerReport); free(profilerReport); } Profiler_reset(vm->profiler); @@ -1674,12 +1753,12 @@ int main(int argc, char* argv[]) { fwrite(json, 1, strlen(json), f); fputc('\n', f); fclose(f); - printf("JSON dump saved: %s\n", filename); + logInfo("JSON dump saved: %s\n", filename); } else { - fprintf(stderr, "Error: Could not write JSON dump to '%s'\n", filename); + logWarn("Could not write JSON dump to '%s'\n", filename); } } else { - printf("%s\n", json); + logInfo("%s\n", json); } free(json); } @@ -1777,13 +1856,13 @@ int main(int argc, char* argv[]) { #endif if (args.exitAtFrame >= 0 && runner->frameCount >= args.exitAtFrame) { - printf("Exiting at frame %d (--exit-at-frame)\n", runner->frameCount); + logInfo("Exiting at frame %d (--exit-at-frame)\n", runner->frameCount); shouldWindowClose = true; } if (shouldStep && args.traceFrames) { double frameElapsedMs = (nowNanos() - frameStartTime) / 1000000.0; - fprintf(stderr, "Frame %d (End, %.2f ms)\n", runner->frameCount, frameElapsedMs); + logInfo("Frame %d (End, %.2f ms)\n", runner->frameCount, frameElapsedMs); } // Only swap when there isn't a room change to match the original runner. @@ -1795,9 +1874,9 @@ int main(int argc, char* argv[]) { if (RunnerKeyboard_checkPressed(runner->keyboard, VK_BACKSPACE)) { size_t bytes_used = get_used_memory(); if (bytes_used == 0) - fprintf(stderr, "Unable to get memory usage\n"); + logWarn("Unable to get memory usage\n"); else - fprintf(stderr, "Memory use right now: %zu bytes (%.1f MB)\n", bytes_used, bytes_used / 1024.0f / 1024.0f); + logInfo("Memory use right now: %zu bytes (%.1f MB)\n", bytes_used, bytes_used / 1024.0f / 1024.0f); } // Limit frame rate to room speed (skip in headless mode for max speed!!) @@ -1852,7 +1931,7 @@ int main(int argc, char* argv[]) { free(currentGameArgs[i]); } arrfree(currentGameArgs); - fprintf(stderr, "Bye! :3\n"); + logInfo("Bye! :3\n"); #ifdef _WIN32 timeEndPeriod(1); #endif @@ -1882,7 +1961,7 @@ int main(int argc, char* argv[]) { } if (dataWinFilename == nullptr) { - fprintf(stderr, "Runner: Launch parameters '%s' did not contain a '-game ' entry! Shutting down...\n", nextLaunchParameters); + logError("Runner: Launch parameters '%s' did not contain a '-game ' entry! Shutting down...\n", nextLaunchParameters); free(nextWorkingDirectory); free(nextLaunchParameters); freeCommandLineArgs(&args); @@ -1940,4 +2019,8 @@ int main(int argc, char* argv[]) { arrfree(newArguments); } } + + if (logFileHandle) { + fclose(logFileHandle); + } } diff --git a/src/event_table.c b/src/event_table.c index 74bccab96..4bcf34d42 100644 --- a/src/event_table.c +++ b/src/event_table.c @@ -115,7 +115,7 @@ void ResolvedEventTable_build(ResolvedEventTable* outTable, DataWin* dw, const E int32_t slotCount = slotMap->slotCount; if (objectCount > MAX_EVENT_TABLE_OBJECT_COUNT) { - fprintf(stderr, "ResolvedEventTable: objectCount=%d exceeds max %d!\n", objectCount, MAX_EVENT_TABLE_OBJECT_COUNT); + logError("ResolvedEventTable: objectCount=%d exceeds max %d!\n", objectCount, MAX_EVENT_TABLE_OBJECT_COUNT); abort(); } diff --git a/src/gl/gl_renderer.c b/src/gl/gl_renderer.c index 60a42ca9f..eaa1c0b08 100644 --- a/src/gl/gl_renderer.c +++ b/src/gl/gl_renderer.c @@ -86,7 +86,7 @@ static GLuint compileShader(GLenum type, const char* source, bool* ok) { if (!success) { char infoLog[512]; glGetShaderInfoLog(shader, sizeof(infoLog), nullptr, infoLog); - fprintf(stderr, "GL: Shader compilation failed: %s\n", infoLog); + logError("GL: Shader compilation failed: %s\n", infoLog); *ok = false; return 0; } @@ -110,11 +110,11 @@ static GLuint linkProgram(const char* name, uint32_t vertexAttributeCount, const if (!success) { char infoLog[512]; glGetProgramInfoLog(program, sizeof(infoLog), nullptr, infoLog); - fprintf(stderr, "GL: Shader %s linking failed: %s\n", name, infoLog); + logError("GL: Shader %s linking failed: %s\n", name, infoLog); *success2 = false; } else { *success2 = true; - fprintf(stderr, "GL: Shader %s succesfully linked!\n", name); + logInfo("GL: Shader %s succesfully linked!\n", name); } return program; } @@ -201,18 +201,18 @@ static void flushIfNeededAndSetActiveState(GLRenderer* gl, BatchType batchType, // ===[ Vtable Implementations ]=== static bool compileProgram(GMLShader* gmlShader, const char* name, const char* vertexShaderSource, const char* fragmentShaderSource, uint32_t vertexAttributeCount, const char** vertexAttributes) { - fprintf(stderr, "GL: Compiling %s vertex shader\n", name); + logInfo("GL: Compiling %s vertex shader\n", name); bool vertexShaderOK = false; bool fragmentShaderOK = false; GLuint vertShaderT = compileShader(GL_VERTEX_SHADER, vertexShaderSource, &vertexShaderOK); if (!vertexShaderOK) { - fprintf(stderr, "GL: Failed to compile %s vertex shader!\n", name); + logError("GL: Failed to compile %s vertex shader!\n", name); return false; } - fprintf(stderr, "GL: Compiling %s fragment shader\n", name); + logInfo("GL: Compiling %s fragment shader\n", name); GLuint fragShaderT = compileShader(GL_FRAGMENT_SHADER, fragmentShaderSource, &fragmentShaderOK); if (!fragmentShaderOK) { - fprintf(stderr, "GL: Failed to compile %s fragment shader!\n", name); + logError("GL: Failed to compile %s fragment shader!\n", name); return false; } @@ -269,14 +269,14 @@ static void glInit(Renderer* renderer, DataWin* dataWin) { GMLShader* defaultShader = (GMLShader*)safeCalloc(1, sizeof(GMLShader)); GLVer ver = GLCommon_getGLVersion(); if (ver.major < 2) { - fprintf(stderr, "GL: The modern-gl renderer requires OpenGL 2.0 or newer\n"); + logError("GL: The modern-gl renderer requires OpenGL 2.0 or newer\n"); abort(); } gl->isGL3 = (ver.major >= 3); gl->isGLES = ver.isGLES; if (!hasFBO()) { - fprintf(stderr, "GL: The modern-gl renderer requires FBO support\n"); + logError("GL: The modern-gl renderer requires FBO support\n"); abort(); } @@ -336,14 +336,14 @@ static void glInit(Renderer* renderer, DataWin* dataWin) { const char* defaultAttributes[] = { "aPos", "aColor", "aTexCoord" }; bool success = compileProgram(defaultShader, "default", vertSrc, fragSrc, 3, defaultAttributes); if (!success) { - fprintf(stderr, "GL: Failed to compile default shaders! Bailing...\n"); + logError("GL: Failed to compile default shaders! Bailing...\n"); abort(); } gl->defaultShaderProgram = defaultShader; gl->gmlShaders = (GMLShader *)safeCalloc(dataWin->shdr.count, sizeof(GMLShader)); - fprintf(stderr, "GL: %u Shaders Found\n", dataWin->shdr.count); + logInfo("GL: %u Shaders Found\n", dataWin->shdr.count); repeat(dataWin->shdr.count, i) { Shader* shdr = &dataWin->shdr.shaders[i]; @@ -351,11 +351,11 @@ static void glInit(Renderer* renderer, DataWin* dataWin) { if (!shdr->present) { gl->gmlShaderCount++; - fprintf(stderr, "GL: Skipping shader %d because it isn't present!\n", (int)i); + logWarn("GL: Skipping shader %d because it isn't present!\n", (int)i); continue; } - fprintf(stderr, "GL: Compiling %s\n", shdr->name); + logInfo("GL: Compiling %s\n", shdr->name); const char* vertexShaderSource = gl->isGLES ? shdr->glslES_Vertex : shdr->glsl_Vertex; const char* fragmentShaderSource = gl->isGLES ? shdr->glslES_Fragment : shdr->glsl_Fragment; @@ -481,7 +481,7 @@ static void glInit(Renderer* renderer, DataWin* dataWin) { gl->originalTpagCount = dataWin->tpag.count; gl->originalSpriteCount = dataWin->sprt.count; - fprintf(stderr, "GL: Renderer initialized (%u texture pages)\n", gl->textureCount); + logInfo("GL: Renderer initialized (%u texture pages)\n", gl->textureCount); } static void glGpuSetShader(Renderer* renderer, int32_t shaderIndex) { @@ -555,7 +555,7 @@ static void glShaderSettingsRefresh(Renderer* renderer) { // camera_apply: swap the active world->clip projection on the current target without touching its viewport. static void glApplyProjection(Renderer* renderer, const Matrix4f* viewMatrix,const Matrix4f* projectionMatrix) { GLRenderer* gl = (GLRenderer*) renderer; - + // Flush first so pending quads draw under the projection they were issued with. flushBatch(gl); @@ -568,13 +568,13 @@ static void glApplyProjection(Renderer* renderer, const Matrix4f* viewMatrix,con Matrix4f worldViewProjection; Matrix4f_multiply(&worldViewProjection, &projection, &worldView); - - renderer->gmlMatrices[MATRIX_VIEW] = view; + + renderer->gmlMatrices[MATRIX_VIEW] = view; renderer->gmlMatrices[MATRIX_PROJECTION] = projection; - renderer->gmlMatrices[MATRIX_WORLD_VIEW] = worldView; + renderer->gmlMatrices[MATRIX_WORLD_VIEW] = worldView; renderer->gmlMatrices[MATRIX_WORLD_VIEW_PROJECTION] = worldViewProjection; //oh my I hope it's good enough. - glShaderSettingsRefresh(renderer); + glShaderSettingsRefresh(renderer); } static void glGpuResetShader(Renderer* renderer) { @@ -866,7 +866,7 @@ bool GLRenderer_ensureTextureLoaded(GLRenderer* gl, uint32_t pageId) { bool gm2022_5 = DataWin_isVersionAtLeast(dw, 2022, 5, 0, 0); uint8_t* pixels = ImageDecoder_decodeToRgba(txtr->blobData, (size_t) txtr->blobSize, gm2022_5, &w, &h); if (pixels == nullptr) { - fprintf(stderr, "GL: Failed to decode TXTR page %u\n", pageId); + logWarn("GL: Failed to decode TXTR page %u\n", pageId); return false; } if (!txtr->mapped) { @@ -890,7 +890,7 @@ bool GLRenderer_ensureTextureLoaded(GLRenderer* gl, uint32_t pageId) { glTexParameteri(GL_TEXTURE_2D, GL_TEXTURE_WRAP_S, wrapMode); glTexParameteri(GL_TEXTURE_2D, GL_TEXTURE_WRAP_T, wrapMode); - fprintf(stderr, "GL: Loaded TXTR page %u (%dx%d)\n", pageId, w, h); + logInfo("GL: Loaded TXTR page %u (%dx%d)\n", pageId, w, h); return true; } @@ -1577,11 +1577,11 @@ static void glDrawTriangle(Renderer *renderer, float x1, float y1, float x2, flo // This gets the vertex data for the new triangle batch Vertex* verts = gl->vertexData + gl->batchCount * VERTICES_PER_TRIANGLE; uint8_t ca = floatToUnormByte(alpha); - + verts[0].x = x1; verts[0].y = y1; verts[0].u = 0.0f; verts[0].v = 0.0f; verts[0].r = (uint8_t) BGR_R(color1); verts[0].g = (uint8_t) BGR_G(color1); verts[0].b = (uint8_t) BGR_B(color1); verts[0].a = ca; verts[1].x = x2; verts[1].y = y2; verts[1].u = 0.0f; verts[1].v = 0.0f; verts[1].r = (uint8_t) BGR_R(color2); verts[1].g = (uint8_t) BGR_G(color2); verts[1].b = (uint8_t) BGR_B(color2); verts[1].a = ca; verts[2].x = x3; verts[2].y = y3; verts[2].u = 0.0f; verts[2].v = 0.0f; verts[2].r = (uint8_t) BGR_R(color3); verts[2].g = (uint8_t) BGR_G(color3); verts[2].b = (uint8_t) BGR_B(color3); verts[2].a = ca; - + gl->batchCount++; } } @@ -1940,7 +1940,7 @@ static int32_t glCreateSurface(Renderer* renderer, int32_t width, int32_t height gl->surfaceWidth[surfaceIndex] = width; gl->surfaceHeight[surfaceIndex] = height; - fprintf(stderr, "GL: Created surface %u with size (%dx%d)\n", surfaceIndex, width, height); + logInfo("GL: Created surface %u with size (%dx%d)\n", surfaceIndex, width, height); glBindFramebuffer(GL_FRAMEBUFFER, (GLuint) prevBinding); return (int32_t) surfaceIndex; @@ -1979,7 +1979,7 @@ static void glSurfaceFree(Renderer* renderer, int32_t surfaceID) { gl->surfaceTexture[surfaceID] = 0; gl->surfaceWidth[surfaceID] = 0; gl->surfaceHeight[surfaceID] = 0; - fprintf(stderr, "GL: Freed Surface %u\n", surfaceID); + logInfo("GL: Freed Surface %u\n", surfaceID); } static void glSurfaceResize(Renderer* renderer, int32_t surfaceID, int32_t width, int32_t height) { @@ -2009,7 +2009,7 @@ static void glSurfaceResize(Renderer* renderer, int32_t surfaceID, int32_t width gl->surfaceWidth[surfaceID] = width; gl->surfaceHeight[surfaceID] = height; - fprintf(stderr, "GL: Resized Surface %u Size (%dx%d)\n", surfaceID, width, height); + logInfo("GL: Resized Surface %u Size (%dx%d)\n", surfaceID, width, height); glBindFramebuffer(GL_FRAMEBUFFER, (GLuint) prevBinding); } @@ -2287,7 +2287,7 @@ static int32_t glCreateSpriteFromSurface(Renderer* renderer, int32_t surfaceID, sprite->maskCount = 0; sprite->masks = nullptr; - fprintf(stderr, "GL: Created dynamic sprite %u (%dx%d) from surface %d at (%d,%d)\n", spriteIndex, w, h, surfaceID, x, y); + logInfo("GL: Created dynamic sprite %u (%dx%d) from surface %d at (%d,%d)\n", spriteIndex, w, h, surfaceID, x, y); return (int32_t) spriteIndex; } @@ -2299,7 +2299,7 @@ static void glDeleteSprite(Renderer* renderer, int32_t spriteIndex) { // Refuse to delete original data.win sprites if (gl->originalSpriteCount > (uint32_t) spriteIndex) { - fprintf(stderr, "GL: Cannot delete data.win sprite %d\n", spriteIndex); + logWarn("GL: Cannot delete data.win sprite %d\n", spriteIndex); return; } @@ -2328,15 +2328,15 @@ static void glDeleteSprite(Renderer* renderer, int32_t spriteIndex) { memset(sprite, 0, sizeof(Sprite)); sprite->name = keepName; - fprintf(stderr, "GL: Deleted sprite %d\n", spriteIndex); + logInfo("GL: Deleted sprite %d\n", spriteIndex); } static BlendFactors glGpuGetBlendFactors(Renderer* renderer) { GLRenderer* gl = (GLRenderer*)renderer; return (BlendFactors){ - gl->currentSFactor, - gl->currentDFactor, - gl->currentSFactorAlpha, + gl->currentSFactor, + gl->currentDFactor, + gl->currentSFactorAlpha, gl->currentDFactorAlpha }; } @@ -2353,7 +2353,7 @@ static void glGpuSetBlendMode(Renderer* renderer, int32_t mode) { gl->currentBlendMode = mode; gl->currentSFactor = GLCommon_blendModeToSFactor(mode); gl->currentDFactor = GLCommon_blendModeToDFactor(mode); - gl->currentSFactorAlpha = gl->currentSFactor; + gl->currentSFactorAlpha = gl->currentSFactor; gl->currentDFactorAlpha = gl->currentDFactor; glBlendEquation(GLCommon_blendModeToEquation(mode)); @@ -2370,9 +2370,9 @@ static void glGpuSetBlendModeExt(Renderer* renderer, int32_t sfactor, int32_t df gl->currentDFactorAlpha = dfactor_alpha; glBlendFuncSeparate( - GLCommon_blendFactorToGL(sfactor), - GLCommon_blendFactorToGL(dfactor), - GLCommon_blendFactorToGL(sfactor_alpha), + GLCommon_blendFactorToGL(sfactor), + GLCommon_blendFactorToGL(dfactor), + GLCommon_blendFactorToGL(sfactor_alpha), GLCommon_blendFactorToGL(dfactor_alpha) ); } @@ -2451,7 +2451,7 @@ static int32_t glShaderGetSamplerIndex(Renderer* renderer, int32_t shaderIndex, } } - fprintf(stderr, "GL: Sampler Index %s not found for shader %d!\n", uniform, shaderIndex); + logWarn("GL: Sampler Index %s not found for shader %d!\n", uniform, shaderIndex); return -1; } @@ -2546,7 +2546,7 @@ static void glTextureSetStage(Renderer* renderer, int32_t slot, uint32_t texHand GLRenderer* gl = (GLRenderer*) renderer; flushBatch(gl); if (slot < 0) { - fprintf(stderr, "GL: Invalid Texture Stage\n"); + logWarn("GL: Invalid Texture Stage\n"); return; } TexturePageItem* tpag; @@ -2557,7 +2557,7 @@ static void glTextureSetStage(Renderer* renderer, int32_t slot, uint32_t texHand gl->currentTextureId = texID; } if (slot > MAX_TEXTURE_STAGES) { - fprintf(stderr, "GL: Texture Stage Higher Than Max\n"); + logWarn("GL: Texture Stage Higher Than Max\n"); return; } glActiveTexture(GL_TEXTURE0 + slot); @@ -2651,8 +2651,8 @@ static void glSetMatrix(Renderer* renderer, int32_t matrixType, Matrix4f matrix) Matrix4f worldViewProjection; Matrix4f_multiply(&worldViewProjection, &projection, &worldView); - - renderer->gmlMatrices[MATRIX_WORLD_VIEW] = worldView; + + renderer->gmlMatrices[MATRIX_WORLD_VIEW] = worldView; renderer->gmlMatrices[MATRIX_WORLD_VIEW_PROJECTION] = worldViewProjection; diff --git a/src/gl_legacy/gl_legacy_renderer.c b/src/gl_legacy/gl_legacy_renderer.c index 09999262f..f516ef031 100644 --- a/src/gl_legacy/gl_legacy_renderer.c +++ b/src/gl_legacy/gl_legacy_renderer.c @@ -115,10 +115,10 @@ static void glApplyProjection(Renderer* renderer, const Matrix4f* viewMatrix, co Matrix4f worldViewProjection; Matrix4f_multiply(&worldViewProjection, &projection, &worldView); - - renderer->gmlMatrices[MATRIX_VIEW] = view; + + renderer->gmlMatrices[MATRIX_VIEW] = view; renderer->gmlMatrices[MATRIX_PROJECTION] = projection; - renderer->gmlMatrices[MATRIX_WORLD_VIEW] = worldView; + renderer->gmlMatrices[MATRIX_WORLD_VIEW] = worldView; renderer->gmlMatrices[MATRIX_WORLD_VIEW_PROJECTION] = worldViewProjection; Matrix4f_flipClipY(&projection); @@ -140,7 +140,7 @@ static void glInit(Renderer* renderer, DataWin* dataWin) { renderer->gmlMatrices[MATRIX_WORLD] = world; if (!hasFBO()) { - fprintf(stderr, "GL: The legacy-gl renderer requires FBO support!\n"); + logError("GL: The legacy-gl renderer requires FBO support!\n"); abort(); } @@ -206,7 +206,7 @@ static void glInit(Renderer* renderer, DataWin* dataWin) { gl->surfaceHeight = nullptr; gl->surfaceCount = 0; - fprintf(stderr, "GL: Renderer initialized (%u texture pages)\n", gl->textureCount); + logInfo("GL: Renderer initialized (%u texture pages)\n", gl->textureCount); } static void glDestroy(Renderer* renderer) { @@ -408,7 +408,7 @@ bool GLLegacyRenderer_ensureTextureLoaded(GLLegacyRenderer* gl, uint32_t pageId) // We'll load the textures on demand. uint8_t* pixels; if (!PS3Textures_loadPage(pageId, &w, &h, &pixels)) { - fprintf(stderr, "GL: PS3 page %u has no pixels\n", pageId); + logWarn("GL: PS3 page %u has no pixels\n", pageId); return false; } gl->textureWidths[pageId] = w; @@ -433,7 +433,7 @@ bool GLLegacyRenderer_ensureTextureLoaded(GLLegacyRenderer* gl, uint32_t pageId) bool gm2022_5 = DataWin_isVersionAtLeast(dw, 2022, 5, 0, 0); uint8_t* pixels = ImageDecoder_decodeToRgba(txtr->blobData, (size_t) txtr->blobSize, gm2022_5, &w, &h); if (pixels == nullptr) { - fprintf(stderr, "GL: Failed to decode TXTR page %u\n", pageId); + logWarn("GL: Failed to decode TXTR page %u\n", pageId); return false; } if (!txtr->mapped) { @@ -454,7 +454,7 @@ bool GLLegacyRenderer_ensureTextureLoaded(GLLegacyRenderer* gl, uint32_t pageId) glTexParameteri(GL_TEXTURE_2D, GL_TEXTURE_WRAP_S, GL_REPEAT); glTexParameteri(GL_TEXTURE_2D, GL_TEXTURE_WRAP_T, GL_REPEAT); #endif - fprintf(stderr, "GL: Loaded TXTR page %u (%dx%d)\n", pageId, w, h); + logInfo("GL: Loaded TXTR page %u (%dx%d)\n", pageId, w, h); return true; } @@ -807,7 +807,7 @@ static void glDrawRectangleColor(Renderer* renderer, float x1, float y1, float x // Vertex 0: top-left glColor4f(r1, g1, b1, alpha); glTexCoord2f(0.5f, 0.5f); - glVertex2f(x1, y1); + glVertex2f(x1, y1); // Vertex 1: top-right glColor4f(r2, g2, b2, alpha); @@ -822,7 +822,7 @@ static void glDrawRectangleColor(Renderer* renderer, float x1, float y1, float x // Vertex 3: bottom-left glColor4f(r4, g4, b4, alpha); glTexCoord2f(0.5f, 0.5f); - glVertex2f(x1, y2+1); + glVertex2f(x1, y2+1); glEnd(); } @@ -900,22 +900,22 @@ static void glDrawLineColor(Renderer* renderer, float x1, float y1, float x2, fl // Vertex 0: start + perpendicular (color1) glColor4f(r1, g1, b1, alpha); glTexCoord2f(0.5f, 0.5f); - glVertex2f(x1 + px, y1 + py); + glVertex2f(x1 + px, y1 + py); // Vertex 1: start - perpendicular (color1) glColor4f(r1, g1, b1, alpha); glTexCoord2f(0.5f, 0.5f); - glVertex2f(x1 - px, y1 - py); + glVertex2f(x1 - px, y1 - py); // Vertex 2: end - perpendicular (color2) glColor4f(r2, g2, b2, alpha); glTexCoord2f(0.5f, 0.5f); - glVertex2f(x2 - px, y2 - py); + glVertex2f(x2 - px, y2 - py); // Vertex 3: end + perpendicular (color2) glColor4f(r2, g2, b2, alpha); glTexCoord2f(0.5f, 0.5f); - glVertex2f(x2 + px, y2 + py); + glVertex2f(x2 + px, y2 + py); glEnd(); } @@ -1419,7 +1419,7 @@ static int32_t glCreateSpriteFromSurface(Renderer* renderer, int32_t surfaceID, sprite->maskCount = 0; sprite->masks = nullptr; - fprintf(stderr, "GL: Created dynamic sprite %u (%dx%d) from surface at (%d,%d)\n", spriteIndex, w, h, x, y); + logInfo("GL: Created dynamic sprite %u (%dx%d) from surface at (%d,%d)\n", spriteIndex, w, h, x, y); return (int32_t) spriteIndex; } @@ -1431,7 +1431,7 @@ static void glDeleteSprite(Renderer* renderer, int32_t spriteIndex) { // Refuse to delete original data.win sprites if (gl->originalSpriteCount > (uint32_t) spriteIndex) { - fprintf(stderr, "GL: Cannot delete data.win sprite %d\n", spriteIndex); + logWarn("GL: Cannot delete data.win sprite %d\n", spriteIndex); return; } @@ -1460,15 +1460,15 @@ static void glDeleteSprite(Renderer* renderer, int32_t spriteIndex) { memset(sprite, 0, sizeof(Sprite)); sprite->name = keepName; - fprintf(stderr, "GL: Deleted sprite %d\n", spriteIndex); + logInfo("GL: Deleted sprite %d\n", spriteIndex); } static BlendFactors glGpuGetBlendFactors(Renderer* renderer) { GLLegacyRenderer* gl = (GLLegacyRenderer*)renderer; return (BlendFactors){ - gl->currentSFactor, - gl->currentDFactor, - gl->currentSFactorAlpha, + gl->currentSFactor, + gl->currentDFactor, + gl->currentSFactorAlpha, gl->currentDFactorAlpha }; } @@ -1480,11 +1480,11 @@ static int32_t glGpuGetBlendMode(Renderer* renderer) { static void glGpuSetBlendMode(Renderer* renderer, int32_t mode) { GLLegacyRenderer* gl = (GLLegacyRenderer*) renderer; - + gl->currentBlendMode = mode; gl->currentSFactor = GLCommon_blendModeToSFactor(mode); gl->currentDFactor = GLCommon_blendModeToDFactor(mode); - gl->currentSFactorAlpha = gl->currentSFactor; + gl->currentSFactorAlpha = gl->currentSFactor; gl->currentDFactorAlpha = gl->currentDFactor; glBlendEquation(GLCommon_blendModeToEquation(mode)); glBlendFunc(gl->currentSFactor, gl->currentDFactor); @@ -1492,17 +1492,17 @@ static void glGpuSetBlendMode(Renderer* renderer, int32_t mode) { static void glGpuSetBlendModeExt(Renderer* renderer, int32_t sfactor, int32_t dfactor, int32_t sfactor_alpha, int32_t dfactor_alpha) { GLLegacyRenderer* gl = (GLLegacyRenderer*) renderer; - + gl->currentBlendMode = bm_complex; gl->currentSFactor = sfactor; gl->currentDFactor = dfactor; gl->currentSFactorAlpha = sfactor_alpha; gl->currentDFactorAlpha = dfactor_alpha; - + glBlendFuncSeparate( - GLCommon_blendFactorToGL(sfactor), - GLCommon_blendFactorToGL(dfactor), - GLCommon_blendFactorToGL(sfactor_alpha), + GLCommon_blendFactorToGL(sfactor), + GLCommon_blendFactorToGL(dfactor), + GLCommon_blendFactorToGL(sfactor_alpha), GLCommon_blendFactorToGL(dfactor_alpha) ); } @@ -1513,7 +1513,7 @@ static void glGpuSetBlendEnable(Renderer* renderer, bool enable) { } static bool glGpuGetBlendEnable(MAYBE_UNUSED Renderer* renderer) { - + return glIsEnabled(GL_BLEND); } @@ -1570,13 +1570,13 @@ static int32_t glLegacyCreateSurface(Renderer* renderer, int32_t width, int32_t GLenum status = glCheckFramebufferStatus(GL_FRAMEBUFFER); if (status != GL_FRAMEBUFFER_COMPLETE) { - fprintf(stderr, "GL: Surface FBO incomplete (status=0x%X)\n", status); + logWarn("GL: Surface FBO incomplete (status=0x%X)\n", status); } gl->surfaceWidth[surfaceIndex] = width; gl->surfaceHeight[surfaceIndex] = height; - fprintf(stderr, "GL: Created surface %u with size (%dx%d)\n", surfaceIndex, width, height); + logInfo("GL: Created surface %u with size (%dx%d)\n", surfaceIndex, width, height); glBindFramebuffer(GL_FRAMEBUFFER, (GLuint) prevBinding); return (int32_t) surfaceIndex; } @@ -1647,7 +1647,7 @@ static void glLegacySurfaceResize(Renderer* renderer, int32_t surfaceId, int32_t gl->surfaceWidth[surfaceId] = width; gl->surfaceHeight[surfaceId] = height; - fprintf(stderr, "GL: Resized Surface %u to (%dx%d)\n", surfaceId, width, height); + logInfo("GL: Resized Surface %u to (%dx%d)\n", surfaceId, width, height); } static void glLegacySurfaceFree(Renderer* renderer, int32_t surfaceId) { @@ -1661,7 +1661,7 @@ static void glLegacySurfaceFree(Renderer* renderer, int32_t surfaceId) { gl->surfaceTexture[surfaceId] = 0; gl->surfaceWidth[surfaceId] = 0; gl->surfaceHeight[surfaceId] = 0; - fprintf(stderr, "GL: Freed Surface %d\n", surfaceId); + logInfo("GL: Freed Surface %d\n", surfaceId); } static bool glLegacySetRenderTarget(Renderer* renderer, int32_t surfaceId, bool implicitApplicationSurface) { diff --git a/src/image/image_decoder.c b/src/image/image_decoder.c index 16b2aacc9..937ce4a86 100644 --- a/src/image/image_decoder.c +++ b/src/image/image_decoder.c @@ -5,6 +5,8 @@ #include #include +#include "log.h" + #include "stb_image.h" #define QOI_HEADER_SIZE 12 @@ -134,7 +136,7 @@ static uint8_t* decodeBz2Qoi(const uint8_t* blob, size_t blobSize, bool gm2022_5 unsigned int destLen = (unsigned int) uncompressedCapacity; int rc = BZ2_bzBuffToBuffDecompress((char*) uncompressed, &destLen, (char*)(blob + headerSize), (unsigned int)(blobSize - headerSize), 0, 0); if (rc != BZ_OK) { - fprintf(stderr, "ImageDecoder: BZ2 decompress failed (rc=%d)\n", rc); + logWarn("ImageDecoder: BZ2 decompress failed (rc=%d)\n", rc); free(uncompressed); return nullptr; } diff --git a/src/ini.c b/src/ini.c index 44afa5fb4..8cdb8d4d9 100644 --- a/src/ini.c +++ b/src/ini.c @@ -114,7 +114,7 @@ IniFile* Ini_parse(const char* text) { currentSection = addSection(ini, nameStart); } } else { - fprintf(stderr, "Ini: malformed section header: %s\n", trimmed); + logWarn("Ini: malformed section header: %s\n", trimmed); } } else { // Key=value pair diff --git a/src/input_recording.c b/src/input_recording.c index 51ec4623c..32bbdf2d7 100644 --- a/src/input_recording.c +++ b/src/input_recording.c @@ -21,7 +21,7 @@ InputRecording* InputRecording_createPlayer(const char* playbackFilePath, const // Read the file contents FILE* f = fopen(playbackFilePath, "rb"); if (f == nullptr) { - fprintf(stderr, "Error: Could not open input recording file '%s'\n", playbackFilePath); + logError("Could not open input recording file '%s'\n", playbackFilePath); exit(1); } @@ -39,7 +39,7 @@ InputRecording* InputRecording_createPlayer(const char* playbackFilePath, const free(contents); if (root == nullptr || !JsonReader_isObject(root)) { - fprintf(stderr, "Error: Invalid JSON in input recording file '%s'\n", playbackFilePath); + logError("Invalid JSON in input recording file '%s'\n", playbackFilePath); exit(1); } @@ -94,7 +94,7 @@ InputRecording* InputRecording_createPlayer(const char* playbackFilePath, const } JsonReader_free(root); - fprintf(stderr, "InputRecording: Loaded %d frames from '%s'\n", rec->playbackFrameCount, playbackFilePath); + logInfo("InputRecording: Loaded %d frames from '%s'\n", rec->playbackFrameCount, playbackFilePath); return rec; } @@ -143,7 +143,7 @@ void InputRecording_processFrame(InputRecording* recording, RunnerKeyboardState* } } else { if (!recording->playbackEnded) { - fprintf(stderr, "InputRecording: Playback ended at frame %d (recorded %d frames)\n", frameNumber, recording->playbackFrameCount); + logInfo("InputRecording: Playback ended at frame %d (recorded %d frames)\n", frameNumber, recording->playbackFrameCount); recording->playbackEnded = true; } } @@ -214,7 +214,7 @@ bool InputRecording_save(InputRecording* recording) { FILE* f = fopen(recording->recordFilePath, "wb"); if (f == nullptr) { - fprintf(stderr, "Error: Could not write input recording to '%s'\n", recording->recordFilePath); + logWarn("Could not write input recording to '%s'\n", recording->recordFilePath); JsonWriter_free(&w); return false; } @@ -224,7 +224,7 @@ bool InputRecording_save(InputRecording* recording) { fputc('\n', f); fclose(f); - fprintf(stderr, "InputRecording: Saved %d frames to '%s'\n", frameCount, recording->recordFilePath); + logInfo("InputRecording: Saved %d frames to '%s'\n", frameCount, recording->recordFilePath); JsonWriter_free(&w); return true; } diff --git a/src/json_reader.c b/src/json_reader.c index c863648ae..6d2e21782 100644 --- a/src/json_reader.c +++ b/src/json_reader.c @@ -107,7 +107,7 @@ static JsonValue* parseString(JsonParser* parser) { break; } default: - fprintf(stderr, "JsonReader: unknown escape sequence '\\%c'\n", escaped); + logWarn("JsonReader: unknown escape sequence '\\%c'\n", escaped); free(buffer); return nullptr; } @@ -122,7 +122,7 @@ static JsonValue* parseString(JsonParser* parser) { } // Unterminated string - fprintf(stderr, "JsonReader: unterminated string\n"); + logWarn("JsonReader: unterminated string\n"); free(buffer); return nullptr; } @@ -132,7 +132,7 @@ static JsonValue* parseNumber(JsonParser* parser) { char* end = nullptr; double number = strtod(start, &end); if (end == start) { - fprintf(stderr, "JsonReader: invalid number\n"); + logWarn("JsonReader: invalid number\n"); return nullptr; } parser->position += (size_t) (end - start); @@ -183,7 +183,7 @@ static JsonValue* parseArray(JsonParser* parser) { advance(parser); return value; } else { - fprintf(stderr, "JsonReader: expected ',' or ']' in array\n"); + logWarn("JsonReader: expected ',' or ']' in array\n"); JsonReader_free(value); return nullptr; } @@ -209,7 +209,7 @@ static JsonValue* parseObject(JsonParser* parser) { while (true) { skipWhitespace(parser); if (peek(parser) != '"') { - fprintf(stderr, "JsonReader: expected string key in object\n"); + logWarn("JsonReader: expected string key in object\n"); JsonReader_free(value); return nullptr; } @@ -225,7 +225,7 @@ static JsonValue* parseObject(JsonParser* parser) { skipWhitespace(parser); if (peek(parser) != ':') { - fprintf(stderr, "JsonReader: expected ':' after object key\n"); + logWarn("JsonReader: expected ':' after object key\n"); free(key); JsonReader_free(value); return nullptr; @@ -260,7 +260,7 @@ static JsonValue* parseObject(JsonParser* parser) { advance(parser); return value; } else { - fprintf(stderr, "JsonReader: expected ',' or '}' in object\n"); + logWarn("JsonReader: expected ',' or '}' in object\n"); JsonReader_free(value); return nullptr; } @@ -292,7 +292,7 @@ static JsonValue* parseValue(JsonParser* parser) { case 't': { JsonValue* value = parseLiteral(parser, "true", 4); if (value == nullptr) { - fprintf(stderr, "JsonReader: invalid literal\n"); + logWarn("JsonReader: invalid literal\n"); return nullptr; } value->type = JSON_BOOL; @@ -302,7 +302,7 @@ static JsonValue* parseValue(JsonParser* parser) { case 'f': { JsonValue* value = parseLiteral(parser, "false", 5); if (value == nullptr) { - fprintf(stderr, "JsonReader: invalid literal\n"); + logWarn("JsonReader: invalid literal\n"); return nullptr; } value->type = JSON_BOOL; @@ -312,7 +312,7 @@ static JsonValue* parseValue(JsonParser* parser) { case 'n': { JsonValue* value = parseLiteral(parser, "null", 4); if (value == nullptr) { - fprintf(stderr, "JsonReader: invalid literal\n"); + logWarn("JsonReader: invalid literal\n"); return nullptr; } return value; @@ -321,7 +321,7 @@ static JsonValue* parseValue(JsonParser* parser) { if (c == '-' || (c >= '0' && c <= '9')) { return parseNumber(parser); } - fprintf(stderr, "JsonReader: unexpected character '%c' at position %zu\n", c, parser->position); + logWarn("JsonReader: unexpected character '%c' at position %zu\n", c, parser->position); return nullptr; } } @@ -348,7 +348,7 @@ JsonValue* JsonReader_parse(const char* json) { if (result != nullptr) { skipWhitespace(&parser); if (parser.position < parser.length) { - fprintf(stderr, "JsonReader: trailing content after JSON value at position %zu\n", parser.position); + logWarn("JsonReader: trailing content after JSON value at position %zu\n", parser.position); JsonReader_free(result); return nullptr; } diff --git a/src/log.c b/src/log.c new file mode 100644 index 000000000..c1a45a673 --- /dev/null +++ b/src/log.c @@ -0,0 +1,83 @@ +#include "log.h" + +#include +#include +#include +#include +#include + +#include "utils.h" + +// In the platform main.c +void platformLog(const logType type, const char *format, va_list va); + +// Example impl: +// void platformLog(const logType type, const char *format, va_list va) { +// FILE *out = stderr; +// switch (type) { +// case LOG_TYPE_NORMAL: +// out = stdout; +// fputs(ANSI_COLOUR_CODE_RESET, out); +// break; +// case LOG_TYPE_WARNING: +// fputs(ANSI_COLOUR_CODE_BOLD_YELLOW"Warning: ", out); +// break; +// case LOG_TYPE_ERROR: +// fputs(ANSI_COLOUR_CODE_BOLD_RED"Error: ", out); +// break; +// case LOG_TYPE_DEBUG: +// fputs(ANSI_COLOUR_CODE_BOLD_PURPLE"Debug: ", out); +// break; +// } +// vfprintf(out, format, va); +// fputs(ANSI_COLOUR_CODE_RESET, out); +// } + +void logInfo(const char* fmt, ...) { + va_list va; + + va_start(va, fmt); + platformLog(LOG_TYPE_NORMAL, fmt, va); + va_end(va); +} + +void vLogInfo(const char* fmt, va_list va) { + platformLog(LOG_TYPE_NORMAL, fmt, va); +} + +void logWarn(const char* fmt, ...) { + va_list va; + + va_start(va, fmt); + platformLog(LOG_TYPE_WARNING, fmt, va); + va_end(va); +} + +void vLogWarn(const char* fmt, va_list va) { + platformLog(LOG_TYPE_WARNING, fmt, va); +} + + +void logError(const char* fmt, ...) { + va_list va; + + va_start(va, fmt); + platformLog(LOG_TYPE_ERROR, fmt, va); + va_end(va); +} + +void vLogError(const char* fmt, va_list va) { + platformLog(LOG_TYPE_ERROR, fmt, va); +} + +void logDebug(const char* fmt, ...) { + va_list va; + + va_start(va, fmt); + platformLog(LOG_TYPE_DEBUG, fmt, va); + va_end(va); +} + +void vLogDebug(const char* fmt, va_list va) { + platformLog(LOG_TYPE_DEBUG, fmt, va); +} diff --git a/src/log.h b/src/log.h new file mode 100644 index 000000000..2f8ee3f29 --- /dev/null +++ b/src/log.h @@ -0,0 +1,32 @@ +#ifndef _BS_LOG_H +#define _BS_LOG_H + +#include +#include +#include + +typedef enum { + LOG_TYPE_NORMAL=0, + LOG_TYPE_WARNING=1, + LOG_TYPE_ERROR=2, + LOG_TYPE_DEBUG=3 +} logType; + +#define ANSI_COLOUR_CODE_RESET "\033[0m" +#define ANSI_COLOUR_CODE_BOLD_YELLOW "\033[1;33m" +#define ANSI_COLOUR_CODE_BOLD_RED "\033[1;31m" +#define ANSI_COLOUR_CODE_BOLD_PURPLE "\033[1;35m" + +void logInfo(const char* fmt, ...); +void vLogInfo(const char* fmt, va_list va); + +void logWarn(const char* fmt, ...); +void vLogWarn(const char* fmt, va_list va); + +void logError(const char* fmt, ...); +void vLogError(const char* fmt, va_list va); + +void logDebug(const char* fmt, ...); +void vLogDebug(const char* fmt, va_list va); + +#endif /* _BS_LOG_H */ diff --git a/src/ps2/debug_font_renderer.c b/src/ps2/debug_font_renderer.c index 02ec124a9..bf1f9d0a4 100644 --- a/src/ps2/debug_font_renderer.c +++ b/src/ps2/debug_font_renderer.c @@ -20,7 +20,7 @@ static uint32_t uploadTable(GSGLOBAL* gsGlobal, const void* srcData, size_t srcB uint32_t vramSize = gsKit_texture_size(width, height, psm); uint32_t vramAddr = gsKit_vram_alloc(gsGlobal, vramSize, GSKIT_ALLOC_USERBUFFER); if (vramAddr == GSKIT_ALLOC_ERROR) { - fprintf(stderr, "DebugFontRenderer: Failed to allocate VRAM for %s\n", what); + logError("DebugFontRenderer: Failed to allocate VRAM for %s\n", what); abort(); } @@ -58,7 +58,7 @@ DebugFontRenderer* DebugFontRenderer_create(GSGLOBAL* gsGlobal) { tex->Filter = GS_FILTER_LINEAR; tex->ClutStorageMode = GS_CLUT_STORAGE_CSM1; - fprintf(stderr, "DebugFontRenderer: uploaded - CLUT 0x%08lX, atlas 0x%08lX\n", (unsigned long) clutVram, (unsigned long) atlasVram); + logInfo("DebugFontRenderer: uploaded - CLUT 0x%08lX, atlas 0x%08lX\n", (unsigned long) clutVram, (unsigned long) atlasVram); return r; } diff --git a/src/ps2/gs_renderer.c b/src/ps2/gs_renderer.c index 75cbbea33..a40e2132e 100644 --- a/src/ps2/gs_renderer.c +++ b/src/ps2/gs_renderer.c @@ -22,7 +22,7 @@ static void rendererPrintf(const char* fmt, ...) { va_list args; va_start(args, fmt); - vfprintf(stderr, fmt, args); + vLogInfo(fmt, args); va_end(args); } #else @@ -47,7 +47,7 @@ static uint8_t* loadFileRaw(const char* path, uint32_t* outSize) { FILE* f = fopen(textureBinPath, "rb"); if (f == nullptr) { - fprintf(stderr, "GsRenderer: Failed to open %s\n", path); + logError("GsRenderer: Failed to open %s\n", path); abort(); } @@ -62,7 +62,7 @@ static uint8_t* loadFileRaw(const char* path, uint32_t* outSize) { fclose(f); if (read != (size_t) size) { - fprintf(stderr, "GsRenderer: Short read on %s (expected %ld, got %zu)\n", path, size, read); + logError("GsRenderer: Short read on %s (expected %ld, got %zu)\n", path, size, read); abort(); } @@ -76,7 +76,7 @@ static void loadAtlas(GsRenderer* gs) { char* atlasBinPath = PS2Utils_createDevicePath("ATLAS.BIN"); FILE* f = fopen(atlasBinPath, "rb"); if (f == nullptr) { - fprintf(stderr, "GsRenderer: Failed to open %s\n", atlasBinPath); + logError("GsRenderer: Failed to open %s\n", atlasBinPath); abort(); } @@ -88,7 +88,7 @@ static void loadAtlas(GsRenderer* gs) { uint8_t version = BinaryReader_readUint8(&reader); if (version != 0) { - fprintf(stderr, "GsRenderer: Unsupported ATLAS.BIN version %u\n", version); + logError("GsRenderer: Unsupported ATLAS.BIN version %u\n", version); abort(); } @@ -111,7 +111,7 @@ static void loadAtlas(GsRenderer* gs) { gs->atlasDataSizes[i] = BinaryReader_readUint32(&reader); gs->atlasCompressionType[i] = BinaryReader_readUint8(&reader); if (gs->atlasBpp[i] != 4 && gs->atlasBpp[i] != 8) { - fprintf(stderr, "GsRenderer: Atlas %u has unsupported bpp %u\n", i, gs->atlasBpp[i]); + logError("GsRenderer: Atlas %u has unsupported bpp %u\n", i, gs->atlasBpp[i]); abort(); } } @@ -175,7 +175,7 @@ static void loadAtlas(GsRenderer* gs) { gs->atlasToChunk[i] = -1; } - fprintf(stderr, "GsRenderer: ATLAS.BIN loaded - %u TPAG entries, %u tile entries, %u atlases\n", gs->atlasTPAGCount, gs->atlasTileCount, gs->atlasCount); + logInfo("GsRenderer: ATLAS.BIN loaded - %u TPAG entries, %u tile entries, %u atlases\n", gs->atlasTPAGCount, gs->atlasTileCount, gs->atlasCount); free(atlasBinPath); } @@ -197,7 +197,7 @@ static void loadAndUploadCLUTs(GsRenderer* gs) { uint32_t clut4FileSize; uint8_t* clut4Data = loadFileRaw("CLUT4.BIN", &clut4FileSize); gs->clut4Count = clut4FileSize / CLUT4_ENTRY_SIZE; - fprintf(stderr, "GsRenderer: CLUT4.BIN loaded - %u CLUTs (%u bytes)\n", gs->clut4Count, clut4FileSize); + logInfo("GsRenderer: CLUT4.BIN loaded - %u CLUTs (%u bytes)\n", gs->clut4Count, clut4FileSize); gs->clut4VramAddrs = (uint32_t *)safeMalloc(gs->clut4Count * sizeof(uint32_t)); @@ -206,7 +206,7 @@ static void loadAndUploadCLUTs(GsRenderer* gs) { uint32_t vramSize = gsKit_texture_size(8, 2, GS_PSM_CT32); uint32_t vramAddr = gsKit_vram_alloc(gsGlobal, vramSize, GSKIT_ALLOC_USERBUFFER); if (vramAddr == GSKIT_ALLOC_ERROR) { - fprintf(stderr, "GsRenderer: Failed to allocate VRAM for CLUT4 index %u\n", i); + logError("GsRenderer: Failed to allocate VRAM for CLUT4 index %u\n", i); abort(); } @@ -216,7 +216,7 @@ static void loadAndUploadCLUTs(GsRenderer* gs) { gs->clut4VramAddrs[i] = vramAddr; } - fprintf(stderr, "GsRenderer: CLUT4 uploaded (%u CLUTs)\n", gs->clut4Count); + logInfo("GsRenderer: CLUT4 uploaded (%u CLUTs)\n", gs->clut4Count); free(clut4Data); } @@ -225,7 +225,7 @@ static void loadAndUploadCLUTs(GsRenderer* gs) { uint32_t clut8FileSize; uint8_t* clut8Data = loadFileRaw("CLUT8.BIN", &clut8FileSize); gs->clut8Count = clut8FileSize / CLUT8_ENTRY_SIZE; - fprintf(stderr, "GsRenderer: CLUT8.BIN loaded - %u CLUTs (%u bytes)\n", gs->clut8Count, clut8FileSize); + logInfo("GsRenderer: CLUT8.BIN loaded - %u CLUTs (%u bytes)\n", gs->clut8Count, clut8FileSize); gs->clut8VramAddrs = (uint32_t *)safeMalloc(gs->clut8Count * sizeof(uint32_t)); @@ -234,7 +234,7 @@ static void loadAndUploadCLUTs(GsRenderer* gs) { uint32_t vramSize = gsKit_texture_size(16, 16, GS_PSM_CT32); uint32_t vramAddr = gsKit_vram_alloc(gsGlobal, vramSize, GSKIT_ALLOC_USERBUFFER); if (vramAddr == GSKIT_ALLOC_ERROR) { - fprintf(stderr, "GsRenderer: Failed to allocate VRAM for CLUT8 index %u\n", i); + logError("GsRenderer: Failed to allocate VRAM for CLUT8 index %u\n", i); abort(); } @@ -243,13 +243,13 @@ static void loadAndUploadCLUTs(GsRenderer* gs) { gs->clut8VramAddrs[i] = vramAddr; } - fprintf(stderr, "GsRenderer: CLUT8 uploaded (%u CLUTs)\n", gs->clut8Count); + logInfo("GsRenderer: CLUT8 uploaded (%u CLUTs)\n", gs->clut8Count); free(clut8Data); } free(tempBuf); - fprintf(stderr, "GsRenderer: VRAM after CLUTs: 0x%08X / 0x%08X\n", gsGlobal->CurrentPointer, GS_VRAM_SIZE); + logInfo("GsRenderer: VRAM after CLUTs: 0x%08X / 0x%08X\n", gsGlobal->CurrentPointer, GS_VRAM_SIZE); } // ===[ VRAM Texture Cache (Buddy System with LRU Eviction) ]=== @@ -283,7 +283,7 @@ static void initTextureCache(GsRenderer* gs) { // Advance CurrentPointer past our chunk pool so any future gsKit allocations fail loudly. gs->gsGlobal->CurrentPointer = gs->textureVramBase + gs->chunkCount * VRAM_CHUNK_SIZE; - fprintf(stderr, "GsRenderer: Texture cache initialized - %u chunks (%u KB each), base 0x%08X, %u KB for textures\n", gs->chunkCount, VRAM_CHUNK_SIZE / 1024, gs->textureVramBase, gs->chunkCount * (VRAM_CHUNK_SIZE / 1024)); + logInfo("GsRenderer: Texture cache initialized - %u chunks (%u KB each), base 0x%08X, %u KB for textures\n", gs->chunkCount, VRAM_CHUNK_SIZE / 1024, gs->textureVramBase, gs->chunkCount * (VRAM_CHUNK_SIZE / 1024)); } // A chunk is free if no atlas, snapshot, or surface occupies it. Snapshots and surfaces both pin the chunk against LRU eviction. @@ -470,7 +470,7 @@ static void computeAtlasReservation(GsRenderer* gs) { } if (worst > gs->chunkCount) worst = gs->chunkCount; gs->reservedAtlasChunks = worst; - fprintf(stderr, "GsRenderer: Reserving first %u chunk(s) (%u KB) as atlas-only fail-safe (largest atlas @ 8bpp)\n", worst, worst * (VRAM_CHUNK_SIZE / 1024)); + logInfo("GsRenderer: Reserving first %u chunk(s) (%u KB) as atlas-only fail-safe (largest atlas @ 8bpp)\n", worst, worst * (VRAM_CHUNK_SIZE / 1024)); } // Initialize the EE RAM cache. Called from gsInit after opening TEXTURES.BIN. @@ -607,7 +607,7 @@ static void uploadAtlasToChunk(GsRenderer* gs, uint16_t atlasId, int32_t firstCh fseek(gs->texturesFile, (long) gs->atlasOffsets[atlasId], SEEK_SET); size_t bytesRead = fread(compressedBuf, 1, dataSize, gs->texturesFile); if (bytesRead != dataSize) { - fprintf(stderr, "GsRenderer: Short read for atlas %u (expected %u, got %zu)\n", atlasId, dataSize, bytesRead); + logError("GsRenderer: Short read for atlas %u (expected %u, got %zu)\n", atlasId, dataSize, bytesRead); abort(); } @@ -668,7 +668,7 @@ static void uploadAtlasToChunk(GsRenderer* gs, uint16_t atlasId, int32_t firstCh // Returns true on success, false on failure. static bool ensureAtlasLoaded(GsRenderer* gs, uint16_t atlasId) { if (atlasId >= gs->atlasCount) { - fprintf(stderr, "GsRenderer: Atlas ID %u out of range (max %u)\n", atlasId, gs->atlasCount - 1); + logWarn("GsRenderer: Atlas ID %u out of range (max %u)\n", atlasId, gs->atlasCount - 1); return false; } @@ -693,7 +693,7 @@ static bool ensureAtlasLoaded(GsRenderer* gs, uint16_t atlasId) { // Determine how many chunks we need uint8_t bpp = gs->atlasBpp[atlasId]; if (bpp != 4 && bpp != 8) { - fprintf(stderr, "GsRenderer: Atlas %u has unknown bpp %u\n", atlasId, bpp); + logWarn("GsRenderer: Atlas %u has unknown bpp %u\n", atlasId, bpp); return false; } int chunksNeeded = atlasChunkCount(gs->atlasWidth[atlasId], gs->atlasHeight[atlasId], bpp); @@ -705,7 +705,7 @@ static bool ensureAtlasLoaded(GsRenderer* gs, uint16_t atlasId) { // Allocate chunks (may evict or defrag) int32_t chunkIdx = allocateChunks(gs, chunksNeeded, 0); if (0 > chunkIdx) { - fprintf(stderr, "GsRenderer: VRAM exhausted! Cannot allocate %d chunk(s) for atlas %u (%ubpp)\n", chunksNeeded, atlasId, bpp); + logError("GsRenderer: VRAM exhausted! Cannot allocate %d chunk(s) for atlas %u (%ubpp)\n", chunksNeeded, atlasId, bpp); abort(); } @@ -903,7 +903,7 @@ static bool setupTextureForTPAG(GsRenderer* gs, GSTEXTURE* tex, int32_t tpagInde tex->ClutPSM = GS_PSM_CT32; if (entry->clutIndex >= gs->clut4Count) { - fprintf(stderr, "GsRenderer: CLUT4 index %u out of range (max %u) for TPAG %d\n", entry->clutIndex, gs->clut4Count - 1, tpagIndex); + logError("GsRenderer: CLUT4 index %u out of range (max %u) for TPAG %d\n", entry->clutIndex, gs->clut4Count - 1, tpagIndex); abort(); } @@ -913,7 +913,7 @@ static bool setupTextureForTPAG(GsRenderer* gs, GSTEXTURE* tex, int32_t tpagInde tex->ClutPSM = GS_PSM_CT32; if (entry->clutIndex >= gs->clut8Count) { - fprintf(stderr, "GsRenderer: CLUT8 index %u out of range (max %u) for TPAG %d\n", entry->clutIndex, gs->clut8Count - 1, tpagIndex); + logError("GsRenderer: CLUT8 index %u out of range (max %u) for TPAG %d\n", entry->clutIndex, gs->clut8Count - 1, tpagIndex); abort(); } @@ -965,7 +965,7 @@ static bool setupTextureForTile(GsRenderer* gs, GSTEXTURE* tex, AtlasTileEntry* tex->ClutPSM = GS_PSM_CT32; if (entry->clutIndex >= gs->clut4Count) { - fprintf(stderr, "GsRenderer: CLUT4 index %u out of range (max %u) for tile (bg=%d)\n", entry->clutIndex, gs->clut4Count - 1, entry->bgDef); + logError("GsRenderer: CLUT4 index %u out of range (max %u) for tile (bg=%d)\n", entry->clutIndex, gs->clut4Count - 1, entry->bgDef); abort(); } @@ -975,7 +975,7 @@ static bool setupTextureForTile(GsRenderer* gs, GSTEXTURE* tex, AtlasTileEntry* tex->ClutPSM = GS_PSM_CT32; if (entry->clutIndex >= gs->clut8Count) { - fprintf(stderr, "GsRenderer: CLUT8 index %u out of range (max %u) for tile (bg=%d)\n", entry->clutIndex, gs->clut8Count - 1, entry->bgDef); + logError("GsRenderer: CLUT8 index %u out of range (max %u) for tile (bg=%d)\n", entry->clutIndex, gs->clut8Count - 1, entry->bgDef); abort(); } @@ -1060,7 +1060,7 @@ static void gsInit(Renderer* renderer, DataWin* dataWin) { char* texturesBinPath = PS2Utils_createDevicePath("TEXTURES.BIN"); gs->texturesFile = fopen(texturesBinPath, "rb"); if (gs->texturesFile == nullptr) { - fprintf(stderr, "GsRenderer: Failed to open %s\n", texturesBinPath); + logError("GsRenderer: Failed to open %s\n", texturesBinPath); abort(); } setvbuf(gs->texturesFile, nullptr, _IOFBF, 128 * 1024); @@ -1081,7 +1081,7 @@ static void gsInit(Renderer* renderer, DataWin* dataWin) { // Initialize EE RAM cache for compressed atlas data initEeCache(gs); - fprintf(stderr, "GsRenderer: Initialized (textured mode)\n"); + logInfo("GsRenderer: Initialized (textured mode)\n"); } static void gsDestroy(Renderer* renderer) { @@ -2295,7 +2295,7 @@ static void gsDeleteSprite(Renderer* renderer, int32_t spriteIndex) { if (0 > spriteIndex || (uint32_t) spriteIndex >= dw->sprt.count) return; // Refuse to delete original data.win sprites - their tpagIndices point into the static atlas, not snapshot pool. if (gs->originalSpriteCount > (uint32_t) spriteIndex) { - fprintf(stderr, "GsRenderer: Cannot delete data.win sprite %d\n", spriteIndex); + logWarn("GsRenderer: Cannot delete data.win sprite %d\n", spriteIndex); return; } @@ -2378,9 +2378,9 @@ static u64 gmsBlendModeToGSAlpha(int32_t mode) { static BlendFactors gsGpuGetBlendFactors(Renderer* renderer) { GsRenderer* gs = (GsRenderer*)renderer; return (BlendFactors){ - gs->currentSFactor, - gs->currentDFactor, - gs->currentSFactorAlpha, + gs->currentSFactor, + gs->currentDFactor, + gs->currentSFactorAlpha, gs->currentDFactorAlpha }; } @@ -2405,7 +2405,7 @@ static void gsGpuSetBlendModeExt(Renderer* renderer, int32_t sfactor, int32_t df gs->currentDFactorAlpha = dfactor_alpha; u64 alpha; if (!gmsFactorPairToGSAlpha(sfactor, dfactor, &alpha) && !gs->blendModeWarned) { - fprintf(stderr, "GsRenderer: blend mode (sf=%d, df=%d) not exactly representable on PS2; approximating\n", sfactor, dfactor); + logWarn("GsRenderer: blend mode (sf=%d, df=%d) not exactly representable on PS2; approximating\n", sfactor, dfactor); gs->blendModeWarned = true; } gs->currentBlendAlpha = alpha; @@ -2668,7 +2668,7 @@ static int32_t gsCreateSurface(Renderer* renderer, int32_t width, int32_t height } if (phantomReason != nullptr) { - fprintf(stderr, "GsRenderer: surface_create(%d, %d) phantom (%s); needed %d chunks (%u bytes)\n", width, height, phantomReason, chunksNeeded, bytes); + logWarn("GsRenderer: surface_create(%d, %d) phantom (%s); needed %d chunks (%u bytes)\n", width, height, phantomReason, chunksNeeded, bytes); Surface* s = &gs->surfaces[row]; s->firstChunk = 0; s->chunkCount = 0; diff --git a/src/ps2/main.c b/src/ps2/main.c index 1a13127d6..26d230219 100644 --- a/src/ps2/main.c +++ b/src/ps2/main.c @@ -88,6 +88,25 @@ static bool padWasStable[2] = {false, false}; // Whether the controllers should be exposed via the GameMaker gamepad API static bool gamepadApiEnabled = false; +void platformLog(const logType type, const char *format, va_list va) { + FILE *out = stderr; + switch (type) { + case LOG_TYPE_NORMAL: + out = stdout; + break; + case LOG_TYPE_WARNING: + fputs("Warning: ", out); + break; + case LOG_TYPE_ERROR: + fputs("Error: ", out); + break; + case LOG_TYPE_DEBUG: + fputs("Debug: ", out); + break; + } + vfprintf(out, format, va); +} + static void parsePadMappings(JsonValue* configRoot, const char* key, PadMapping** outMappings, int* outCount, const char* logLabel) { JsonValue* mappingsObj = JsonReader_getJsonValueByKey(configRoot, key); if (mappingsObj == nullptr || !JsonReader_isObject(mappingsObj)) return; @@ -98,7 +117,7 @@ static void parsePadMappings(JsonValue* configRoot, const char* key, PadMapping* JsonValue* gmlKeyVal = JsonReader_getJsonValueByIndex(mappingsObj, i); mappings[i].padButton = (uint16_t) atoi(padButtonStr); mappings[i].gmlKey = (int32_t) JsonReader_getInt(gmlKeyVal); - printf("CONFIG.JSN: %s mapping pad=%d -> gmlKey=%d\n", logLabel, mappings[i].padButton, mappings[i].gmlKey); + logInfo("CONFIG.JSN: %s mapping pad=%d -> gmlKey=%d\n", logLabel, mappings[i].padButton, mappings[i].gmlKey); } *outMappings = mappings; *outCount = count; @@ -253,15 +272,15 @@ int main(int argc, char* argv[]) { PS2Utils_extractDeviceKey(argv[0]); - fprintf(stderr, "argv0 is %s, device key is %s\n", argv[0], deviceKey.key); + logInfo("argv0 is %s, device key is %s\n", argv[0], deviceKey.key); PS2Utils_loadFSDrivers(); - fprintf(stderr, "Loaded FS drivers!\n"); + logInfo("Loaded FS drivers!\n"); char* dataWinPath = PS2Utils_createDevicePath("DATA.WIN"); - printf("Butterscotch PS2 - Loading %s\n", dataWinPath); + logInfo("Butterscotch PS2 - Loading %s\n", dataWinPath); // ===[ Initialize gsKit ]=== // This must happen first so we can show the loading screen during other init steps @@ -294,51 +313,51 @@ int main(int argc, char* argv[]) { int ret; ret = SifExecModuleBuffer(freesio2_irx, size_freesio2_irx, 0, nullptr, nullptr); if (0 > ret) { - printf("Failed to load freesio2: %d\n", ret); + logError("Failed to load freesio2: %d\n", ret); return 1; } ret = SifExecModuleBuffer(mcman_irx, size_mcman_irx, 0, nullptr, nullptr); if (0 > ret) { - printf("Failed to load mcman: %d\n", ret); + logError("Failed to load mcman: %d\n", ret); return 1; } ret = SifExecModuleBuffer(mcserv_irx, size_mcserv_irx, 0, nullptr, nullptr); if (0 > ret) { - printf("Failed to load mcserv: %d\n", ret); + logError("Failed to load mcserv: %d\n", ret); return 1; } ret = mcInit(MC_TYPE_MC); if (0 > ret) { - printf("Failed to init libmc: %d\n", ret); + logError("Failed to init libmc: %d\n", ret); return 1; } ret = SifExecModuleBuffer(freepad_irx, size_freepad_irx, 0, nullptr, nullptr); if (0 > ret) { - printf("Failed to load freepad: %d\n", ret); + logError("Failed to load freepad: %d\n", ret); return 1; } padInit(0); padOpened[0] = (padPortOpen(0, 0, padBuf[0]) != 0); padOpened[1] = (padPortOpen(1, 0, padBuf[1]) != 0); - if (!padOpened[0]) printf("Warning: failed to open pad port 0\n"); - if (!padOpened[1]) printf("Warning: failed to open pad port 1\n"); + if (!padOpened[0]) logWarn("failed to open pad port 0\n"); + if (!padOpened[1]) logWarn("failed to open pad port 1\n"); // ===[ Load USB Keyboard IOP Modules ]=== int usbdRet = SifExecModuleBuffer(usbd_irx, size_usbd_irx, 0, nullptr, nullptr); if (0 > usbdRet) { - printf("Warning: failed to load usbd: %d (keyboard disabled)\n", usbdRet); + logWarn("failed to load usbd: %d (keyboard disabled)\n", usbdRet); } else { int kbdRet = SifExecModuleBuffer(ps2kbd_irx, size_ps2kbd_irx, 0, nullptr, nullptr); if (0 > kbdRet) { - printf("Warning: failed to load ps2kbd: %d (keyboard disabled)\n", kbdRet); + logWarn("failed to load ps2kbd: %d (keyboard disabled)\n", kbdRet); } else if (PS2KbdInit() == 0) { - printf("Warning: PS2KbdInit failed (keyboard disabled)\n"); + logWarn("PS2KbdInit failed (keyboard disabled)\n"); } else { PS2KbdSetReadmode(PS2KBD_READMODE_RAW); PS2KbdSetBlockingMode(PS2KBD_NONBLOCKING); kbdAvailable = true; - printf("USB keyboard initialized\n"); + logInfo("USB keyboard initialized\n"); } } @@ -346,11 +365,11 @@ int main(int argc, char* argv[]) { // ===[ Load Audio IOP Modules ]=== ret = SifExecModuleBuffer(freesd_irx, size_freesd_irx, 0, nullptr, nullptr); if (0 > ret) { - printf("Failed to load freesd: %d\n", ret); + logWarn("Failed to load freesd: %d\n", ret); } ret = SifExecModuleBuffer(audsrv_irx, size_audsrv_irx, 0, nullptr, nullptr); if (0 > ret) { - printf("Failed to load audsrv: %d\n", ret); + logWarn("Failed to load audsrv: %d\n", ret); } #endif @@ -361,7 +380,7 @@ int main(int argc, char* argv[]) { padState = padGetState(0, 0); } while (PAD_STATE_STABLE != padState && PAD_STATE_FINDCTP1 != padState); - printf("Controller initialized\n"); + logInfo("Controller initialized\n"); // ===[ Load CONFIG.JSN ]=== PS2Overlay_drawStatusScreen(nullptr, "Loading CONFIG.JSN...", false); @@ -431,7 +450,7 @@ int main(int argc, char* argv[]) { options.eagerlyLoadedRooms = eagerRooms; options.progressCallback = PS2Overlay_statusScreenCallback; options.progressCallbackUserData = PS2Overlay_getCallbackData(); - + DataWin* dataWin = DataWin_parse(dataWinPath, options); free(dataWinPath); shfree(eagerRooms); @@ -458,7 +477,7 @@ int main(int argc, char* argv[]) { void* heapTop = sbrk(0); int32_t usedBytes = (int32_t) (uintptr_t) heapTop; int32_t freeBytes = MAX_MEMORY_BYTES - usedBytes; - printf("Memory after data.win parsing: used=%d bytes (%.1f KB), total=%d bytes (%.1f KB), free=%d bytes (%.1f KB)\n", usedBytes, (double) (usedBytes / 1024.0f), MAX_MEMORY_BYTES, (double) (MAX_MEMORY_BYTES / 1024.0f), freeBytes, (double) (freeBytes / 1024.0f)); + logInfo("Memory after data.win parsing: used=%d bytes (%.1f KB), total=%d bytes (%.1f KB), free=%d bytes (%.1f KB)\n", usedBytes, (double) (usedBytes / 1024.0f), MAX_MEMORY_BYTES, (double) (MAX_MEMORY_BYTES / 1024.0f), freeBytes, (double) (freeBytes / 1024.0f)); } FileSystem* fileSystem = Ps2FileSystem_create(configRoot, dataWin->gen8.displayName); @@ -499,7 +518,7 @@ int main(int argc, char* argv[]) { if (elem != nullptr && JsonReader_isString(elem)) { const char* objName = JsonReader_getString(elem); shput(runner->disabledObjects, objName, 1); - printf("Disabled object: %s\n", objName); + logInfo("Disabled object: %s\n", objName); } } } @@ -513,14 +532,14 @@ int main(int argc, char* argv[]) { gamepadApiEnabled = JsonReader_getBool(JsonReader_getJsonValueByKey(gamepadObj, "enabled")); } if (gamepadApiEnabled) { - printf("CONFIG.JSN: GameMaker gamepad API enabled\n"); + logInfo("CONFIG.JSN: GameMaker gamepad API enabled\n"); } { void* heapTop = sbrk(0); int32_t usedBytes = (int32_t) (uintptr_t) heapTop; int32_t freeBytes = MAX_MEMORY_BYTES - usedBytes; - printf("Memory after VM and runner creation: used=%d bytes (%.1f KB), total=%d bytes (%.1f KB), free=%d bytes (%.1f KB)\n", usedBytes, (double) (usedBytes / 1024.0f), MAX_MEMORY_BYTES, (double) (MAX_MEMORY_BYTES / 1024.0f), freeBytes, (double) (freeBytes / 1024.0f)); + logInfo("Memory after VM and runner creation: used=%d bytes (%.1f KB), total=%d bytes (%.1f KB), free=%d bytes (%.1f KB)\n", usedBytes, (double) (usedBytes / 1024.0f), MAX_MEMORY_BYTES, (double) (MAX_MEMORY_BYTES / 1024.0f), freeBytes, (double) (freeBytes / 1024.0f)); } PS2Overlay_drawStatusScreen(dataWin->gen8.displayName, "Initializing first room...", true); @@ -538,7 +557,7 @@ int main(int argc, char* argv[]) { PS2Utils_loadMassStorageDrivers(); gprof_start(); - fprintf(stderr, "gprof: Profiling started!\n"); + logInfo("gprof: Profiling started!\n"); #endif Gen8* gen8 = &dataWin->gen8; @@ -607,7 +626,7 @@ int main(int argc, char* argv[]) { int32_t nextIdx = dw->gen8.roomOrder[runner->currentRoomOrderPosition + 1]; runner->pendingRoom = nextIdx; runner->audioSystem->vtable->stopAll(runner->audioSystem); - fprintf(stderr, "Debug: Going to next room -> %s\n", dw->room.rooms[nextIdx].name); + logDebug("Going to next room -> %s\n", dw->room.rooms[nextIdx].name); } } @@ -632,7 +651,7 @@ int main(int argc, char* argv[]) { int32_t interactVarId = shget(runner->vmContext->varNameMap, "interact"); Instance_setSelfVar(runner->vmContext->globalScopeInstance, interactVarId, RValue_makeInt32(0)); - printf("Changed global.interact [%d] value!\n", interactVarId); + logInfo("Changed global.interact [%d] value!\n", interactVarId); } // ===[ Game Logic ]=== @@ -708,9 +727,9 @@ int main(int argc, char* argv[]) { } else { gprofPath = "mass:gmon.out"; } - fprintf(stderr, "gprof: Writing profiling data to %s\n", gprofPath); + logInfo("gprof: Writing profiling data to %s\n", gprofPath); gprof_stop(gprofPath, 1); - fprintf(stderr, "gprof: Done\n"); + logInfo("gprof: Done\n"); } #endif diff --git a/src/ps2/ps2_file_system.c b/src/ps2/ps2_file_system.c index cf7e4412b..7a73a4179 100644 --- a/src/ps2/ps2_file_system.c +++ b/src/ps2/ps2_file_system.c @@ -184,9 +184,9 @@ static void copyIconIcoIfMissing(const char* dirPath) { // Copy from boot device char* srcPath = PS2Utils_createDevicePath("ICON.ICO"); if (copyFile(srcPath, dstPath)) { - fprintf(stderr, "Ps2FileSystem: Copied ICON.ICO to %s\n", dirPath); + logInfo("Ps2FileSystem: Copied ICON.ICO to %s\n", dirPath); } else { - fprintf(stderr, "Ps2FileSystem: Failed to copy ICON.ICO from %s to %s\n", srcPath, dstPath); + logWarn("Ps2FileSystem: Failed to copy ICON.ICO from %s to %s\n", srcPath, dstPath); } free(srcPath); @@ -217,9 +217,9 @@ static void writeIconSysIfMissing(const char* dirPath, const char* gameTitle, co if (f != nullptr) { fwrite(buffer, 1, ICON_SYS_SIZE, f); fclose(f); - fprintf(stderr, "Ps2FileSystem: Created icon.sys in %s\n", dirPath); + logInfo("Ps2FileSystem: Created icon.sys in %s\n", dirPath); } else { - fprintf(stderr, "Ps2FileSystem: Failed to create icon.sys in %s\n", dirPath); + logWarn("Ps2FileSystem: Failed to create icon.sys in %s\n", dirPath); } free(iconSysPath); @@ -612,13 +612,13 @@ FileSystem* Ps2FileSystem_create(JsonValue* configRoot, const char* gameTitle) { const char* rawPath = JsonReader_getString(pathElement); char* resolved = expandBootPrefix(rawPath); arrput(resolvedPaths, resolved); - fprintf(stderr, "Ps2FileSystem: '%s' -> '%s'\n", gameFileName, resolved); + logInfo("Ps2FileSystem: '%s' -> '%s'\n", gameFileName, resolved); } shput(pfs->mappings, gameFileName, resolvedPaths); } - fprintf(stderr, "Ps2FileSystem: Loaded %d file mappings\n", (int) shlen(pfs->mappings)); + logInfo("Ps2FileSystem: Loaded %d file mappings\n", (int) shlen(pfs->mappings)); return (FileSystem*) pfs; } diff --git a/src/ps2/ps2_gamepad.c b/src/ps2/ps2_gamepad.c index 1c2aaa4aa..36f332bc8 100644 --- a/src/ps2/ps2_gamepad.c +++ b/src/ps2/ps2_gamepad.c @@ -5,6 +5,8 @@ #include #include +#include "log.h" + // Track DualShock-mode handshake completion per port so poll() can lazily kick it off if it hasn't run yet. static bool analogModeReady[2] = {false, false}; @@ -33,21 +35,21 @@ static void setupAnalogMode(int port) { } } if (!supportsDualshock) { - printf("Ps2Gamepad: port %d does not support DualShock mode\n", port); + logWarn("Ps2Gamepad: port %d does not support DualShock mode\n", port); analogModeReady[port] = true; return; } if (padSetMainMode(port, 0, PAD_MMODE_DUALSHOCK, PAD_MMODE_LOCK) == 0) { - printf("Ps2Gamepad: padSetMainMode failed on port %d\n", port); + logWarn("Ps2Gamepad: padSetMainMode failed on port %d\n", port); return; } if (!waitForRequest(port)) { - printf("Ps2Gamepad: DualShock mode request did not complete on port %d\n", port); + logWarn("Ps2Gamepad: DualShock mode request did not complete on port %d\n", port); return; } analogModeReady[port] = true; - printf("Ps2Gamepad: port %d set to DualShock analog mode\n", port); + logInfo("Ps2Gamepad: port %d set to DualShock analog mode\n", port); } void Ps2Gamepad_poll(RunnerGamepadState* gp, int port) { diff --git a/src/ps2/ps2_utils.c b/src/ps2/ps2_utils.c index bdb0021d9..71f2a5c0e 100644 --- a/src/ps2/ps2_utils.c +++ b/src/ps2/ps2_utils.c @@ -33,23 +33,23 @@ void PS2Utils_loadFSDrivers() { require(deviceKeyLoaded); if (deviceKey.usesISO9660) { - fprintf(stderr, "PS2Utils: Loading CDVD drivers for device key '%s'\n", deviceKey.key); + logInfo("PS2Utils: Loading CDVD drivers for device key '%s'\n", deviceKey.key); int ret; ret = SifLoadModule("rom0:CDVDMAN", 0, nullptr); if (0 > ret) { - fprintf(stderr, "PS2Utils: Failed to load CDVDMAN: %d\n", ret); + logError("PS2Utils: Failed to load CDVDMAN: %d\n", ret); abort(); } ret = SifLoadModule("rom0:CDVDFSV", 0, nullptr); if (0 > ret) { - fprintf(stderr, "PS2Utils: Failed to load CDVDFSV: %d\n", ret); + logError("PS2Utils: Failed to load CDVDFSV: %d\n", ret); abort(); } sceCdInit(SCECdINIT); - fprintf(stderr, "PS2Utils: CDVD initialized\n"); + logInfo("PS2Utils: CDVD initialized\n"); } } @@ -67,33 +67,33 @@ extern unsigned int size_usbmass_bd_irx; void PS2Utils_loadMassStorageDrivers() { require(deviceKeyLoaded); - fprintf(stderr, "PS2Utils: Loading USB mass storage drivers for gprof output...\n"); + logInfo("PS2Utils: Loading USB mass storage drivers for gprof output...\n"); int ret; ret = SifExecModuleBuffer(usbd_irx, size_usbd_irx, 0, nullptr, nullptr); if (0 > ret) { - fprintf(stderr, "PS2Utils: Failed to load usbd: %d\n", ret); + logWarn("PS2Utils: Failed to load usbd: %d\n", ret); } ret = SifExecModuleBuffer(bdm_irx, size_bdm_irx, 0, nullptr, nullptr); if (0 > ret) { - fprintf(stderr, "PS2Utils: Failed to load bdm: %d\n", ret); + logWarn("PS2Utils: Failed to load bdm: %d\n", ret); } ret = SifExecModuleBuffer(bdmfs_fatfs_irx, size_bdmfs_fatfs_irx, 0, nullptr, nullptr); if (0 > ret) { - fprintf(stderr, "PS2Utils: Failed to load bdmfs_fatfs: %d\n", ret); + logWarn("PS2Utils: Failed to load bdmfs_fatfs: %d\n", ret); } ret = SifExecModuleBuffer(usbmass_bd_irx, size_usbmass_bd_irx, 0, nullptr, nullptr); if (0 > ret) { - fprintf(stderr, "PS2Utils: Failed to load usbmass_bd: %d\n", ret); + logWarn("PS2Utils: Failed to load usbmass_bd: %d\n", ret); } // Wait for USB device detection sleep(3); - fprintf(stderr, "PS2Utils: USB mass storage drivers loaded\n"); + logInfo("PS2Utils: USB mass storage drivers loaded\n"); } #endif diff --git a/src/ps3/main.c b/src/ps3/main.c index 4eabdb9a1..0bd03bd43 100644 --- a/src/ps3/main.c +++ b/src/ps3/main.c @@ -81,7 +81,7 @@ const StickMapping STICK_MAPPINGS[] = { static bool prevStickState[sizeof(STICK_MAPPINGS) / sizeof(STICK_MAPPINGS[0])] = {0}; // ===[ MAIN ]=== -static double freq = 0; +static double freq = 0; #define PS3_GET_TIME ((double)__builtin_ppc_get_timebase() / (double)freq) bool shouldExit = false; @@ -94,7 +94,7 @@ static void sys_callback(uint64_t status, uint64_t param, void* userdata) { case SYSUTIL_EXIT_GAME: shouldExit = true; break; - + case SYSUTIL_MENU_OPEN: case SYSUTIL_MENU_CLOSE: break; @@ -155,9 +155,27 @@ char *str_replace(char *orig, char *rep, char *with) { return result; } +void platformLog(const logType type, const char *format, va_list va) { + FILE *out = stderr; + switch (type) { + case LOG_TYPE_NORMAL: + out = stdout; + break; + case LOG_TYPE_WARNING: + fputs("Warning: ", out); + break; + case LOG_TYPE_ERROR: + fputs("Error: ", out); + break; + case LOG_TYPE_DEBUG: + fputs("Debug: ", out); + break; + } + vfprintf(out, format, va); +} static char buffer[9999]; int main(int argc, char* argv[]) { - printf("%s\n", argv[0]); + logInfo("%s\n", argv[0]); if (argc > 0) strcpy(buffer, argv[0]); char* tmp = str_replace(buffer, "butterscotch.elf", ""); @@ -176,7 +194,7 @@ int main(int argc, char* argv[]) { sysUtilRegisterCallback(SYSUTIL_EVENT_SLOT0, sys_callback, NULL); freq = sysGetTimebaseFrequency(); - printf("Loading %s...\n", dataWinPath); + logInfo("Loading %s...\n", dataWinPath); DataWinParserOptions options = {0}; options.parseGen8 = true; @@ -210,7 +228,7 @@ int main(int argc, char* argv[]) { DataWin* dataWin = DataWin_parse(dataWinPath, options); Gen8* gen8 = &dataWin->gen8; - printf("Loaded \"%s\" (%d) successfully! [WAD Version %u / GameMaker version %u.%u.%u.%u]\n", gen8->name, gen8->gameID, gen8->wadVersion, dataWin->detectedFormat.major, dataWin->detectedFormat.minor, dataWin->detectedFormat.release, dataWin->detectedFormat.build); + logInfo("Loaded \"%s\" (%d) successfully! [WAD Version %u / GameMaker version %u.%u.%u.%u]\n", gen8->name, gen8->gameID, gen8->wadVersion, dataWin->detectedFormat.major, dataWin->detectedFormat.minor, dataWin->detectedFormat.release, dataWin->detectedFormat.build); // Initialize VM VMContext* vm = VM_create(dataWin); @@ -254,7 +272,7 @@ int main(int argc, char* argv[]) { memcpy(texturesBinPath, dataWinDir, dirLen); strcpy(texturesBinPath + dirLen, "textures.bin"); if (!PS3Textures_init(texturesBinPath)) { - fprintf(stderr, "FATAL: failed to load %s\n", texturesBinPath); + logError("Fatal: failed to load %s\n", texturesBinPath); return 1; } free(texturesBinPath); @@ -285,7 +303,7 @@ int main(int argc, char* argv[]) { glUseProgram(gPalettedProgram); glUniform1i(uPaletteLoc, 1); glUseProgram(0); - printf("Paletted shader: program=%u uPaletteV=%d uPalette=%d\n", gPalettedProgram, gPalettedUPaletteVLoc, uPaletteLoc); + logInfo("Paletted shader: program=%u uPaletteV=%d uPalette=%d\n", gPalettedProgram, gPalettedUPaletteVLoc, uPaletteLoc); } // Initialize the runner @@ -310,7 +328,7 @@ int main(int argc, char* argv[]) { bool shouldStep = true; if (runner->debugMode && debugPaused) { shouldStep = RunnerKeyboard_checkPressed(runner->keyboard, 'O'); - if (shouldStep) fprintf(stderr, "Debug: Frame advance (frame %d)\n", runner->frameCount); + if (shouldStep) logDebug("Frame advance (frame %d)\n", runner->frameCount); } @@ -450,6 +468,6 @@ int main(int argc, char* argv[]) { sysUtilUnregisterCallback(SYSUTIL_EVENT_SLOT0); gcmSetWaitFlip(context); rsxFinish(context,1); - printf("Bye! :3\n"); + logInfo("Bye! :3\n"); return 0; } diff --git a/src/ps3/ps3_overlay.c b/src/ps3/ps3_overlay.c index 5eaa4cacd..9c154b110 100644 --- a/src/ps3/ps3_overlay.c +++ b/src/ps3/ps3_overlay.c @@ -31,7 +31,7 @@ void PS3Overlay_init(void) { // Convert the 8bpp atlas into RGBA uint8_t* rgba = (uint8_t*) malloc((size_t) (DEBUGFONT_ATLAS_W * DEBUGFONT_ATLAS_H * 4)); if (rgba == nullptr) { - fprintf(stderr, "PS3Overlay: failed to allocate %d bytes for the font atlas\n", DEBUGFONT_ATLAS_W * DEBUGFONT_ATLAS_H * 4); + logWarn("PS3Overlay: failed to allocate %d bytes for the font atlas\n", DEBUGFONT_ATLAS_W * DEBUGFONT_ATLAS_H * 4); return; } diff --git a/src/ps3/ps3_textures.c b/src/ps3/ps3_textures.c index b05cbc474..a946caa74 100644 --- a/src/ps3/ps3_textures.c +++ b/src/ps3/ps3_textures.c @@ -4,6 +4,8 @@ #include #include +#include "log.h" + // We stream the texture pages on demand from the file instead of loading everything in RAM. #define PAGE_HEADER_SIZE 12 // u16 w, u16 h, u32 pixelOffset, u32 pixelDataSize @@ -44,7 +46,7 @@ bool PS3Textures_init(const char* texturesBinPath) { gFp = fopen(texturesBinPath, "rb"); if (gFp == NULL) { - fprintf(stderr, "PS3Textures: cannot open %s\n", texturesBinPath); + logWarn("PS3Textures: cannot open %s\n", texturesBinPath); return false; } @@ -52,7 +54,7 @@ bool PS3Textures_init(const char* texturesBinPath) { uint8_t headerBuf[7]; if (fread(headerBuf, 1, 7, gFp) != 7) goto fail; if (headerBuf[0] != 0) { - fprintf(stderr, "PS3Textures: unsupported version %u\n", headerBuf[0]); + logWarn("PS3Textures: unsupported version %u\n", headerBuf[0]); goto fail; } gClutCount = readU16BE(headerBuf + 1); @@ -63,7 +65,7 @@ bool PS3Textures_init(const char* texturesBinPath) { size_t clutBytes = (size_t) gClutCount * 256 * 4; uint8_t* clutBuf = (uint8_t*) malloc(clutBytes); if (clutBuf == NULL) { - fprintf(stderr, "PS3Textures: malloc(%zu) for CLUT failed\n", clutBytes); + logWarn("PS3Textures: malloc(%zu) for CLUT failed\n", clutBytes); goto fail; } if (fread(clutBuf, 1, clutBytes, gFp) != clutBytes) { @@ -112,7 +114,7 @@ bool PS3Textures_init(const char* texturesBinPath) { // Pixel block starts here. Pages are streamed from disk on demand. gPixelBlockBase = ftell(gFp); - fprintf(stderr, "PS3Textures: opened %s (clutCount=%u pages=%u tpags=%u, streaming pixels)\n", texturesBinPath, gClutCount, gPageCount, gTpagCount); + logInfo("PS3Textures: opened %s (clutCount=%u pages=%u tpags=%u, streaming pixels)\n", texturesBinPath, gClutCount, gPageCount, gTpagCount); gInitialized = true; return true; @@ -152,7 +154,7 @@ bool PS3Textures_loadPage(uint32_t pageId, int* outW, int* outH, uint8_t** outPi uint8_t* buf = (uint8_t*) malloc(h->pixelDataSize); if (buf == NULL) { - fprintf(stderr, "PS3Textures: malloc(%u) for page %u failed\n", h->pixelDataSize, pageId); + logWarn("PS3Textures: malloc(%u) for page %u failed\n", h->pixelDataSize, pageId); return false; } diff --git a/src/runner.c b/src/runner.c index a147ced1d..4cd0d2170 100644 --- a/src/runner.c +++ b/src/runner.c @@ -59,7 +59,7 @@ void Runner_updateCameraViewSimple(GMLCamera* camera) { Matrix4f projectionMatrix; Matrix4f_Orthographic(&projectionMatrix, (float) camera->viewWidth, -((float) camera->viewHeight), 32000.0, 0.0); - + camera->viewMatrix = viewMatrix; camera->projectionMatrix = projectionMatrix; @@ -394,9 +394,9 @@ static void Runner_executeResolvedEvent(Runner* runner, Instance* instance, int3 if (shouldTrace) { if (eventType == EVENT_ALARM) { - fprintf(stderr, "Runner: [%s] %s %d (instanceId=%d)\n", objectName, eventName, eventSubtype, instance->instanceId); + logInfo("Runner: [%s] %s %d (instanceId=%d)\n", objectName, eventName, eventSubtype, instance->instanceId); } else { - fprintf(stderr, "Runner: [%s] %s (instanceId=%d)\n", objectName, eventName, instance->instanceId); + logInfo("Runner: [%s] %s (instanceId=%d)\n", objectName, eventName, instance->instanceId); } } } @@ -687,7 +687,7 @@ void Runner_drawTileLayer(Runner* runner, RoomLayerTilesData* data, float layerO bool rotate = (cell & GMS2_TILE_ROTATE_MASK) != 0; if (rotate && !rotateWarned) { - fprintf(stderr, "Runner: WARNING: GMS2 tile layer has rotated tiles; rotation not yet implemented, drawing unrotated\n"); + logWarn("Runner: GMS2 tile layer has rotated tiles; rotation not yet implemented, drawing unrotated\n"); rotateWarned = true; } @@ -881,14 +881,14 @@ void Runner_draw(Runner* runner) { int32_t tpagIndex = Renderer_resolveObjectTPAGIndex(dataWin, tile); if (tpagIndex >= 0) { TexturePageItem* tpag = &dataWin->tpag.items[tpagIndex]; - fprintf(stderr, "Runner: [%s] Drawing tile #%d bg=%s(%d) tpag(srcX=%d srcY=%d srcW=%d srcH=%d tgtX=%d tgtY=%d bndW=%d bndH=%d page=%d) tile(srcX=%d srcY=%d w=%u h=%u) at pos=(%d,%d) depth=%d\n", roomName, d->tileIndex, bgName, tile->backgroundDefinition, tpag->sourceX, tpag->sourceY, tpag->sourceWidth, tpag->sourceHeight, tpag->targetX, tpag->targetY, tpag->boundingWidth, tpag->boundingHeight, tpag->texturePageId, tile->sourceX, tile->sourceY, tile->width, tile->height, tile->x, tile->y, tile->tileDepth); + logInfo("Runner: [%s] Drawing tile #%d bg=%s(%d) tpag(srcX=%d srcY=%d srcW=%d srcH=%d tgtX=%d tgtY=%d bndW=%d bndH=%d page=%d) tile(srcX=%d srcY=%d w=%u h=%u) at pos=(%d,%d) depth=%d\n", roomName, d->tileIndex, bgName, tile->backgroundDefinition, tpag->sourceX, tpag->sourceY, tpag->sourceWidth, tpag->sourceHeight, tpag->targetX, tpag->targetY, tpag->boundingWidth, tpag->boundingHeight, tpag->texturePageId, tile->sourceX, tile->sourceY, tile->width, tile->height, tile->x, tile->y, tile->tileDepth); // Warn if tile source rect exceeds TPAG content bounds if ((uint32_t) (tile->sourceX + tile->width) > (uint32_t) tpag->sourceWidth || (uint32_t) (tile->sourceY + tile->height) > (uint32_t) tpag->sourceHeight) { - fprintf(stderr, "Runner: [%s] WARNING: Tile #%d source rect (%d,%d %ux%u) exceeds TPAG content bounds (%dx%d)\n", roomName, d->tileIndex, tile->sourceX, tile->sourceY, tile->width, tile->height, tpag->sourceWidth, tpag->sourceHeight); + logWarn("Runner: [%s] Tile #%d source rect (%d,%d %ux%u) exceeds TPAG content bounds (%dx%d)\n", roomName, d->tileIndex, tile->sourceX, tile->sourceY, tile->width, tile->height, tpag->sourceWidth, tpag->sourceHeight); } } else { - fprintf(stderr, "Runner: [%s] Drawing tile #%d bg=%s(%d) tpag=UNRESOLVED tile(srcX=%d srcY=%d w=%u h=%u) at pos=(%d,%d) depth=%d\n", roomName, d->tileIndex, bgName, tile->backgroundDefinition, tile->sourceX, tile->sourceY, tile->width, tile->height, tile->x, tile->y, tile->tileDepth); + logInfo("Runner: [%s] Drawing tile #%d bg=%s(%d) tpag=UNRESOLVED tile(srcX=%d srcY=%d w=%u h=%u) at pos=(%d,%d) depth=%d\n", roomName, d->tileIndex, bgName, tile->backgroundDefinition, tile->sourceX, tile->sourceY, tile->width, tile->height, tile->x, tile->y, tile->tileDepth); } } } @@ -915,14 +915,14 @@ void Runner_draw(Runner* runner) { Instance* savedInstance = ctx->currentInstance; int32_t savedEventType = ctx->currentEventType; int32_t savedEventSubtype = ctx->currentEventSubtype; - + ctx->currentInstance = ctx->globalScopeInstance; ctx->currentEventType = EVENT_DRAW; ctx->currentEventSubtype = DRAW_NORMAL; - + if (runtimeLayer->beginScript >= 0) VM_callCodeIndex(ctx, runtimeLayer->beginScript, nullptr, 0); - + ctx->currentInstance = savedInstance; ctx->currentEventType = savedEventType; ctx->currentEventSubtype = savedEventSubtype; @@ -983,14 +983,14 @@ void Runner_draw(Runner* runner) { int32_t tpagIndex = Renderer_resolveObjectTPAGIndex(dataWin, tile); if (tpagIndex >= 0) { TexturePageItem* tpag = &dataWin->tpag.items[tpagIndex]; - fprintf(stderr, "Runner: [%s] Drawing tile #%d bg=%s(%d) tpag(srcX=%d srcY=%d srcW=%d srcH=%d tgtX=%d tgtY=%d bndW=%d bndH=%d page=%d) tile(srcX=%d srcY=%d w=%u h=%u) at pos=(%d,%d) depth=%d\n", roomName, d->tileIndex, bgName, tile->backgroundDefinition, tpag->sourceX, tpag->sourceY, tpag->sourceWidth, tpag->sourceHeight, tpag->targetX, tpag->targetY, tpag->boundingWidth, tpag->boundingHeight, tpag->texturePageId, tile->sourceX, tile->sourceY, tile->width, tile->height, tile->x, tile->y, tile->tileDepth); + logInfo("Runner: [%s] Drawing tile #%d bg=%s(%d) tpag(srcX=%d srcY=%d srcW=%d srcH=%d tgtX=%d tgtY=%d bndW=%d bndH=%d page=%d) tile(srcX=%d srcY=%d w=%u h=%u) at pos=(%d,%d) depth=%d\n", roomName, d->tileIndex, bgName, tile->backgroundDefinition, tpag->sourceX, tpag->sourceY, tpag->sourceWidth, tpag->sourceHeight, tpag->targetX, tpag->targetY, tpag->boundingWidth, tpag->boundingHeight, tpag->texturePageId, tile->sourceX, tile->sourceY, tile->width, tile->height, tile->x, tile->y, tile->tileDepth); // Warn if tile source rect exceeds TPAG content bounds if ((uint32_t) (tile->sourceX + tile->width) > (uint32_t) tpag->sourceWidth || (uint32_t) (tile->sourceY + tile->height) > (uint32_t) tpag->sourceHeight) { - fprintf(stderr, "Runner: [%s] WARNING: Tile #%d source rect (%d,%d %ux%u) exceeds TPAG content bounds (%dx%d)\n", roomName, d->tileIndex, tile->sourceX, tile->sourceY, tile->width, tile->height, tpag->sourceWidth, tpag->sourceHeight); + logWarn("Runner: [%s] Tile #%d source rect (%d,%d %ux%u) exceeds TPAG content bounds (%dx%d)\n", roomName, d->tileIndex, tile->sourceX, tile->sourceY, tile->width, tile->height, tpag->sourceWidth, tpag->sourceHeight); } } else { - fprintf(stderr, "Runner: [%s] Drawing tile #%d bg=%s(%d) tpag=UNRESOLVED tile(srcX=%d srcY=%d w=%u h=%u) at pos=(%d,%d) depth=%d\n", roomName, d->tileIndex, bgName, tile->backgroundDefinition, tile->sourceX, tile->sourceY, tile->width, tile->height, tile->x, tile->y, tile->tileDepth); + logInfo("Runner: [%s] Drawing tile #%d bg=%s(%d) tpag=UNRESOLVED tile(srcX=%d srcY=%d w=%u h=%u) at pos=(%d,%d) depth=%d\n", roomName, d->tileIndex, bgName, tile->backgroundDefinition, tile->sourceX, tile->sourceY, tile->width, tile->height, tile->x, tile->y, tile->tileDepth); } } } @@ -1031,10 +1031,10 @@ void Runner_draw(Runner* runner) { ctx->currentInstance = ctx->globalScopeInstance; ctx->currentEventType = EVENT_DRAW; ctx->currentEventSubtype = DRAW_NORMAL; - + if (runtimeLayer->endScript >= 0) VM_callCodeIndex(ctx, runtimeLayer->endScript, nullptr, 0); - + ctx->currentInstance = savedInstance; ctx->currentEventType = savedEventType; ctx->currentEventSubtype = savedEventSubtype; @@ -1288,7 +1288,7 @@ static Instance* createAndInitInstance(Runner* runner, int32_t instanceId, int32 #ifdef ENABLE_VM_TRACING if (shgeti(runner->vmContext->instanceLifecyclesToBeTraced, "*") != -1 || shgeti(runner->vmContext->instanceLifecyclesToBeTraced, objDef->name) != -1) { - fprintf(stderr, "VM: Instance %s (instanceId=%d,objectIndex=%d) created at (%f, %f)\n", objDef->name, instanceId, inst->objectIndex, x, y); + logInfo("VM: Instance %s (instanceId=%d,objectIndex=%d) created at (%f, %f)\n", objDef->name, instanceId, inst->objectIndex, x, y); } #endif @@ -1308,7 +1308,7 @@ static Instance** takePersistentInstances(Runner* runner) { #ifdef ENABLE_VM_TRACING GameObject* gameObject = &runner->dataWin->objt.objects[inst->objectIndex]; if (shgeti(runner->vmContext->instanceLifecyclesToBeTraced, "*") != -1 || shgeti(runner->vmContext->instanceLifecyclesToBeTraced, gameObject->name) != -1) { - fprintf(stderr, "VM: Instance %s (instanceId=%d,objectIndex=%d) has been persisted at (%f, %f) due to room change\n", gameObject->name, inst->instanceId, inst->objectIndex, inst->x, inst->y); + logInfo("VM: Instance %s (instanceId=%d,objectIndex=%d) has been persisted at (%f, %f) due to room change\n", gameObject->name, inst->instanceId, inst->objectIndex, inst->x, inst->y); } #endif @@ -1321,7 +1321,7 @@ static Instance** takePersistentInstances(Runner* runner) { #ifdef ENABLE_VM_TRACING GameObject* gameObject = &runner->dataWin->objt.objects[inst->objectIndex]; if (shgeti(runner->vmContext->instanceLifecyclesToBeTraced, "*") != -1 || shgeti(runner->vmContext->instanceLifecyclesToBeTraced, gameObject->name) != -1) { - fprintf(stderr, "VM: Instance %s (instanceId=%d,objectIndex=%d) destroyed at (%f, %f) due to room change\n", gameObject->name, inst->instanceId, inst->objectIndex, inst->x, inst->y); + logInfo("VM: Instance %s (instanceId=%d,objectIndex=%d) destroyed at (%f, %f) due to room change\n", gameObject->name, inst->instanceId, inst->objectIndex, inst->x, inst->y); } #endif @@ -1467,7 +1467,7 @@ static void initRoom(Runner* runner, int32_t roomIndex) { returnPersistentInstances(runner, carriedPersistent); // No Create events, no preCreateCode, no creationCode, no room creation code - fprintf(stderr, "Runner: Room restored (persistent): %s (room %d) with %d instances\n", room->name, roomIndex, (int) arrlen(runner->instances)); + logInfo("Runner: Room restored (persistent): %s (room %d) with %d instances\n", room->name, roomIndex, (int) arrlen(runner->instances)); return; } @@ -1674,7 +1674,7 @@ static void initRoom(Runner* runner, int32_t roomIndex) { RoomGameObject* roomObj = &room->gameObjects[i]; if (roomObj->objectDefinition == -1) { - fprintf(stderr, "Runner: Object %d in room %s does not have a valid object definition reference! Was it deleted in the editor?\n", roomObj->instanceID, room->name); + logWarn("Runner: Object %d in room %s does not have a valid object definition reference! Was it deleted in the editor?\n", roomObj->instanceID, room->name); continue; } @@ -1752,7 +1752,7 @@ static void initRoom(Runner* runner, int32_t roomIndex) { // Mark this room as initialized for persistent room support savedState->initialized = true; - fprintf(stderr, "Runner: Room loaded: %s (room %d) with %d instances\n", room->name, roomIndex, (int) arrlen(runner->instances)); + logInfo("Runner: Room loaded: %s (room %d) with %d instances\n", room->name, roomIndex, (int) arrlen(runner->instances)); } // Cleans up the runner state, used when freeing the Runner or when restarting the Runner @@ -2256,7 +2256,7 @@ Runner* Runner_create(DataWin* dataWin, VMContext* vm, Renderer* renderer, FileS repeat(shlen(vm->builtinMap), i) { bool isRegistered = shgeti(vm->codeIndexByName, vm->builtinMap[i].key) != -1; if (isRegistered) { - fprintf(stderr, "Runner: Builtin function %s has the same name as a GML script! The script may be a compatibility script provided by GM:S 2+, and the game may have issues due to the builtin overriding it!\n", vm->builtinMap[i].key); + logWarn("Runner: Builtin function %s has the same name as a GML script! The script may be a compatibility script provided by GM:S 2+, and the game may have issues due to the builtin overriding it!\n", vm->builtinMap[i].key); } } @@ -2308,7 +2308,7 @@ Instance* Runner_createInstanceWithLayer(Runner* runner, GMLReal x, GMLReal y, i if (isObjectDisabled(runner, objectIndex)) return nullptr; RuntimeLayer* rl = Runner_findRuntimeLayerById(runner, layerId); if (rl == nullptr) { - fprintf(stderr, "Runner: instance_create_layer: Layer ID %d not found!\n", layerId); + logWarn("Runner: instance_create_layer: Layer ID %d not found!\n", layerId); return nullptr; } Instance* inst = createAndInitInstance(runner, runner->nextInstanceId++, objectIndex, x, y); @@ -2355,7 +2355,7 @@ void Runner_destroyInstance(MAYBE_UNUSED Runner* runner, Instance* inst, bool ru #ifdef ENABLE_VM_TRACING GameObject* gameObject = &runner->dataWin->objt.objects[inst->objectIndex]; if (shgeti(runner->vmContext->instanceLifecyclesToBeTraced, "*") != -1 || shgeti(runner->vmContext->instanceLifecyclesToBeTraced, gameObject->name) != -1) { - fprintf(stderr, "VM: Instance %s (instanceId=%d,objectIndex=%d) destroyed\n", gameObject->name, inst->instanceId, inst->objectIndex); + logInfo("VM: Instance %s (instanceId=%d,objectIndex=%d) destroyed\n", gameObject->name, inst->instanceId, inst->objectIndex); } #endif } @@ -2503,7 +2503,7 @@ void Runner_initFirstRoom(Runner* runner) { repeat(dataWin->glob.count, i) { int32_t codeId = dataWin->glob.codeIds[i]; if (codeId >= 0 && dataWin->code.count > (uint32_t) codeId) { - fprintf(stderr, "Runner: Executing global init script: %s\n", dataWin->code.entries[codeId].name); + logInfo("Runner: Executing global init script: %s\n", dataWin->code.entries[codeId].name); RValue result = VM_executeCode(runner->vmContext, codeId); RValue_free(&result); } @@ -2518,12 +2518,12 @@ void Runner_initFirstRoom(Runner* runner) { if (initScript == nullptr || initScript[0] == '\0') continue; int32_t scriptIndex = shget(runner->assetsByName, initScript); if (0 > scriptIndex || (uint32_t) scriptIndex >= dataWin->scpt.count) { - fprintf(stderr, "Runner: Extension init script '%s' not found, skipping\n", initScript); + logWarn("Runner: Extension init script '%s' not found, skipping\n", initScript); continue; } int32_t codeId = dataWin->scpt.scripts[scriptIndex].codeId; if (codeId >= 0 && dataWin->code.count > (uint32_t) codeId) { - fprintf(stderr, "Runner: Executing extension init script: %s\n", initScript); + logInfo("Runner: Executing extension init script: %s\n", initScript); RValue result = VM_executeCode(runner->vmContext, codeId); RValue_free(&result); } @@ -2608,7 +2608,7 @@ static void executeCollisionEvent(Runner* runner, Instance* self, Instance* othe const char* targetName = runner->dataWin->objt.objects[targetObjectIndex].name; bool shouldTrace = shgeti(vm->eventsToBeTraced, "*") != -1 || shgeti(vm->eventsToBeTraced, "Collision") != -1 || shgeti(vm->eventsToBeTraced, selfName) != -1; if (shouldTrace) { - fprintf(stderr, "Runner: [%s] Collision with %s (instanceId=%d, otherId=%d)\n", selfName, targetName, self->instanceId, other->instanceId); + logInfo("Runner: [%s] Collision with %s (instanceId=%d, otherId=%d)\n", selfName, targetName, self->instanceId, other->instanceId); } } #endif @@ -3076,7 +3076,7 @@ static void dispatchCollisionEvents(Runner* runner) { #ifdef ENABLE_VM_TRACING bool traceThisPair = shouldTraceCollisionPair(runner->vmContext, dataWin, self, other); if (traceThisPair && (!bboxSelf.valid || !bboxOther.valid)) { - fprintf(stderr, "Collision: [%s id=%d] vs [%s id=%d] bbox-invalid (selfValid=%d otherValid=%d)\n", + logInfo("Collision: [%s id=%d] vs [%s id=%d] bbox-invalid (selfValid=%d otherValid=%d)\n", dataWin->objt.objects[self->objectIndex].name, self->instanceId, dataWin->objt.objects[other->objectIndex].name, other->instanceId, bboxSelf.valid, bboxOther.valid); @@ -3088,7 +3088,7 @@ static void dispatchCollisionEvents(Runner* runner) { bool aabbMiss = bboxSelf.left >= bboxOther.right || bboxOther.left >= bboxSelf.right || bboxSelf.top >= bboxOther.bottom || bboxOther.top >= bboxSelf.bottom; #ifdef ENABLE_VM_TRACING if (traceThisPair) { - fprintf(stderr, "Collision: [%s id=%d pos=(%g,%g)] vs [%s id=%d pos=(%g,%g)] selfBB=(%g,%g,%g,%g %gx%g) otherBB=(%g,%g,%g,%g %gx%g) selfSolid=%d otherSolid=%d AABB=%s\n", + logInfo("Collision: [%s id=%d pos=(%g,%g)] vs [%s id=%d pos=(%g,%g)] selfBB=(%g,%g,%g,%g %gx%g) otherBB=(%g,%g,%g,%g %gx%g) selfSolid=%d otherSolid=%d AABB=%s\n", dataWin->objt.objects[self->objectIndex].name, self->instanceId, self->x, self->y, dataWin->objt.objects[other->objectIndex].name, other->instanceId, other->x, other->y, bboxSelf.left, bboxSelf.top, bboxSelf.right, bboxSelf.bottom, bboxSelf.right - bboxSelf.left, bboxSelf.bottom - bboxSelf.top, @@ -3105,7 +3105,7 @@ static void dispatchCollisionEvents(Runner* runner) { if (needsPrecise) { bool preciseHit = Collision_instancesOverlapPrecise(runner, self, other, bboxSelf, bboxOther); #ifdef ENABLE_VM_TRACING - if (traceThisPair) fprintf(stderr, " precise=%s (selfSepMasks=%d otherSepMasks=%d)\n", preciseHit ? "hit" : "miss", sprSelf ? (int32_t)sprSelf->sepMasks : -1, sprOther ? (int32_t)sprOther->sepMasks : -1); + if (traceThisPair) logInfo(" precise=%s (selfSepMasks=%d otherSepMasks=%d)\n", preciseHit ? "hit" : "miss", sprSelf ? (int32_t)sprSelf->sepMasks : -1, sprOther ? (int32_t)sprOther->sepMasks : -1); #endif if (!preciseHit) continue; } @@ -3114,7 +3114,7 @@ static void dispatchCollisionEvents(Runner* runner) { bool hadSolid = self->solid || other->solid; if (hadSolid) { #ifdef ENABLE_VM_TRACING - if (traceThisPair) fprintf(stderr, " solid-restore: self.solid=%d other.solid=%d self=(%g,%g)->(%g,%g) other=(%g,%g)->(%g,%g)\n", self->solid, other->solid, self->x, self->y, self->xprevious, self->yprevious, other->x, other->y, other->xprevious, other->yprevious); + if (traceThisPair) logInfo(" solid-restore: self.solid=%d other.solid=%d self=(%g,%g)->(%g,%g) other=(%g,%g)->(%g,%g)\n", self->solid, other->solid, self->x, self->y, self->xprevious, self->yprevious, other->x, other->y, other->xprevious, other->yprevious); #endif self->x = self->xprevious; self->y = self->yprevious; @@ -3130,7 +3130,7 @@ static void dispatchCollisionEvents(Runner* runner) { // And if it DOES move via GML, the variable write handlers will set it to dirty #ifdef ENABLE_VM_TRACING - if (traceThisPair) fprintf(stderr, " fire self->other: subtype=%d (%s) owner=%d (%s) codeId=%d codeName=%s\n", targetObjIndex, dataWin->objt.objects[targetObjIndex].name, evt->ownerObjectIndex, dataWin->objt.objects[evt->ownerObjectIndex].name, evt->codeId, dataWin->code.entries[evt->codeId].name); + if (traceThisPair) logInfo(" fire self->other: subtype=%d (%s) owner=%d (%s) codeId=%d codeName=%s\n", targetObjIndex, dataWin->objt.objects[targetObjIndex].name, evt->ownerObjectIndex, dataWin->objt.objects[evt->ownerObjectIndex].name, evt->codeId, dataWin->code.entries[evt->codeId].name); #endif executeCollisionEvent(runner, self, other, targetObjIndex, evt->codeId, evt->ownerObjectIndex); @@ -3143,8 +3143,8 @@ static void dispatchCollisionEvents(Runner* runner) { FlattenedCollisionEvent* reverseEvt = findSymmetricCollisionEvent(runner, other, self); #ifdef ENABLE_VM_TRACING if (traceThisPair) { - if (reverseEvt != nullptr) fprintf(stderr, " fire other->self: subtype=%u (%s) owner=%d (%s) codeId=%d codeName=%s [symmetric]\n", reverseEvt->targetObjectIndex, dataWin->objt.objects[reverseEvt->targetObjectIndex].name, reverseEvt->ownerObjectIndex, dataWin->objt.objects[reverseEvt->ownerObjectIndex].name, reverseEvt->codeId, dataWin->code.entries[evt->codeId].name); - else fprintf(stderr, " fire other->self: none (no matching handler) [symmetric]\n"); + if (reverseEvt != nullptr) logInfo(" fire other->self: subtype=%u (%s) owner=%d (%s) codeId=%d codeName=%s [symmetric]\n", reverseEvt->targetObjectIndex, dataWin->objt.objects[reverseEvt->targetObjectIndex].name, reverseEvt->ownerObjectIndex, dataWin->objt.objects[reverseEvt->ownerObjectIndex].name, reverseEvt->codeId, dataWin->code.entries[evt->codeId].name); + else logInfo(" fire other->self: none (no matching handler) [symmetric]\n"); } #endif if (reverseEvt != nullptr) @@ -3187,7 +3187,7 @@ static void dispatchCollisionEvents(Runner* runner) { } if (stillColliding) { #ifdef ENABLE_VM_TRACING - if (traceThisPair) fprintf(stderr, " post-event re-revert: still colliding, restoring self=(%g,%g)->(%g,%g) other=(%g,%g)->(%g,%g)\n", self->x, self->y, self->xprevious, self->yprevious, other->x, other->y, other->xprevious, other->yprevious); + if (traceThisPair) logInfo(" post-event re-revert: still colliding, restoring self=(%g,%g)->(%g,%g) other=(%g,%g)->(%g,%g)\n", self->x, self->y, self->xprevious, self->yprevious, other->x, other->y, other->xprevious, other->yprevious); #endif self->x = self->xprevious; self->y = self->yprevious; @@ -3483,7 +3483,7 @@ void Runner_handlePendingRoomChange(Runner* runner) { require(runner->dataWin->room.count > (uint32_t) newRoomIndex); const char* newRoomName = runner->dataWin->room.rooms[newRoomIndex].name; - fprintf(stderr, "Room changed: %s (room %d) -> %s (room %d)\n", oldRoomName, oldRoomIndex, newRoomName, newRoomIndex); + logInfo("Room changed: %s (room %d) -> %s (room %d)\n", oldRoomName, oldRoomIndex, newRoomName, newRoomIndex); // If the old room is persistent, save its instance and visual state if (oldRoom->persistent) { @@ -3645,10 +3645,10 @@ void Runner_step(Runner* runner) { inst->imageIndex += inst->imageSpeed * sprite->gms2PlaybackSpeed; } else { inst->imageIndex += (1.0/runner->currentRoom->speed) * sprite->gms2PlaybackSpeed * inst->imageSpeed; - } + } } } else { - inst->imageIndex += inst->imageSpeed; + inst->imageIndex += inst->imageSpeed; } float frameCount = (float) sprite->textureCount; bool wrapped = false; @@ -3713,7 +3713,7 @@ void Runner_step(Runner* runner) { #ifdef ENABLE_VM_TRACING GameObject* object = &runner->dataWin->objt.objects[inst->objectIndex]; if (shgeti(runner->vmContext->alarmsToBeTraced, "*") != -1 || shgeti(runner->vmContext->alarmsToBeTraced, object->name) != -1) { - fprintf(stderr, "VM: [%s] Ticking down Alarm[%d] (instanceId=%d), current tick is %d\n", object->name, (int)alarmIdx, inst->instanceId, inst->alarm[alarmIdx]); + logInfo("VM: [%s] Ticking down Alarm[%d] (instanceId=%d), current tick is %d\n", object->name, (int)alarmIdx, inst->instanceId, inst->alarm[alarmIdx]); } #endif @@ -3724,7 +3724,7 @@ void Runner_step(Runner* runner) { #ifdef ENABLE_VM_TRACING if (shgeti(runner->vmContext->alarmsToBeTraced, "*") != -1 || shgeti(runner->vmContext->alarmsToBeTraced, object->name) != -1) { - fprintf(stderr, "VM: [%s] Firing Alarm[%d] (instanceId=%d)\n", object->name, (int)alarmIdx, inst->instanceId); + logInfo("VM: [%s] Firing Alarm[%d] (instanceId=%d)\n", object->name, (int)alarmIdx, inst->instanceId); } #endif @@ -4032,9 +4032,9 @@ void Runner_dumpState(Runner* runner) { DataWin* dataWin = runner->dataWin; int32_t instanceCount = (int32_t) arrlen(runner->instances); - printf("=== Frame %d State Dump ===\n", runner->frameCount); - printf("Room: %s (index %d)\n", runner->currentRoom->name, runner->currentRoomIndex); - printf("Instance count: %d\n", instanceCount); + logInfo("=== Frame %d State Dump ===\n", runner->frameCount); + logInfo("Room: %s (index %d)\n", runner->currentRoom->name, runner->currentRoomIndex); + logInfo("Instance count: %d\n", instanceCount); repeat(instanceCount, i) { Instance* inst = runner->instances[i]; @@ -4057,23 +4057,23 @@ void Runner_dumpState(Runner* runner) { parentName = dataWin->objt.objects[gameObject->parentId].name; } - printf("\n--- Instance #%d (%s, objectIndex=%d) ---\n", inst->instanceId, objName, inst->objectIndex); - printf(" Position: (%g, %g)\n", (double) inst->x, (double) inst->y); - printf(" Depth: %d\n", inst->depth); - printf(" Sprite: %s (index %d), imageIndex=%g, imageSpeed=%g\n", spriteName, inst->spriteIndex, (double) inst->imageIndex, (double) inst->imageSpeed); - printf(" Scale: (%g, %g), Angle: %g, Alpha: %g, Blend: 0x%06X\n", (double) inst->imageXscale, (double) inst->imageYscale, (double) inst->imageAngle, (double) inst->imageAlpha, inst->imageBlend); - printf(" Visible: %s, Active: %s, Solid: %s, Persistent: %s\n", inst->visible ? "true" : "false", inst->active ? "true" : "false", inst->solid ? "true" : "false", inst->persistent ? "true" : "false"); - printf(" Parent: %s (parentId=%d)\n", parentName, gameObject != nullptr ? gameObject->parentId : -1); + logInfo("\n--- Instance #%d (%s, objectIndex=%d) ---\n", inst->instanceId, objName, inst->objectIndex); + logInfo(" Position: (%g, %g)\n", (double) inst->x, (double) inst->y); + logInfo(" Depth: %d\n", inst->depth); + logInfo(" Sprite: %s (index %d), imageIndex=%g, imageSpeed=%g\n", spriteName, inst->spriteIndex, (double) inst->imageIndex, (double) inst->imageSpeed); + logInfo(" Scale: (%g, %g), Angle: %g, Alpha: %g, Blend: 0x%06X\n", (double) inst->imageXscale, (double) inst->imageYscale, (double) inst->imageAngle, (double) inst->imageAlpha, inst->imageBlend); + logInfo(" Visible: %s, Active: %s, Solid: %s, Persistent: %s\n", inst->visible ? "true" : "false", inst->active ? "true" : "false", inst->solid ? "true" : "false", inst->persistent ? "true" : "false"); + logInfo(" Parent: %s (parentId=%d)\n", parentName, gameObject != nullptr ? gameObject->parentId : -1); // Active alarms bool hasAlarm = false; repeat(GML_ALARM_COUNT, alarmIdx) { if (inst->alarm[alarmIdx] >= 0) { - if (!hasAlarm) { printf(" Alarms:"); hasAlarm = true; } - printf(" [%d]=%d", (int)alarmIdx, inst->alarm[alarmIdx]); + if (!hasAlarm) { logInfo(" Alarms:"); hasAlarm = true; } + logInfo(" [%d]=%d", (int)alarmIdx, inst->alarm[alarmIdx]); } } - if (hasAlarm) printf("\n"); + if (hasAlarm) logInfo("\n"); // Self variables bool hasSelfVars = false; @@ -4095,25 +4095,25 @@ void Runner_dumpState(Runner* runner) { } if (val.type == RVALUE_ARRAY && val.array != nullptr) { - if (!hasSelfArrays) { printf(" Self Arrays:\n"); hasSelfArrays = true; } + if (!hasSelfArrays) { logInfo(" Self Arrays:\n"); hasSelfArrays = true; } repeat(GMLArray_length1D(val.array), ai) { RValue* cell = GMLArray_slot(val.array, ai); if (cell == nullptr || cell->type == RVALUE_UNDEFINED) continue; char* innerStr = RValue_toStringFancy(*cell); - printf(" %s[%d] = %s\n", varName, (int) ai, innerStr); + logInfo(" %s[%d] = %s\n", varName, (int) ai, innerStr); free(innerStr); } } else { - if (!hasSelfVars) { printf(" Self Variables:\n"); hasSelfVars = true; } + if (!hasSelfVars) { logInfo(" Self Variables:\n"); hasSelfVars = true; } char* valStr = RValue_toStringFancy(val); - printf(" %s = %s\n", varName, valStr); + logInfo(" %s = %s\n", varName, valStr); free(valStr); } } } // Global variables (non-array) - printf("\n=== Global Variables ===\n"); + logInfo("\n=== Global Variables ===\n"); repeat(runner->vmContext->globalScopeInstance->selfVars.capacity, i) { IntRValueEntry entryOnTheVarStruct = runner->vmContext->globalScopeInstance->selfVars.entries[i]; @@ -4127,18 +4127,18 @@ void Runner_dumpState(Runner* runner) { RValue* cell = GMLArray_slot(target.array, ai); if (cell == nullptr || cell->type == RVALUE_UNDEFINED) continue; char* innerStr = RValue_toStringFancy(*cell); - printf(" %s[%d] = %s\n", name, (int) ai, innerStr); + logInfo(" %s[%d] = %s\n", name, (int) ai, innerStr); free(innerStr); } } char* valStr = RValue_toStringTyped(target); - printf(" %s = %s\n", name, valStr); + logInfo(" %s = %s\n", name, valStr); free(valStr); } } - printf("\n=== End Frame %d State Dump ===\n", runner->frameCount); + logInfo("\n=== End Frame %d State Dump ===\n", runner->frameCount); } // ===[ JSON State Dump ]=== @@ -4413,7 +4413,7 @@ void Runner_free(Runner* runner) { free(runner->flattenedCollisionEvents); runner->flattenedCollisionEvents = nullptr; } - + arrfree(runner->cachedDrawables); runner->cachedDrawables = nullptr; arrfree(runner->instanceSnapshots); diff --git a/src/runner.h b/src/runner.h index 78bbfaa87..8178ecc13 100644 --- a/src/runner.h +++ b/src/runner.h @@ -542,7 +542,7 @@ struct Runner { DsMapEntry** dsMapPool; // stb_ds array of stb_ds hashmaps DsList* dsListPool; // stb_ds array of DsList DsQueue* dsQueuePool; // stb_ds array of DsQueue - DsStack* dsStackPool; // stb_ds array of DsStack + DsStack* dsStackPool; // stb_ds array of DsStack DsPriority* dsPriorityPool; // stb_ds array of DsPriority DsGrid* dsGridPool; // stb_ds array of DsGrid GmlBuffer* gmlBufferPool; // stb_ds array of GmlBuffer @@ -722,7 +722,7 @@ static inline void Runner_setActiveState(Runner* runner, Instance* instance, boo GameObject* objDef = &runner->dataWin->objt.objects[instance->objectIndex]; if (shgeti(runner->vmContext->instanceLifecyclesToBeTraced, "*") != -1 || shgeti(runner->vmContext->instanceLifecyclesToBeTraced, objDef->name) != -1) { - fprintf(stderr, "VM: Instance %s (instanceId=%d,objectIndex=%d) marked as %s at (%f, %f)\n", objDef->name, instance->instanceId, instance->objectIndex, active ? "active" : "inactive", instance->x, instance->y); + logInfo("VM: Instance %s (instanceId=%d,objectIndex=%d) marked as %s at (%f, %f)\n", objDef->name, instance->instanceId, instance->objectIndex, active ? "active" : "inactive", instance->x, instance->y); } } #else diff --git a/src/spatial_grid.c b/src/spatial_grid.c index e3f9a31f4..1f91a8e37 100644 --- a/src/spatial_grid.c +++ b/src/spatial_grid.c @@ -13,7 +13,7 @@ SpatialGrid* SpatialGrid_create(uint32_t roomWidth, uint32_t roomHeight) { uint32_t gridHeight = (roomHeight / SPATIAL_GRID_CELL_SIZE) + 1; #ifdef ENABLE_SPATIAL_GRID_LOGS - fprintf(stderr, "SpatialGrid: Grid size: %dx%d\n", gridWidth, gridHeight); + logInfo("SpatialGrid: Grid size: %dx%d\n", gridWidth, gridHeight); #endif grid->gridWidth = gridWidth; grid->gridHeight = gridHeight; @@ -53,7 +53,7 @@ void SpatialGrid_syncGrid(Runner* runner, SpatialGrid* grid) { if (!requiresResync) return; #ifdef ENABLE_SPATIAL_GRID_LOGS - fprintf(stderr, "SpatialGrid: Syncing grid with %d dirty instances\n", arrlen(grid->dirtyInstances)); + logInfo("SpatialGrid: Syncing grid with %d dirty instances\n", arrlen(grid->dirtyInstances)); #endif repeat(arrlen(grid->dirtyInstances), i) { diff --git a/src/utils.h b/src/utils.h index c527822ba..bdf43631a 100644 --- a/src/utils.h +++ b/src/utils.h @@ -12,6 +12,8 @@ #include "real_type.h" +#include "log.h" + #ifdef PLATFORM_PS2 #include #endif @@ -45,34 +47,34 @@ #define require(condition) \ do { \ if (!(condition)) { \ - fprintf(stderr, "Requirement failed at %s:%d\n", __FILE__, __LINE__); \ + logError("Requirement failed at %s:%d\n", __FILE__, __LINE__); \ abort(); \ } \ } while (0) #define requireMessage(condition, message) \ -do { \ -if (!(condition)) { \ -fprintf(stderr, "Requirement failed at %s:%d: %s\n", __FILE__, __LINE__, message); \ -abort(); \ -} \ + do { \ + if (!(condition)) { \ + logError("Requirement failed at %s:%d: %s\n", __FILE__, __LINE__, message); \ + abort(); \ + } \ } while (0) static inline void requireMessageFormatted(const char *file, int line, bool condition, const char *fmt, ...) { if (condition) return; va_list args; - fprintf(stderr, "Requirement failed at %s:%d: ", file, line); + logError("Requirement failed at %s:%d: ", file, line); va_start(args, fmt); - vfprintf(stderr, fmt, args); + vLogError(fmt, args); va_end(args); - fputc('\n', stderr); + logError("\n"); abort(); } static inline void* requireNotNullFunction(void* ptr, const char* file, int line, const char* name) { if (!ptr) { - fprintf(stderr, "%s:%d: requireNotNull failed: '%s'\n", file, line, name); + logError("%s:%d: requireNotNull failed: '%s'\n", file, line, name); abort(); } return ptr; @@ -84,7 +86,7 @@ static inline void* requireNotNullFunction(void* ptr, const char* file, int line static inline void *safeMallocFunction(size_t size, const char *file, int line) { void *ret = malloc(size); if (!ret) { - fprintf(stderr, "FATAL: malloc(%zu) failed at %s:%d\n", size, file, line); + logError("FATAL: malloc(%zu) failed at %s:%d\n", size, file, line); abort(); } return ret; @@ -94,7 +96,7 @@ static inline void *safeMallocFunction(size_t size, const char *file, int line) static inline void *safeCallocFunction(size_t count, size_t size, const char *file, int line) { void *ret = calloc(count, size); if (!ret) { - fprintf(stderr, "FATAL: calloc(%zu, %zu) failed at %s:%d\n", count, size, file, line); + logError("FATAL: calloc(%zu, %zu) failed at %s:%d\n", count, size, file, line); abort(); } return ret; @@ -104,7 +106,7 @@ static inline void *safeCallocFunction(size_t count, size_t size, const char *fi static inline void *safeReallocFunction(void *ptr, size_t size, const char *file, int line) { void *ret = realloc(ptr, size); if (!ret) { - fprintf(stderr, "FATAL: realloc(%zu) failed at %s:%d\n", size, file, line); + logError("FATAL: realloc(%zu) failed at %s:%d\n", size, file, line); abort(); } return ret; @@ -116,7 +118,7 @@ static inline void *safeReallocFunction(void *ptr, size_t size, const char *file static inline void *safeMemalignFunction(size_t alignment, size_t size, const char *file, int line) { void *ret = memalign(alignment, size); if (!ret) { - fprintf(stderr, "FATAL: memalign(%zu, %zu) failed at %s:%d\n", alignment, size, file, line); + logError("FATAL: memalign(%zu, %zu) failed at %s:%d\n", alignment, size, file, line); abort(); } return ret; @@ -128,7 +130,7 @@ static inline void *safeMemalignFunction(size_t alignment, size_t size, const ch // Reads exactly n bytes or aborts with the "pathForError" that caused the error. static inline void safeFreadFunction(void *dst, size_t n, FILE *read_file, const char *pathForError, const char *file, int line) { if (fread(dst, 1, n, read_file) != n) { - fprintf(stderr, "FATAL: failed to read %zu bytes from %s at %s:%d\n", n, pathForError, file, line); + logError("FATAL: failed to read %zu bytes from %s at %s:%d\n", n, pathForError, file, line); abort(); } } @@ -137,7 +139,7 @@ static inline void safeFreadFunction(void *dst, size_t n, FILE *read_file, const static inline char *safeStrdupFunction(const char *str, const char *file, int line) { char *ret = strdup(str); if (!ret) { - fprintf(stderr, "FATAL: strdup() failed at %s:%d\n", file, line); + logError("FATAL: strdup() failed at %s:%d\n", file, line); abort(); } return ret; diff --git a/src/vm.c b/src/vm.c index c7085f574..feec4c74a 100644 --- a/src/vm.c +++ b/src/vm.c @@ -64,7 +64,7 @@ static void stackPush(VMContext* ctx, RValue val) { char* valStr = RValue_toStringTyped(val); ctx->stack.slots[ctx->stack.top++] = val; char* stackBuf = formatStackContents(ctx); - fprintf(stderr, "VM: [%s] PUSH %s [stack=%d -> %d] %s\n", ctx->currentCodeName, valStr, ctx->stack.top - 1, ctx->stack.top, stackBuf); + logInfo("VM: [%s] PUSH %s [stack=%d -> %d] %s\n", ctx->currentCodeName, valStr, ctx->stack.top - 1, ctx->stack.top, stackBuf); free(stackBuf); free(valStr); return; @@ -85,7 +85,7 @@ static RValue stackPop(VMContext* ctx) { if (shouldTraceStack(ctx)) { char* valStr = RValue_toStringTyped(val); char* stackBuf = formatStackContents(ctx); - fprintf(stderr, "VM: [%s] POP %s [stack=%d -> %d] %s\n", ctx->currentCodeName, valStr, ctx->stack.top + 1, ctx->stack.top, stackBuf); + logInfo("VM: [%s] POP %s [stack=%d -> %d] %s\n", ctx->currentCodeName, valStr, ctx->stack.top + 1, ctx->stack.top, stackBuf); free(stackBuf); free(valStr); } @@ -680,9 +680,9 @@ static RValue resolveVariableRead(VMContext* ctx, int32_t instanceType, uint32_t const char* varTypeName = varTypeToString((varRef >> 24) & 0xF8); if (instanceType < INSTANCE_ID_BASE && (uint32_t) instanceType < ctx->dataWin->objt.count) { GameObject* gameObject = &ctx->dataWin->objt.objects[instanceType]; - fprintf(stderr, "VM: [%s] READ var '%s' on object index %d (%s) but no instance found (varType=%s, isArray=%s, originalInstanceType=%d, hasInstanceType=%s, varID=%d)\n", ctx->currentCodeName, varDef->name, instanceType, gameObject->name, varTypeName, access.isArray ? "true" : "false", originalInstanceType, access.hasInstanceType ? "true" : "false", varDef->varID); + logWarn("VM: [%s] READ var '%s' on object index %d (%s) but no instance found (varType=%s, isArray=%s, originalInstanceType=%d, hasInstanceType=%s, varID=%d)\n", ctx->currentCodeName, varDef->name, instanceType, gameObject->name, varTypeName, access.isArray ? "true" : "false", originalInstanceType, access.hasInstanceType ? "true" : "false", varDef->varID); } else { - fprintf(stderr, "VM: [%s] READ var '%s' on instance %d but no instance found (varType=%s, isArray=%s, originalInstanceType=%d, hasInstanceType=%s, varID=%d)\n", ctx->currentCodeName, varDef->name, instanceType, varTypeName, access.isArray ? "true" : "false", originalInstanceType, access.hasInstanceType ? "true" : "false", varDef->varID); + logWarn("VM: [%s] READ var '%s' on instance %d but no instance found (varType=%s, isArray=%s, originalInstanceType=%d, hasInstanceType=%s, varID=%d)\n", ctx->currentCodeName, varDef->name, instanceType, varTypeName, access.isArray ? "true" : "false", originalInstanceType, access.hasInstanceType ? "true" : "false", varDef->varID); } return RValue_makeReal(0.0); } @@ -730,7 +730,7 @@ static RValue resolveVariableRead(VMContext* ctx, int32_t instanceType, uint32_t result = RValue_makeUndefined(); } } else { - fprintf(stderr, "VM: [%s] INSTANCE_ARG read on unknown variable '%s' (builtinVarId=%d)\n", ctx->currentCodeName, varDef->name, builtinVarId); + logWarn("VM: [%s] INSTANCE_ARG read on unknown variable '%s' (builtinVarId=%d)\n", ctx->currentCodeName, varDef->name, builtinVarId); result = RValue_makeUndefined(); } return result; @@ -779,7 +779,7 @@ static RValue resolveVariableRead(VMContext* ctx, int32_t instanceType, uint32_t Instance* inst = targetInstance; if (inst == nullptr) { const char* varTypeName = varTypeToString((varRef >> 24) & 0xF8); - fprintf(stderr, "VM: [%s] Read on self var '%s' but no current instance (instanceType=%d, varType=%s, isArray=%s, originalInstanceType=%d, hasInstanceType=%s, varID=%d)\n", ctx->currentCodeName, varDef->name, instanceType, varTypeName, access.isArray ? "true" : "false", originalInstanceType, access.hasInstanceType ? "true" : "false", varDef->varID); + logWarn("VM: [%s] Read on self var '%s' but no current instance (instanceType=%d, varType=%s, isArray=%s, originalInstanceType=%d, hasInstanceType=%s, varID=%d)\n", ctx->currentCodeName, varDef->name, instanceType, varTypeName, access.isArray ? "true" : "false", originalInstanceType, access.hasInstanceType ? "true" : "false", varDef->varID); return RValue_makeReal(0.0); } slot = IntRValueHashMap_findSlot(&inst->selfVars, varDef->varID); @@ -954,7 +954,7 @@ static void resolveVariableWrite(VMContext* ctx, int32_t instanceType, uint32_t if (ctx->dataWin->objt.count > (uint32_t) instanceType) { GameObject* gameObject = &ctx->dataWin->objt.objects[instanceType]; char* valAsString = RValue_toString(val); - fprintf(stderr, "VM: [%s] WRITE var '%s' on object %d (%s) but no instances found (value=%s)\n", ctx->currentCodeName, varDef->name, instanceType, gameObject->name, valAsString); + logWarn("VM: [%s] WRITE var '%s' on object %d (%s) but no instances found (value=%s)\n", ctx->currentCodeName, varDef->name, instanceType, gameObject->name, valAsString); free(valAsString); } } @@ -969,7 +969,7 @@ static void resolveVariableWrite(VMContext* ctx, int32_t instanceType, uint32_t if (targetInstance == nullptr) { const char* varTypeName = varTypeToString((varRef >> 24) & 0xF8); char* valAsString = RValue_toString(val); - fprintf(stderr, "VM: [%s] WRITE var '%s' on instance %d but no instance found (varType=%s, isArray=%s, originalInstanceType=%d, hasInstanceType=%s, varID=%d, value=%s)\n", ctx->currentCodeName, varDef->name, instanceType, varTypeName, access.isArray ? "true" : "false", originalInstanceType, access.hasInstanceType ? "true" : "false", varDef->varID, valAsString); + logWarn("VM: [%s] WRITE var '%s' on instance %d but no instance found (varType=%s, isArray=%s, originalInstanceType=%d, hasInstanceType=%s, varID=%d, value=%s)\n", ctx->currentCodeName, varDef->name, instanceType, varTypeName, access.isArray ? "true" : "false", originalInstanceType, access.hasInstanceType ? "true" : "false", varDef->varID, valAsString); free(valAsString); return; } @@ -986,7 +986,7 @@ static void resolveVariableWrite(VMContext* ctx, int32_t instanceType, uint32_t } else if (bid == BUILTIN_VAR_ARGUMENT) { writeIndex = access.arrayIndex; } else { - fprintf(stderr, "VM: [%s] INSTANCE_ARG write on unknown variable '%s' (builtinVarId=%d)\n", ctx->currentCodeName, varDef->name, bid); + logWarn("VM: [%s] INSTANCE_ARG write on unknown variable '%s' (builtinVarId=%d)\n", ctx->currentCodeName, varDef->name, bid); } if (writeIndex >= 0) { VM_writeToScriptArgs(ctx, writeIndex, val); @@ -1031,7 +1031,7 @@ static void resolveVariableWrite(VMContext* ctx, int32_t instanceType, uint32_t if (inst == nullptr) { const char* varTypeName = varTypeToString((varRef >> 24) & 0xF8); char* valAsString = RValue_toString(val); - fprintf(stderr, "VM: [%s] Write on self var '%s' but no current instance (instanceType=%d, varType=%s, isArray=%s, originalInstanceType=%d, hasInstanceType=%s, varID=%d, value=%s)\n", ctx->currentCodeName, varDef->name, instanceType, varTypeName, access.isArray ? "true" : "false", originalInstanceType, access.hasInstanceType ? "true" : "false", varDef->varID, valAsString); + logWarn("VM: [%s] Write on self var '%s' but no current instance (instanceType=%d, varType=%s, isArray=%s, originalInstanceType=%d, hasInstanceType=%s, varID=%d, value=%s)\n", ctx->currentCodeName, varDef->name, instanceType, varTypeName, access.isArray ? "true" : "false", originalInstanceType, access.hasInstanceType ? "true" : "false", varDef->varID, valAsString); free(valAsString); RValue_free(&val); return; @@ -1106,7 +1106,7 @@ static RValue convertValue(RValue val, uint8_t targetType) { // Variable type on stack is just an RValue passthrough return val; default: - fprintf(stderr, "VM: Unknown target type 0x%X for conversion\n", targetType); + logWarn("VM: Unknown target type 0x%X for conversion\n", targetType); return val; } } @@ -1175,7 +1175,7 @@ static void handlePush(VMContext* ctx, uint32_t instr, const uint8_t* extraData, // Positive scopes are real instance IDs resolved by lookup. Instance* inst = (0 > scope) ? (Instance*) ctx->currentInstance : VM_findInstanceByTarget(ctx, scope); if (inst == nullptr) { - fprintf(stderr, "VM: ARRAYPUSHAF: no instance for scope %d varID=%d\n", scope, varDef->varID); + logError("VM: ARRAYPUSHAF: no instance for scope %d varID=%d\n", scope, varDef->varID); abort(); } slot = IntRValueHashMap_getOrInsertUndefined(&inst->selfVars, varDef->varID); @@ -1229,7 +1229,7 @@ static void handlePush(VMContext* ctx, uint32_t instr, const uint8_t* extraData, break; } default: - fprintf(stderr, "VM: Push with unknown type 0x%X\n", type1); + logError("VM: Push with unknown type 0x%X\n", type1); abort(); } } @@ -1270,7 +1270,7 @@ static void handlePushBltn(VMContext* ctx, uint32_t instr, const uint8_t* extraD inst = (Instance*) ctx->currentInstance; } if (inst == nullptr) { - fprintf(stderr, "VM: PushBltn ARRAYPUSHAF: no instance for scope %d varID=%d\n", scope, varDef->varID); + logError("VM: PushBltn ARRAYPUSHAF: no instance for scope %d varID=%d\n", scope, varDef->varID); abort(); } RValue* slot = IntRValueHashMap_getOrInsertUndefined(&inst->selfVars, varDef->varID); @@ -1427,9 +1427,9 @@ static void handlePop(VMContext* ctx, uint8_t type1, uint8_t type2, uint32_t var const char* varTypeName = varTypeToString(varType); char* valAsString = RValue_toString(val); if (instanceType < INSTANCE_ID_BASE && (uint32_t) instanceType < ctx->dataWin->objt.count) { - fprintf(stderr, "VM: [%s] WRITE array var '%s[%d]' on object index %d (%s) but no instance found (varType=%s, originalInstanceType=%d, varID=%d, value=%s)\n", ctx->currentCodeName, varDef->name, arrayIndex, instanceType, ctx->dataWin->objt.objects[instanceType].name, varTypeName, originalInstanceType, varDef->varID, valAsString); + logWarn("VM: [%s] WRITE array var '%s[%d]' on object index %d (%s) but no instance found (varType=%s, originalInstanceType=%d, varID=%d, value=%s)\n", ctx->currentCodeName, varDef->name, arrayIndex, instanceType, ctx->dataWin->objt.objects[instanceType].name, varTypeName, originalInstanceType, varDef->varID, valAsString); } else { - fprintf(stderr, "VM: [%s] WRITE array var '%s[%d]' on instance %d but no instance found (varType=%s, originalInstanceType=%d, varID=%d, value=%s)\n", ctx->currentCodeName, varDef->name, arrayIndex, instanceType, varTypeName, originalInstanceType, varDef->varID, valAsString); + logWarn("VM: [%s] WRITE array var '%s[%d]' on instance %d but no instance found (varType=%s, originalInstanceType=%d, varID=%d, value=%s)\n", ctx->currentCodeName, varDef->name, arrayIndex, instanceType, varTypeName, originalInstanceType, varDef->varID, valAsString); } free(valAsString); RValue_free(&val); @@ -1700,7 +1700,7 @@ static void handleConv(VMContext* ctx, uint8_t srcType, uint8_t dstType, uint8_t case 0x5F: result = val; break; default: - fprintf(stderr, "VM: [%s] Conv unhandled conversion 0x%02X (src=0x%X dst=0x%X)\n", ctx->currentCodeName, convKey, srcType, dstType); + logWarn("VM: [%s] Conv unhandled conversion 0x%02X (src=0x%X dst=0x%X)\n", ctx->currentCodeName, convKey, srcType, dstType); result = val; break; } @@ -1960,7 +1960,7 @@ static void handleCall(VMContext* ctx, uint32_t instr, const uint8_t* extraData) free(display); } - fprintf(stderr, "VM: [%s] Calling function \"%s(%s)\"\n", ctx->currentCodeName, funcName, functionArgumentList); + logInfo("VM: [%s] Calling function \"%s(%s)\"\n", ctx->currentCodeName, funcName, functionArgumentList); } #endif @@ -1982,7 +1982,7 @@ static void handleCall(VMContext* ctx, uint32_t instr, const uint8_t* extraData) #ifdef ENABLE_VM_TRACING if (functionIsBeingTraced) { char* returnValueAsString = RValue_toStringFancy(result); - fprintf(stderr, "VM: [%s] Built-in function \"%s(%s)\" returned %s\n", ctx->currentCodeName, funcName, functionArgumentList, returnValueAsString); + logInfo("VM: [%s] Built-in function \"%s(%s)\" returned %s\n", ctx->currentCodeName, funcName, functionArgumentList, returnValueAsString); free(returnValueAsString); free(functionArgumentList); } @@ -1999,7 +1999,7 @@ static void handleCall(VMContext* ctx, uint32_t instr, const uint8_t* extraData) #ifdef ENABLE_VM_TRACING if (functionIsBeingTraced) { char* returnValueAsString = RValue_toStringFancy(result); - fprintf(stderr, "VM: [%s] Script function \"%s(%s)\" returned %s\n", ctx->currentCodeName, funcName, functionArgumentList, returnValueAsString); + logInfo("VM: [%s] Script function \"%s(%s)\" returned %s\n", ctx->currentCodeName, funcName, functionArgumentList, returnValueAsString); free(returnValueAsString); free(functionArgumentList); } @@ -2027,7 +2027,7 @@ static void handleCall(VMContext* ctx, uint32_t instr, const uint8_t* extraData) if (ctx->alwaysLogUnknownFunctions || 0 > shgeti(ctx->loggedUnknownFuncs, dedupKey)) { shput(ctx->loggedUnknownFuncs, dedupKey, true); - fprintf(stderr, "VM: [%s] Unknown function \"%s\"!\n", callerName, unknownFuncName); + logWarn("VM: [%s] Unknown function \"%s\"!\n", callerName, unknownFuncName); } else { free(dedupKey); } @@ -2114,14 +2114,14 @@ static void handleCallV(VMContext* ctx, uint32_t instr) { char* dedupKey = VM_createDedupKey(callerName, unresolvedName); if (ctx->alwaysLogUnknownFunctions || 0 > shgeti(ctx->loggedUnknownFuncs, dedupKey)) { shput(ctx->loggedUnknownFuncs, dedupKey, true); - fprintf(stderr, "VM: [%s] Unknown function \"%s\"! (via CallV)\n", callerName, unresolvedName); + logWarn("VM: [%s] Unknown function \"%s\"! (via CallV)\n", callerName, unresolvedName); } else { free(dedupKey); } #endif result = RValue_makeUndefined(); } else { - fprintf(stderr, "VM: [%s] CALLV with unresolvable function reference (type=%d, codeIndex=%d)\n", ctx->currentCodeName, function.type, codeIndex); + logWarn("VM: [%s] CALLV with unresolvable function reference (type=%d, codeIndex=%d)\n", ctx->currentCodeName, function.type, codeIndex); #ifdef ENABLE_WAD17 VMException* exception = (VMException *)safeCalloc(1, sizeof(VMException)); exception->message = safeStrdup("CALLV with unresolvable function reference"); @@ -2312,9 +2312,9 @@ static void handlePushEnv(VMContext* ctx, uint32_t instr, uint32_t instrAddr) { } if (0 > target) { - fprintf(stderr, "VM: [%s] PushEnv with negative target %d, this could be a Int64 number that is getting truncated to Int32!\n", ctx->currentCodeName, target); + logWarn("VM: [%s] PushEnv with negative target %d, this could be a Int64 number that is getting truncated to Int32!\n", ctx->currentCodeName, target); } else { - fprintf(stderr, "VM: [%s] PushEnv with unhandled target %d\n", ctx->currentCodeName, target); + logWarn("VM: [%s] PushEnv with unhandled target %d\n", ctx->currentCodeName, target); } ctx->ip = instrAddr + jumpOffset; } @@ -2463,17 +2463,17 @@ void VM_printOpcodeProfilerReport(const VMContext* ctx) { entries[j] = tmp; } - fprintf(stderr, "=== Opcode Profiler Report ===\n"); - fprintf(stderr, "Total instructions executed: %llu\n", (unsigned long long) total); - fprintf(stderr, "%-12s %-6s %16s %8s\n", "Opcode", "Hex", "Count", "Pct"); + logInfo("=== Opcode Profiler Report ===\n"); + logInfo("Total instructions executed: %llu\n", (unsigned long long) total); + logInfo("%-12s %-6s %16s %8s\n", "Opcode", "Hex", "Count", "Pct"); forEachIndexed(CountEntry, entry, i, entries, entryCount) { (void) i; double pct = total > 0 ? (100.0 * (double) entry->count / (double) total) : 0.0; - fprintf(stderr, "%-12s 0x%02X %16llu %7.2f%%\n", opcodeName((uint8_t) entry->key), (uint8_t) entry->key, (unsigned long long) entry->count, pct); + logInfo("%-12s 0x%02X %16llu %7.2f%%\n", opcodeName((uint8_t) entry->key), (uint8_t) entry->key, (unsigned long long) entry->count, pct); } // Per-opcode breakdown by type variant. Sorted within each opcode by count desc. - fprintf(stderr, "\n--- Type variant breakdown (per opcode) ---\n"); + logInfo("\n--- Type variant breakdown (per opcode) ---\n"); forEachIndexed(CountEntry, entry, idx, entries, entryCount) { (void) idx; uint8_t opcode = (uint8_t) entry->key; @@ -2498,13 +2498,13 @@ void VM_printOpcodeProfilerReport(const VMContext* ctx) { variantEntries[j] = tmp; } - fprintf(stderr, "%s (0x%02X): %llu total\n", opcodeName(opcode), opcode, (unsigned long long) entry->count); + logInfo("%s (0x%02X): %llu total\n", opcodeName(opcode), opcode, (unsigned long long) entry->count); forEachIndexed(CountEntry, ve, vi, variantEntries, variantCount) { (void) vi; uint8_t type1 = (uint8_t) ((ve->key >> 4) & 0xF); uint8_t type2 = (uint8_t) (ve->key & 0xF); double vpct = entry->count > 0 ? (100.0 * (double) ve->count / (double) entry->count) : 0.0; - fprintf(stderr, " .%c.%c %16llu %7.2f%%\n", gmlTypeChar(type1), gmlTypeChar(type2), (unsigned long long) ve->count, vpct); + logInfo(" .%c.%c %16llu %7.2f%%\n", gmlTypeChar(type1), gmlTypeChar(type2), (unsigned long long) ve->count, vpct); } // Runtime RValue type breakdown (a, b types observed at execution time) @@ -2531,13 +2531,13 @@ void VM_printOpcodeProfilerReport(const VMContext* ctx) { } rvEntries[j] = tmp; } - fprintf(stderr, " -- runtime types (a, b):\n"); + logInfo(" -- runtime types (a, b):\n"); forEachIndexed(CountEntry, re, ri, rvEntries, rvCount) { (void) ri; uint8_t typeA = (uint8_t) ((re->key >> 4) & 0xF); uint8_t typeB = (uint8_t) (re->key & 0xF); double rpct = rvTotal > 0 ? (100.0 * (double) re->count / (double) rvTotal) : 0.0; - fprintf(stderr, " (%-6s, %-6s) %16llu %7.2f%%\n", rvalueTypeName(typeA), rvalueTypeName(typeB), (unsigned long long) re->count, rpct); + logInfo(" (%-6s, %-6s) %16llu %7.2f%%\n", rvalueTypeName(typeA), rvalueTypeName(typeB), (unsigned long long) re->count, rpct); } } } @@ -2562,16 +2562,16 @@ void VM_printOpcodeProfilerReport(const VMContext* ctx) { } breakEntries[j] = tmp; } - fprintf(stderr, " -- sub-opcodes:\n"); + logInfo(" -- sub-opcodes:\n"); forEachIndexed(CountEntry, be, bi, breakEntries, breakCount) { (void) bi; int16_t breakType = (int16_t) -((int) be->key); double bpct = entry->count > 0 ? (100.0 * (double) be->count / (double) entry->count) : 0.0; - fprintf(stderr, " %-12s (%4d) %16llu %7.2f%%\n", breakSubOpName(breakType), (int) breakType, (unsigned long long) be->count, bpct); + logInfo(" %-12s (%4d) %16llu %7.2f%%\n", breakSubOpName(breakType), (int) breakType, (unsigned long long) be->count, bpct); } } } - fprintf(stderr, "==============================\n"); + logInfo("==============================\n"); } #endif // ENABLE_VM_OPCODE_PROFILER @@ -2586,7 +2586,7 @@ static void handleBreakChkIndex(VMContext* ctx, uint32_t instrAddr) { RValue* top = stackPeek(ctx); int32_t idx = RValue_toInt32(*top); if (0 > idx || 32000 <= idx) { - fprintf(stderr, "VM: chkindex out of bounds: %d at offset %u in %s\n", idx, instrAddr, ctx->currentCodeName); + logError("VM: chkindex out of bounds: %d at offset %u in %s\n", idx, instrAddr, ctx->currentCodeName); abort(); } } @@ -2629,7 +2629,7 @@ static void handleBreakPushAC(VMContext* ctx, uint32_t instrAddr) { int32_t idx = stackPopInt32(ctx); RValue arrayRef = stackPop(ctx); if (arrayRef.type != RVALUE_ARRAY || arrayRef.array == nullptr) { - fprintf(stderr, "VM: pushac on non-array (type=%d) at offset %u in %s\n", arrayRef.type, instrAddr, ctx->currentCodeName); + logError("VM: pushac on non-array (type=%d) at offset %u in %s\n", arrayRef.type, instrAddr, ctx->currentCodeName); abort(); } GMLArray* parent = arrayRef.array; @@ -2740,7 +2740,7 @@ static void handleBreak(VMContext* ctx, uint32_t instr, uint32_t instrAddr, cons case BREAK_ISNULLISH: handleBreakIsNullish(ctx); break; case BREAK_PUSHREF: handleBreakPushRef(ctx, extraData); break; default: - fprintf(stderr, "VM: Unknown BREAK sub-opcode %d at offset %u in %s\n", breakType, instrAddr, ctx->currentCodeName); + logError("VM: Unknown BREAK sub-opcode %d at offset %u in %s\n", breakType, instrAddr, ctx->currentCodeName); abort(); } } @@ -2780,11 +2780,11 @@ static RValue executeLoop(VMContext* ctx) { #ifdef ENABLE_WAD17 if (ctx->exception != nullptr) { #ifdef ENABLE_VM_EXCEPTIONS_LOGS - fprintf(stderr, "VM: Exception thrown! Stack Top is %d\n", ctx->exceptionHandlerStackTop); + logError("VM: Exception thrown! Stack Top is %d\n", ctx->exceptionHandlerStackTop); #endif if (ctx->exceptionHandlerStackTop == 0) { // TODO: When Butterscotch is better, we could have a strict mode that DOES throw a error - fprintf(stderr, "VM: The exception handler frame stack is 0, but we have a pending exception to be dispatched! This would've technically crashed the game in the original runner... or we aren't handling exceptions correctly. We'll swallow the exception and hope for the best... (Exception: %s)\n", ctx->exception->message); + logError("VM: The exception handler frame stack is 0, but we have a pending exception to be dispatched! This would've technically crashed the game in the original runner... or we aren't handling exceptions correctly. We'll swallow the exception and hope for the best... (Exception: %s)\n", ctx->exception->message); free(ctx->exception->message); free(ctx->exception); ctx->exception = nullptr; @@ -2797,7 +2797,7 @@ static RValue executeLoop(VMContext* ctx) { // Not for us, propagate the exception! if (exceptionHandlerFrame->boundToCallDepth != ctx->callDepth) { #ifdef ENABLE_VM_EXCEPTIONS_LOGS - fprintf(stderr, "VM: We wanted %d but we are %d - Propagating...\n", exceptionHandlerFrame->boundToCallDepth, ctx->callDepth); + logWarn("VM: We wanted %d but we are %d - Propagating...\n", exceptionHandlerFrame->boundToCallDepth, ctx->callDepth); #endif return RValue_makeUndefined(); } @@ -2810,7 +2810,7 @@ static RValue executeLoop(VMContext* ctx) { VM_SYNC_IP(); #ifdef ENABLE_VM_EXCEPTIONS_LOGS - fprintf(stderr, "VM: Jumped to %d due to exception handler, is this a exception? %d\n", ip, isException); + logWarn("VM: Jumped to %d due to exception handler, is this a exception? %d\n", ip, isException); #endif if (isException) { @@ -2892,9 +2892,9 @@ static RValue executeLoop(VMContext* ctx) { char* stackBuf = formatStackContents(ctx); if (operandStr[0] != '\0') { - fprintf(stderr, "VM: [%s] @%04X (%d) [0x%08X] %s %s [stack=%d] %s\n", ctx->currentCodeName, instrAddr, instrAddr, instr, opcodeStr, operandStr, ctx->stack.top, stackBuf); + logInfo("VM: [%s] @%04X (%d) [0x%08X] %s %s [stack=%d] %s\n", ctx->currentCodeName, instrAddr, instrAddr, instr, opcodeStr, operandStr, ctx->stack.top, stackBuf); } else { - fprintf(stderr, "VM: [%s] @%04X (%d) [0x%08X] %s [stack=%d] %s\n", ctx->currentCodeName, instrAddr, instrAddr, instr, opcodeStr, ctx->stack.top, stackBuf); + logInfo("VM: [%s] @%04X (%d) [0x%08X] %s [stack=%d] %s\n", ctx->currentCodeName, instrAddr, instrAddr, instr, opcodeStr, ctx->stack.top, stackBuf); } free(stackBuf); } @@ -3294,7 +3294,7 @@ static RValue executeLoop(VMContext* ctx) { break; default: - fprintf(stderr, "VM: Unknown opcode 0x%02X at offset %u\n", opcode, instrAddr); + logError("VM: Unknown opcode 0x%02X at offset %u\n", opcode, instrAddr); abort(); } } @@ -3576,7 +3576,7 @@ VMContext* VM_create(DataWin* dataWin) { } } - fprintf(stderr, "VM: Initialized with %u functions mapped\n", (uint32_t) shlen(ctx->codeIndexByName)); + logInfo("VM: Initialized with %u functions mapped\n", (uint32_t) shlen(ctx->codeIndexByName)); return ctx; } @@ -3643,7 +3643,7 @@ void VM_reset(VMContext* ctx) { } #endif - fprintf(stderr, "VM: Reset complete\n"); + logInfo("VM: Reset complete\n"); } static CodeLocals* resolveCodeLocals(VMContext* ctx, const char* codeName) { @@ -4290,17 +4290,17 @@ void VM_disassemble(VMContext* ctx, int32_t codeIndex) { CodeEntry* code = &dw->code.entries[codeIndex]; // Header - printf("=== %s (length=%u, locals=%u, args=%u) ===\n", code->name, code->length, code->localsCount, code->argumentsCount); + logInfo("=== %s (length=%u, locals=%u, args=%u) ===\n", code->name, code->length, code->localsCount, code->argumentsCount); // CodeLocals CodeLocals* locals = resolveCodeLocals(ctx, code->name); if (locals != nullptr && locals->localVarCount > 0) { - printf("Locals:"); + logInfo("Locals:"); repeat(locals->localVarCount, i) { - if (i > 0) printf(","); - printf(" [%u] %s", locals->locals[i].varID, locals->locals[i].name); + if (i > 0) logInfo(","); + logInfo(" [%u] %s", locals->locals[i].varID, locals->locals[i].name); } - printf("\n"); + logInfo("\n"); } // Cross-references @@ -4308,16 +4308,16 @@ void VM_disassemble(VMContext* ctx, int32_t codeIndex) { ptrdiff_t mapIdx = hmgeti(ctx->crossRefMap, codeIndex); if (mapIdx >= 0) { int32_t* callers = ctx->crossRefMap[mapIdx].value; - printf("Called by:"); + logInfo("Called by:"); for (ptrdiff_t i = 0; arrlen(callers) > i; i++) { - if (i > 0) printf(","); - printf(" %s", dw->code.entries[callers[i]].name); + if (i > 0) logInfo(","); + logInfo(" %s", dw->code.entries[callers[i]].name); } - printf("\n"); + logInfo("\n"); } } - printf("\n"); + logInfo("\n"); const uint8_t* bytecodeBase = dw->bytecodeBuffer + (code->bytecodeAbsoluteOffset - dw->bytecodeBufferBase); uint32_t codeLength = code->length; @@ -4369,7 +4369,7 @@ void VM_disassemble(VMContext* ctx, int32_t codeIndex) { // Print label if this address is a branch target if (hmgeti(branchTargets, instrAddr) >= 0) { - printf(" %04X: L_%04X:\n", instrAddr, instrAddr); + logInfo(" %04X: L_%04X:\n", instrAddr, instrAddr); } int32_t indent = 2 + envDepth * 4; @@ -4381,9 +4381,9 @@ void VM_disassemble(VMContext* ctx, int32_t codeIndex) { // Print the formatted line if (commentStr[0] != '\0') { - printf("%*s%04X (%6d): [0x%08X] %-16s %-45s %s\n", indent, "", instrAddr, instrAddr, instr, opcodeStr, operandStr, commentStr); + logInfo("%*s%04X (%6d): [0x%08X] %-16s %-45s %s\n", indent, "", instrAddr, instrAddr, instr, opcodeStr, operandStr, commentStr); } else { - printf("%*s%04X (%6d): [0x%08X] %-16s %s\n", indent, "", instrAddr, instrAddr, instr, opcodeStr, operandStr); + logInfo("%*s%04X (%6d): [0x%08X] %-16s %s\n", indent, "", instrAddr, instrAddr, instr, opcodeStr, operandStr); } // PushEnv increases depth after printing @@ -4391,7 +4391,7 @@ void VM_disassemble(VMContext* ctx, int32_t codeIndex) { } hmfree(branchTargets); - printf("\n"); + logInfo("\n"); } void VM_registerBuiltin(VMContext* ctx, const char* name, BuiltinFunc func) { diff --git a/src/vm.h b/src/vm.h index 2fa33b73e..3ea72a8da 100644 --- a/src/vm.h +++ b/src/vm.h @@ -402,7 +402,7 @@ static inline void VM_checkIfVariableShouldBeTracedAndLog(VMContext* ctx, const if (arrayIndex >= 0) snprintf(indexBuf, sizeof(indexBuf), "[%d]", arrayIndex); char instanceIdBuf[28] = ""; if (instanceId >= 0) snprintf(instanceIdBuf, sizeof(instanceIdBuf), " (instanceId=%d)", instanceId); - fprintf(stderr, "VM: [%s] %s %s.%s%s %s %s%s%s\n", ctx->currentCodeName, verb, scopeName, name, indexBuf, arrow, rvalueAsString, instanceIdBuf, additional); + logInfo("VM: [%s] %s %s.%s%s %s %s%s%s\n", ctx->currentCodeName, verb, scopeName, name, indexBuf, arrow, rvalueAsString, instanceIdBuf, additional); free(rvalueAsString); } #endif diff --git a/src/vm_builtins.c b/src/vm_builtins.c index ffd1c0b51..9e936e436 100644 --- a/src/vm_builtins.c +++ b/src/vm_builtins.c @@ -107,7 +107,7 @@ static void logStubbedFunction(VMContext* ctx, const char* funcName) { if (ctx->alwaysLogStubbedFunctions || 0 > shgeti(ctx->loggedStubbedFuncs, dedupKey)) { // shput stores the key pointer, so don't free it when inserting shput(ctx->loggedStubbedFuncs, dedupKey, true); - fprintf(stderr, "VM: [%s] Stubbed function \"%s\"!\n", callerName, funcName); + logWarn("VM: [%s] Stubbed function \"%s\"!\n", callerName, funcName); } else { free(dedupKey); } @@ -120,7 +120,7 @@ static void logSemiStubbedFunction(VMContext* ctx, const char* funcName) { if (ctx->alwaysLogStubbedFunctions || 0 > shgeti(ctx->loggedStubbedFuncs, dedupKey)) { // shput stores the key pointer, so don't free it when inserting shput(ctx->loggedStubbedFuncs, dedupKey, true); - fprintf(stderr, "VM: [%s] Semi-Stubbed function \"%s\"!\n", callerName, funcName); + logWarn("VM: [%s] Semi-Stubbed function \"%s\"!\n", callerName, funcName); } else { free(dedupKey); } @@ -1259,7 +1259,7 @@ RValue VMBuiltins_getVariable(VMContext* ctx, Instance* inst, int16_t builtinVar break; } - fprintf(stderr, "VM: [%s] Unhandled built-in variable read '%s' (arrayIndex=%d)\n", ctx->currentCodeName, name, arrayIndex); + logWarn("VM: [%s] Unhandled built-in variable read '%s' (arrayIndex=%d)\n", ctx->currentCodeName, name, arrayIndex); return RValue_makeReal(0.0); } @@ -1476,7 +1476,7 @@ void VMBuiltins_setVariable(VMContext* ctx, Instance* inst, int16_t builtinVarId #ifdef ENABLE_VM_TRACING if (inst->objectIndex >= 0 && (shgeti(ctx->alarmsToBeTraced, "*") != -1 || shgeti(ctx->alarmsToBeTraced, runner->dataWin->objt.objects[inst->objectIndex].name) != -1)) { - fprintf(stderr, "VM: [%s] Setting Alarm[%d] = %d (instanceId=%d)\n", runner->dataWin->objt.objects[inst->objectIndex].name, arrayIndex, newValue, inst->instanceId); + logInfo("VM: [%s] Setting Alarm[%d] = %d (instanceId=%d)\n", runner->dataWin->objt.objects[inst->objectIndex].name, arrayIndex, newValue, inst->instanceId); } #endif @@ -1770,23 +1770,23 @@ void VMBuiltins_setVariable(VMContext* ctx, Instance* inst, int16_t builtinVarId case BUILTIN_VAR_DEBUG_MODE: case BUILTIN_VAR_ROOM_FIRST: case BUILTIN_VAR_ROOM_LAST: - fprintf(stderr, "VM: [%s] Attempted write to read-only built-in '%s'\n", ctx->currentCodeName, name); + logWarn("VM: [%s] Attempted write to read-only built-in '%s'\n", ctx->currentCodeName, name); return; } - fprintf(stderr, "VM: [%s] Unhandled built-in variable write '%s' (arrayIndex=%d)\n", ctx->currentCodeName, name, arrayIndex); + logWarn("VM: [%s] Unhandled built-in variable write '%s' (arrayIndex=%d)\n", ctx->currentCodeName, name, arrayIndex); } // ===[ BUILTIN FUNCTION IMPLEMENTATIONS ]=== static RValue builtin_show_debug_message(MAYBE_UNUSED VMContext* ctx, RValue* args, int32_t argCount) { if (1 > argCount) { - fprintf(stderr, "[show_debug_message] Expected at least 1 argument\n"); + logWarn("[show_debug_message] Expected at least 1 argument\n"); return RValue_makeUndefined(); } char* val = RValue_toString(args[0]); - printf("Game: %s\n", val); + logInfo("Game: %s\n", val); free(val); return RValue_makeUndefined(); @@ -3289,7 +3289,7 @@ static RValue builtin_room_goto_next(VMContext* ctx, MAYBE_UNUSED RValue* args, if ((int32_t) runner->dataWin->gen8.roomOrderCount > nextPos) { runner->pendingRoom = runner->dataWin->gen8.roomOrder[nextPos]; } else { - fprintf(stderr, "VM: room_goto_next - already at last room!\n"); + logWarn("VM: room_goto_next - already at last room!\n"); } return RValue_makeUndefined(); } @@ -3301,7 +3301,7 @@ static RValue builtin_room_goto_previous(VMContext* ctx, MAYBE_UNUSED RValue* ar if (previousPos >= 0) { runner->pendingRoom = runner->dataWin->gen8.roomOrder[previousPos]; } else { - fprintf(stderr, "VM: room_goto_previous - already at first room!\n"); + logWarn("VM: room_goto_previous - already at first room!\n"); } return RValue_makeUndefined(); } @@ -3638,7 +3638,7 @@ static RValue builtin_camera_set_view_angle(VMContext* ctx, RValue* args, int32_ if (2 > argCount) return RValue_makeUndefined(); Runner* runner = ctx->runner; GMLCamera* camera = Runner_getCameraById(runner, RValue_toInt32(args[0])); - if (camera != nullptr) { + if (camera != nullptr) { camera->viewAngle = (float) RValue_toReal(args[1]); Runner_updateCameraViewSimple(camera); } @@ -3706,7 +3706,7 @@ static RValue builtin_camera_create_view(VMContext* ctx, RValue* args, int32_t a if (argCount > 9) camera->borderY = (uint32_t) RValue_toInt32(args[9]); Runner_updateCameraViewSimple(camera); - + return RValue_makeReal(id); } @@ -4076,7 +4076,7 @@ static RValue builtin_script_execute(VMContext* ctx, RValue* args, int32_t argCo // Fallback: treat as SCPT index (BC16 and earlier, or when FUNC lookup failed) if (0 > codeId) { if (0 > rawArg || (uint32_t) rawArg >= ctx->dataWin->scpt.count) { - fprintf(stderr, "VM: script_execute - invalid script index %d\n", rawArg); + logWarn("VM: script_execute - invalid script index %d\n", rawArg); return RValue_makeUndefined(); } codeId = ctx->dataWin->scpt.scripts[rawArg].codeId; @@ -4084,7 +4084,7 @@ static RValue builtin_script_execute(VMContext* ctx, RValue* args, int32_t argCo } if (0 > codeId || ctx->dataWin->code.count <= (uint32_t) codeId) { - fprintf(stderr, "VM: script_execute - invalid codeId %d\n", codeId); + logWarn("VM: script_execute - invalid codeId %d\n", codeId); return RValue_makeUndefined(); } @@ -6577,7 +6577,7 @@ static RValue builtin_audio_group_is_loaded(VMContext* ctx, RValue* args, MAYBE_ static RValue builtin_audio_play_music(VMContext* ctx, RValue* args, MAYBE_UNUSED int32_t argCount) { if (ctx->dataWin->gen8.wadVersion >= 14) { - fprintf(stderr, "VM: [%s] audio_play_music is no-op in WAD version 14+!\n", ctx->currentCodeName); + logWarn("VM: [%s] audio_play_music is no-op in WAD version 14+!\n", ctx->currentCodeName); return RValue_makeUndefined(); } @@ -6593,7 +6593,7 @@ static RValue builtin_audio_play_music(VMContext* ctx, RValue* args, MAYBE_UNUSE static RValue builtin_audio_stop_music(VMContext* ctx, MAYBE_UNUSED RValue* args, MAYBE_UNUSED int32_t argCount) { if (ctx->dataWin->gen8.wadVersion >= 14) { - fprintf(stderr, "VM: [%s] audio_stop_music is no-op in WAD version 14+!\n", ctx->currentCodeName); + logWarn("VM: [%s] audio_stop_music is no-op in WAD version 14+!\n", ctx->currentCodeName); return RValue_makeUndefined(); } @@ -7105,7 +7105,7 @@ static RValue builtin_file_text_open_read(VMContext* ctx, RValue* args, int32_t int32_t slot = findFreeTextFileSlot(runner); if (0 > slot) { - fprintf(stderr, "Warning: Too many open text files!\n"); + logError("Too many open text files!\n"); abort(); } @@ -7135,7 +7135,7 @@ static RValue builtin_file_text_open_write(VMContext* ctx, RValue* args, int32_t int32_t slot = findFreeTextFileSlot(runner); if (0 > slot) { - fprintf(stderr, "Warning: Too many open text files!\n"); + logError("Too many open text files!\n"); abort(); } @@ -7444,7 +7444,7 @@ static RValue builtin_file_bin_open(VMContext* ctx, RValue* args, int32_t argCou int32_t slot = findFreeBinaryFileSlot(runner); if (0 > slot) { - fprintf(stderr, "Warning: Too many open binary files!\n"); + logWarn("Too many open binary files!\n"); return RValue_makeReal(-1.0); } @@ -7826,7 +7826,7 @@ static RValue builtin_window_set_caption(VMContext* ctx, MAYBE_UNUSED RValue* ar runner->windowTitle = safeStrdup(val); if (runner->setWindowTitle) { runner->setWindowTitle(val); - printf("Runner: Window title set to: %s\n", val); + logInfo("Runner: Window title set to: %s\n", val); } } @@ -7994,7 +7994,7 @@ static RValue builtin_instance_create(VMContext* ctx, RValue* args, int32_t argC GMLReal y = RValue_toReal(args[1]); int32_t objectIndex = RValue_toInt32(args[2]); if (0 > objectIndex || runner->dataWin->objt.count <= (uint32_t) objectIndex) { - fprintf(stderr, "VM: instance_create: objectIndex %d out of range\n", objectIndex); + logWarn("VM: instance_create: objectIndex %d out of range\n", objectIndex); return RValue_makeReal(0.0); } Instance* callerInst = ctx->currentInstance; @@ -8010,7 +8010,7 @@ static RValue builtin_instance_copy(VMContext* ctx, RValue* args, int32_t argCou Runner* runner = ctx->runner; Instance* source = ctx->currentInstance; if (source == nullptr) { - fprintf(stderr, "VM: instance_copy: no current instance\n"); + logWarn("VM: instance_copy: no current instance\n"); return RValue_makeReal(INSTANCE_NOONE); } bool performEvent = argCount > 0 ? RValue_toBool(args[0]) : false; @@ -8068,7 +8068,7 @@ static RValue builtin_instance_create_depth(VMContext* ctx, RValue* args, int32_ int32_t depth = RValue_toInt32(args[2]); int32_t objectIndex = RValue_toInt32(args[3]); if (0 > objectIndex || runner->dataWin->objt.count <= (uint32_t) objectIndex) { - fprintf(stderr, "VM: instance_create: objectIndex %d out of range\n", objectIndex); + logWarn("VM: instance_create: objectIndex %d out of range\n", objectIndex); return RValue_makeReal(0.0); } Instance* callerInst = ctx->currentInstance; @@ -8091,7 +8091,7 @@ static RValue builtin_instance_change(VMContext* ctx, RValue* args, int32_t argC bool performEvents = RValue_toBool(args[1]); if (0 > objectIndex || (uint32_t) objectIndex >= runner->dataWin->objt.count) { - fprintf(stderr, "VM: instance_change: objectIndex %d out of range\n", objectIndex); + logWarn("VM: instance_change: objectIndex %d out of range\n", objectIndex); return RValue_makeUndefined(); } @@ -8270,20 +8270,20 @@ static RValue builtin_event_inherited(VMContext* ctx, MAYBE_UNUSED RValue* args, Runner* runner = ctx->runner; Instance* inst = ctx->currentInstance; if (inst == nullptr || 0 > ctx->currentEventObjectIndex || 0 > ctx->currentEventType) { - fprintf(stderr, "VM: event_inherited called with no event context (inst=%p, eventObjIdx=%d, eventType=%d)\n", (void*) inst, ctx->currentEventObjectIndex, ctx->currentEventType); + logWarn("VM: event_inherited called with no event context (inst=%p, eventObjIdx=%d, eventType=%d)\n", (void*) inst, ctx->currentEventObjectIndex, ctx->currentEventType); return RValue_makeReal(0.0); } DataWin* dataWin = ctx->dataWin; int32_t ownerObjectIndex = ctx->currentEventObjectIndex; if ((uint32_t) ownerObjectIndex >= dataWin->objt.count) { - fprintf(stderr, "VM: event_inherited ownerObjectIndex %d out of range\n", ownerObjectIndex); + logWarn("VM: event_inherited ownerObjectIndex %d out of range\n", ownerObjectIndex); return RValue_makeReal(0.0); } int32_t parentObjectIndex = dataWin->objt.objects[ownerObjectIndex].parentId; if (ctx->traceEventInherited) { - fprintf(stderr, "VM: [%s] event_inherited owner=%s(%d) parent=%s(%d) event=%s (instanceId=%d)\n", dataWin->objt.objects[inst->objectIndex].name, dataWin->objt.objects[ownerObjectIndex].name, ownerObjectIndex, (0 > parentObjectIndex) ? "none" : dataWin->objt.objects[parentObjectIndex].name, parentObjectIndex, Runner_getEventName(ctx->currentEventType, ctx->currentEventSubtype), inst->instanceId); + logInfo("VM: [%s] event_inherited owner=%s(%d) parent=%s(%d) event=%s (instanceId=%d)\n", dataWin->objt.objects[inst->objectIndex].name, dataWin->objt.objects[ownerObjectIndex].name, ownerObjectIndex, (0 > parentObjectIndex) ? "none" : dataWin->objt.objects[parentObjectIndex].name, parentObjectIndex, Runner_getEventName(ctx->currentEventType, ctx->currentEventSubtype), inst->instanceId); } if (0 > parentObjectIndex) return RValue_makeReal(0.0); @@ -8332,7 +8332,7 @@ static RValue builtin_action_create_object(VMContext* ctx, RValue* args, int32_t GMLReal x = RValue_toReal(args[1]); GMLReal y = RValue_toReal(args[2]); if (0 > objectIndex || runner->dataWin->objt.count <= (uint32_t) objectIndex) { - fprintf(stderr, "VM: action_create_object: objectIndex %d out of range\n", objectIndex); + logWarn("VM: action_create_object: objectIndex %d out of range\n", objectIndex); return RValue_makeUndefined(); } Instance* callerInst = ctx->currentInstance; @@ -8855,7 +8855,7 @@ static RValue builtin_buffer_write(MAYBE_UNUSED VMContext* ctx, RValue* args, MA break; } default: - fprintf(stderr, "buffer_write: unsupported data type %d\n", dataType); + logWarn("buffer_write: unsupported data type %d\n", dataType); break; } @@ -8966,7 +8966,7 @@ static RValue builtin_buffer_read(MAYBE_UNUSED VMContext* ctx, RValue* args, MAY break; } default: - fprintf(stderr, "buffer_read: unsupported data type %d\n", dataType); + logWarn("buffer_read: unsupported data type %d\n", dataType); break; } @@ -9186,7 +9186,7 @@ static RValue builtin_buffer_save_async(MAYBE_UNUSED VMContext* ctx, RValue* arg static RValue builtin_buffer_async_group_begin(MAYBE_UNUSED VMContext* ctx, RValue* args, MAYBE_UNUSED int32_t argCount) { Runner* runner = ctx->runner; if (runner->asyncBufferGroupActive) { - fprintf(stderr, "buffer_async_group_begin: a buffer group is already open\n"); + logWarn("buffer_async_group_begin: a buffer group is already open\n"); return RValue_makeUndefined(); } free(runner->asyncBufferGroupName); @@ -9198,7 +9198,7 @@ static RValue builtin_buffer_async_group_begin(MAYBE_UNUSED VMContext* ctx, RVal static RValue builtin_buffer_async_group_end(MAYBE_UNUSED VMContext* ctx, MAYBE_UNUSED RValue* args, MAYBE_UNUSED int32_t argCount) { Runner* runner = ctx->runner; if (!runner->asyncBufferGroupActive) { - fprintf(stderr, "buffer_async_group_end: no matching buffer_async_group_begin\n"); + logWarn("buffer_async_group_end: no matching buffer_async_group_begin\n"); return RValue_makeReal(-1.0); } @@ -10543,7 +10543,7 @@ static RValue builtin_surface_copy_part(VMContext* ctx, RValue* args, MAYBE_UNUS float ys = (float) RValue_toReal(args[5]); float ws = (float) RValue_toReal(args[6]); float hs = (float) RValue_toReal(args[7]); - //fprintf(stderr, "Set Surface Target Yes\n"); + // logInfo("Set Surface Target Yes\n"); Runner* runner = ctx->runner; if (runner->renderer != nullptr) { runner->renderer->vtable->surfaceCopy(runner->renderer, sourceID, x, y, destinationID, xs, ys, ws, hs, true); @@ -10556,7 +10556,7 @@ static RValue builtin_surface_copy(VMContext* ctx, RValue* args, MAYBE_UNUSED in float x = (float) RValue_toReal(args[1]); float y = (float) RValue_toReal(args[2]); int32_t destinationID = (int32_t) RValue_toReal(args[3]); - //fprintf(stderr, "Set Surface Target Yes\n"); + // logInfo("Set Surface Target Yes\n"); Runner* runner = ctx->runner; if (runner->renderer != nullptr) { runner->renderer->vtable->surfaceCopy(runner->renderer, sourceID, x, y, destinationID, 0.0, 0.0, 0.0, 0.0, false); @@ -12134,7 +12134,7 @@ static RValue builtin_action_set_alarm(VMContext* ctx, MAYBE_UNUSED RValue* args #ifdef ENABLE_VM_TRACING Runner* runner = ctx->runner; if (shgeti(ctx->alarmsToBeTraced, "*") != -1 || shgeti(ctx->alarmsToBeTraced, runner->dataWin->objt.objects[inst->objectIndex].name) != -1) { - fprintf(stderr, "VM: [%s] Setting Alarm[%d] = %d (instanceId=%d)\n", runner->dataWin->objt.objects[inst->objectIndex].name, alarmIndex, steps, inst->instanceId); + logInfo("VM: [%s] Setting Alarm[%d] = %d (instanceId=%d)\n", runner->dataWin->objt.objects[inst->objectIndex].name, alarmIndex, steps, inst->instanceId); } #endif @@ -12160,7 +12160,7 @@ static RValue builtin_alarm_set(VMContext* ctx, MAYBE_UNUSED RValue* args, MAYBE #ifdef ENABLE_VM_TRACING Runner* runner = ctx->runner; if (shgeti(ctx->alarmsToBeTraced, "*") != -1 || shgeti(ctx->alarmsToBeTraced, runner->dataWin->objt.objects[inst->objectIndex].name) != -1) { - fprintf(stderr, "VM: [%s] Setting Alarm[%d] = %d (instanceId=%d)\n", runner->dataWin->objt.objects[inst->objectIndex].name, alarmIndex, value, inst->instanceId); + logInfo("VM: [%s] Setting Alarm[%d] = %d (instanceId=%d)\n", runner->dataWin->objt.objects[inst->objectIndex].name, alarmIndex, value, inst->instanceId); } #endif @@ -12545,7 +12545,7 @@ static RValue builtin_action_sprite_color(VMContext* ctx, RValue* args, MAYBE_UN // action_message(text) - shows a dialog. static RValue builtin_action_message(MAYBE_UNUSED VMContext* ctx, RValue* args, MAYBE_UNUSED int32_t argCount) { char* text = RValue_toString(args[0]); - fprintf(stderr, "VM: action_message: %s\n", text); + logInfo("VM: action_message: %s\n", text); free(text); return RValue_makeUndefined(); } @@ -12571,7 +12571,7 @@ static RValue builtin_action_next_room(VMContext* ctx, MAYBE_UNUSED RValue* args if ((int32_t) runner->dataWin->gen8.roomOrderCount > nextPos) { runner->pendingRoom = runner->dataWin->gen8.roomOrder[nextPos]; } else { - fprintf(stderr, "VM: action_next_room - already at last room!\n"); + logWarn("VM: action_next_room - already at last room!\n"); } return RValue_makeUndefined(); } @@ -12716,7 +12716,7 @@ static RValue builtin_tile_add(VMContext* ctx, RValue* args, MAYBE_UNUSED int32_ int32_t backgroundIndex = RValue_toInt32(args[0]); if (0 > backgroundIndex || backgroundIndex >= (int32_t) ctx->dataWin->bgnd.count) { - fprintf(stderr, "VM: tile_add: background does not exist (%d)\n", backgroundIndex); + logWarn("VM: tile_add: background does not exist (%d)\n", backgroundIndex); return RValue_makeReal(-1.0); } @@ -12809,7 +12809,7 @@ static RValue builtin_tile_delete(VMContext* ctx, RValue* args, MAYBE_UNUSED int runner->drawableListStructureDirty = true; return RValue_makeUndefined(); } - fprintf(stderr, "VM: tile_delete: tile does not exist (%u)\n", id); + logWarn("VM: tile_delete: tile does not exist (%u)\n", id); return RValue_makeUndefined(); } @@ -12825,7 +12825,7 @@ static RValue builtin_tile_set_alpha(VMContext* ctx, RValue* args, MAYBE_UNUSED room->tiles[i].alpha = alpha; return RValue_makeUndefined(); } - fprintf(stderr, "VM: tile_set_alpha: tile does not exist (%u)\n", id); + logWarn("VM: tile_set_alpha: tile does not exist (%u)\n", id); return RValue_makeUndefined(); } @@ -13961,7 +13961,7 @@ static RValue builtin_tilemap_set(VMContext* ctx, RValue* args, MAYBE_UNUSED int uint32_t cell = (uint32_t) RValue_toInt32(args[1]); uint32_t tileIndex = (cell >> 0) & TILEINDEX_SHIFTEDMASK; if (tileset != nullptr && tileset->gms2TileCount != 0 && tileIndex >= tileset->gms2TileCount) { - fprintf(stderr, "VM: [%s] tilemap_set() - tile index outside tile set count\n", ctx->currentCodeName); + logWarn("VM: [%s] tilemap_set() - tile index outside tile set count\n", ctx->currentCodeName); return RValue_makeBool(false); } @@ -13985,7 +13985,7 @@ static RValue builtin_tilemap_set_at_pixel(VMContext* ctx, RValue* args, MAYBE_U uint32_t cell = (uint32_t) RValue_toInt32(args[1]); uint32_t tileIndex = cell & TILEINDEX_SHIFTEDMASK; if (tileset->gms2TileCount != 0 && tileIndex >= tileset->gms2TileCount) { - fprintf(stderr, "VM: [%s] tilemap_set_at_pixel() - tile index outside tile set count\n", ctx->currentCodeName); + logWarn("VM: [%s] tilemap_set_at_pixel() - tile index outside tile set count\n", ctx->currentCodeName); return RValue_makeBool(false); } @@ -14138,7 +14138,7 @@ static RValue builtin_SetStatic(VMContext* ctx, MAYBE_UNUSED RValue* args, MAYBE // We reuse Instance (with objectIndex = STRUCT_OBJECT_INDEX) the same way globalScopeInstance is used for GLOB scripts, instead of introducing a separate struct type. static RValue builtin_NewGMLObject(VMContext* ctx, RValue* args, int32_t argCount) { if (1 > argCount) { - fprintf(stderr, "VM: @@NewGMLObject@@ called with no arguments\n"); + logWarn("VM: @@NewGMLObject@@ called with no arguments\n"); return RValue_makeUndefined(); } @@ -14160,7 +14160,7 @@ static RValue builtin_NewGMLObject(VMContext* ctx, RValue* args, int32_t argCoun } } if (0 > codeIndex || (uint32_t) codeIndex > ctx->dataWin->code.count) { - fprintf(stderr, "VM: @@NewGMLObject@@ method has invalid codeIndex %d\n", codeIndex); + logWarn("VM: @@NewGMLObject@@ method has invalid codeIndex %d\n", codeIndex); return RValue_makeUndefined(); } @@ -14220,7 +14220,7 @@ static RValue builtin_try_hook(VMContext* ctx, RValue* args, int32_t argCount) { exceptionStackHandler->stackTop = ctx->stack.top; #ifdef ENABLE_VM_EXCEPTIONS_LOGS - fprintf(stderr, "VM: Configured exception handler for jump on exception: %d, jump on success: %d\n", jumpToOnException, jumpToOnSuccess); + logInfo("VM: Configured exception handler for jump on exception: %d, jump on success: %d\n", jumpToOnException, jumpToOnSuccess); #endif return RValue_makeUndefined(); @@ -15271,7 +15271,7 @@ static RValue jsonDecodeValue(VMContext* ctx, JsonValue* json) { static RValue builtin_json_decode(VMContext* ctx, RValue* args, int32_t argCount) { if (1 > argCount) { - fprintf(stderr, "[json_decode] Expected at least 1 argument\n"); + logWarn("[json_decode] Expected at least 1 argument\n"); return RValue_makeUndefined(); } @@ -15336,7 +15336,7 @@ static RValue builtin_object_get_solid(VMContext* ctx, RValue* args, int32_t arg static RValue builtin_object_get_sprite(VMContext* ctx, RValue* args, int32_t argCount) { if (1 > argCount) { - fprintf(stderr, "[object_get_sprite] Expected at least 1 argument\n"); + logWarn("[object_get_sprite] Expected at least 1 argument\n"); return RValue_makeUndefined(); } @@ -15476,7 +15476,7 @@ static RValue fontAddSpriteImpl(VMContext* ctx, int32_t spriteIndex, uint16_t* c DataWin* dw = ctx->dataWin; if (0 > spriteIndex || (uint32_t) spriteIndex >= dw->sprt.count) { - fprintf(stderr, "[font_add_sprite] Invalid sprite index %d\n", spriteIndex); + logWarn("[font_add_sprite] Invalid sprite index %d\n", spriteIndex); return RValue_makeReal(-1.0); } @@ -15596,7 +15596,7 @@ static RValue fontAddSpriteImpl(VMContext* ctx, int32_t spriteIndex, uint16_t* c static RValue builtin_font_get_name(VMContext* ctx, RValue* args, int32_t argCount) { if (1 > argCount) { - fprintf(stderr, "[font_get_name] Expected 1 argument, got 0"); + logWarn("[font_get_name] Expected 1 argument, got 0"); return RValue_makeUndefined(); } @@ -15647,7 +15647,7 @@ static RValue builtin_font_get_info(VMContext* ctx, RValue* args, int32_t argCou // font_add_sprite_ext(sprite, string_map, prop, sep) static RValue builtin_font_add_sprite_ext(VMContext* ctx, RValue* args, int32_t argCount) { if (4 > argCount) { - fprintf(stderr, "[font_add_sprite_ext] Expected 4 arguments, got %d\n", argCount); + logWarn("[font_add_sprite_ext] Expected 4 arguments, got %d\n", argCount); return RValue_makeReal(-1.0); } @@ -15672,7 +15672,7 @@ static RValue builtin_font_add_sprite_ext(VMContext* ctx, RValue* args, int32_t // font_add_sprite(sprite, first, prop, sep) static RValue builtin_font_add_sprite(VMContext* ctx, RValue* args, int32_t argCount) { if (4 > argCount) { - fprintf(stderr, "[font_add_sprite] Expected 4 arguments, got %d\n", argCount); + logWarn("[font_add_sprite] Expected 4 arguments, got %d\n", argCount); return RValue_makeReal(-1.0); } @@ -15699,7 +15699,7 @@ static RValue builtin_font_add_sprite(VMContext* ctx, RValue* args, int32_t argC static RValue builtin_asset_get_index(VMContext* ctx, RValue* args, int32_t argCount) { if (1 > argCount) { - fprintf(stderr, "[asset_get_index] Expected at least 1 argument\n"); + logWarn("[asset_get_index] Expected at least 1 argument\n"); return RValue_makeUndefined(); } @@ -15863,8 +15863,8 @@ static RValue builtin_parameter_string(VMContext* ctx, RValue* args, int32_t arg static RValue builtin_shader_set(VMContext* ctx, MAYBE_UNUSED RValue* args, MAYBE_UNUSED int32_t argCount) { int32_t ShaderID = (int32_t) RValue_toReal(args[0]); - //fprintf(stderr, "Set Shader ID %u\n", ShaderID); - //gpuSetShader + // logInfo("Set Shader ID %u\n", ShaderID); + // gpuSetShader ctx->runner->renderer->vtable->gpuSetShader(ctx->runner->renderer, ShaderID); return RValue_makeUndefined(); } @@ -15920,7 +15920,7 @@ static RValue builtin_texture_set_stage(VMContext* ctx, MAYBE_UNUSED RValue* arg static RValue builtin_shader_set_uniformF(VMContext* ctx, MAYBE_UNUSED RValue* args, MAYBE_UNUSED int32_t argCount) { int32_t handle = (int32_t) RValue_toReal(args[0]); float value1, value2, value3, value4; - //fprintf(stderr, "Set ARG Count %u\n", argCount); + // logInfo("Set ARG Count %u\n", argCount); if (argCount == 2) { value1 = (float) RValue_toReal(args[1]); ctx->runner->renderer->vtable->shaderSetUniformF(ctx->runner->renderer, handle, 1, value1, 0.0, 0.0, 0.0); @@ -15938,7 +15938,7 @@ static RValue builtin_shader_set_uniformF(VMContext* ctx, MAYBE_UNUSED RValue* a value2 = (float) RValue_toReal(args[2]); value3 = (float) RValue_toReal(args[3]); value4 = (float) RValue_toReal(args[4]); - //fprintf(stderr, "Value4 %.8f\n", value4); + // logInfo("Value4 %.8f\n", value4); ctx->runner->renderer->vtable->shaderSetUniformF(ctx->runner->renderer, handle, 4, value1, value2, value3, value4); } return RValue_makeUndefined(); @@ -16245,7 +16245,7 @@ void VMBuiltins_registerAll(VMContext* ctx) { VM_registerBuiltin(ctx, "matrix_build_projection_ortho", builtin_matrix_build_projection_ortho); VM_registerBuiltin(ctx, "matrix_build_projection_perspective_fov", builtin_matrix_build_projection_perspective_fov); VM_registerBuiltin(ctx, "matrix_get", builtin_matrix_get); - VM_registerBuiltin(ctx, "matrix_set", builtin_matrix_set); + VM_registerBuiltin(ctx, "matrix_set", builtin_matrix_set); // Random VM_registerBuiltin(ctx, "random", builtin_random); VM_registerBuiltin(ctx, "random_range", builtin_random_range); diff --git a/src/web-meta/main.c b/src/web-meta/main.c index 8bf23e105..99ba8549a 100644 --- a/src/web-meta/main.c +++ b/src/web-meta/main.c @@ -4,6 +4,25 @@ #include #include "data_win.h" +void platformLog(const logType type, const char *format, va_list va) { + FILE *out = stderr; + switch (type) { + case LOG_TYPE_NORMAL: + out = stdout; + break; + case LOG_TYPE_WARNING: + fputs("Warning: ", out); + break; + case LOG_TYPE_ERROR: + fputs("Error: ", out); + break; + case LOG_TYPE_DEBUG: + fputs("Debug: ", out); + break; + } + vfprintf(out, format, va); +} + DataWin* parseDataWin(const char* path) { DataWinParserOptions opts = {0}; opts.parseGen8 = true; diff --git a/src/web/main.c b/src/web/main.c index dd3380e47..57400044a 100644 --- a/src/web/main.c +++ b/src/web/main.c @@ -22,6 +22,25 @@ static int32_t gAudioSampleRate = 48000; uint8_t keyDown[GML_KEY_COUNT] = {0}; uint8_t keyUp[GML_KEY_COUNT] = {0}; +void platformLog(const logType type, const char *format, va_list va) { + FILE *out = stderr; + switch (type) { + case LOG_TYPE_NORMAL: + out = stdout; + break; + case LOG_TYPE_WARNING: + fputs("Warning: ", out); + break; + case LOG_TYPE_ERROR: + fputs("Error: ", out); + break; + case LOG_TYPE_DEBUG: + fputs("Debug: ", out); + break; + } + vfprintf(out, format, va); +} + // Configures the sample rate that miniaudio will mix at. Must match the AudioContext's sampleRate // on the JS side, and must be called BEFORE startRunner. void setAudioSampleRate(int32_t rate) { @@ -53,7 +72,7 @@ int getKeyCount() { } int main() { - printf("Howdy! Loritta is so cute! lol\n"); + logInfo("Howdy! Loritta is so cute! lol\n"); emscripten_exit_with_live_runtime(); return 0; } @@ -62,12 +81,12 @@ int main() { int mountOpfs(void) { backend_t opfs = wasmfs_create_opfs_backend(); if (!opfs) { - fprintf(stderr, "Failed to create OPFS backend\n"); + logWarn("Failed to create OPFS backend\n"); return -1; } int rc = wasmfs_create_directory("/butterscotch", 0777, opfs); if (rc != 0) { - fprintf(stderr, "Failed to mount OPFS at /butterscotch: %s\n", strerror(errno)); + logWarn("Failed to mount OPFS at /butterscotch: %s\n", strerror(errno)); return -1; } return 0; @@ -163,7 +182,7 @@ void* loop() { } // Cleanup - fprintf(stderr, "Cleaning up runner!\n"); + logInfo("Cleaning up runner!\n"); gRunner->audioSystem->vtable->destroy(gRunner->audioSystem); gRunner->audioSystem = nullptr; @@ -189,7 +208,7 @@ void setWindowTitle(const char* title) { // gamePath: WASMFS path to the data.win to load (example: "/butterscotch/games/undertale/data.win"). // savesPath: WASMFS directory where saves should live (example: "/butterscotch/saves/undertale" - Created if it does not exist). void startRunner(const char* gamePath, const char* savesPath) { - fprintf(stderr, "Starting runner! gamePath=%s savesPath=%s\n", gamePath, savesPath); + logInfo("Starting runner! gamePath=%s savesPath=%s\n", gamePath, savesPath); EmscriptenWebGLContextAttributes attrs; emscripten_webgl_init_context_attributes(&attrs); @@ -206,7 +225,7 @@ void startRunner(const char* gamePath, const char* savesPath) { // But that's how Emscripten works for SOME REASON ctx = emscripten_webgl_create_context("#canvas", &attrs); if (0 >= ctx) { - printf("Failed to create WebGL context: %d\n", (int)ctx); + logError("Failed to create WebGL context: %d\n", (int)ctx); abort(); } @@ -218,7 +237,7 @@ void startRunner(const char* gamePath, const char* savesPath) { // Make sure the saves directory exists. The FileSystem impl will write into it. if (savesPath != nullptr && savesPath[0] != '\0') { if (mkdirP(savesPath) != 0) { - fprintf(stderr, "Warning: failed to ensure saves dir exists at %s: %s\n", savesPath, strerror(errno)); + logWarn("failed to ensure saves dir exists at %s: %s\n", savesPath, strerror(errno)); } } @@ -295,6 +314,6 @@ void startRunner(const char* gamePath, const char* savesPath) { } void stopRunner() { - fprintf(stderr, "Marked runner to exit!\n"); + logInfo("Marked runner to exit!\n"); gRunner->shouldExit = true; } diff --git a/tests/tests.conf b/tests/tests.conf index 67ea97802..ee83bf4a0 100644 --- a/tests/tests.conf +++ b/tests/tests.conf @@ -1,7 +1,7 @@ tests = [ { name = "Test if collisions are executed sorted in object index order NOT in instance creation order" - butterscotchArgs = ["object-index-iteration-test/data.win", "--headless", "--exit-at-frame", "1"] + butterscotchArgs = ["--disable-log-colours", "--disable-file-log", "object-index-iteration-test/data.win", "--headless", "--exit-at-frame", "1"] expectedStdoutOutput = [ [ "Game: start frame", @@ -13,7 +13,7 @@ tests = [ }, { name = "Test Loritta and the Stars" - butterscotchArgs = ["loritta-and-the-stars/data.win", "--playback-inputs", "loritta-and-the-stars/gameplay.json", "--exit-at-frame", "9000", "--screenshot-surfaces-at-frame", "9000", "--screenshot-surfaces", "loritta-and-the-stars/actual.%d.%d.png", "--headless"] + butterscotchArgs = ["--disable-log-colours", "--disable-file-log", "loritta-and-the-stars/data.win", "--playback-inputs", "loritta-and-the-stars/gameplay.json", "--exit-at-frame", "9000", "--screenshot-surfaces-at-frame", "9000", "--screenshot-surfaces", "loritta-and-the-stars/actual.%d.%d.png", "--headless"] expectedScreenshots = [ { expected = "loritta-and-the-stars/expected.9000.0.png" @@ -24,10 +24,10 @@ tests = [ { name = "Test Undertale PT-BR (WinPack/TranslaTale WAD)" commercialGame = true - butterscotchArgs = ["undertale-ptbr-winpack/data.win", "--playback-inputs", "undertale-ptbr-winpack/gameplay.json", "--exit-at-frame", "730", "--screenshot-surfaces-at-frame", "730", "--screenshot-surfaces", "undertale-ptbr-winpack/actual.%d.%d.png", "--headless", "--lazy-textures"] + butterscotchArgs = ["--disable-log-colours", "--disable-file-log", "undertale-ptbr-winpack/data.win", "--playback-inputs", "undertale-ptbr-winpack/gameplay.json", "--exit-at-frame", "730", "--screenshot-surfaces-at-frame", "730", "--screenshot-surfaces", "undertale-ptbr-winpack/actual.%d.%d.png", "--headless", "--lazy-textures"] expectedStderrOutput = [ [ - "DataWin: Allocated new TPAG! Was the WAD built with WinPack? (TranslaTale)" + "Warning: DataWin: Allocated new TPAG! Was the WAD built with WinPack? (TranslaTale)" ] ] expectedScreenshots = [ @@ -40,7 +40,7 @@ tests = [ { name = "Test Underfavela (Bogus Sprite Types and Bogus AGPR padding checks)" commercialGame = true - butterscotchArgs = ["underfavela/data.win", "--seed", "0", "--playback-inputs", "underfavela/gameplay.json", "--screenshot-surfaces", "underfavela/actual.%d.%d.png", "--screenshot-surfaces-at-frame", "2000", "--exit-at-frame", "2000", "--headless", "--lazy-textures"] + butterscotchArgs = ["--disable-log-colours", "--disable-file-log", "underfavela/data.win", "--seed", "0", "--playback-inputs", "underfavela/gameplay.json", "--screenshot-surfaces", "underfavela/actual.%d.%d.png", "--screenshot-surfaces-at-frame", "2000", "--exit-at-frame", "2000", "--headless", "--lazy-textures"] expectedScreenshots = [ { expected = "underfavela/expected.2000.0.png" @@ -51,7 +51,7 @@ tests = [ { name = "Test Simple Structs, Methods and Dynamic Methods" commercialGame = false - butterscotchArgs = ["simple-structs-methods-and-dynamic-methods/data.win", "--exit-at-frame", "1"] + butterscotchArgs = ["--disable-log-colours", "--disable-file-log", "simple-structs-methods-and-dynamic-methods/data.win", "--exit-at-frame", "1"] expectedStdoutOutput = [ [ "Game: My name is Loritta Morenitta!", @@ -63,6 +63,8 @@ tests = [ "Game: Howdy! This was invoked via a dynamic method, but now bound to a asset reference woo - x: 640, y: 224", "Game: Name: Loritta Morenitta", "Game: Stars: 1437", + ], + [ "Game: Hiii, my name is Pantufa!", "Game: This is another function!!" ] @@ -71,10 +73,12 @@ tests = [ { name = "Test Out of Lives Event Ordering" commercialGame = false - butterscotchArgs = ["lives-and-health-events-check/data.win", "--exit-at-frame", "20", "--headless"] + butterscotchArgs = ["--disable-log-colours", "--disable-file-log", "lives-and-health-events-check/data.win", "--exit-at-frame", "20", "--headless"] expectedStdoutOutput = [ [ "Game: Current lives is 10, decreasing one...", + ], + [ "Game: Current lives is 9, decreasing one...", "Game: Current lives is 8, decreasing one...", "Game: Current lives is 7, decreasing one...", @@ -97,7 +101,7 @@ tests = [ { name = "Test if path_add is creating paths closed by default (DELTARUNE Chapter 4 - Jackenstein)" commercialGame = true - butterscotchArgs = ["deltarune-chapter4-105-beta/data.win", "--playback-inputs", "deltarune-chapter4-105-beta/jackenstein-path-test.json", "--lazy-textures", "--seed", "0", "--screenshot-surfaces", "deltarune-chapter4-105-beta/actual.jackenstein-path-test.%d.%d.png", "--screenshot-surfaces-at-frame", "9473", "--screenshot-surfaces-at-frame", "9474", "--headless", "--exit-at-frame", "9474", "--save-folder", "deltarune-chapter4-105-beta/jackenstein/"] + butterscotchArgs = ["--disable-log-colours", "--disable-file-log", "deltarune-chapter4-105-beta/data.win", "--playback-inputs", "deltarune-chapter4-105-beta/jackenstein-path-test.json", "--lazy-textures", "--seed", "0", "--screenshot-surfaces", "deltarune-chapter4-105-beta/actual.jackenstein-path-test.%d.%d.png", "--screenshot-surfaces-at-frame", "9473", "--screenshot-surfaces-at-frame", "9474", "--headless", "--exit-at-frame", "9474", "--save-folder", "deltarune-chapter4-105-beta/jackenstein/"] expectedScreenshots = [ { expected = "deltarune-chapter4-105-beta/expected.jackenstein-path-test.9473.0.png" @@ -112,7 +116,7 @@ tests = [ { name = "Test struct_get_names and variable_instance_get_names" commercialGame = false - butterscotchArgs = ["struct-get-names-test/data.win", "--exit-at-frame", "1", "--headless"] + butterscotchArgs = ["--disable-log-colours", "--disable-file-log", "struct-get-names-test/data.win", "--exit-at-frame", "1", "--headless"] # The order is not guaranteed by GameMaker, so we also won't check for the exact order expectedStdoutOutput = [ [ "Game: [struct(struct_get_names)] Name is gabrielaName" ], @@ -150,7 +154,7 @@ tests = [ { name = "Test Stack Unwinding" commercialGame = false - butterscotchArgs = ["stack-unwinding/data.win", "--exit-at-frame", "1", "--headless"] + butterscotchArgs = ["--disable-log-colours", "--disable-file-log", "stack-unwinding/data.win", "--exit-at-frame", "1", "--headless"] expectedStdoutOutput = [ [ "Game: Exited loop! Current count is 2047" ], ] @@ -158,10 +162,10 @@ tests = [ { name = "Test try ... catch ... finally" commercialGame = false - butterscotchArgs = ["try-catch-finally-test/data.win", "--exit-at-frame", "1", "--headless"] + butterscotchArgs = ["--disable-log-colours", "--disable-file-log", "try-catch-finally-test/data.win", "--exit-at-frame", "1", "--headless"] expectedStderrOutput = [ - [ "VM: The exception handler frame stack is 0, but we have a pending exception to be dispatched! This would've technically crashed the game in the original runner... or we aren't handling exceptions correctly. We'll swallow the exception and hope for the best... (Exception: b)" ] + [ "Error: VM: The exception handler frame stack is 0, but we have a pending exception to be dispatched! This would've technically crashed the game in the original runner... or we aren't handling exceptions correctly. We'll swallow the exception and hope for the best... (Exception: b)" ] ] expectedStdoutOutput = [