From 0f48292de19227fcc61dd9ea71be321824368f9e Mon Sep 17 00:00:00 2001 From: Morph <39850852+Morph1984@users.noreply.github.com> Date: Sun, 13 Jun 2021 04:30:54 -0400 Subject: [PATCH] fsp_srv: Fix filesystem access logging This introduces a new setting Enable FS Access Log which saves the filesystem access log to sdmc:/FsAccessLog.txt If this setting is not enabled, this will indicate to FS to not call OutputAccessLogToSdCard. Fixes softlocks during loading in Xenoblade Chronicles 2 when certain DLC is enabled. --- src/common/settings.h | 1 + src/core/hle/service/filesystem/fsp_srv.cpp | 15 ++++++--- src/core/hle/service/filesystem/fsp_srv.h | 12 +++---- src/core/reporter.cpp | 36 ++++++++++++--------- src/core/reporter.h | 9 ++---- src/yuzu/configuration/config.cpp | 4 +++ src/yuzu/configuration/configure_debug.cpp | 11 +++++-- src/yuzu/configuration/configure_debug.ui | 9 +++++- src/yuzu_cmd/config.cpp | 2 ++ src/yuzu_cmd/default_ini.h | 2 ++ 10 files changed, 63 insertions(+), 38 deletions(-) diff --git a/src/common/settings.h b/src/common/settings.h index 1af8c5ac2e..bf34f2b5b8 100644 --- a/src/common/settings.h +++ b/src/common/settings.h @@ -218,6 +218,7 @@ struct Values { std::string program_args; bool dump_exefs; bool dump_nso; + bool enable_fs_access_log; bool reporting_services; bool quest_flag; bool disable_macro_jit; diff --git a/src/core/hle/service/filesystem/fsp_srv.cpp b/src/core/hle/service/filesystem/fsp_srv.cpp index 3af9881c2a..db4d44c128 100644 --- a/src/core/hle/service/filesystem/fsp_srv.cpp +++ b/src/core/hle/service/filesystem/fsp_srv.cpp @@ -13,6 +13,7 @@ #include "common/common_types.h" #include "common/hex_util.h" #include "common/logging/log.h" +#include "common/settings.h" #include "common/string_util.h" #include "core/core.h" #include "core/file_sys/directory.h" @@ -785,6 +786,10 @@ FSP_SRV::FSP_SRV(Core::System& system_) }; // clang-format on RegisterHandlers(functions); + + if (Settings::values.enable_fs_access_log) { + access_log_mode = AccessLogMode::SdCard; + } } FSP_SRV::~FSP_SRV() = default; @@ -1041,9 +1046,9 @@ void FSP_SRV::DisableAutoSaveDataCreation(Kernel::HLERequestContext& ctx) { void FSP_SRV::SetGlobalAccessLogMode(Kernel::HLERequestContext& ctx) { IPC::RequestParser rp{ctx}; - log_mode = rp.PopEnum(); + access_log_mode = rp.PopEnum(); - LOG_DEBUG(Service_FS, "called, log_mode={:08X}", log_mode); + LOG_DEBUG(Service_FS, "called, access_log_mode={}", access_log_mode); IPC::ResponseBuilder rb{ctx, 2}; rb.Push(ResultSuccess); @@ -1054,7 +1059,7 @@ void FSP_SRV::GetGlobalAccessLogMode(Kernel::HLERequestContext& ctx) { IPC::ResponseBuilder rb{ctx, 3}; rb.Push(ResultSuccess); - rb.PushEnum(log_mode); + rb.PushEnum(access_log_mode); } void FSP_SRV::OutputAccessLogToSdCard(Kernel::HLERequestContext& ctx) { @@ -1062,9 +1067,9 @@ void FSP_SRV::OutputAccessLogToSdCard(Kernel::HLERequestContext& ctx) { auto log = Common::StringFromFixedZeroTerminatedBuffer( reinterpret_cast(raw.data()), raw.size()); - LOG_DEBUG(Service_FS, "called, log='{}'", log); + LOG_DEBUG(Service_FS, "called"); - reporter.SaveFilesystemAccessReport(log_mode, std::move(log)); + reporter.SaveFSAccessLog(log); IPC::ResponseBuilder rb{ctx, 2}; rb.Push(ResultSuccess); diff --git a/src/core/hle/service/filesystem/fsp_srv.h b/src/core/hle/service/filesystem/fsp_srv.h index ff7455a20c..556708284e 100644 --- a/src/core/hle/service/filesystem/fsp_srv.h +++ b/src/core/hle/service/filesystem/fsp_srv.h @@ -24,11 +24,10 @@ enum class AccessLogVersion : u32 { Latest = V7_0_0, }; -enum class LogMode : u32 { - Off, +enum class AccessLogMode : u32 { + None, Log, - RedirectToSdCard, - LogToSdCard = Log | RedirectToSdCard, + SdCard, }; class FSP_SRV final : public ServiceFramework { @@ -59,13 +58,12 @@ private: FileSystemController& fsc; const FileSys::ContentProvider& content_provider; + const Core::Reporter& reporter; FileSys::VirtualFile romfs; u64 current_process_id = 0; u32 access_log_program_index = 0; - LogMode log_mode = LogMode::LogToSdCard; - - const Core::Reporter& reporter; + AccessLogMode access_log_mode = AccessLogMode::None; }; } // namespace Service::FileSystem diff --git a/src/core/reporter.cpp b/src/core/reporter.cpp index ec2a16e620..82b0f535aa 100644 --- a/src/core/reporter.cpp +++ b/src/core/reporter.cpp @@ -195,7 +195,9 @@ json GetHLERequestContextData(Kernel::HLERequestContext& ctx, Core::Memory::Memo namespace Core { -Reporter::Reporter(System& system_) : system(system_) {} +Reporter::Reporter(System& system_) : system(system_) { + ClearFSAccessLog(); +} Reporter::~Reporter() = default; @@ -362,22 +364,12 @@ void Reporter::SaveErrorReport(u64 title_id, ResultCode result, SaveToFile(std::move(out), GetPath("error_report", title_id, timestamp)); } -void Reporter::SaveFilesystemAccessReport(Service::FileSystem::LogMode log_mode, - std::string log_message) const { - if (!IsReportingEnabled()) - return; +void Reporter::SaveFSAccessLog(std::string_view log_message) const { + const auto access_log_path = + Common::FS::GetYuzuPath(Common::FS::YuzuPath::SDMCDir) / "FsAccessLog.txt"; - const auto timestamp = GetTimestamp(); - const auto title_id = system.CurrentProcess()->GetTitleID(); - json out; - - out["yuzu_version"] = GetYuzuVersionData(); - out["report_common"] = GetReportCommonData(title_id, ResultSuccess, timestamp); - - out["log_mode"] = fmt::format("{:08X}", static_cast(log_mode)); - out["log_message"] = std::move(log_message); - - SaveToFile(std::move(out), GetPath("filesystem_access_report", title_id, timestamp)); + void(Common::FS::AppendStringToFile(access_log_path, Common::FS::FileType::TextFile, + log_message)); } void Reporter::SaveUserReport() const { @@ -392,6 +384,18 @@ void Reporter::SaveUserReport() const { GetPath("user_report", title_id, timestamp)); } +void Reporter::ClearFSAccessLog() const { + const auto access_log_path = + Common::FS::GetYuzuPath(Common::FS::YuzuPath::SDMCDir) / "FsAccessLog.txt"; + + Common::FS::IOFile access_log_file{access_log_path, Common::FS::FileAccessMode::Write, + Common::FS::FileType::TextFile}; + + if (!access_log_file.IsOpen()) { + LOG_ERROR(Common_Filesystem, "Failed to clear the filesystem access log."); + } +} + bool Reporter::IsReportingEnabled() const { return Settings::values.reporting_services; } diff --git a/src/core/reporter.h b/src/core/reporter.h index 6fb6ebffae..6e9edeea30 100644 --- a/src/core/reporter.h +++ b/src/core/reporter.h @@ -16,10 +16,6 @@ namespace Kernel { class HLERequestContext; } // namespace Kernel -namespace Service::FileSystem { -enum class LogMode : u32; -} - namespace Service::LM { struct LogMessage; } // namespace Service::LM @@ -69,14 +65,15 @@ public: std::optional custom_text_main = {}, std::optional custom_text_detail = {}) const; - void SaveFilesystemAccessReport(Service::FileSystem::LogMode log_mode, - std::string log_message) const; + void SaveFSAccessLog(std::string_view log_message) const; // Can be used anywhere to generate a backtrace and general info report at any point during // execution. Not intended to be used for anything other than debugging or testing. void SaveUserReport() const; private: + void ClearFSAccessLog() const; + bool IsReportingEnabled() const; System& system; diff --git a/src/yuzu/configuration/config.cpp b/src/yuzu/configuration/config.cpp index a59b36e138..712319783a 100644 --- a/src/yuzu/configuration/config.cpp +++ b/src/yuzu/configuration/config.cpp @@ -647,6 +647,8 @@ void Config::ReadDebuggingValues() { ReadSetting(QStringLiteral("program_args"), QString{}).toString().toStdString(); Settings::values.dump_exefs = ReadSetting(QStringLiteral("dump_exefs"), false).toBool(); Settings::values.dump_nso = ReadSetting(QStringLiteral("dump_nso"), false).toBool(); + Settings::values.enable_fs_access_log = + ReadSetting(QStringLiteral("enable_fs_access_log"), false).toBool(); Settings::values.reporting_services = ReadSetting(QStringLiteral("reporting_services"), false).toBool(); Settings::values.quest_flag = ReadSetting(QStringLiteral("quest_flag"), false).toBool(); @@ -1258,6 +1260,8 @@ void Config::SaveDebuggingValues() { QString::fromStdString(Settings::values.program_args), QString{}); WriteSetting(QStringLiteral("dump_exefs"), Settings::values.dump_exefs, false); WriteSetting(QStringLiteral("dump_nso"), Settings::values.dump_nso, false); + WriteSetting(QStringLiteral("enable_fs_access_log"), Settings::values.enable_fs_access_log, + false); WriteSetting(QStringLiteral("quest_flag"), Settings::values.quest_flag, false); WriteSetting(QStringLiteral("use_debug_asserts"), Settings::values.use_debug_asserts, false); WriteSetting(QStringLiteral("disable_macro_jit"), Settings::values.disable_macro_jit, false); diff --git a/src/yuzu/configuration/configure_debug.cpp b/src/yuzu/configuration/configure_debug.cpp index b207e07cb0..15d6a5ad79 100644 --- a/src/yuzu/configuration/configure_debug.cpp +++ b/src/yuzu/configuration/configure_debug.cpp @@ -28,17 +28,21 @@ ConfigureDebug::ConfigureDebug(QWidget* parent) : QWidget(parent), ui(new Ui::Co ConfigureDebug::~ConfigureDebug() = default; void ConfigureDebug::SetConfiguration() { - ui->toggle_console->setEnabled(!Core::System::GetInstance().IsPoweredOn()); + const bool runtime_lock = !Core::System::GetInstance().IsPoweredOn(); + + ui->toggle_console->setEnabled(runtime_lock); ui->toggle_console->setChecked(UISettings::values.show_console); ui->log_filter_edit->setText(QString::fromStdString(Settings::values.log_filter)); ui->homebrew_args_edit->setText(QString::fromStdString(Settings::values.program_args)); + ui->fs_access_log->setEnabled(runtime_lock); + ui->fs_access_log->setChecked(Settings::values.enable_fs_access_log); ui->reporting_services->setChecked(Settings::values.reporting_services); ui->quest_flag->setChecked(Settings::values.quest_flag); ui->use_debug_asserts->setChecked(Settings::values.use_debug_asserts); ui->use_auto_stub->setChecked(Settings::values.use_auto_stub); - ui->enable_graphics_debugging->setEnabled(!Core::System::GetInstance().IsPoweredOn()); + ui->enable_graphics_debugging->setEnabled(runtime_lock); ui->enable_graphics_debugging->setChecked(Settings::values.renderer_debug); - ui->disable_macro_jit->setEnabled(!Core::System::GetInstance().IsPoweredOn()); + ui->disable_macro_jit->setEnabled(runtime_lock); ui->disable_macro_jit->setChecked(Settings::values.disable_macro_jit); ui->extended_logging->setChecked(Settings::values.extended_logging); } @@ -47,6 +51,7 @@ void ConfigureDebug::ApplyConfiguration() { UISettings::values.show_console = ui->toggle_console->isChecked(); Settings::values.log_filter = ui->log_filter_edit->text().toStdString(); Settings::values.program_args = ui->homebrew_args_edit->text().toStdString(); + Settings::values.enable_fs_access_log = ui->fs_access_log->isChecked(); Settings::values.reporting_services = ui->reporting_services->isChecked(); Settings::values.quest_flag = ui->quest_flag->isChecked(); Settings::values.use_debug_asserts = ui->use_debug_asserts->isChecked(); diff --git a/src/yuzu/configuration/configure_debug.ui b/src/yuzu/configuration/configure_debug.ui index c9e60ee083..c8087542f9 100644 --- a/src/yuzu/configuration/configure_debug.ui +++ b/src/yuzu/configuration/configure_debug.ui @@ -144,9 +144,16 @@ - Dump + Debugging + + + + Enable FS Access Log + + + diff --git a/src/yuzu_cmd/config.cpp b/src/yuzu_cmd/config.cpp index 63f368fe52..107f097d02 100644 --- a/src/yuzu_cmd/config.cpp +++ b/src/yuzu_cmd/config.cpp @@ -477,6 +477,8 @@ void Config::ReadValues() { Settings::values.program_args = sdl2_config->Get("Debugging", "program_args", ""); Settings::values.dump_exefs = sdl2_config->GetBoolean("Debugging", "dump_exefs", false); Settings::values.dump_nso = sdl2_config->GetBoolean("Debugging", "dump_nso", false); + Settings::values.enable_fs_access_log = + sdl2_config->GetBoolean("Debugging", "enable_fs_access_log", false); Settings::values.reporting_services = sdl2_config->GetBoolean("Debugging", "reporting_services", false); Settings::values.quest_flag = sdl2_config->GetBoolean("Debugging", "quest_flag", false); diff --git a/src/yuzu_cmd/default_ini.h b/src/yuzu_cmd/default_ini.h index f48d935a1f..c324216716 100644 --- a/src/yuzu_cmd/default_ini.h +++ b/src/yuzu_cmd/default_ini.h @@ -338,6 +338,8 @@ record_frame_times = dump_exefs=false # Determines whether or not yuzu will dump all NSOs it attempts to load while loading them dump_nso=false +# Determines whether or not yuzu will save the filesystem access log. +enable_fs_access_log=false # Determines whether or not yuzu will report to the game that the emulated console is in Kiosk Mode # false: Retail/Normal Mode (default), true: Kiosk Mode quest_flag =