misc: various clean up for diagnosing launch failures (#872)

## Link to GitHub Issue or related Pull Request, if one exists
#345 

## Description of change

**IIDX TDJ rom probe no longer touches removable media** —
`C:\000rom.txt` and `D:\001rom.txt` are not emulated paths; they hit
whatever is actually mounted on the user's machine. `D:` is commonly an
optical drive or card reader, and the launcher clears
`SEM_FAILCRITICALERRORS` process-wide before attach, so an empty drive
raises the modal *"insert a disk"* dialog and blocks the attaching
thread. The probe now checks `GetDriveTypeW` and only reads fixed and
RAM disks.

**`iat_find` no longer calls `log_fatal` on an unparseable module** —
`iat_try(nullptr)` walks every loaded module, including foreign ones
(injected, manually mapped, header wiped by AV/EDR/overlays). A non-`MZ`
DOS header called `log_fatal`. There is nothing to hook in such a
module, so it is skipped.

**`logger::stop()` can no longer hang forever** — hook installation
suspends every other thread, including the logging thread. `stop()`
unconditionally joined that thread, so `log_fatal` and the 30-second
`show_popup` watchdog both wedged instead of terminating, and logging is
asynchronous so nothing reached log.txt either. It now waits with a
timeout, then detaches and flushes synchronously.

**`GetFileSizeEx` was never hooked** — the hook was registered under the
name `"GetFileSize"`, so it re-patched that slot instead.

**Warn when `-modules` is set** — it changes where the game is run from,
and is usually set accidentally.

## Testing
*how was the code tested?*
This commit is contained in:
bicarus
2026-08-17 22:41:07 -07:00
committed by GitHub
parent 94574c485a
commit 3863d5a4ed
5 changed files with 136 additions and 29 deletions
+24 -2
View File
@@ -279,6 +279,26 @@ namespace games::iidx {
return nullptr;
}
// best-effort read of a TDJ ROM file to determine if the game is running in TDJ mode
//
// these paths are not emulated - they hit whatever is actually mounted at that drive letter.
// an empty optical or removable drive raises the modal "insert a disk" error (the launcher
// clears SEM_FAILCRITICALERRORS process-wide) and a downed network drive stalls on redirector
// timeouts, so only probe what a TDJ cabinet would actually be laid out on.
// drive_path must be absolute and start with a drive letter.
static bool tdj_rom_matches(const char *drive_path, const char *expected) {
const wchar_t root[] = { (wchar_t) drive_path[0], L':', L'\\', L'\0' };
const auto drive_type = GetDriveTypeW(root);
if (drive_type != DRIVE_FIXED && drive_type != DRIVE_RAMDISK) {
log_misc("iidx", "not probing '{}' for TDJ, not a local disk (drive type {})",
drive_path, drive_type);
return false;
}
return fileutils::text_read(drive_path) == expected;
}
#endif
IIDXGame::IIDXGame() : Game("Beatmania IIDX") {
@@ -339,8 +359,10 @@ namespace games::iidx {
HAS_LIBAIO = true;
// check TDJ mode
TDJ_MODE |= fileutils::text_read("C:\\000rom.txt") == "TDJ-JA";
TDJ_MODE |= fileutils::text_read("D:\\001rom.txt") == "TDJ";
if (!TDJ_MODE) {
TDJ_MODE = tdj_rom_matches("C:\\000rom.txt", "TDJ-JA")
|| tdj_rom_matches("D:\\001rom.txt", "TDJ");
}
// force TDJ mode
if (TDJ_MODE) {
+1 -1
View File
@@ -574,7 +574,7 @@ void devicehook_init(HMODULE module) {
STORE(EscapeCommFunction_orig, detour::iat_try("EscapeCommFunction", EscapeCommFunction_hook, module));
STORE(GetCommState_orig, detour::iat_try("GetCommState", GetCommState_hook, module));
STORE(GetFileSize_orig, detour::iat_try("GetFileSize", GetFileSize_hook, module));
STORE(GetFileSizeEx_orig, detour::iat_try("GetFileSize", GetFileSizeEx_hook, module));
STORE(GetFileSizeEx_orig, detour::iat_try("GetFileSizeEx", GetFileSizeEx_hook, module));
STORE(GetFileInformationByHandle_orig, detour::iat_try(
"GetFileInformationByHandle", GetFileInformationByHandle_hook, module));
STORE(PurgeComm_orig, detour::iat_try("PurgeComm", PurgeComm_hook, module));
+20
View File
@@ -1683,6 +1683,26 @@ int main_implementation(int argc, char *argv[]) {
});
}
if (options[launcher::Options::PathToModules].is_active() && !cfg::CONFIGURATOR_STANDALONE) {
log_warning(
"launcher",
"WARNING - user specified -modules option\n\n\n"
"!!! !!!\n"
"!!! Using -modules changes which game DLLs get loaded! !!!\n"
"!!! Unless you know exactly what you are doing, clear -modules !!!\n"
"!!! and try again; usually this is accidentally set by users !!!\n"
"!!! without understanding the implications. !!!\n"
"!!! !!!\n"
);
deferredlogs::defer_error_messages({
"-modules option specified by user",
" game DLLs and patches are loaded from that folder instead of the spice folder,",
" and it is also prepended to the DLL search path, so dependencies may resolve to",
" unexpected copies; instead, clear -modules option and place spice binaries in",
" the intended game directory",
});
}
if (launcher::signal::DISABLE && !cfg::CONFIGURATOR_STANDALONE) {
log_warning(
"launcher",
+64 -14
View File
@@ -1,6 +1,7 @@
#include "logger.h"
#include <algorithm>
#include <atomic>
#include <condition_variable>
#include <mutex>
#include <thread>
@@ -25,13 +26,16 @@ namespace logger {
bool COLOR = true;
// state
static bool RUNNING = false;
static std::atomic<bool> RUNNING = false;
static WORD DEFAULT_ATTRIBUTES = 0;
static std::mutex EVENT_MUTEX;
static std::condition_variable EVENT_CV;
static std::thread *THREAD = nullptr;
static HANDLE THREAD_FINISHED = nullptr;
static std::atomic<bool> THREAD_ABANDONED = false;
static std::mutex OUTPUT_MUTEX;
static bool OUTPUT_BUFFER_HOT = false;
static std::mutex FLUSH_MUTEX;
static std::atomic<bool> OUTPUT_BUFFER_HOT = false;
static std::vector<std::pair<std::string, Style>> OUTPUT_BUFFER1;
static std::vector<std::pair<std::string, Style>> OUTPUT_BUFFER2;
static std::vector<std::pair<std::string, Style>> *OUTPUT_BUFFER = &OUTPUT_BUFFER1;
@@ -71,7 +75,9 @@ namespace logger {
SetConsoleTextAttribute(hTerminal, info.wAttributes);
}
static void output_buffer_flush() {
// the buffer is swapped under OUTPUT_MUTEX but drained outside of it, so two concurrent
// drains would leave one of them iterating a buffer that push() has started appending to
static void output_buffer_flush_locked() {
// get buffer and swap
auto buffer = output_buffer_swap();
@@ -142,6 +148,23 @@ namespace logger {
}
}
static void output_buffer_flush() {
// a detached logging thread can hold FLUSH_MUTEX forever, so never wait on it
if (THREAD_ABANDONED) {
std::unique_lock<std::mutex> guard(FLUSH_MUTEX, std::try_to_lock);
if (guard.owns_lock()) {
output_buffer_flush_locked();
}
return;
}
std::lock_guard<std::mutex> guard(FLUSH_MUTEX);
output_buffer_flush_locked();
}
void start() {
// don't start if blocking
@@ -151,6 +174,7 @@ namespace logger {
// start logging thread
RUNNING = true;
THREAD_FINISHED = CreateEvent(nullptr, TRUE, FALSE, nullptr);
THREAD = new std::thread([] {
std::unique_lock<std::mutex> lock(EVENT_MUTEX);
@@ -160,7 +184,7 @@ namespace logger {
while (RUNNING) {
// wait for hot buffer
EVENT_CV.wait(lock, [] { return OUTPUT_BUFFER_HOT; });
EVENT_CV.wait(lock, [] { return OUTPUT_BUFFER_HOT.load(); });
OUTPUT_BUFFER_HOT = false;
// flush buffer
@@ -180,22 +204,51 @@ namespace logger {
HANDLE hTerminal = GetStdHandle(STD_OUTPUT_HANDLE);
SetConsoleTextAttribute(hTerminal, DEFAULT_ATTRIBUTES);
}
if (THREAD_FINISHED) {
SetEvent(THREAD_FINISHED);
}
});
}
void stop() {
log_info("logger", "stop");
// NOTE: don't log to the logger here!
RUNNING = false;
// clean up thread if required
RUNNING = false;
if (THREAD) {
// fake notify to exit wait loop
OUTPUT_BUFFER_HOT = true;
EVENT_CV.notify_all();
// join and clean up
THREAD->join();
// never block forever - this also runs on the fatal/crash path, where the logging
// thread may be suspended or wedged and would take the whole process down with it
const bool finished = THREAD_FINISHED != nullptr &&
WaitForSingleObject(THREAD_FINISHED, 1000) == WAIT_OBJECT_0;
if (finished) {
THREAD->join();
CloseHandle(THREAD_FINISHED);
THREAD_FINISHED = nullptr;
} else {
THREAD->detach();
THREAD_ABANDONED = true;
// THREAD_FINISHED is leaked on purpose: the detached thread can still wake up and
// signal it, and closing it here risks signaling an unrelated recycled handle
// write out whatever the logging thread never got to
output_buffer_flush();
if (LOG_FILE && LOG_FILE != INVALID_HANDLE_VALUE) {
FlushFileBuffers(LOG_FILE);
}
}
delete THREAD;
THREAD = nullptr;
}
@@ -229,17 +282,14 @@ namespace logger {
// check if blocking or the logging thread is not running
if (BLOCKING || !RUNNING) {
// blocking guard
static std::mutex blocking_lock;
std::lock_guard<std::mutex> blocking_guard(blocking_lock);
// immediately process logs
output_buffer_flush();
} else {
// mark buffer as hot
std::unique_lock<std::mutex> lock(EVENT_MUTEX);
// never block here - the logging thread can be suspended while holding EVENT_MUTEX,
// and it re-checks OUTPUT_BUFFER_HOT before waiting again
std::unique_lock<std::mutex> lock(EVENT_MUTEX, std::try_to_lock);
OUTPUT_BUFFER_HOT = true;
EVENT_CV.notify_one();
}
+27 -12
View File
@@ -119,6 +119,14 @@ static void *pe_offset(void *ptr, size_t offset) {
return reinterpret_cast<uint8_t *>(ptr) + offset;
}
// foreign modules (injected, manually mapped) have no import table to patch - skip them
// instead of taking the process down
static bool has_pe_header(HMODULE module) {
const auto dos_headers = reinterpret_cast<const IMAGE_DOS_HEADER *>(module);
return dos_headers->e_magic == IMAGE_DOS_SIGNATURE;
}
void **detour::iat_find(const char *function, HMODULE module, const char *iid_name) {
// check module
@@ -127,11 +135,13 @@ void **detour::iat_find(const char *function, HMODULE module, const char *iid_na
}
// check signature
const IMAGE_DOS_HEADER *pImgDosHeaders = (IMAGE_DOS_HEADER *) module;
if (pImgDosHeaders->e_magic != IMAGE_DOS_SIGNATURE) {
log_fatal("detour", "signature mismatch ({} != {})", pImgDosHeaders->e_magic, IMAGE_DOS_SIGNATURE);
if (!has_pe_header(module)) {
log_misc("detour", "no PE header in {}, not looking for {}", fmt::ptr(module), function);
return nullptr;
}
const IMAGE_DOS_HEADER *pImgDosHeaders = (IMAGE_DOS_HEADER *) module;
// get import table
const auto nt_headers = reinterpret_cast<IMAGE_NT_HEADERS *>(pe_offset(module, pImgDosHeaders->e_lfanew));
const auto data_dir = &nt_headers->OptionalHeader.DataDirectory[IMAGE_DIRECTORY_ENTRY_IMPORT];
@@ -191,11 +201,13 @@ void **detour::iat_find_ordinal(const char *iid_name, DWORD ordinal, HMODULE mod
}
// check signature
const auto pImgDosHeaders = reinterpret_cast<IMAGE_DOS_HEADER *>(module);
if (pImgDosHeaders->e_magic != IMAGE_DOS_SIGNATURE) {
log_fatal("detour", "signature error");
if (!has_pe_header(module)) {
log_misc("detour", "no PE header in {}, not looking for {}:{}", fmt::ptr(module), iid_name, ordinal);
return nullptr;
}
const auto pImgDosHeaders = reinterpret_cast<IMAGE_DOS_HEADER *>(module);
// get import table
const auto nt_headers = reinterpret_cast<IMAGE_NT_HEADERS *>(pe_offset(module, pImgDosHeaders->e_lfanew));
const auto data_dir = &nt_headers->OptionalHeader.DataDirectory[IMAGE_DIRECTORY_ENTRY_IMPORT];
@@ -246,11 +258,13 @@ void **detour::iat_find_proc(const char *iid_name, void *proc, HMODULE module) {
}
// check signature
const auto pImgDosHeaders = reinterpret_cast<IMAGE_DOS_HEADER *>(module);
if (pImgDosHeaders->e_magic != IMAGE_DOS_SIGNATURE) {
log_fatal("detour", "signature error");
if (!has_pe_header(module)) {
log_misc("detour", "no PE header in {}, not looking for {}", fmt::ptr(module), iid_name);
return nullptr;
}
const auto pImgDosHeaders = reinterpret_cast<IMAGE_DOS_HEADER *>(module);
// get import table
const auto nt_headers = reinterpret_cast<IMAGE_NT_HEADERS *>(pe_offset(module, pImgDosHeaders->e_lfanew));
const auto data_dir = &nt_headers->OptionalHeader.DataDirectory[IMAGE_DIRECTORY_ENTRY_IMPORT];
@@ -298,7 +312,9 @@ void *detour::iat_try(const char *function, void *new_func, HMODULE module, cons
while (cur_entry != nullptr) {
module = reinterpret_cast<HMODULE>(cur_entry->DllBase);
if (module) {
// walking the PEB turns up foreign modules too, and those are expected to have
// nothing to patch - filter them here so iat_find only complains about real callers
if (module && has_pe_header(module)) {
auto old_func = iat_try(function, new_func, module, iid_name);
ret = ret != nullptr ? ret : old_func;
}
@@ -328,7 +344,6 @@ void *detour::iat_try(const char *function, void *new_func, HMODULE module, cons
}
void *detour::iat_try_ordinal(const char *iid_name, DWORD ordinal, void *new_func, HMODULE module) {
// fail when no module was specified
if (module == nullptr) {
return nullptr;
@@ -367,7 +382,7 @@ void *detour::iat_try_proc(const char *iid_name, void *proc, void *new_func, HMO
while (cur_entry != nullptr) {
module = reinterpret_cast<HMODULE>(cur_entry->DllBase);
if (module) {
if (module && has_pe_header(module)) {
auto old_func = iat_try_proc(iid_name, proc, new_func, module);
ret = ret != nullptr ? ret : old_func;
}