diff --git a/src/xenia/app/emulator_window.cc b/src/xenia/app/emulator_window.cc index 3060c1bee..a7d5c7177 100644 --- a/src/xenia/app/emulator_window.cc +++ b/src/xenia/app/emulator_window.cc @@ -1071,6 +1071,11 @@ void EmulatorWindow::OnKeyDown(ui::KeyEvent& e) { // RE: snapshot the next frame's draws (world-space vertex positions) to // xenia_ship_capture.log for capital-ship placement correlation. xe::gpu::RequestShipCaptureFrame(); + // …and, when `log_ui_draws` is set, the next few frames' draws in + // SUBMISSION ORDER for 2D screen paint-order correlation. It shares this + // hotkey because every F-key in this switch is already bound; the cvar + // keeps it off the normal ship-capture path. + xe::gpu::RequestUiDrawCapture(); } break; case ui::VirtualKey::kEscape: { diff --git a/src/xenia/gpu/command_processor.cc b/src/xenia/gpu/command_processor.cc index b96d00647..e350f1132 100644 --- a/src/xenia/gpu/command_processor.cc +++ b/src/xenia/gpu/command_processor.cc @@ -104,6 +104,32 @@ DEFINE_bool( "reused later in the frame.", "GPU"); +DEFINE_bool( + log_ui_draws, false, + "OBSOLETE — the UI draw-order capture is armed by F10 unconditionally now, " + "so this flag is no longer needed and is kept only so old command lines " + "still parse. Reverse-engineering aid: F10 writes " + "every draw of the next few swapped frames to xenia_re_ui_draws_NN.log in " + "SUBMISSION ORDER and undeduplicated, with each draw's bound texture base " + "and dimensions. For recovering the paint order of a 2D screen, which " + "log_draws cannot give (it de-dups by vertex declaration) and the F10 ship " + "capture cannot either (it skips draws with no f32x3 position stream).", + "GPU"); + +DEFINE_int32( + ui_draw_capture_frames, 3, + "Reverse-engineering aid: how many submitted frames one `log_ui_draws` " + "capture covers. 3 is enough for a screen that redraws its elements every " + "frame; a screen that composites once and then re-blits needs a window long " + "enough to contain the rebuild.", + "GPU"); + +DEFINE_int32( + ui_draw_capture_max, 20000, + "Reverse-engineering aid: hard stop on the number of draws one " + "`log_ui_draws` capture records, whatever the frame window says.", + "GPU"); + DEFINE_bool( readback_memexport, false, "Read data written by memory export in shaders on the CPU. " @@ -160,6 +186,201 @@ void RequestShipCaptureFrame() { XELOGI("[SHIP-CAP] capture armed → xenia_ship_capture_{:02d}.log", gen); } +// ── UI draw-order capture (RE) ────────────────────────────────────────────── +// F9 arms a snapshot of the next few swapped frames. Unlike the two hooks +// above this one does NOT de-duplicate: the whole question it answers is what +// order the guest submits a 2D screen's sprites in, and a de-duplicating log +// cannot answer that. Bounded by a frame count rather than a draw count so the +// records line up with what is on screen. +namespace { +std::atomic g_ui_capture_gen{0}; +std::atomic g_ui_capture_armed{false}; +// Frames are counted HERE rather than from `counter_`, which looks like a frame +// number and is not one: MarkVblank() also increments it, from the vblank +// thread, so it advances between two draws of the SAME frame. A capture bounded +// by it ended after a single draw. This one is bumped only by the VdSwap packet, +// on the command-processor thread, so it is exactly "frames submitted". +std::atomic g_ui_swap_count{0}; +} // namespace + +void NoteUiDrawCaptureSwap() { + if (g_ui_capture_armed.load(std::memory_order_relaxed)) { + g_ui_swap_count.fetch_add(1, std::memory_order_relaxed); + } +} + +void RequestUiDrawCapture() { + // No cvar gate. It used to require `log_ui_draws`, which meant a run that + // wanted a UI capture had to pass the flag at LAUNCH — and launching with it + // correlates, across 12 runs, with the title screen refusing (A) (0 of 7 with + // the flag, 4 of 5 without). No mechanism was found for that and boot time + // does not explain it either, so rather than keep an unexplained variable in + // every navigation run, the arming is now unconditional: F10 arms it, exactly + // as it arms the ship capture next to it. The cost when nobody presses F10 is + // one relaxed atomic load per draw. + uint32_t gen = g_ui_capture_gen.fetch_add(1, std::memory_order_relaxed) + 1; + g_ui_swap_count.store(0, std::memory_order_relaxed); + g_ui_capture_armed.store(true, std::memory_order_relaxed); + XELOGI("[UI-CAP] capture armed -> xenia_re_ui_draws_{:02d}.log", gen); +} + +void CommandProcessor::CaptureUiDrawForRE( + uint32_t vgt_draw_initiator_value, + const IndexBufferInfo* index_buffer_info) { + if (!g_ui_capture_armed.load(std::memory_order_relaxed)) { + return; + } + static std::mutex ui_mutex; + static std::ofstream ui_out; + static uint32_t ui_gen = 0; + static uint32_t ui_first_frame = 0; + static int ui_draws = 0; + static uint32_t ui_last_frame = 0; + std::lock_guard lock(ui_mutex); + if (!g_ui_capture_armed.load(std::memory_order_relaxed)) { + return; + } + + uint32_t gen = g_ui_capture_gen.load(std::memory_order_relaxed); + if (gen != ui_gen || !ui_out.is_open()) { + if (ui_out.is_open()) { + ui_out.close(); + } + auto name = fmt::format("xenia_re_ui_draws_{:02d}.log", gen); + ui_out.open(name, std::ios::out | std::ios::trunc); + ui_gen = gen; + ui_first_frame = g_ui_swap_count.load(std::memory_order_relaxed); + ui_last_frame = ui_first_frame; + ui_draws = 0; + XELOGI("[UI-CAP] writing {} (from frame {})", name, ui_first_frame); + ui_out << fmt::format( + "# every draw in SUBMISSION ORDER, undeduplicated, frames {}..{}\n" + "# tex dimensions identify the sprite; base is the guest address\n", + ui_first_frame, + ui_first_frame + uint32_t(std::max(1, cvars::ui_draw_capture_frames)) - + 1); + } + if (!ui_out.is_open()) { + g_ui_capture_armed.store(false, std::memory_order_relaxed); + return; + } + uint32_t frame = g_ui_swap_count.load(std::memory_order_relaxed); + const uint32_t capture_frames = + uint32_t(std::max(1, cvars::ui_draw_capture_frames)); + if (frame - ui_first_frame >= capture_frames || + ui_draws >= std::max(1, cvars::ui_draw_capture_max)) { + ui_out.flush(); + g_ui_capture_armed.store(false, std::memory_order_relaxed); + XELOGI("[UI-CAP] done: {} draws over {} frames", ui_draws, + frame - ui_first_frame); + return; + } + if (frame != ui_last_frame) { + ui_out << fmt::format("--- frame {} ---\n", frame); + ui_last_frame = frame; + } + + reg::VGT_DRAW_INITIATOR init; + init.value = vgt_draw_initiator_value; + ui_out << fmt::format("{:4} prim={} indices={}", ui_draws++, + uint32_t(init.prim_type), + uint32_t(init.num_indices)); + if (index_buffer_info) { + ui_out << fmt::format(" ib=0x{:08X}", index_buffer_info->guest_base); + } + if (active_vertex_shader_) { + ui_out << fmt::format(" vs=0x{:016X}", + active_vertex_shader_->ucode_data_hash()); + } + Shader* ps = active_pixel_shader_; + if (ps) { + ui_out << fmt::format(" ps=0x{:016X}", ps->ucode_data_hash()); + } + if (ps && ps->is_ucode_analyzed()) { + for (const auto& tb : ps->texture_bindings()) { + xenos::xe_gpu_texture_fetch_t tf = + register_file_->GetTextureFetch(tb.fetch_constant); + // Dimensions are stored as (actual - 1). + ui_out << fmt::format(" tex[base=0x{:08X} {}x{} fmt={}]", + uint32_t(tf.base_address) << 12, + uint32_t(tf.size_2d.width) + 1, + uint32_t(tf.size_2d.height) + 1, + uint32_t(tf.format)); + } + } + // The quad's geometry is the only thing that says WHICH element a draw is: + // these sprites all share one shader and sample big texture pages, so the + // vertex data is the identity. Dump attribute 0 of binding 0 for the first + // few vertices, raw and as big-endian floats — the format is not assumed. + Shader* vs = active_vertex_shader_; + if (vs && vs->is_ucode_analyzed() && !vs->vertex_bindings().empty()) { + const auto& binding = vs->vertex_bindings()[0]; + xenos::xe_gpu_vertex_fetch_t fetch = + register_file_->GetVertexFetch(binding.fetch_constant); + uint32_t stride = binding.stride_words * 4; + uint32_t vbase = uint32_t(fetch.address) << 2; + ui_out << fmt::format("\n vb=0x{:08X} stride={} attrs=[", vbase, stride); + int32_t pos_off = -1; + uint32_t pos_fmt = 0; + // The k_8_8_8_8 attribute is the per-vertex colour, and its ALPHA is what + // separates two elements that decode to the same size: the bundle gives + // them different resting fade alphas. Without it a draw of, say, 1133x280 + // could be either `ptlogo_back2eff` or `ptlogo_back2eff5`. + int32_t col_off = -1; + for (const auto& attr : binding.attributes) { + uint32_t f = uint32_t(attr.fetch_instr.attributes.data_format); + uint32_t off = attr.fetch_instr.attributes.offset * 4; + ui_out << fmt::format("{}@{} ", f, off); + if (pos_off < 0) { + pos_off = int32_t(off); + pos_fmt = f; + } + if (col_off < 0 && + attr.fetch_instr.attributes.data_format == + xenos::VertexFormat::k_8_8_8_8) { + col_off = int32_t(off); + } + } + ui_out << "]"; + if (stride && vbase && pos_off >= 0) { + auto be_u32 = [](const uint8_t* q) { + return (uint32_t(q[0]) << 24) | (uint32_t(q[1]) << 16) | + (uint32_t(q[2]) << 8) | uint32_t(q[3]); + }; + uint32_t nv = uint32_t(init.num_indices); + if (nv > 8) { + nv = 8; + } + ui_out << fmt::format(" fmt0={} v:", pos_fmt); + for (uint32_t v = 0; v < nv; ++v) { + const uint8_t* q = memory_->TranslatePhysical( + vbase + v * stride + uint32_t(pos_off)); + if (!q) { + break; + } + // Three floats, not two: attribute 0 of a UI quad is k_32_32_32_FLOAT, + // so the stream carries a Z per vertex — which is the game's own layer + // key if it has one, and the whole question this capture is asked. + uint32_t w0 = be_u32(q), w1 = be_u32(q + 4), w2 = be_u32(q + 8); + float f0, f1, f2; + std::memcpy(&f0, &w0, 4); + std::memcpy(&f1, &w1, 4); + std::memcpy(&f2, &w2, 4); + ui_out << fmt::format(" [{:.2f},{:.2f},z={:.5f}", f0, f1, f2); + if (col_off >= 0) { + const uint8_t* c = memory_->TranslatePhysical( + vbase + v * stride + uint32_t(col_off)); + if (c) { + ui_out << fmt::format(",col={:08X}", be_u32(c)); + } + } + ui_out << "]"; + } + } + } + ui_out << "\n"; +} + void CommandProcessor::CaptureShipDrawForRE( uint32_t vgt_draw_initiator_value, const IndexBufferInfo* index_buffer_info) { @@ -341,8 +562,9 @@ void CommandProcessor::CaptureShipDrawForRE( void CommandProcessor::LogDrawForRE(uint32_t vgt_draw_initiator_value, const IndexBufferInfo* index_buffer_info) { - // One-shot ship-placement capture runs independently of the log_draws cvar. + // One-shot captures run independently of the log_draws cvar. CaptureShipDrawForRE(vgt_draw_initiator_value, index_buffer_info); + CaptureUiDrawForRE(vgt_draw_initiator_value, index_buffer_info); if (!cvars::log_draws) { return; } diff --git a/src/xenia/gpu/command_processor.h b/src/xenia/gpu/command_processor.h index 75866938b..05e4baeda 100644 --- a/src/xenia/gpu/command_processor.h +++ b/src/xenia/gpu/command_processor.h @@ -39,6 +39,15 @@ namespace gpu { // Called from the UI thread (F10 hotkey); thread-safe. Defined in command_processor.cc. void RequestShipCaptureFrame(); +// Arm a one-shot UI DRAW-ORDER capture (see CommandProcessor::CaptureUiDrawForRE). +// Shares the F10 hotkey with the ship capture; the `log_ui_draws` cvar is what +// separates them. +void RequestUiDrawCapture(); + +// Count one submitted frame for that capture. Called from the VdSwap packet +// handler, on the command-processor thread. +void NoteUiDrawCaptureSwap(); + enum class GPUSetting { ClearMemoryPageState, ReadbackMemexport }; enum class ReadbackResolveMode { @@ -471,6 +480,24 @@ class CommandProcessor { void CaptureShipDrawForRE(uint32_t vgt_draw_initiator_value, const IndexBufferInfo* index_buffer_info); + // UI draw-order capture (RE): a one-shot snapshot armed by + // RequestUiDrawCapture() (F9 hotkey). Writes EVERY draw of the next few + // swapped frames to xenia_re_ui_draws_NN.log **in submission order and + // undeduplicated**, with each draw's bound texture base and dimensions. + // + // This exists because neither of the other two hooks can answer "in what + // order does the game paint a 2D screen": + // * `log_draws` de-dups by vertex-declaration fingerprint, so a screen's + // sprites — which share a declaration — collapse to one record, and what + // survives is first-seen order, not per-frame submission order; + // * CaptureShipDrawForRE returns early on any draw with no f32x3 position + // stream, which is every UI quad. + // Texture dimensions are the identity here: a screen's sprites decode to + // near-unique sizes, so `640x360` names the title screen's background as + // surely as a resource name would. Defined in command_processor.cc. + void CaptureUiDrawForRE(uint32_t vgt_draw_initiator_value, + const IndexBufferInfo* index_buffer_info); + // "Actual" is for the command processor thread, to be read by the // implementations. SwapPostEffect GetActualSwapPostEffect() const { diff --git a/src/xenia/gpu/pm4_command_processor_implement.h b/src/xenia/gpu/pm4_command_processor_implement.h index b09e0c877..3ef27d527 100644 --- a/src/xenia/gpu/pm4_command_processor_implement.h +++ b/src/xenia/gpu/pm4_command_processor_implement.h @@ -663,6 +663,10 @@ bool COMMAND_PROCESSOR::ExecutePacketType3_XE_SWAP(uint32_t packet, COMMAND_PROCESSOR::IssueSwap(frontbuffer_ptr, frontbuffer_width, frontbuffer_height); + // RE: bracket the UI draw-order capture on real submitted frames (`counter_` + // below is also bumped by MarkVblank, from another thread, so it cannot). + xe::gpu::NoteUiDrawCaptureSwap(); + ++counter_; return true; } diff --git a/src/xenia/kernel/xam/profile_manager.cc b/src/xenia/kernel/xam/profile_manager.cc index aa797ecfb..219f8528c 100644 --- a/src/xenia/kernel/xam/profile_manager.cc +++ b/src/xenia/kernel/xam/profile_manager.cc @@ -27,6 +27,16 @@ DEFINE_string(logged_profile_slot_2_xuid, "", DEFINE_string(logged_profile_slot_3_xuid, "", "XUID of the profile to load on boot in slot 3", "Profiles"); +DEFINE_string( + create_profile_if_none, "", + "Reverse-engineering aid: if no profile exists on disk, create one with " + "this gamertag at startup and sign it in. Without a signed-in profile the " + "title screen's (A) opens the Sign In dialog and the game goes no further, " + "and this container has no way to type a gamertag into it: the dialog is " + "an ImGui text field and synthetic X key events never reach it. Ignored " + "when a profile already exists.", + "Profiles"); + namespace xe { namespace kernel { namespace xam { @@ -105,6 +115,17 @@ ProfileManager::ProfileManager(KernelState* kernel_state, LoadAccount(account_xuid); } + // RE aid: bootstrap a profile for scripted runs (see the cvar's help). The + // fixed XUID is what makes it usable from a script — `default_xuid` gives + // 0xB13EBABEBABEBABE every time, so a run can pass + // --logged_profile_slot_0_xuid=B13EBABEBABEBABE and be deterministic. + if (accounts_.empty() && !cvars::create_profile_if_none.empty()) { + const bool ok = + CreateProfile(cvars::create_profile_if_none, true, true); + XELOGI("ProfileManager: RE bootstrap profile '{}' -> {}", + cvars::create_profile_if_none, ok ? "created" : "FAILED"); + } + if (!cvars::logged_profile_slot_0_xuid.empty()) { Login(xe::string_util::from_string( cvars::logged_profile_slot_0_xuid, true), diff --git a/src/xenia/kernel/xam/xam_input.cc b/src/xenia/kernel/xam/xam_input.cc index 4a6d6cadb..c890b30da 100644 --- a/src/xenia/kernel/xam/xam_input.cc +++ b/src/xenia/kernel/xam/xam_input.cc @@ -195,9 +195,39 @@ dword_result_t XamInputGetKeystrokeEx_entry( keystroke.Zero(); if (kernel_state()->xam_state()->IsUIActive()) { + // RE aid: this early return hands the guest a SUCCESS with an empty + // keystroke without ever asking a driver, so scripted input goes silently + // dead for as long as any Xenia UI is up — including a dialog that was + // closed by its own [x] rather than by the menu toggle that decrements the + // counter. An invisible input blackout is expensive to diagnose from the + // outside; say so, rarely enough not to spam. + static std::atomic swallowed{0}; + const uint32_t n = swallowed.fetch_add(1, std::memory_order_relaxed); + if ((n % 600) == 0) { + XELOGW( + "[RE-INPUT] XamInputGetKeystrokeEx swallowed by IsUIActive " + "(dialogs={} nui={}, {} so far)", + kernel_state()->xam_state()->xam_dialogs_shown_.load(), + kernel_state()->xam_state()->xam_nui_dialogs_shown_.load(), n + 1); + } return X_ERROR_SUCCESS; } + // RE aid, the other half of the pair above: count the calls that DO reach a + // driver, and log every keystroke actually handed to the guest. Without this, + // "the swallow log is silent" is ambiguous between "the game is polling and + // getting nothing" and "the game is not polling at all" — which is exactly + // the fork the title-screen investigation got stuck on + // (docs/re/ui-paint-order-third-permutation.md in the Reborn tree). + { + static std::atomic polled{0}; + const uint32_t n = polled.fetch_add(1, std::memory_order_relaxed); + if ((n % 600) == 0) { + XELOGI("[RE-INPUT] XamInputGetKeystrokeEx reached the driver ({} so far)", + n + 1); + } + } + uint32_t user_index = *user_index_ptr; auto input_system = kernel_state()->emulator()->input_system(); auto lock = input_system->lock(); @@ -227,6 +257,19 @@ dword_result_t XamInputGetKeystrokeEx_entry( if (XSUCCEEDED(result)) { *user_index_ptr = keystroke->user_index; } + // Test the code EXACTLY, not with XSUCCEEDED. `X_ERROR_EMPTY` is `0x10D2` + // and XSUCCEEDED is `(s & 0xC0000000) == 0`, so an empty poll "succeeds" — + // logging on XSUCCEEDED buried two real keystrokes under 6 499 empties in + // the first run of this instrumentation. (The assignment above shares the + // quirk; it is upstream's and harmless, since the struct is zeroed.) + if (result == X_ERROR_SUCCESS) { + // Rare by construction — one per physical press — so log every one. + XELOGI( + "[RE-INPUT] XamInputGetKeystrokeEx -> user={} vk={:04X} flags={:04X} " + "(call flags {:08X})", + (uint32_t)keystroke->user_index, (uint32_t)keystroke->virtual_key, + (uint32_t)keystroke->flags, (uint32_t)flags); + } return result; } DECLARE_XAM_EXPORT1(XamInputGetKeystrokeEx, kInput, kImplemented);