nx2: frame-locked input replay and quieter logs
EDEN_NX2_KEY_RECORD records keyboard transitions as "f<frame>:code" against a global count of guest presents; EDEN_NX2_KEY_SCRIPT replays them on the same frames (or by seconds, as before), so a played session reproduces exactly. Debug aids: the PC/LR/SP of the first unmapped reads, NSO load addresses, EDEN_NX2_IPC_SUMMARY (request counts every 5 s), EDEN_NX2_FORCE_LOD0. Unmapped-access logging is rate limited and the per-draw/semaphore spam is demoted, so long sessions stay under the log size cap.
This commit is contained in:
parent
6f38217ed3
commit
d4dc5af3be
13 changed files with 145 additions and 17 deletions
|
|
@ -4,6 +4,7 @@
|
|||
// SPDX-FileCopyrightText: Copyright 2018 yuzu Emulator Project
|
||||
// SPDX-License-Identifier: GPL-2.0-or-later
|
||||
|
||||
#include <atomic>
|
||||
#include "common/settings.h"
|
||||
#include "core/arm/dynarmic/arm_dynarmic.h"
|
||||
#include "core/arm/dynarmic/arm_dynarmic_64.h"
|
||||
|
|
@ -24,13 +25,24 @@ DynarmicCallbacks64::DynarmicCallbacks64(ArmDynarmic64& parent, Kernel::KProcess
|
|||
|
||||
u64 DynarmicCallbacks64::MemoryRead(u64 vaddr, size_t size) {
|
||||
CheckMemoryAccess(vaddr, size, Kernel::DebugWatchpointType::Read);
|
||||
u64 value{};
|
||||
switch (size) {
|
||||
case sizeof(u64): return m_memory.Read64(vaddr);
|
||||
case sizeof(u32): return m_memory.Read32(vaddr);
|
||||
case sizeof(u16): return m_memory.Read16(vaddr);
|
||||
case sizeof(u8): return m_memory.Read8(vaddr);
|
||||
case sizeof(u64): value = m_memory.Read64(vaddr); break;
|
||||
case sizeof(u32): value = m_memory.Read32(vaddr); break;
|
||||
case sizeof(u16): value = m_memory.Read16(vaddr); break;
|
||||
case sizeof(u8): value = m_memory.Read8(vaddr); break;
|
||||
default: UNREACHABLE();
|
||||
}
|
||||
// With memory aborts ignored the guest keeps running on zeros: say where it read from.
|
||||
if (auto& unmapped = Core::Memory::UnmappedReadFlag(); unmapped != 0) {
|
||||
unmapped = 0;
|
||||
static std::atomic<u32> logged{};
|
||||
if (logged.fetch_add(1) < 32) {
|
||||
LOG_ERROR(Core_ARM, "Unmapped read {:#x} ({} bytes) at pc {:#x} lr {:#x} sp {:#x}", vaddr, size,
|
||||
m_parent.m_jit->GetPC(), m_parent.m_jit->GetRegister(30), m_parent.m_jit->GetSP());
|
||||
}
|
||||
}
|
||||
return value;
|
||||
}
|
||||
Dynarmic::A64::Vector DynarmicCallbacks64::MemoryRead128(u64 vaddr) {
|
||||
CheckMemoryAccess(vaddr, 16, Kernel::DebugWatchpointType::Read);
|
||||
|
|
|
|||
|
|
@ -68,6 +68,8 @@
|
|||
|
||||
namespace Core {
|
||||
|
||||
std::atomic<u64> g_nx2_present_count{};
|
||||
|
||||
FileSys::VirtualFile GetGameFileFromPath(const FileSys::VirtualFilesystem& vfs,
|
||||
const std::string& path) {
|
||||
// To account for split 00+01+etc files.
|
||||
|
|
|
|||
|
|
@ -6,6 +6,7 @@
|
|||
|
||||
#pragma once
|
||||
|
||||
#include <atomic>
|
||||
#include <cstddef>
|
||||
#include <deque>
|
||||
#include <functional>
|
||||
|
|
@ -115,6 +116,9 @@ class RenderdocAPI;
|
|||
|
||||
namespace Core {
|
||||
|
||||
/// Frames the guest has presented (Switch 2 vi2 present calls); input replay is locked to it.
|
||||
extern std::atomic<u64> g_nx2_present_count;
|
||||
|
||||
class CpuManager;
|
||||
class Debugger;
|
||||
class DeviceMemory;
|
||||
|
|
|
|||
|
|
@ -564,6 +564,7 @@ private:
|
|||
void PresentClientBuffer(HLERequestContext& ctx) {
|
||||
const auto* w = ctx.CommandBuffer();
|
||||
++m_presents;
|
||||
Core::g_nx2_present_count.fetch_add(1, std::memory_order_relaxed);
|
||||
if (m_presents <= 4 || (m_presents % 600) == 0) {
|
||||
LOG_INFO(Service, "nx2:vi2 229 present #{} token={:#x} slot={} image={}", m_presents,
|
||||
u64{w[2]} | (u64{w[3]} << 32), w[4], w[5]);
|
||||
|
|
|
|||
|
|
@ -4,6 +4,13 @@
|
|||
// SPDX-FileCopyrightText: Copyright 2018 yuzu Emulator Project
|
||||
// SPDX-License-Identifier: GPL-2.0-or-later
|
||||
|
||||
#include "common/scope_exit.h"
|
||||
#include <vector>
|
||||
#include <tuple>
|
||||
#include <mutex>
|
||||
#include <map>
|
||||
#include <chrono>
|
||||
#include <algorithm>
|
||||
#include <cstdlib>
|
||||
#include <fmt/ranges.h>
|
||||
#include "common/assert.h"
|
||||
|
|
@ -125,9 +132,59 @@ void ServiceFrameworkBase::InvokeRequestTipc(HLERequestContext& ctx) {
|
|||
handler_invoker(this, info->handler_callback, ctx);
|
||||
}
|
||||
|
||||
namespace {
|
||||
// EDEN_NX2_IPC_SUMMARY: every 5 s, log how often each service command ran and with which result
|
||||
// since the last summary (finds a game polling something that never becomes ready).
|
||||
void CountRequest(const std::string& service, u32 command, u32 type, u32 result) {
|
||||
static const bool enabled = std::getenv("EDEN_NX2_IPC_SUMMARY") != nullptr;
|
||||
if (!enabled) {
|
||||
return;
|
||||
}
|
||||
static std::mutex mutex;
|
||||
static std::map<std::tuple<std::string, u32, u32, u32>, u32> counts;
|
||||
static auto last = std::chrono::steady_clock::now();
|
||||
std::scoped_lock lock{mutex};
|
||||
++counts[{service, command, type, result}];
|
||||
const auto now = std::chrono::steady_clock::now();
|
||||
if (now - last < std::chrono::seconds{5}) {
|
||||
return;
|
||||
}
|
||||
last = now;
|
||||
std::vector<std::pair<u32, std::string>> lines;
|
||||
for (const auto& [key, count] : counts) {
|
||||
lines.emplace_back(count, fmt::format("{}::{}{} -> {:#x}", std::get<0>(key), std::get<1>(key),
|
||||
std::get<2>(key) >= 16 ? " (tipc)" : "",
|
||||
std::get<3>(key)));
|
||||
}
|
||||
std::sort(lines.begin(), lines.end(), [](const auto& a, const auto& b) { return a.first > b.first; });
|
||||
std::string text;
|
||||
for (size_t i = 0; i < std::min<size_t>(lines.size(), 24); ++i) {
|
||||
text += fmt::format(" | {}x {}", lines[i].first, lines[i].second);
|
||||
}
|
||||
LOG_INFO(Service, "ipc summary ({} kinds){}", lines.size(), text);
|
||||
counts.clear();
|
||||
}
|
||||
} // Anonymous namespace
|
||||
|
||||
Result ServiceFrameworkBase::HandleSyncRequest(Kernel::KServerSession& session,
|
||||
HLERequestContext& ctx) {
|
||||
const auto guard = LockService();
|
||||
SCOPE_EXIT {
|
||||
const auto* cmd_buf = ctx.CommandBuffer();
|
||||
u32 result_word = 0;
|
||||
const u32 type = static_cast<u32>(ctx.GetCommandType());
|
||||
if (type >= 16) {
|
||||
result_word = cmd_buf[2];
|
||||
} else {
|
||||
for (int i = 0; i < 12; ++i) {
|
||||
if (cmd_buf[i] == 0x4F434653) { // "SFCO"
|
||||
result_word = cmd_buf[i + 2];
|
||||
break;
|
||||
}
|
||||
}
|
||||
}
|
||||
CountRequest(service_name, ctx.GetCommand(), type, result_word);
|
||||
};
|
||||
|
||||
Result result = ResultSuccess;
|
||||
|
||||
|
|
|
|||
|
|
@ -247,6 +247,7 @@ std::optional<VAddr> AppLoader_NSO::LoadModule(Kernel::KProcess& process, Core::
|
|||
}
|
||||
|
||||
// Load codeset for current process
|
||||
LOG_INFO(Loader, "Module {} loaded at {:#x} (size {:#x})", nso_file.GetName(), load_base, image_size);
|
||||
process.LoadModule(system.Kernel(), std::move(codeset), load_base);
|
||||
return load_base + image_size;
|
||||
}
|
||||
|
|
|
|||
|
|
@ -5,6 +5,7 @@
|
|||
// SPDX-FileCopyrightText: 2018 yuzu Emulator Project
|
||||
// SPDX-License-Identifier: GPL-2.0-or-later
|
||||
|
||||
#include <atomic>
|
||||
#include <algorithm>
|
||||
#include <cstring>
|
||||
#include <mutex>
|
||||
|
|
@ -36,6 +37,11 @@
|
|||
|
||||
namespace Core::Memory {
|
||||
|
||||
u32& UnmappedReadFlag() {
|
||||
thread_local u32 flag{};
|
||||
return flag;
|
||||
}
|
||||
|
||||
static inline bool AddressSpaceContains(const Common::PageTable& table, const Common::ProcessAddress addr, const std::size_t size) {
|
||||
const Common::ProcessAddress max_addr = 1ULL << table.GetAddressSpaceBits();
|
||||
return addr + size >= addr && addr + size <= max_addr;
|
||||
|
|
@ -623,7 +629,13 @@ struct Memory::Impl {
|
|||
inline T Read(Common::ProcessAddress vaddr) noexcept requires(std::is_trivially_copyable_v<T>) {
|
||||
const u64 addr = GetInteger(vaddr);
|
||||
if (auto const ptr = GetPointerImpl(addr, [addr]() {
|
||||
LOG_ERROR(HW_Memory, "Unmapped Read{} @ {:#016x}", sizeof(T) * 8, addr);
|
||||
// A guest spinning on a bad pointer reads unmapped memory tens of thousands of times
|
||||
// a second: keep the first ones and then a sample.
|
||||
static std::atomic<u64> unmapped_reads{};
|
||||
if (const u64 count = unmapped_reads.fetch_add(1); count < 1000 || count % 100000 == 0) {
|
||||
LOG_ERROR(HW_Memory, "Unmapped Read{} @ {:#016x} (#{})", sizeof(T) * 8, addr, count);
|
||||
}
|
||||
++UnmappedReadFlag();
|
||||
}, [&]() {
|
||||
HandleRasterizerDownload(addr, sizeof(T));
|
||||
}); ptr) [[likely]] {
|
||||
|
|
|
|||
|
|
@ -38,6 +38,9 @@ class MemoryManager;
|
|||
|
||||
namespace Core::Memory {
|
||||
|
||||
/// Counts unmapped reads on this host thread since the CPU callbacks last checked (debug aid).
|
||||
u32& UnmappedReadFlag();
|
||||
|
||||
/**
|
||||
* Page size used by the ARM architecture. This is the smallest granularity with which memory can
|
||||
* be mapped.
|
||||
|
|
|
|||
|
|
@ -335,7 +335,7 @@ void Puller::CallPullerMethod(DmaPusher& dma_pusher, const MethodCall& method_ca
|
|||
break;
|
||||
}
|
||||
case BufferMethods::MemOpA: {
|
||||
LOG_ERROR(HW_GPU, "Memory Operation A");
|
||||
LOG_TRACE(HW_GPU, "Memory Operation A");
|
||||
break;
|
||||
}
|
||||
case BufferMethods::MemOpB: {
|
||||
|
|
@ -345,7 +345,7 @@ void Puller::CallPullerMethod(DmaPusher& dma_pusher, const MethodCall& method_ca
|
|||
}
|
||||
case BufferMethods::MemOpC:
|
||||
case BufferMethods::MemOpD: {
|
||||
LOG_ERROR(HW_GPU, "Memory Operation C,D");
|
||||
LOG_TRACE(HW_GPU, "Memory Operation C,D");
|
||||
break;
|
||||
}
|
||||
case BufferMethods::SemaphoreAcquire: {
|
||||
|
|
|
|||
|
|
@ -250,7 +250,7 @@ void RasterizerVulkan::PrepareDraw(bool is_indexed, Func&& draw_func) {
|
|||
auto& native = maxwell3d->GetNativeMacroEngine();
|
||||
if (native.native_turing && !submitted) {
|
||||
native.native_execution_failed = true;
|
||||
LOG_ERROR(HW_GPU, "Native graphics draw failed; refusing submission completion");
|
||||
LOG_DEBUG(HW_GPU, "Native graphics draw failed; refusing submission completion");
|
||||
}
|
||||
};
|
||||
FlushWork();
|
||||
|
|
|
|||
|
|
@ -2826,6 +2826,11 @@ Sampler::Sampler(TextureCacheRuntime& runtime, const Tegra::Texture::TSCEntry& t
|
|||
if (tsc.mipmap_filter != TextureMipmapFilter::None) {
|
||||
min_lod = tsc.MinLod();
|
||||
max_lod = tsc.MaxLod();
|
||||
// EDEN_NX2_FORCE_LOD0: sample only the top mip level (debug aid for mip layout problems).
|
||||
if (static const bool force_lod0 = std::getenv("EDEN_NX2_FORCE_LOD0") != nullptr; force_lod0) {
|
||||
min_lod = 0.0f;
|
||||
max_lod = 0.25f;
|
||||
}
|
||||
}
|
||||
base_ci = VkSamplerCreateInfo{
|
||||
.sType = VK_STRUCTURE_TYPE_SAMPLER_CREATE_INFO,
|
||||
|
|
|
|||
|
|
@ -4,6 +4,10 @@
|
|||
// SPDX-FileCopyrightText: 2016 Citra Emulator Project
|
||||
// SPDX-License-Identifier: GPL-2.0-or-later
|
||||
|
||||
#include <cstdlib>
|
||||
#include <cstdio>
|
||||
#include <chrono>
|
||||
#include <array>
|
||||
#include <SDL3/SDL.h>
|
||||
#include <SDL3/SDL_timer.h>
|
||||
#ifdef __EMSCRIPTEN__
|
||||
|
|
@ -118,7 +122,26 @@ void EmuWindow_SDL3::OnFingerUp() {
|
|||
input_subsystem->GetTouchScreen()->ReleaseAllTouch();
|
||||
}
|
||||
|
||||
// Seconds since the first frame; shared by the key script (yuzu.cpp) and key recording.
|
||||
double Nx2KeyClockSeconds() {
|
||||
static const auto begin = std::chrono::steady_clock::now();
|
||||
return std::chrono::duration<double>(std::chrono::steady_clock::now() - begin).count();
|
||||
}
|
||||
|
||||
void EmuWindow_SDL3::OnKeyEvent(int key, u8 state) {
|
||||
// EDEN_NX2_KEY_RECORD=<file>: append each press/release ("seconds:code", "seconds:-code").
|
||||
static std::FILE* const record = [] {
|
||||
const char* path = std::getenv("EDEN_NX2_KEY_RECORD");
|
||||
return path ? std::fopen(path, "w") : nullptr;
|
||||
}();
|
||||
static std::array<bool, 512> held{};
|
||||
if (record && key >= 0 && key < static_cast<int>(held.size()) && held[key] != (state != 0)) {
|
||||
held[key] = state != 0;
|
||||
std::fprintf(record, "f%llu:%s%d,",
|
||||
static_cast<unsigned long long>(Core::g_nx2_present_count.load()),
|
||||
state != 0 ? "" : "-", key);
|
||||
std::fflush(record);
|
||||
}
|
||||
if (state != 0) {
|
||||
input_subsystem->GetKeyboard()->PressKey(static_cast<std::size_t>(key));
|
||||
} else {
|
||||
|
|
|
|||
|
|
@ -333,9 +333,12 @@ extern "C" SDL_AppResult SDL_AppInit(void **appstate, int argc, char **argv) {
|
|||
}
|
||||
// EDEN_NX2_KEY_SCRIPT="seconds:code,seconds:-code,...": press (code) or release (-code) keyboard
|
||||
// keys, by SDL scancode, that many seconds after start. Lets hidden test runs drive menus.
|
||||
double Nx2KeyClockSeconds(); // emu_window_sdl3.cpp
|
||||
|
||||
static void RunKeyScript(InputCommon::InputSubsystem& input_subsystem) {
|
||||
struct KeyEvent {
|
||||
double seconds;
|
||||
double seconds; // when frame is 0
|
||||
u64 frame; // "f<frame>:code": after that many presents
|
||||
int code;
|
||||
};
|
||||
static const std::vector<KeyEvent> script = [] {
|
||||
|
|
@ -347,22 +350,27 @@ static void RunKeyScript(InputCommon::InputSubsystem& input_subsystem) {
|
|||
const size_t end = std::min(list.find(',', start), list.size());
|
||||
const std::string item = list.substr(start, end - start);
|
||||
if (const size_t colon = item.find(':'); colon != std::string::npos) {
|
||||
events.push_back({std::stod(item.substr(0, colon)),
|
||||
std::stoi(item.substr(colon + 1))});
|
||||
const std::string when = item.substr(0, colon);
|
||||
const int code = std::stoi(item.substr(colon + 1));
|
||||
if (!when.empty() && when[0] == 'f') {
|
||||
events.push_back({0.0, std::stoull(when.substr(1)), code});
|
||||
} else {
|
||||
events.push_back({std::stod(when), 0, code});
|
||||
}
|
||||
}
|
||||
start = end + 1;
|
||||
}
|
||||
}
|
||||
return events;
|
||||
}();
|
||||
static const auto begin = std::chrono::steady_clock::now();
|
||||
static size_t next = 0;
|
||||
const double elapsed =
|
||||
std::chrono::duration<double>(std::chrono::steady_clock::now() - begin).count();
|
||||
while (next < script.size() && script[next].seconds <= elapsed) {
|
||||
const double elapsed = Nx2KeyClockSeconds();
|
||||
const u64 frame = Core::g_nx2_present_count.load();
|
||||
while (next < script.size() && (script[next].frame != 0 ? script[next].frame <= frame
|
||||
: script[next].seconds <= elapsed)) {
|
||||
const int code = script[next].code;
|
||||
LOG_INFO(Frontend, "Key script: {} key {} at {:.1f} s", code < 0 ? "release" : "press",
|
||||
code < 0 ? -code : code, elapsed);
|
||||
LOG_INFO(Frontend, "Key script: {} key {} at {:.1f} s (frame {})",
|
||||
code < 0 ? "release" : "press", code < 0 ? -code : code, elapsed, frame);
|
||||
if (code < 0) {
|
||||
input_subsystem.GetKeyboard()->ReleaseKey(static_cast<std::size_t>(-code));
|
||||
} else {
|
||||
|
|
|
|||
Loading…
Reference in a new issue