franklinblanco/yuzu
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

Merge pull request #2654 from DarkLordZach/lm-log-rewrite

Browse Source 
lm: Rewrite logger to use core reporting services
This commit is contained in:
bunnei 2019-10-08 20:23:13 -04:00 committed by GitHub
commit b9c831de62
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
10 changed files with 367 additions and 159 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
src/core/CMakeLists.txt
View File

@ -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

17
src/core/core.cpp
View File

@ -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<Memory::CheatEngine> cheat_engine;
std::unique_ptr<Tools::Freezer> memory_freezer;
std::array<u8, 0x20> 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::SM::ServiceManager> service_manager;
@ -357,8 +362,6 @@ struct System::Impl {
/// Telemetry session for this emulation session
std::unique_ptr<Core::TelemetrySession> 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;
}

8
src/core/core.h
View File

@ -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;

187
src/core/hle/service/lm/lm.cpp
View File

@ -6,8 +6,10 @@
#include <string>
#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<ILogger> {
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<Field>(Memory::Read8(addr++))};
const std::size_t length{Memory::Read8(addr++)};
const auto field = static_cast<Field>(Memory::Read8(addr++));
const auto length = Memory::Read8(addr++);
if (static_cast<Field>(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<u8> 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;
manager.Log({header, std::move(fields)});
}
// 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;
}
}
}
// 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<DestinationFlag>();
LOG_DEBUG(Service_LM, "called, destination={:08X}", static_cast<u32>(destination));
manager.SetDestination(destination);
IPC::ResponseBuilder rb{ctx, 2};
rb.Push(RESULT_SUCCESS);
}
std::ostringstream log_stream;
Manager& manager;
};
class LM final : public ServiceFramework<LM> {
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<ILogger>();
rb.PushIpcInterface<ILogger>(manager);
}
Manager& manager;
};
void InstallInterfaces(SM::ServiceManager& service_manager) {
std::make_shared<LM>()->InstallAsService(service_manager);
void InstallInterfaces(Core::System& system) {
std::make_shared<LM>(system.GetLogManager())->InstallAsService(system.ServiceManager());
}
} // namespace Service::LM

6
src/core/hle/service/lm/lm.h
View File

@ -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

133
src/core/hle/service/lm/manager.cpp Normal file
View File

@ -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<std::string> array;
const auto check_single_flag = [dest, &array](DestinationFlag check, std::string name) {
if ((static_cast<u32>(check) & static_cast<u32>(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<u32>(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<u32>(field));
}
}
std::string FormatField(Field type, const std::vector<u8>& 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<const char*>(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<u32>(destination), std::move(current_log));
LOG_INFO(Service_LM, "Finalized current log session");
}
} // namespace Service::LM

106
src/core/hle/service/lm/manager.h Normal file
View File

@ -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 <map>
#include <ostream>
#include <vector>
#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<Field, std::vector<u8>>;
struct LogMessage {
MessageHeader header;
FieldMap fields;
};
std::string FormatField(Field type, const std::vector<u8>& 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<LogMessage> current_log;
Core::Reporter& reporter;
};
} // namespace Service::LM

2
src/core/hle/service/service.cpp
View File

@ -226,7 +226,7 @@ void Init(std::shared_ptr<SM::ServiceManager>& 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);

51
src/core/reporter.cpp
View File

@ -7,6 +7,7 @@
#include <fmt/chrono.h>
#include <fmt/format.h>
#include <fmt/ostream.h>
#include <json.hpp>
#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<Service::LM::LogMessage> 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<Service::LM::DestinationFlag>(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())

14
src/core/reporter.h
View File

@ -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<u64, 31>& registers, const std::array<u64, 32>& 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<std::vector<u8>> 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<std::vector<u8>> normal_channel,
@ -55,6 +63,7 @@ public:
void SavePlayReport(PlayReportType type, u64 title_id, std::vector<std::vector<u8>> data,
std::optional<u64> process_id = {}, std::optional<u128> user_id = {}) const;
// Used by error applet
void SaveErrorReport(u64 title_id, ResultCode result,
std::optional<std::string> custom_text_main = {},
std::optional<std::string> 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<Service::LM::LogMessage> 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: