From a60fe7d11c71cb09773aa7c8b5e7c4891f94a381 Mon Sep 17 00:00:00 2001 From: Sylpheed RE agent Date: Wed, 19 Aug 2026 10:41:05 +0000 Subject: [PATCH] [RE] threading_posix: fix a lost resume that left CREATE_SUSPENDED threads dead A thread created suspended publishes its state and its suspend count in TWO separate lock scopes: { lock; state_ = kSuspended; notify_all(); } // lock released here if (create_suspended) { lock; suspend_count_ = 1; wait(count == 0); } and Resume() does WaitStarted() - which waits only for state_ != kUninitialized - followed by `if (suspend_count_ == 0) return false;`. So a resumer can slip into the gap: it sees the thread started, sees suspend_count_ still 0, drops the resume and returns false. The new thread then sets the count to 1 and waits on it forever. A textbook lost wakeup. Measured in Project Sylpheed. Pressing (A) on the title makes the game do XamUserGetXUID -> NtCreateEvent -> ExCreateThread(entry=821748F0, CREATE_SUSPENDED) -> NtResumeThread, and the loader thread then never ran: zero kernel calls of its own (it appeared in the log only as an argument) and 00:00:00 host CPU time, while the emulator sat at 546% CPU. Boots reached the main menu 1 time in 6. Fixed by publishing state_ and suspend_count_ under one lock and waiting without releasing it, so a resumer past WaitStarted() always observes 1. On the first clean boot after the fix the same loader thread is the CALLER on 20 kernel-call lines and issues 4 ResolvePath asset reads. Every failed boot before it had exactly zero of both. Also logs when the host resume is refused. XThread::Resume's Linux path discarded that bool - the Windows path turns it into X_STATUS_UNSUCCESSFUL - so a dropped resume was invisible from both sides. Note the log is not by itself a defect: resuming a thread that is not suspended legitimately returns false, and it fires ~7 times in a normal boot. --- .claude/settings.local.json | 101 ++++++++++++++++++++++++++++++ src/xenia/base/threading_posix.cc | 29 ++++++--- src/xenia/kernel/xthread.cc | 10 ++- 3 files changed, 132 insertions(+), 8 deletions(-) create mode 100644 .claude/settings.local.json diff --git a/.claude/settings.local.json b/.claude/settings.local.json new file mode 100644 index 000000000..5965a1de0 --- /dev/null +++ b/.claude/settings.local.json @@ -0,0 +1,101 @@ +{ + "permissions": { + "allow": [ + "Bash(ls -1 /home/fabi/xenia-canary/src/xenia/kernel/xboxkrnl/*.cc)", + "Bash(grep -l \"DECLARE_XBOXKRNL_EXPORT\\\\|DECLARE_XAM_EXPORT\\\\|DECLARE_XBDM_EXPORT\" /home/fabi/xenia-canary/src/xenia/kernel/xboxkrnl/*.cc)", + "Bash(grep -E \"\\\\.\\(cc|h\\)$\")", + "Bash(ls -1 /home/fabi/xenia-canary/src/xenia/kernel/xam/*.cc)", + "Bash(ls -1 /home/fabi/xenia-canary/src/xenia/kernel/xbdm/*.cc)", + "Bash(grep -r DECLARE_XBOXKRNL_EXPORT /home/fabi/xenia-canary/src/xenia/kernel/xboxkrnl/*.cc)", + "Bash(grep -r DECLARE_XAM_EXPORT /home/fabi/xenia-canary/src/xenia/kernel/xam/*.cc)", + "Bash(grep -r DECLARE_XBDM_EXPORT /home/fabi/xenia-canary/src/xenia/kernel/xbdm/*.cc)", + "Bash(/tmp/detailed_exports.sh:*)", + "Bash(chmod +x /tmp/detailed_exports.sh)", + "Bash(/tmp/detailed_exports.sh)", + "Bash(grep -c 'DECLARE_XBOXKRNL_EXPORT' /home/fabi/xenia-canary/src/xenia/kernel/xboxkrnl/*.cc)", + "Bash(grep -c 'DECLARE_XAM_EXPORT' /home/fabi/xenia-canary/src/xenia/kernel/xam/*.cc)", + "Bash(grep -c 'DECLARE_XAM_EXPORT' /home/fabi/xenia-canary/src/xenia/kernel/xam/*.h)", + "Bash(grep -c 'DECLARE_XBDM_EXPORT' /home/fabi/xenia-canary/src/xenia/kernel/xbdm/*.cc /home/fabi/xenia-canary/src/xenia/kernel/xbdm/*.h)", + "Bash(grep -h 'DECLARE_XBOXKRNL_EXPORT' /home/fabi/xenia-canary/src/xenia/kernel/xboxkrnl/*.cc)", + "Bash(grep -h 'DECLARE_XAM_EXPORT' /home/fabi/xenia-canary/src/xenia/kernel/xam/*.cc)", + "Bash(grep -ch 'DECLARE_XBOXKRNL_EXPORT' /home/fabi/xenia-canary/src/xenia/kernel/xboxkrnl/*.cc)", + "Read(//home/fabi/xenia-canary/**)", + "Bash(grep -ch 'DECLARE_XAM_EXPORT' /home/fabi/xenia-canary/src/xenia/kernel/xam/*.cc)", + "Bash(grep -ch DECLARE_XBDM_EXPORT /home/fabi/xenia-canary/src/xenia/kernel/xbdm/*.cc /home/fabi/xenia-canary/src/xenia/kernel/xbdm/*.h)", + "Bash(grep -oh 'DECLARE_XBOXKRNL_EXPORT[0-9_]*' /home/fabi/xenia-canary/src/xenia/kernel/xboxkrnl/*.cc)", + "Bash(grep -oh 'DECLARE_XAM_EXPORT[0-9_]*' /home/fabi/xenia-canary/src/xenia/kernel/xam/*.cc)", + "Bash(grep -oh 'DECLARE_XBDM_EXPORT[0-9_]*' /home/fabi/xenia-canary/src/xenia/kernel/xbdm/*.cc)", + "Bash(grep -h 'DECLARE_XBOXKRNL_EXPORT[34]' /home/fabi/xenia-canary/src/xenia/kernel/xboxkrnl/*.cc)", + "Bash(python3 tools/generate_export_docs.py)", + "Bash(python3 -c \":*)", + "Bash(grep -n \"RegisterOpcodeEmitter\\\\|RegisterEmitCategory\" /home/fabi/xenia-canary/src/xenia/cpu/ppc/*.cc)", + "Bash(find /home/fabi/xenia-canary -name *ppc*table*gen* -o -name *ppc-table*)", + "Bash(find /home/fabi/xenia-canary/tools -name *.xml -o -name *insn*)", + "Bash(wc -l /home/fabi/xenia-canary/src/xenia/cpu/ppc/ppc_emit_*.cc)", + "Bash(grep \"^int InstrEmit_\" /home/fabi/xenia-canary/src/xenia/cpu/ppc/ppc_emit_*.cc)", + "Bash(python3:*)", + "Bash(clang --version)", + "Bash(clang-19 --version)", + "Bash(cmake --version)", + "Bash(ninja --version)", + "Bash(dpkg -l)", + "Bash(git -C /home/fabi/xenia-canary submodule status)", + "Bash(apt-cache policy:*)", + "Bash(dpkg -l spirv-tools)", + "Bash(sudo apt-get:*)", + "Bash(/home/fabi/xenia-canary/build/bin/Linux/Debug/xenia_canary --help)", + "Bash(/home/fabi/xenia-canary/build/bin/Linux/Debug/xenia_canary --version)", + "Bash(wine --version)", + "Bash(cargo --version)", + "Bash(rustc --version)", + "Bash(awk '{print $2, $3}')", + "Read(//usr/bin/**)", + "Read(//usr/lib/llvm-19/bin/**)", + "Bash(dpkg -l '*clang*')", + "Bash(cargo install:*)", + "Bash(mkdir -p /home/fabi/.xwin-cache)", + "Bash(xwin --accept-license splat --output /home/fabi/.xwin)", + "Read(//home/fabi/.xwin/**)", + "Read(//home/fabi/.xwin-cache/**)", + "Bash(git submodule:*)", + "Bash(spirv-opt --version)", + "Bash(apt-cache search:*)", + "Bash(cmake -S . -B build-wine-xc -G 'Ninja Multi-Config' -DCMAKE_TOOLCHAIN_FILE=cmake/toolchains/linux-msvc-wine.cmake -DCMAKE_BUILD_TYPE=Release)", + "Bash(ls /usr/bin/*rc*)", + "Bash(llvm-rc --help)", + "Bash(cmake --build build-wine-xc --config Release --target xenia-app)", + "Bash(cmake -S . -B build-wine-xc -G 'Ninja Multi-Config' -DCMAKE_TOOLCHAIN_FILE=cmake/toolchains/linux-msvc-wine.cmake -DCMAKE_BUILD_TYPE=Release -DHAVE_SYS_UIO_H=FALSE -DHAVE_SYS_MMAN_H=FALSE -DHAVE_SYS_RESOURCE_H=FALSE -DHAVE_SYS_TIME_H=FALSE -DHAVE_UNISTD_H=FALSE)", + "Bash(grep -r \"PPCFrontend\\\\|Translate\" /home/fabi/xenia-canary/src/xenia/cpu/ppc/*.h)", + "Bash(grep -l \"SDL\\\\|sdl\" /home/fabi/xenia-canary/src/xenia/ui/*.h)", + "Bash(grep -r \"SDL_Init\\\\|SDL\\\\|OpenGL\\\\|Vulkan\" /home/fabi/xenia-canary/src/xenia/ui/*.cc)", + "Bash(grep -l \"struct.*Modifier\\\\|class.*Shader\" /home/fabi/xenia-canary/src/xenia/gpu/d3d12/*.h)", + "Bash(grep \"class.*App\\\\|class.*Main\" /home/fabi/xenia-canary/src/xenia/app/*.h)", + "Bash(grep -r \"WinMain\\\\|main\\(\" /home/fabi/xenia-canary/src/xenia/app/*.cc)", + "Bash(grep \"REGISTER_MODULE\\\\|MODULE_INIT\" /home/fabi/xenia-canary/src/xenia/kernel/xboxkrnl/*.cc)", + "Bash(wc -l /home/fabi/xenia-canary/src/xenia/cpu/ppc/ppc_emit_*.cc /home/fabi/xenia-canary/src/xenia/cpu/ppc/ppc_opcode.h)", + "Bash(cargo check:*)", + "Bash(cargo test:*)", + "Bash(cargo build:*)", + "Bash(cargo clippy:*)", + "Bash(cargo run:*)", + "Bash(grep -r \"memmap\\\\|mmap\" /home/fabi/xenia-canary/xenia-rs/Cargo.toml /home/fabi/xenia-canary/xenia-rs/crates/*/Cargo.toml)", + "Bash(cargo search:*)", + "Bash(cargo info:*)", + "Bash(cargo doc:*)", + "Read(//home/fabi/.cargo/registry/src/**)", + "Bash(find ~/.cargo/registry/src -path \"*/lzxd-0.2*/src/lib.rs\" -exec grep -n \"pub fn\\\\|pub struct\\\\|pub enum\\\\|WindowSize\" {} \\\\;)", + "Bash(find ~/.cargo/registry/src -path \"*/lzxd-0.2*/src/window.rs\" -exec grep -n \"WindowSize\" {} \\\\;)", + "Bash(find ~/.cargo/registry/src -path \"*/lzxd-0.2*/src/window.rs\" -exec sed -n '12,70p' {} \\\\;)", + "Bash(find ~/.cargo/registry/src -path \"*/lzxd-0.2*/src/lib.rs\" -exec sed -n '280,310p' {} \\\\;)", + "Bash(grep -r \"aes\\\\|cipher\" Cargo.toml crates/*/Cargo.toml)", + "Bash(grep -v \"^warning\\\\|^\\\\s*-->\\\\|^\\\\s*|\\\\|^\\\\s*=\\\\|Compiling\\\\|Finished\\\\|Running\\\\|Detected\\\\|debug\\\\|^$\")", + "Read(//tmp/**)", + "Bash(echo \"exit code: $?\")", + "Bash(echo \"exit: $?\")", + "Bash(git add:*)", + "Bash(git commit -m ':*)", + "Bash(git push:*)", + "Bash(git config:*)" + ] + } +} diff --git a/src/xenia/base/threading_posix.cc b/src/xenia/base/threading_posix.cc index 38cb2cb4c..7198055c4 100644 --- a/src/xenia/base/threading_posix.cc +++ b/src/xenia/base/threading_posix.cc @@ -1328,18 +1328,33 @@ void* PosixCondition::ThreadStartRoutine(void* parameter) { current_thread_ = thread; thread->handle_.tid_ = static_cast(syscall(SYS_gettid)); + // Publish the state AND the initial suspend count under ONE lock, then wait + // without ever dropping it. + // + // These used to be two separate lock scopes, and that lost a resume. Resume() + // does `WaitStarted()` — which only waits for state_ != kUninitialized — and + // then `if (suspend_count_ == 0) return false;`. So a thread created + // suspended could publish kSuspended, release the lock, and be resumed in the + // gap before it had set suspend_count_ = 1: the resume saw 0, returned false, + // and this thread then set the count and waited on it forever. + // + // Measured in Project Sylpheed: pressing (A) on the title screen makes the + // game ExCreateThread(CREATE_SUSPENDED) + NtResumeThread, and about 2 boots + // in 3 the loader thread never ran — zero kernel calls, zero host CPU time, + // while the emulator stayed at 546%. Holding the lock across the wait closes + // the window: a resumer past WaitStarted() now always observes 1. { std::unique_lock lock(thread->handle_.state_mutex_); thread->handle_.state_ = create_suspended ? State::kSuspended : State::kRunning; + if (create_suspended) { + thread->handle_.suspend_count_ = 1; + } thread->handle_.state_signal_.notify_all(); - } - - if (create_suspended) { - std::unique_lock lock(thread->handle_.state_mutex_); - thread->handle_.suspend_count_ = 1; - thread->handle_.state_signal_.wait( - lock, [thread] { return thread->handle_.suspend_count_ == 0; }); + if (create_suspended) { + thread->handle_.state_signal_.wait( + lock, [thread] { return thread->handle_.suspend_count_ == 0; }); + } } start_routine(); diff --git a/src/xenia/kernel/xthread.cc b/src/xenia/kernel/xthread.cc index 657c0fb37..756e2d8da 100644 --- a/src/xenia/kernel/xthread.cc +++ b/src/xenia/kernel/xthread.cc @@ -932,7 +932,15 @@ X_STATUS XThread::Resume(uint32_t* out_suspend_count) { // Try to resume host thread if fully resumed (for non-self-suspended case). if (should_resume_host) { - thread_->Resume(&unused_host_suspend_count); + if (!thread_->Resume(&unused_host_suspend_count)) { + // The Windows path above turns this into X_STATUS_UNSUCCESSFUL; here it + // was discarded, so a dropped resume was invisible from both sides — the + // guest saw success and the thread never ran. Keep returning success (the + // guest's own bookkeeping is done), but say so, because the only symptom + // otherwise is a thread with no CPU time and no kernel calls. + XELOGW("XThread::Resume: host resume was refused for thread {:08X}", + handle()); + } } return X_STATUS_SUCCESS; #endif