[fs] debug_knobs controlled delay (us) for IStorage::Read

src/android/app/src/main/java/org/yuzu/yuzu_emu/features/settings/model/StringSetting.kt

@@ -11,6 +11,7 @@ import org.yuzu.yuzu_emu.utils.NativeConfig
 enum class StringSetting(override val key: String) : AbstractStringSetting {
     DRIVER_PATH("driver_path"),
     DEVICE_NAME("device_name"),
+    LOG_FILTER("log_filter"),
     PROGRAM_ARGS("program_args"),
 
     WEB_TOKEN("eden_token"),

src/android/app/src/main/java/org/yuzu/yuzu_emu/features/settings/model/view/SettingsItem.kt

@@ -1032,6 +1032,13 @@ abstract class SettingsItem(
                     descriptionId = R.string.use_auto_stub_description
                 )
             )
+            put(
+                StringInputSetting(
+                    StringSetting.LOG_FILTER,
+                    titleId = R.string.log_filter,
+                    descriptionId = R.string.log_filter_description
+                )
+            )
             put(
                 SpinBoxSetting(
                     ShortSetting.DEBUG_KNOBS,

src/android/app/src/main/java/org/yuzu/yuzu_emu/features/settings/ui/SettingsFragmentPresenter.kt

@@ -1322,6 +1322,7 @@ class SettingsFragmentPresenter(
                 add(HeaderSetting(R.string.log))
 
                 add(BooleanSetting.DEBUG_FLUSH_BY_LINE.key)
+                add(StringSetting.LOG_FILTER.key)
             }
 
             add(HeaderSetting(R.string.general))

src/android/app/src/main/res/values/strings.xml

@@ -636,6 +636,8 @@
     <string name="log">Logging</string>
     <string name="flush_by_line">Flush debug logs by line</string>
     <string name="flush_by_line_description">Flushes debugging logs on each line written, making debugging easier in cases of crashing or freezing.</string>
+    <string name="log_filter">Log filter</string>
+    <string name="log_filter_description">Controls Eden\'s log categories. Example: *:Info Service.LM:Debug</string>
 
     <!-- GPU Logging strings -->
     <string name="gpu_logging_header">GPU Logging</string>

src/common/settings.h

@@ -904,7 +904,7 @@ struct Values {
                                            0,
                                            65535,
                                            "debug_knobs",
-                                           Category::Debugging,
+                                           Category::System,
                                            Specialization::Countable,
                                            true,
                                            true};

src/core/arm/arm_interface.cpp

@@ -3,14 +3,158 @@
 // SPDX-FileCopyrightText: Copyright 2018 yuzu Emulator Project
 // SPDX-License-Identifier: GPL-2.0-or-later
 
+#include <algorithm>
+#include <array>
+#include <cctype>
+#include <string>
+#include <string_view>
+#include <vector>
+
 #include "common/logging.h"
 #include "core/arm/arm_interface.h"
 #include "core/arm/debug.h"
 #include "core/core.h"
+#include "core/hle/kernel/k_memory_block.h"
 #include "core/hle/kernel/k_process.h"
+#include "core/hle/kernel/svc_types.h"
 
 namespace Core {
 
+namespace {
+
+constexpr std::size_t GuestStringProbeBytes = 0x100;
+constexpr std::size_t StackProbeWords = 96;
+constexpr std::size_t MaxGuestStringLogs = 16;
+constexpr std::size_t MaxBacktraceFrames = 64;
+constexpr std::size_t MinGuestStringLength = 4;
+
+std::string SanitizeGuestString(std::string_view text) {
+    std::string sanitized;
+    sanitized.reserve(text.size());
+
+    for (const char ch : text) {
+        switch (ch) {
+        case '\\':
+            sanitized += "\\\\";
+            break;
+        case '"':
+            sanitized += "\\\"";
+            break;
+        default:
+            sanitized += ch;
+            break;
+        }
+    }
+
+    return sanitized;
+}
+
+bool IsUsefulGuestString(std::string_view text) {
+    if (text.size() < MinGuestStringLength) {
+        return false;
+    }
+
+    std::size_t alpha_numeric_count{};
+    for (const char ch : text) {
+        const auto byte = static_cast<unsigned char>(ch);
+        if (std::isprint(byte) == 0) {
+            return false;
+        }
+
+        if (std::isalnum(byte) != 0) {
+            alpha_numeric_count++;
+        }
+    }
+
+    return alpha_numeric_count > 0;
+}
+
+bool QueryGuestMemoryInfo(Kernel::KProcess* process, u64 address,
+                          Kernel::Svc::MemoryInfo* out_info) {
+    if (address == 0) {
+        return false;
+    }
+
+    Kernel::KMemoryInfo mem_info{};
+    Kernel::Svc::PageInfo page_info{};
+    if (process->GetPageTable().QueryInfo(&mem_info, &page_info, address).IsFailure()) {
+        return false;
+    }
+
+    *out_info = mem_info.GetSvcMemoryInfo();
+    return true;
+}
+
+void LogGuestStringCandidate(Kernel::KProcess* process, u64 address, std::string_view label,
+                             std::vector<u64>& logged_strings) {
+    if (logged_strings.size() >= MaxGuestStringLogs) {
+        return;
+    }
+    if (std::find(logged_strings.begin(), logged_strings.end(), address) != logged_strings.end()) {
+        return;
+    }
+
+    Kernel::Svc::MemoryInfo mem_info{};
+    if (!QueryGuestMemoryInfo(process, address, &mem_info)) {
+        return;
+    }
+    if (mem_info.state == Kernel::Svc::MemoryState::Free ||
+        mem_info.permission == Kernel::Svc::MemoryPermission::None) {
+        return;
+    }
+
+    if (address < mem_info.base_address) {
+        return;
+    }
+
+    const u64 region_offset = address - mem_info.base_address;
+    if (region_offset >= mem_info.size) {
+        return;
+    }
+
+    const u64 available_bytes = mem_info.size - region_offset;
+    const auto probe_size =
+        static_cast<std::size_t>(std::min<u64>(GuestStringProbeBytes, available_bytes));
+    if (probe_size < MinGuestStringLength ||
+        !process->GetMemory().IsValidVirtualAddressRange(address, probe_size)) {
+        return;
+    }
+
+    const auto text = process->GetMemory().ReadCString(address, probe_size);
+    if (!IsUsefulGuestString(text)) {
+        return;
+    }
+
+    logged_strings.push_back(address);
+    LOG_ERROR(Core_ARM, "Guest backtrace string {:02}: {}={:016X} \"{}\"",
+              logged_strings.size() - 1, label, address, SanitizeGuestString(text));
+}
+
+void LogStackStringCandidates(Kernel::KProcess* process, u64 base, std::string_view label,
+                              std::vector<u64>& logged_strings) {
+    if (base == 0) {
+        return;
+    }
+
+    auto& memory = process->GetMemory();
+    for (std::size_t i = 0; i < StackProbeWords; i++) {
+        const u64 address = base + i * sizeof(u64);
+        if (!memory.IsValidVirtualAddressRange(address, sizeof(u64))) {
+            break;
+        }
+
+        u64 value{};
+        if (!memory.ReadBlock(address, &value, sizeof(value))) {
+            continue;
+        }
+
+        LogGuestStringCandidate(process, value, fmt::format("{}+{:03X}", label, i * sizeof(u64)),
+                                logged_strings);
+    }
+}
+
+} // namespace
+
 void ArmInterface::LogBacktrace(Kernel::KProcess* process) const {
     Kernel::Svc::ThreadContext ctx;
     this->GetContext(ctx);
@@ -26,21 +170,45 @@ void ArmInterface::LogBacktrace(Kernel::KProcess* process) const {
         ctx.r[28], ctx.fp, ctx.lr, ctx.sp,
     };
 
-    std::string msg = fmt::format("Backtrace @ PC={:016X}\n", ctx.pc);
-    for (size_t i = 0; i < 32; i += 4)
-        msg += fmt::format("R{:02}={:016X} R{:02}={:016X} R{:02}={:016X} R{:02}={:016X}\n",
-            i + 0, xreg[i + 0], i + 1, xreg[i + 1],
-            i + 2, xreg[i + 2], i + 3, xreg[i + 3]);
-    for (size_t i = 0; i < 32; i += 2)
-        msg += fmt::format("V{:02}={:016X}_{:016X} V{:02}={:016X}_{:016X}\n",
-            i + 0, ctx.v[i + 0][0], ctx.v[i + 0][1],
-            i + 1, ctx.v[i + 1][0], ctx.v[i + 1][1]);
-    msg += fmt::format("PSTATE={:08X} FPCR={:08X} FPSR={:08X} TPIDR={:016X}\n", ctx.pstate, ctx.fpcr, ctx.fpsr, ctx.tpidr);
-    msg += fmt::format("{:20}{:20}{:20}{:20}{}\n", "Module", "Address", "Original Address", "Offset", "Symbol");
+    LOG_ERROR(Core_ARM,
+              "Guest backtrace context: process=\"{}\" pid={} program_id={:016X} pc={:016X} "
+              "lr={:016X} fp={:016X} sp={:016X} pstate={:08X}",
+              process->GetName(), process->GetProcessId(), process->GetProgramId(), ctx.pc,
+              ctx.lr, ctx.fp, ctx.sp, ctx.pstate);
+
+    std::vector<u64> logged_strings;
+    for (size_t i = 0; i < xreg.size(); i++) {
+        LogGuestStringCandidate(process, xreg[i], fmt::format("R{:02}", i), logged_strings);
+    }
+    LogStackStringCandidates(process, ctx.sp, "SP", logged_strings);
+    if (ctx.fp != ctx.sp) {
+        LogStackStringCandidates(process, ctx.fp, "FP", logged_strings);
+    }
+    if (logged_strings.empty()) {
+        LOG_ERROR(Core_ARM, "Guest backtrace strings: none found in registers or stack");
+    }
+
     auto const backtrace = GetBacktraceFromContext(process, ctx);
-    for (auto const& entry : backtrace)
-        msg += fmt::format("{:20}{:016X}    {:016X}    {:016X}    {}\n", entry.module, entry.address, entry.original_address, entry.offset, entry.name);
-    LOG_ERROR(Core_ARM, "{}", msg);
+    for (size_t i = 0; i < std::min(backtrace.size(), MaxBacktraceFrames); i++) {
+        const auto& entry = backtrace[i];
+        if (entry.original_address == 0) {
+            break;
+        }
+
+        if (entry.name.empty()) {
+            LOG_ERROR(Core_ARM, "Guest backtrace frame {:03}: {}+0x{:X} pc={:016X} mapped={:016X}",
+                      i, entry.module, entry.offset, entry.original_address, entry.address);
+        } else {
+            LOG_ERROR(Core_ARM,
+                      "Guest backtrace frame {:03}: {}+0x{:X} pc={:016X} mapped={:016X} symbol={}",
+                      i, entry.module, entry.offset, entry.original_address, entry.address,
+                      entry.name);
+        }
+    }
+    if (backtrace.size() > MaxBacktraceFrames) {
+        LOG_ERROR(Core_ARM, "Guest backtrace truncated: logged={} total={}", MaxBacktraceFrames,
+                  backtrace.size());
+    }
 }
 
 const Kernel::DebugWatchpoint* ArmInterface::MatchingWatchpoint(

src/core/hle/service/filesystem/fsp/fs_i_storage.cpp

@@ -3,6 +3,9 @@
 
 // SPDX-FileCopyrightText: Copyright 2023 yuzu Emulator Project
 // SPDX-License-Identifier: GPL-2.0-or-later
+#include <chrono>
+#include <thread>
+#include "common/settings.h"
 
 #include "core/file_sys/errors.h"
 #include "core/hle/service/cmif_serialization.h"
@@ -30,6 +33,15 @@ Result IStorage::Read(
 
     R_UNLESS(length >= 0, FileSys::ResultInvalidSize);
     R_UNLESS(offset >= 0, FileSys::ResultInvalidOffset);
+    static thread_local std::chrono::steady_clock::time_point last_read_tick{};
+    const auto now = std::chrono::steady_clock::now();
+    const auto period = Settings::values.debug_knobs.GetValue();
+    const auto ReadInterval = std::chrono::microseconds{period};
+    if (last_read_tick != std::chrono::steady_clock::time_point{} &&
+        now - last_read_tick < ReadInterval) {
+        std::this_thread::sleep_for(ReadInterval - (now - last_read_tick));
+    }
+    last_read_tick = std::chrono::steady_clock::now();
 
     // Read the data from the Storage backend
     backend->Read(out_bytes.data(), length, offset);