diff --git a/src/core/CMakeLists.txt b/src/core/CMakeLists.txt index 3416854db..3b1d72cf9 100644 --- a/src/core/CMakeLists.txt +++ b/src/core/CMakeLists.txt @@ -335,6 +335,8 @@ add_library(core STATIC hle/service/ldr/ldr.h hle/service/lm/lm.cpp hle/service/lm/lm.h + hle/service/lm/manager.cpp + hle/service/lm/manager.h hle/service/mig/mig.cpp hle/service/mig/mig.h hle/service/mii/mii.cpp diff --git a/src/core/core.cpp b/src/core/core.cpp index a58ceb703..4d0ac72a5 100644 --- a/src/core/core.cpp +++ b/src/core/core.cpp @@ -35,6 +35,7 @@ #include "core/hle/service/apm/controller.h" #include "core/hle/service/filesystem/filesystem.h" #include "core/hle/service/glue/manager.h" +#include "core/hle/service/lm/manager.h" #include "core/hle/service/service.h" #include "core/hle/service/sm/sm.h" #include "core/loader/loader.h" @@ -250,6 +251,8 @@ struct System::Impl { telemetry_session->AddField(Telemetry::FieldType::Performance, "Mean_Frametime_MS", perf_stats->GetMeanFrametime()); + lm_manager.Flush(); + is_powered_on = false; exit_lock = false; @@ -338,6 +341,7 @@ struct System::Impl { bool is_powered_on = false; bool exit_lock = false; + Reporter reporter; std::unique_ptr cheat_engine; std::unique_ptr memory_freezer; std::array build_id{}; @@ -348,8 +352,9 @@ struct System::Impl { /// APM (Performance) services Service::APM::Controller apm_controller{core_timing}; - /// Glue services + /// Service State Service::Glue::ARPManager arp_manager; + Service::LM::Manager lm_manager{reporter}; /// Service manager std::shared_ptr service_manager; @@ -357,8 +362,6 @@ struct System::Impl { /// Telemetry session for this emulation session std::unique_ptr telemetry_session; - Reporter reporter; - ResultStatus status = ResultStatus::Success; std::string status_details = ""; @@ -634,6 +637,14 @@ const Service::APM::Controller& System::GetAPMController() const { return impl->apm_controller; } +Service::LM::Manager& System::GetLogManager() { + return impl->lm_manager; +} + +const Service::LM::Manager& System::GetLogManager() const { + return impl->lm_manager; +} + void System::SetExitLock(bool locked) { impl->exit_lock = locked; } diff --git a/src/core/core.h b/src/core/core.h index d13b6aa5e..90e7ac607 100644 --- a/src/core/core.h +++ b/src/core/core.h @@ -57,6 +57,10 @@ namespace Glue { class ARPManager; } +namespace LM { +class Manager; +} // namespace LM + namespace SM { class ServiceManager; } // namespace SM @@ -327,6 +331,10 @@ public: const Service::APM::Controller& GetAPMController() const; + Service::LM::Manager& GetLogManager(); + + const Service::LM::Manager& GetLogManager() const; + void SetExitLock(bool locked); bool GetExitLock() const; diff --git a/src/core/hle/service/lm/lm.cpp b/src/core/hle/service/lm/lm.cpp index 2a61593e2..435f2d286 100644 --- a/src/core/hle/service/lm/lm.cpp +++ b/src/core/hle/service/lm/lm.cpp @@ -6,8 +6,10 @@ #include #include "common/logging/log.h" +#include "common/scope_exit.h" #include "core/hle/ipc_helpers.h" #include "core/hle/service/lm/lm.h" +#include "core/hle/service/lm/manager.h" #include "core/hle/service/service.h" #include "core/memory.h" @@ -15,65 +17,16 @@ namespace Service::LM { class ILogger final : public ServiceFramework { public: - ILogger() : ServiceFramework("ILogger") { + ILogger(Manager& manager) : ServiceFramework("ILogger"), manager(manager) { static const FunctionInfo functions[] = { - {0x00000000, &ILogger::Initialize, "Initialize"}, - {0x00000001, &ILogger::SetDestination, "SetDestination"}, + {0, &ILogger::Log, "Log"}, + {1, &ILogger::SetDestination, "SetDestination"}, }; RegisterHandlers(functions); } private: - struct MessageHeader { - enum Flags : u32_le { - IsHead = 1, - IsTail = 2, - }; - enum Severity : u32_le { - Trace, - Info, - Warning, - Error, - Critical, - }; - - u64_le pid; - u64_le threadContext; - union { - BitField<0, 16, Flags> flags; - BitField<16, 8, Severity> severity; - BitField<24, 8, u32> verbosity; - }; - u32_le payload_size; - - bool IsHeadLog() const { - return flags & Flags::IsHead; - } - bool IsTailLog() const { - return flags & Flags::IsTail; - } - }; - static_assert(sizeof(MessageHeader) == 0x18, "MessageHeader is incorrect size"); - - /// Log field type - enum class Field : u8 { - Skip = 1, - Message = 2, - Line = 3, - Filename = 4, - Function = 5, - Module = 6, - Thread = 7, - }; - - /** - * ILogger::Initialize service function - * Inputs: - * 0: 0x00000000 - * Outputs: - * 0: ResultCode - */ - void Initialize(Kernel::HLERequestContext& ctx) { + void Log(Kernel::HLERequestContext& ctx) { // This function only succeeds - Get that out of the way IPC::ResponseBuilder rb{ctx, 2}; rb.Push(RESULT_SUCCESS); @@ -85,140 +38,70 @@ private: Memory::ReadBlock(addr, &header, sizeof(MessageHeader)); addr += sizeof(MessageHeader); - if (header.IsHeadLog()) { - log_stream.str(""); - log_stream.clear(); - } - - // Parse out log metadata - u32 line{}; - std::string module; - std::string message; - std::string filename; - std::string function; - std::string thread; + FieldMap fields; while (addr < end_addr) { - const Field field{static_cast(Memory::Read8(addr++))}; - const std::size_t length{Memory::Read8(addr++)}; + const auto field = static_cast(Memory::Read8(addr++)); + const auto length = Memory::Read8(addr++); if (static_cast(Memory::Read8(addr)) == Field::Skip) { ++addr; } - switch (field) { - case Field::Skip: - break; - case Field::Message: - message = Memory::ReadCString(addr, length); - break; - case Field::Line: - line = Memory::Read32(addr); - break; - case Field::Filename: - filename = Memory::ReadCString(addr, length); - break; - case Field::Function: - function = Memory::ReadCString(addr, length); - break; - case Field::Module: - module = Memory::ReadCString(addr, length); - break; - case Field::Thread: - thread = Memory::ReadCString(addr, length); - break; + SCOPE_EXIT({ addr += length; }); + + if (field == Field::Skip) { + continue; } - addr += length; + std::vector data(length); + Memory::ReadBlock(addr, data.data(), length); + fields.emplace(field, std::move(data)); } - // Empty log - nothing to do here - if (log_stream.str().empty() && message.empty()) { - return; - } - - // Format a nicely printable string out of the log metadata - if (!filename.empty()) { - log_stream << filename << ':'; - } - if (!module.empty()) { - log_stream << module << ':'; - } - if (!function.empty()) { - log_stream << function << ':'; - } - if (line) { - log_stream << std::to_string(line) << ':'; - } - if (!thread.empty()) { - log_stream << thread << ':'; - } - if (log_stream.str().length() > 0 && log_stream.str().back() == ':') { - log_stream << ' '; - } - log_stream << message; - - if (header.IsTailLog()) { - switch (header.severity) { - case MessageHeader::Severity::Trace: - LOG_DEBUG(Debug_Emulated, "{}", log_stream.str()); - break; - case MessageHeader::Severity::Info: - LOG_INFO(Debug_Emulated, "{}", log_stream.str()); - break; - case MessageHeader::Severity::Warning: - LOG_WARNING(Debug_Emulated, "{}", log_stream.str()); - break; - case MessageHeader::Severity::Error: - LOG_ERROR(Debug_Emulated, "{}", log_stream.str()); - break; - case MessageHeader::Severity::Critical: - LOG_CRITICAL(Debug_Emulated, "{}", log_stream.str()); - break; - } - } + manager.Log({header, std::move(fields)}); } - // This service function is intended to be used as a way to - // redirect logging output to different destinations, however, - // given we always want to see the logging output, it's sufficient - // to do nothing and return success here. void SetDestination(Kernel::HLERequestContext& ctx) { - LOG_DEBUG(Service_LM, "called"); + IPC::RequestParser rp{ctx}; + const auto destination = rp.PopEnum(); + + LOG_DEBUG(Service_LM, "called, destination={:08X}", static_cast(destination)); + + manager.SetDestination(destination); IPC::ResponseBuilder rb{ctx, 2}; rb.Push(RESULT_SUCCESS); } - std::ostringstream log_stream; + Manager& manager; }; class LM final : public ServiceFramework { public: - explicit LM() : ServiceFramework{"lm"} { + explicit LM(Manager& manager) : ServiceFramework{"lm"}, manager(manager) { + // clang-format off static const FunctionInfo functions[] = { - {0x00000000, &LM::OpenLogger, "OpenLogger"}, + {0, &LM::OpenLogger, "OpenLogger"}, }; + // clang-format on + RegisterHandlers(functions); } - /** - * LM::OpenLogger service function - * Inputs: - * 0: 0x00000000 - * Outputs: - * 0: ResultCode - */ +private: void OpenLogger(Kernel::HLERequestContext& ctx) { LOG_DEBUG(Service_LM, "called"); IPC::ResponseBuilder rb{ctx, 2, 0, 1}; rb.Push(RESULT_SUCCESS); - rb.PushIpcInterface(); + rb.PushIpcInterface(manager); } + + Manager& manager; }; -void InstallInterfaces(SM::ServiceManager& service_manager) { - std::make_shared()->InstallAsService(service_manager); +void InstallInterfaces(Core::System& system) { + std::make_shared(system.GetLogManager())->InstallAsService(system.ServiceManager()); } } // namespace Service::LM diff --git a/src/core/hle/service/lm/lm.h b/src/core/hle/service/lm/lm.h index 7806ae27b..d40410b5c 100644 --- a/src/core/hle/service/lm/lm.h +++ b/src/core/hle/service/lm/lm.h @@ -4,13 +4,13 @@ #pragma once -namespace Service::SM { -class ServiceManager; +namespace Core { +class System; } namespace Service::LM { /// Registers all LM services with the specified service manager. -void InstallInterfaces(SM::ServiceManager& service_manager); +void InstallInterfaces(Core::System& system); } // namespace Service::LM diff --git a/src/core/hle/service/lm/manager.cpp b/src/core/hle/service/lm/manager.cpp new file mode 100644 index 000000000..b67081b86 --- /dev/null +++ b/src/core/hle/service/lm/manager.cpp @@ -0,0 +1,133 @@ +// Copyright 2019 yuzu emulator team +// Licensed under GPLv2 or any later version +// Refer to the license.txt file included. + +#include "common/assert.h" +#include "common/logging/log.h" +#include "common/string_util.h" +#include "core/hle/service/lm/manager.h" +#include "core/reporter.h" + +namespace Service::LM { + +std::ostream& operator<<(std::ostream& os, DestinationFlag dest) { + std::vector array; + const auto check_single_flag = [dest, &array](DestinationFlag check, std::string name) { + if ((static_cast(check) & static_cast(dest)) != 0) { + array.emplace_back(std::move(name)); + } + }; + + check_single_flag(DestinationFlag::Default, "Default"); + check_single_flag(DestinationFlag::UART, "UART"); + check_single_flag(DestinationFlag::UARTSleeping, "UART (Sleeping)"); + + os << "["; + for (const auto& entry : array) { + os << entry << ", "; + } + return os << "]"; +} + +std::ostream& operator<<(std::ostream& os, MessageHeader::Severity severity) { + switch (severity) { + case MessageHeader::Severity::Trace: + return os << "Trace"; + case MessageHeader::Severity::Info: + return os << "Info"; + case MessageHeader::Severity::Warning: + return os << "Warning"; + case MessageHeader::Severity::Error: + return os << "Error"; + case MessageHeader::Severity::Critical: + return os << "Critical"; + default: + return os << fmt::format("{:08X}", static_cast(severity)); + } +} + +std::ostream& operator<<(std::ostream& os, Field field) { + switch (field) { + case Field::Skip: + return os << "Skip"; + case Field::Message: + return os << "Message"; + case Field::Line: + return os << "Line"; + case Field::Filename: + return os << "Filename"; + case Field::Function: + return os << "Function"; + case Field::Module: + return os << "Module"; + case Field::Thread: + return os << "Thread"; + default: + return os << fmt::format("{:08X}", static_cast(field)); + } +} + +std::string FormatField(Field type, const std::vector& data) { + switch (type) { + case Field::Skip: + return ""; + case Field::Line: + if (data.size() >= sizeof(u32)) { + u32 line; + std::memcpy(&line, data.data(), sizeof(u32)); + return fmt::format("{}", line); + } + return "[ERROR DECODING LINE NUMBER]"; + case Field::Message: + case Field::Filename: + case Field::Function: + case Field::Module: + case Field::Thread: + return Common::StringFromFixedZeroTerminatedBuffer( + reinterpret_cast(data.data()), data.size()); + default: + UNIMPLEMENTED(); + } +} + +Manager::Manager(Core::Reporter& reporter) : reporter(reporter) {} + +Manager::~Manager() = default; + +void Manager::SetEnabled(bool enabled) { + this->enabled = enabled; +} + +void Manager::SetDestination(DestinationFlag destination) { + this->destination = destination; +} + +void Manager::Log(LogMessage message) { + if (message.header.IsHeadLog()) { + InitializeLog(); + } + + current_log.emplace_back(std::move(message)); + + if (current_log.back().header.IsTailLog()) { + FinalizeLog(); + } +} + +void Manager::Flush() { + FinalizeLog(); +} + +void Manager::InitializeLog() { + current_log.clear(); + + LOG_INFO(Service_LM, "Initialized new log session"); +} + +void Manager::FinalizeLog() { + reporter.SaveLogReport(static_cast(destination), std::move(current_log)); + + LOG_INFO(Service_LM, "Finalized current log session"); +} + +} // namespace Service::LM diff --git a/src/core/hle/service/lm/manager.h b/src/core/hle/service/lm/manager.h new file mode 100644 index 000000000..544e636ba --- /dev/null +++ b/src/core/hle/service/lm/manager.h @@ -0,0 +1,106 @@ +// Copyright 2019 yuzu emulator team +// Licensed under GPLv2 or any later version +// Refer to the license.txt file included. + +#pragma once + +#include +#include +#include +#include "common/bit_field.h" +#include "common/common_types.h" +#include "common/swap.h" + +namespace Core { +class Reporter; +} + +namespace Service::LM { + +enum class DestinationFlag : u32 { + Default = 1, + UART = 2, + UARTSleeping = 4, + + All = 0xFFFF, +}; + +struct MessageHeader { + enum Flags : u32_le { + IsHead = 1, + IsTail = 2, + }; + enum Severity : u32_le { + Trace, + Info, + Warning, + Error, + Critical, + }; + + u64_le pid; + u64_le thread_context; + union { + BitField<0, 16, Flags> flags; + BitField<16, 8, Severity> severity; + BitField<24, 8, u32> verbosity; + }; + u32_le payload_size; + + bool IsHeadLog() const { + return flags & IsHead; + } + bool IsTailLog() const { + return flags & IsTail; + } +}; +static_assert(sizeof(MessageHeader) == 0x18, "MessageHeader is incorrect size"); + +enum class Field : u8 { + Skip = 1, + Message = 2, + Line = 3, + Filename = 4, + Function = 5, + Module = 6, + Thread = 7, +}; + +std::ostream& operator<<(std::ostream& os, DestinationFlag dest); +std::ostream& operator<<(std::ostream& os, MessageHeader::Severity severity); +std::ostream& operator<<(std::ostream& os, Field field); + +using FieldMap = std::map>; + +struct LogMessage { + MessageHeader header; + FieldMap fields; +}; + +std::string FormatField(Field type, const std::vector& data); + +class Manager { +public: + explicit Manager(Core::Reporter& reporter); + ~Manager(); + + void SetEnabled(bool enabled); + void SetDestination(DestinationFlag destination); + + void Log(LogMessage message); + + void Flush(); + +private: + void InitializeLog(); + void FinalizeLog(); + + bool enabled = true; + DestinationFlag destination = DestinationFlag::All; + + std::vector current_log; + + Core::Reporter& reporter; +}; + +} // namespace Service::LM diff --git a/src/core/hle/service/service.cpp b/src/core/hle/service/service.cpp index f2c6fe9dc..7c5302017 100644 --- a/src/core/hle/service/service.cpp +++ b/src/core/hle/service/service.cpp @@ -226,7 +226,7 @@ void Init(std::shared_ptr& sm, Core::System& system) { LBL::InstallInterfaces(*sm); LDN::InstallInterfaces(*sm); LDR::InstallInterfaces(*sm, system); - LM::InstallInterfaces(*sm); + LM::InstallInterfaces(system); Migration::InstallInterfaces(*sm); Mii::InstallInterfaces(*sm); MM::InstallInterfaces(*sm); diff --git a/src/core/reporter.cpp b/src/core/reporter.cpp index 9c657929e..6f4af77fd 100644 --- a/src/core/reporter.cpp +++ b/src/core/reporter.cpp @@ -7,6 +7,7 @@ #include #include +#include #include #include "common/file_util.h" @@ -17,6 +18,7 @@ #include "core/hle/kernel/hle_ipc.h" #include "core/hle/kernel/process.h" #include "core/hle/result.h" +#include "core/hle/service/lm/manager.h" #include "core/reporter.h" #include "core/settings.h" @@ -354,6 +356,55 @@ void Reporter::SaveErrorReport(u64 title_id, ResultCode result, SaveToFile(std::move(out), GetPath("error_report", title_id, timestamp)); } +void Reporter::SaveLogReport(u32 destination, std::vector messages) const { + if (!IsReportingEnabled()) { + return; + } + + const auto timestamp = GetTimestamp(); + json out; + + out["yuzu_version"] = GetYuzuVersionData(); + out["report_common"] = + GetReportCommonData(system.CurrentProcess()->GetTitleID(), RESULT_SUCCESS, timestamp); + + out["log_destination"] = + fmt::format("{}", static_cast(destination)); + + auto json_messages = json::array(); + std::transform(messages.begin(), messages.end(), std::back_inserter(json_messages), + [](const Service::LM::LogMessage& message) { + json out; + out["is_head"] = fmt::format("{}", message.header.IsHeadLog()); + out["is_tail"] = fmt::format("{}", message.header.IsTailLog()); + out["pid"] = fmt::format("{:016X}", message.header.pid); + out["thread_context"] = + fmt::format("{:016X}", message.header.thread_context); + out["payload_size"] = fmt::format("{:016X}", message.header.payload_size); + out["flags"] = fmt::format("{:04X}", message.header.flags.Value()); + out["severity"] = fmt::format("{}", message.header.severity.Value()); + out["verbosity"] = fmt::format("{:02X}", message.header.verbosity); + + auto fields = json::array(); + std::transform(message.fields.begin(), message.fields.end(), + std::back_inserter(fields), [](const auto& kv) { + json out; + out["type"] = fmt::format("{}", kv.first); + out["data"] = + Service::LM::FormatField(kv.first, kv.second); + return out; + }); + + out["fields"] = std::move(fields); + return out; + }); + + out["log_messages"] = std::move(json_messages); + + SaveToFile(std::move(out), + GetPath("log_report", system.CurrentProcess()->GetTitleID(), timestamp)); +} + void Reporter::SaveFilesystemAccessReport(Service::FileSystem::LogMode log_mode, std::string log_message) const { if (!IsReportingEnabled()) diff --git a/src/core/reporter.h b/src/core/reporter.h index f08aa11fb..380941b1b 100644 --- a/src/core/reporter.h +++ b/src/core/reporter.h @@ -20,6 +20,10 @@ namespace Service::FileSystem { enum class LogMode : u32; } +namespace Service::LM { +struct LogMessage; +} // namespace Service::LM + namespace Core { class System; @@ -29,18 +33,22 @@ public: explicit Reporter(System& system); ~Reporter(); + // Used by fatal services void SaveCrashReport(u64 title_id, ResultCode result, u64 set_flags, u64 entry_point, u64 sp, u64 pc, u64 pstate, u64 afsr0, u64 afsr1, u64 esr, u64 far, const std::array& registers, const std::array& backtrace, u32 backtrace_size, const std::string& arch, u32 unk10) const; + // Used by syscall svcBreak void SaveSvcBreakReport(u32 type, bool signal_debugger, u64 info1, u64 info2, std::optional> resolved_buffer = {}) const; + // Used by HLE service handler void SaveUnimplementedFunctionReport(Kernel::HLERequestContext& ctx, u32 command_id, const std::string& name, const std::string& service_name) const; + // Used by stub applet implementation void SaveUnimplementedAppletReport(u32 applet_id, u32 common_args_version, u32 library_version, u32 theme_color, bool startup_sound, u64 system_tick, std::vector> normal_channel, @@ -55,6 +63,7 @@ public: void SavePlayReport(PlayReportType type, u64 title_id, std::vector> data, std::optional process_id = {}, std::optional user_id = {}) const; + // Used by error applet void SaveErrorReport(u64 title_id, ResultCode result, std::optional custom_text_main = {}, std::optional custom_text_detail = {}) const; @@ -62,6 +71,11 @@ public: void SaveFilesystemAccessReport(Service::FileSystem::LogMode log_mode, std::string log_message) const; + // Used by lm services + void SaveLogReport(u32 destination, std::vector messages) 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: