From 616d87444313db865c60fbeee36ebe5250ef301e Mon Sep 17 00:00:00 2001 From: Yuri Kunde Schlesner Date: Tue, 28 Oct 2014 05:36:00 -0200 Subject: New logging system --- src/common/logging/backend.cpp | 151 ++++++++++++++++++++++++++++++++++ src/common/logging/backend.h | 134 ++++++++++++++++++++++++++++++ src/common/logging/log.h | 115 ++++++++++++++++++++++++++ src/common/logging/text_formatter.cpp | 47 +++++++++++ src/common/logging/text_formatter.h | 26 ++++++ 5 files changed, 473 insertions(+) create mode 100644 src/common/logging/backend.cpp create mode 100644 src/common/logging/backend.h create mode 100644 src/common/logging/log.h create mode 100644 src/common/logging/text_formatter.cpp create mode 100644 src/common/logging/text_formatter.h (limited to 'src/common/logging') diff --git a/src/common/logging/backend.cpp b/src/common/logging/backend.cpp new file mode 100644 index 00000000..e79b8460 --- /dev/null +++ b/src/common/logging/backend.cpp @@ -0,0 +1,151 @@ +// Copyright 2014 Citra Emulator Project +// Licensed under GPLv2+ +// Refer to the license.txt file included. + +#include + +#include "common/log.h" // For _dbg_assert_ + +#include "common/logging/backend.h" +#include "common/logging/log.h" +#include "common/logging/text_formatter.h" + +namespace Log { + +static std::shared_ptr global_logger; + +/// Macro listing all log classes. Code should define CLS and SUB as desired before invoking this. +#define ALL_LOG_CLASSES() \ + CLS(Log) \ + CLS(Common) \ + SUB(Common, Filesystem) \ + SUB(Common, Memory) \ + CLS(Core) \ + SUB(Core, ARM11) \ + CLS(Config) \ + CLS(Debug) \ + SUB(Debug, Emulated) \ + SUB(Debug, GPU) \ + SUB(Debug, Breakpoint) \ + CLS(Kernel) \ + SUB(Kernel, SVC) \ + CLS(Service) \ + SUB(Service, SRV) \ + SUB(Service, FS) \ + SUB(Service, APT) \ + SUB(Service, GSP) \ + SUB(Service, AC) \ + SUB(Service, PTM) \ + SUB(Service, CFG) \ + SUB(Service, DSP) \ + SUB(Service, HID) \ + CLS(HW) \ + SUB(HW, Memory) \ + SUB(HW, GPU) \ + CLS(Frontend) \ + CLS(Render) \ + SUB(Render, Software) \ + SUB(Render, OpenGL) \ + CLS(Loader) + +Logger::Logger() { + // Register logging classes so that they can be queried at runtime + size_t parent_class; + all_classes.reserve((size_t)Class::Count); + +#define CLS(x) \ + all_classes.push_back(Class::x); \ + parent_class = all_classes.size() - 1; +#define SUB(x, y) \ + all_classes.push_back(Class::x##_##y); \ + all_classes[parent_class].num_children += 1; + + ALL_LOG_CLASSES() +#undef CLS +#undef SUB + + // Ensures that ALL_LOG_CLASSES isn't missing any entries. + _dbg_assert_(Log, all_classes.size() == (size_t)Class::Count); +} + +// GetClassName is a macro defined by Windows.h, grrr... +const char* Logger::GetLogClassName(Class log_class) { + switch (log_class) { +#define CLS(x) case Class::x: return #x; +#define SUB(x, y) case Class::x##_##y: return #x "." #y; + ALL_LOG_CLASSES() +#undef CLS +#undef SUB + } + return "Unknown"; +} + +const char* Logger::GetLevelName(Level log_level) { +#define LVL(x) case Level::x: return #x + switch (log_level) { + LVL(Trace); + LVL(Debug); + LVL(Info); + LVL(Warning); + LVL(Error); + LVL(Critical); + } + return "Unknown"; +#undef LVL +} + +void Logger::LogMessage(Entry entry) { + ring_buffer.Push(std::move(entry)); +} + +size_t Logger::GetEntries(Entry* out_buffer, size_t buffer_len) { + return ring_buffer.BlockingPop(out_buffer, buffer_len); +} + +std::shared_ptr InitGlobalLogger() { + global_logger = std::make_shared(); + return global_logger; +} + +Entry CreateEntry(Class log_class, Level log_level, + const char* filename, unsigned int line_nr, const char* function, + const char* format, va_list args) { + using std::chrono::steady_clock; + using std::chrono::duration_cast; + + static steady_clock::time_point time_origin = steady_clock::now(); + + std::array formatting_buffer; + + Entry entry; + entry.timestamp = duration_cast(steady_clock::now() - time_origin); + entry.log_class = log_class; + entry.log_level = log_level; + + snprintf(formatting_buffer.data(), formatting_buffer.size(), "%s:%s:%u", filename, function, line_nr); + entry.location = std::string(formatting_buffer.data()); + + vsnprintf(formatting_buffer.data(), formatting_buffer.size(), format, args); + entry.message = std::string(formatting_buffer.data()); + + return std::move(entry); +} + +void LogMessage(Class log_class, Level log_level, + const char* filename, unsigned int line_nr, const char* function, + const char* format, ...) { + va_list args; + va_start(args, format); + Entry entry = CreateEntry(log_class, log_level, + filename, line_nr, function, format, args); + va_end(args); + + if (global_logger != nullptr && !global_logger->IsClosed()) { + global_logger->LogMessage(std::move(entry)); + } else { + // Fall back to directly printing to stderr + PrintMessage(entry); + } +} + +} diff --git a/src/common/logging/backend.h b/src/common/logging/backend.h new file mode 100644 index 00000000..ae270efe --- /dev/null +++ b/src/common/logging/backend.h @@ -0,0 +1,134 @@ +// Copyright 2014 Citra Emulator Project +// Licensed under GPLv2+ +// Refer to the license.txt file included. + +#pragma once + +#include +#include +#include + +#include "common/concurrent_ring_buffer.h" + +#include "common/logging/log.h" + +namespace Log { + +/** + * A log entry. Log entries are store in a structured format to permit more varied output + * formatting on different frontends, as well as facilitating filtering and aggregation. + */ +struct Entry { + std::chrono::microseconds timestamp; + Class log_class; + Level log_level; + std::string location; + std::string message; + + Entry() = default; + + // TODO(yuriks) Use defaulted move constructors once MSVC supports them +#define MOVE(member) member(std::move(o.member)) + Entry(Entry&& o) + : MOVE(timestamp), MOVE(log_class), MOVE(log_level), + MOVE(location), MOVE(message) + {} +#undef MOVE + + Entry& operator=(const Entry&& o) { +#define MOVE(member) member = std::move(o.member) + MOVE(timestamp); + MOVE(log_class); + MOVE(log_level); + MOVE(location); + MOVE(message); +#undef MOVE + return *this; + } +}; + +struct ClassInfo { + Class log_class; + + /** + * Total number of (direct or indirect) sub classes this class has. If any, they follow in + * sequence after this class in the class list. + */ + unsigned int num_children = 0; + + ClassInfo(Class log_class) : log_class(log_class) {} +}; + +/** + * Logging management class. This class has the dual purpose of acting as an exchange point between + * the logging clients and the log outputter, as well as containing reflection info about available + * log classes. + */ +class Logger { +private: + using Buffer = Common::ConcurrentRingBuffer; + +public: + static const size_t QUEUE_CLOSED = Buffer::QUEUE_CLOSED; + + Logger(); + + /** + * Returns a list of all vector classes and subclasses. The sequence returned is a pre-order of + * classes and subclasses, which together with the `num_children` field in ClassInfo, allows + * you to recover the hierarchy. + */ + const std::vector& GetClasses() const { return all_classes; } + + /** + * Returns the name of the passed log class as a C-string. Subclasses are separated by periods + * instead of underscores as in the enumeration. + */ + static const char* GetLogClassName(Class log_class); + + /** + * Returns the name of the passed log level as a C-string. + */ + static const char* GetLevelName(Level log_level); + + /** + * Appends a messages to the log buffer. + * @note This function is thread safe. + */ + void LogMessage(Entry entry); + + /** + * Retrieves a batch of messages from the log buffer, blocking until they are available. + * @note This function is thread safe. + * + * @param out_buffer Destination buffer that will receive the log entries. + * @param buffer_len The maximum size of `out_buffer`. + * @return The number of entries stored. In case the logger is shutting down, `QUEUE_CLOSED` is + * returned, no entries are stored and the logger should shutdown. + */ + size_t GetEntries(Entry* out_buffer, size_t buffer_len); + + /** + * Initiates a shutdown of the logger. This will indicate to log output clients that they + * should shutdown. + */ + void Close() { ring_buffer.Close(); } + + /** + * Returns true if Close() has already been called on the Logger. + */ + bool IsClosed() const { return ring_buffer.IsClosed(); } + +private: + Buffer ring_buffer; + std::vector all_classes; +}; + +/// Creates a log entry by formatting the given source location, and message. +Entry CreateEntry(Class log_class, Level log_level, + const char* filename, unsigned int line_nr, const char* function, + const char* format, va_list args); +/// Initializes the default Logger. +std::shared_ptr InitGlobalLogger(); + +} diff --git a/src/common/logging/log.h b/src/common/logging/log.h new file mode 100644 index 00000000..1eec34fb --- /dev/null +++ b/src/common/logging/log.h @@ -0,0 +1,115 @@ +// Copyright 2014 Citra Emulator Project +// Licensed under GPLv2+ +// Refer to the license.txt file included. + +#pragma once + +#include +#include +#include + +#include "common/common_types.h" + +namespace Log { + +/// Specifies the severity or level of detail of the log message. +enum class Level : u8 { + Trace, ///< Extremely detailed and repetitive debugging information that is likely to + /// pollute logs. + Debug, ///< Less detailed debugging information. + Info, ///< Status information from important points during execution. + Warning, ///< Minor or potential problems found during execution of a task. + Error, ///< Major problems found during execution of a task that prevent it from being + /// completed. + Critical, ///< Major problems during execution that threathen the stability of the entire + /// application. + + Count ///< Total number of logging levels +}; + +typedef u8 ClassType; + +/** + * Specifies the sub-system that generated the log message. + * + * @note If you add a new entry here, also add a corresponding one to `ALL_LOG_CLASSES` in log.cpp. + */ +enum class Class : ClassType { + Log, ///< Messages about the log system itself + Common, ///< Library routines + Common_Filesystem, ///< Filesystem interface library + Common_Memory, ///< Memory mapping and management functions + Core, ///< LLE emulation core + Core_ARM11, ///< ARM11 CPU core + Config, ///< Emulator configuration (including commandline) + Debug, ///< Debugging tools + Debug_Emulated, ///< Debug messages from the emulated programs + Debug_GPU, ///< GPU debugging tools + Debug_Breakpoint, ///< Logging breakpoints and watchpoints + Kernel, ///< The HLE implementation of the CTR kernel + Kernel_SVC, ///< Kernel system calls + Service, ///< HLE implementation of system services. Each major service + /// should have its own subclass. + Service_SRV, ///< The SRV (Service Directory) implementation + Service_FS, ///< The FS (Filesystem) service implementation + Service_APT, ///< The APT (Applets) service + Service_GSP, ///< The GSP (GPU control) service + Service_AC, ///< The AC (WiFi status) service + Service_PTM, ///< The PTM (Power status & misc.) service + Service_CFG, ///< The CFG (Configuration) service + Service_DSP, ///< The DSP (DSP control) service + Service_HID, ///< The HID (User input) service + HW, ///< Low-level hardware emulation + HW_Memory, ///< Memory-map and address translation + HW_GPU, ///< GPU control emulation + Frontend, ///< Emulator UI + Render, ///< Emulator video output and hardware acceleration + Render_Software, ///< Software renderer backend + Render_OpenGL, ///< OpenGL backend + Loader, ///< ROM loader + + Count ///< Total number of logging classes +}; + +/** + * Level below which messages are simply discarded without buffering regardless of the display + * settings. + */ +const Level MINIMUM_LEVEL = +#ifdef _DEBUG + Level::Trace; +#else + Level::Debug; +#endif + +/** + * Logs a message to the global logger. This proxy exists to avoid exposing the details of the + * Logger class, including the ConcurrentRingBuffer template, to all files that desire to log + * messages, reducing unecessary recompilations. + */ +void LogMessage(Class log_class, Level log_level, + const char* filename, unsigned int line_nr, const char* function, +#ifdef _MSC_VER + _Printf_format_string_ +#endif + const char* format, ...) +#ifdef __GNUC__ + __attribute__((format(printf, 6, 7))) +#endif + ; + +} // namespace Log + +#define LOG_GENERIC(log_class, log_level, ...) \ + do { \ + if (::Log::Level::log_level >= ::Log::MINIMUM_LEVEL) \ + ::Log::LogMessage(::Log::Class::log_class, ::Log::Level::log_level, \ + __FILE__, __LINE__, __func__, __VA_ARGS__); \ + } while (0) + +#define LOG_TRACE( log_class, ...) LOG_GENERIC(log_class, Trace, __VA_ARGS__) +#define LOG_DEBUG( log_class, ...) LOG_GENERIC(log_class, Debug, __VA_ARGS__) +#define LOG_INFO( log_class, ...) LOG_GENERIC(log_class, Info, __VA_ARGS__) +#define LOG_WARNING( log_class, ...) LOG_GENERIC(log_class, Warning, __VA_ARGS__) +#define LOG_ERROR( log_class, ...) LOG_GENERIC(log_class, Error, __VA_ARGS__) +#define LOG_CRITICAL(log_class, ...) LOG_GENERIC(log_class, Critical, __VA_ARGS__) diff --git a/src/common/logging/text_formatter.cpp b/src/common/logging/text_formatter.cpp new file mode 100644 index 00000000..01c355bb --- /dev/null +++ b/src/common/logging/text_formatter.cpp @@ -0,0 +1,47 @@ +// Copyright 2014 Citra Emulator Project +// Licensed under GPLv2+ +// Refer to the license.txt file included. + +#include +#include + +#include "common/logging/backend.h" +#include "common/logging/log.h" +#include "common/logging/text_formatter.h" + +namespace Log { + +void FormatLogMessage(const Entry& entry, char* out_text, size_t text_len) { + unsigned int time_seconds = static_cast(entry.timestamp.count() / 1000000); + unsigned int time_fractional = static_cast(entry.timestamp.count() % 1000000); + + const char* class_name = Logger::GetLogClassName(entry.log_class); + const char* level_name = Logger::GetLevelName(entry.log_level); + + snprintf(out_text, text_len, "[%4u.%06u] %s <%s> %s: %s", + time_seconds, time_fractional, class_name, level_name, + entry.location.c_str(), entry.message.c_str()); +} + +void PrintMessage(const Entry& entry) { + std::array format_buffer; + FormatLogMessage(entry, format_buffer.data(), format_buffer.size()); + fputs(format_buffer.data(), stderr); + fputc('\n', stderr); +} + +void TextLoggingLoop(std::shared_ptr logger) { + std::array entry_buffer; + + while (true) { + size_t num_entries = logger->GetEntries(entry_buffer.data(), entry_buffer.size()); + if (num_entries == Logger::QUEUE_CLOSED) { + break; + } + for (size_t i = 0; i < num_entries; ++i) { + PrintMessage(entry_buffer[i]); + } + } +} + +} diff --git a/src/common/logging/text_formatter.h b/src/common/logging/text_formatter.h new file mode 100644 index 00000000..6c2a6f1e --- /dev/null +++ b/src/common/logging/text_formatter.h @@ -0,0 +1,26 @@ +// Copyright 2014 Citra Emulator Project +// Licensed under GPLv2+ +// Refer to the license.txt file included. + +#pragma once + +#include +#include + +namespace Log { + +class Logger; +struct Entry; + +/// Formats a log entry into the provided text buffer. +void FormatLogMessage(const Entry& entry, char* out_text, size_t text_len); +/// Formats and prints a log entry to stderr. +void PrintMessage(const Entry& entry); + +/** + * Logging loop that repeatedly reads messages from the provided logger and prints them to the + * console. It is the baseline barebones log outputter. + */ +void TextLoggingLoop(std::shared_ptr logger); + +} -- cgit v1.2.3