Logging: Add customizable logging backends and fmtlib based macros

* Change the logging backend to support multiple sinks through the
Backend Interface
* Add a new set of logging macros to use fmtlib instead.
* Qt: Compile as GUI application on windows to make the console hidden by
default. Add filter configuration and a button to open log location.
* SDL: Migrate to the new logging macros
This commit is contained in:
Daniel Lim Wee Soong 2018-02-19 17:51:27 -07:00 committed by James Rowe
parent 7d8b7d93fc
commit 51398e0301
17 changed files with 405 additions and 24 deletions

View file

@ -257,7 +257,12 @@ int main(int argc, char** argv) {
Log::Filter log_filter;
log_filter.ParseFilterString(Settings::values.log_filter);
Log::SetFilter(&log_filter);
Log::SetGlobalFilter(log_filter);
Log::AddBackend(std::make_unique<Log::ColorConsoleBackend>());
FileUtil::CreateFullPath(FileUtil::GetUserPath(D_LOGS_IDX));
Log::AddBackend(
std::make_unique<Log::FileBackend>(FileUtil::GetUserPath(D_LOGS_IDX) + LOG_FILE));
// Apply the command line arguments
Settings::values.gdbstub_port = gdb_port;

View file

@ -28,6 +28,8 @@ add_executable(citra-qt
configuration/configure_system.h
configuration/configure_web.cpp
configuration/configure_web.h
debugger/console.h
debugger/console.cpp
debugger/graphics/graphics.cpp
debugger/graphics/graphics.h
debugger/graphics/graphics_breakpoint_observer.cpp
@ -165,6 +167,14 @@ if (APPLE)
target_sources(citra-qt PRIVATE ${MACOSX_ICON})
set_target_properties(citra-qt PROPERTIES MACOSX_BUNDLE TRUE)
set_target_properties(citra-qt PROPERTIES MACOSX_BUNDLE_INFO_PLIST ${CMAKE_CURRENT_SOURCE_DIR}/Info.plist)
elseif(WIN32)
# compile as a win32 gui application instead of a console application
target_link_libraries(citra-qt PRIVATE Qt5::WinMain)
if(MSVC)
set_target_properties(citra-qt PROPERTIES LINK_FLAGS_RELEASE "/SUBSYSTEM:WINDOWS")
elseif(MINGW)
set_target_properties(citra-qt PROPERTIES LINK_FLAGS_RELEASE "-mwindows")
endif()
endif()
create_target_directory_groups(citra-qt)

View file

@ -231,6 +231,7 @@ void Config::ReadValues() {
UISettings::values.confirm_before_closing = qt_config->value("confirmClose", true).toBool();
UISettings::values.first_start = qt_config->value("firstStart", true).toBool();
UISettings::values.callout_flags = qt_config->value("calloutFlags", 0).toUInt();
UISettings::values.show_console = qt_config->value("showConsole", false).toBool();
qt_config->beginGroup("Multiplayer");
UISettings::values.nickname = qt_config->value("nickname", "").toString();
@ -391,6 +392,7 @@ void Config::SaveValues() {
qt_config->setValue("confirmClose", UISettings::values.confirm_before_closing);
qt_config->setValue("firstStart", UISettings::values.first_start);
qt_config->setValue("calloutFlags", UISettings::values.callout_flags);
qt_config->setValue("showConsole", UISettings::values.show_console);
qt_config->beginGroup("Multiplayer");
qt_config->setValue("nickname", UISettings::values.nickname);

View file

@ -2,13 +2,26 @@
// Licensed under GPLv2 or any later version
// Refer to the license.txt file included.
#include <QDesktopServices>
#include <QUrl>
#include "citra_qt/configuration/configure_debug.h"
#include "citra_qt/debugger/console.h"
#include "citra_qt/ui_settings.h"
#include "common/file_util.h"
#include "common/logging/backend.h"
#include "common/logging/filter.h"
#include "common/logging/log.h"
#include "core/core.h"
#include "core/settings.h"
#include "ui_configure_debug.h"
ConfigureDebug::ConfigureDebug(QWidget* parent) : QWidget(parent), ui(new Ui::ConfigureDebug) {
ui->setupUi(this);
this->setConfiguration();
connect(ui->open_log_button, &QPushButton::pressed, []() {
QString path = QString::fromStdString(FileUtil::GetUserPath(D_LOGS_IDX));
QDesktopServices::openUrl(QUrl::fromLocalFile(path));
});
}
ConfigureDebug::~ConfigureDebug() {}
@ -17,11 +30,20 @@ void ConfigureDebug::setConfiguration() {
ui->toggle_gdbstub->setChecked(Settings::values.use_gdbstub);
ui->gdbport_spinbox->setEnabled(Settings::values.use_gdbstub);
ui->gdbport_spinbox->setValue(Settings::values.gdbstub_port);
ui->toggle_console->setEnabled(!Core::System::GetInstance().IsPoweredOn());
ui->toggle_console->setChecked(UISettings::values.show_console);
ui->log_filter_edit->setText(QString::fromStdString(Settings::values.log_filter));
}
void ConfigureDebug::applyConfiguration() {
Settings::values.use_gdbstub = ui->toggle_gdbstub->isChecked();
Settings::values.gdbstub_port = ui->gdbport_spinbox->value();
UISettings::values.show_console = ui->toggle_console->isChecked();
Settings::values.log_filter = ui->log_filter_edit->text().toStdString();
Debugger::ToggleConsole();
Log::Filter filter;
filter.ParseFilterString(Settings::values.log_filter);
Log::SetGlobalFilter(filter);
Settings::Apply();
}

View file

@ -72,6 +72,47 @@
</item>
</layout>
</item>
<item>
<widget class="QGroupBox" name="groupBox_2">
<property name="title">
<string>Logging</string>
</property>
<layout class="QVBoxLayout" name="verticalLayout">
<item>
<layout class="QHBoxLayout" name="horizontalLayout">
<item>
<widget class="QLabel" name="label">
<property name="text">
<string>Global Log Filter</string>
</property>
</widget>
</item>
<item>
<widget class="QLineEdit" name="log_filter_edit"/>
</item>
</layout>
</item>
<item>
<layout class="QHBoxLayout" name="horizontalLayout_2">
<item>
<widget class="QCheckBox" name="toggle_console">
<property name="text">
<string>Show Log Console (Windows Only)</string>
</property>
</widget>
</item>
<item>
<widget class="QPushButton" name="open_log_button">
<property name="text">
<string>Open Log Location</string>
</property>
</widget>
</item>
</layout>
</item>
</layout>
</widget>
</item>
<item>
<spacer name="verticalSpacer">
<property name="orientation">

View file

@ -0,0 +1,39 @@
// Copyright 2018 Citra Emulator Project
// Licensed under GPLv2 or any later version
// Refer to the license.txt file included.
#ifdef _WIN32
#include <windows.h>
#include <wincon.h>
#endif
#include "citra_qt/debugger/console.h"
#include "citra_qt/ui_settings.h"
#include "common/logging/backend.h"
namespace Debugger {
void ToggleConsole() {
#ifdef _WIN32
FILE* temp;
if (UISettings::values.show_console) {
if (AllocConsole()) {
// The first parameter for freopen_s is a out parameter, so we can just ignore it
freopen_s(&temp, "CONIN$", "r", stdin);
freopen_s(&temp, "CONOUT$", "w", stdout);
freopen_s(&temp, "CONOUT$", "w", stderr);
Log::AddBackend(std::make_unique<Log::ColorConsoleBackend>());
}
} else {
if (FreeConsole()) {
// In order to close the console, we have to also detach the streams on it.
// Just redirect them to NUL if there is no console window
Log::RemoveBackend(Log::ColorConsoleBackend::Name());
freopen_s(&temp, "NUL", "r", stdin);
freopen_s(&temp, "NUL", "w", stdout);
freopen_s(&temp, "NUL", "w", stderr);
}
}
#endif
}
} // namespace Debugger

View file

@ -0,0 +1,14 @@
// Copyright 2018 Citra Emulator Project
// Licensed under GPLv2 or any later version
// Refer to the license.txt file included.
#pragma once
namespace Debugger {
/**
* Uses the WINAPI to hide or show the stderr console. This function is a placeholder until we can
* get a real qt logging window which would work for all platforms.
*/
void ToggleConsole();
} // namespace Debugger

View file

@ -19,6 +19,7 @@
#include "citra_qt/compatdb.h"
#include "citra_qt/configuration/config.h"
#include "citra_qt/configuration/configure_dialog.h"
#include "citra_qt/debugger/console.h"
#include "citra_qt/debugger/graphics/graphics.h"
#include "citra_qt/debugger/graphics/graphics_breakpoints.h"
#include "citra_qt/debugger/graphics/graphics_cmdlists.h"
@ -35,6 +36,7 @@
#include "citra_qt/ui_settings.h"
#include "citra_qt/updater/updater.h"
#include "citra_qt/util/clickable_label.h"
#include "common/common_paths.h"
#include "common/logging/backend.h"
#include "common/logging/filter.h"
#include "common/logging/log.h"
@ -387,6 +389,7 @@ void GMainWindow::RestoreUIState() {
ui.action_Show_Status_Bar->setChecked(UISettings::values.show_status_bar);
statusBar()->setVisible(ui.action_Show_Status_Bar->isChecked());
Debugger::ToggleConsole();
}
void GMainWindow::ConnectWidgetEvents() {
@ -1335,8 +1338,7 @@ void GMainWindow::SyncMenuUISettings() {
#endif
int main(int argc, char* argv[]) {
Log::Filter log_filter(Log::Level::Info);
Log::SetFilter(&log_filter);
Log::AddBackend(std::make_unique<Log::ColorConsoleBackend>());
MicroProfileOnThreadCreate("Frontend");
SCOPE_EXIT({ MicroProfileShutdown(); });
@ -1354,7 +1356,12 @@ int main(int argc, char* argv[]) {
GMainWindow main_window;
// After settings have been loaded by GMainWindow, apply the filter
Log::Filter log_filter;
log_filter.ParseFilterString(Settings::values.log_filter);
Log::SetGlobalFilter(log_filter);
FileUtil::CreateFullPath(FileUtil::GetUserPath(D_LOGS_IDX));
Log::AddBackend(
std::make_unique<Log::FileBackend>(FileUtil::GetUserPath(D_LOGS_IDX) + LOG_FILE));
main_window.show();
return app.exec();

View file

@ -67,6 +67,9 @@ struct Values {
QString room_port;
uint host_type;
qulonglong game_id;
// logging
bool show_console;
};
extern Values values;

View file

@ -36,8 +36,12 @@
#define SDMC_DIR "sdmc"
#define NAND_DIR "nand"
#define SYSDATA_DIR "sysdata"
#define LOG_DIR "log"
// Filenames
// Files in the directory returned by GetUserPath(D_LOGS_IDX)
#define LOG_FILE "citra_log.txt"
// Files in the directory returned by GetUserPath(D_CONFIG_IDX)
#define EMU_CONFIG "emu.ini"
#define DEBUGGER_CONFIG "debugger.ini"

View file

@ -713,6 +713,8 @@ const std::string& GetUserPath(const unsigned int DirIDX, const std::string& new
paths[D_SDMC_IDX] = paths[D_USER_IDX] + SDMC_DIR DIR_SEP;
paths[D_NAND_IDX] = paths[D_USER_IDX] + NAND_DIR DIR_SEP;
paths[D_SYSDATA_IDX] = paths[D_USER_IDX] + SYSDATA_DIR DIR_SEP;
// TODO: Put the logs in a better location for each OS
paths[D_LOGS_IDX] = paths[D_USER_IDX] + LOG_DIR DIR_SEP;
}
if (!newPath.empty()) {
@ -799,8 +801,8 @@ void SplitFilename83(const std::string& filename, std::array<char, 9>& short_nam
IOFile::IOFile() {}
IOFile::IOFile(const std::string& filename, const char openmode[]) {
Open(filename, openmode);
IOFile::IOFile(const std::string& filename, const char openmode[], int flags) {
Open(filename, openmode, flags);
}
IOFile::~IOFile() {
@ -821,11 +823,16 @@ void IOFile::Swap(IOFile& other) {
std::swap(m_good, other.m_good);
}
bool IOFile::Open(const std::string& filename, const char openmode[]) {
bool IOFile::Open(const std::string& filename, const char openmode[], int flags) {
Close();
#ifdef _WIN32
_wfopen_s(&m_file, Common::UTF8ToUTF16W(filename).c_str(),
Common::UTF8ToUTF16W(openmode).c_str());
if (flags != 0) {
m_file = _wfsopen(Common::UTF8ToUTF16W(filename).c_str(),
Common::UTF8ToUTF16W(openmode).c_str(), flags);
} else {
_wfopen_s(&m_file, Common::UTF8ToUTF16W(filename).c_str(),
Common::UTF8ToUTF16W(openmode).c_str());
}
#else
m_file = fopen(filename.c_str(), openmode);
#endif

View file

@ -156,7 +156,11 @@ void SplitFilename83(const std::string& filename, std::array<char, 9>& short_nam
class IOFile : public NonCopyable {
public:
IOFile();
IOFile(const std::string& filename, const char openmode[]);
// flags is used for windows specific file open mode flags, which
// allows citra to open the logs in shared write mode, so that the file
// isn't considered "locked" while citra is open and people can open the log file and view it
IOFile(const std::string& filename, const char openmode[], int flags = 0);
~IOFile();
@ -165,7 +169,7 @@ public:
void Swap(IOFile& other);
bool Open(const std::string& filename, const char openmode[]);
bool Open(const std::string& filename, const char openmode[], int flags = 0);
bool Close();
template <typename T>
@ -224,6 +228,10 @@ public:
return WriteArray(&object, 1);
}
size_t WriteString(const std::string& str) {
return WriteArray(str.c_str(), str.length());
}
bool IsOpen() const {
return nullptr != m_file;
}

View file

@ -4,17 +4,144 @@
#include <algorithm>
#include <array>
#include <chrono>
#include <condition_variable>
#include <cstdio>
#include <memory>
#include <thread>
#ifdef _WIN32
#include <share.h> // For _SH_DENYWR
#else
#define _SH_DENYWR 0
#endif
#include "common/assert.h"
#include "common/common_funcs.h" // snprintf compatibility define
#include "common/logging/backend.h"
#include "common/logging/filter.h"
#include "common/logging/log.h"
#include "common/logging/text_formatter.h"
#include "common/string_util.h"
#include "common/threadsafe_queue.h"
namespace Log {
/**
* Static state as a singleton.
*/
class Impl {
public:
static Impl& Instance() {
static Impl backend;
return backend;
}
Impl(Impl const&) = delete;
const Impl& operator=(Impl const&) = delete;
void PushEntry(Entry e) {
std::lock_guard<std::mutex> lock(message_mutex);
message_queue.Push(std::move(e));
message_cv.notify_one();
}
void AddBackend(std::unique_ptr<Backend> backend) {
std::lock_guard<std::mutex> lock(writing_mutex);
backends.push_back(std::move(backend));
}
void RemoveBackend(const std::string& backend_name) {
std::lock_guard<std::mutex> lock(writing_mutex);
auto it = std::remove_if(backends.begin(), backends.end(), [&backend_name](const auto& i) {
return !strcmp(i->GetName(), backend_name.c_str());
});
backends.erase(it, backends.end());
}
const Filter& GetGlobalFilter() const {
return filter;
}
void SetGlobalFilter(const Filter& f) {
filter = f;
}
Backend* GetBackend(const std::string& backend_name) {
auto it = std::find_if(backends.begin(), backends.end(), [&backend_name](const auto& i) {
return !strcmp(i->GetName(), backend_name.c_str());
});
if (it == backends.end())
return nullptr;
return it->get();
}
private:
Impl() {
backend_thread = std::thread([&] {
Entry entry;
auto write_logs = [&](Entry& e) {
std::lock_guard<std::mutex> lock(writing_mutex);
for (const auto& backend : backends) {
backend->Write(e);
}
};
while (true) {
std::unique_lock<std::mutex> lock(message_mutex);
message_cv.wait(lock, [&] { return !running || message_queue.Pop(entry); });
if (!running) {
break;
}
write_logs(entry);
}
// Drain the logging queue. Only writes out up to MAX_LOGS_TO_WRITE to prevent a case
// where a system is repeatedly spamming logs even on close.
constexpr int MAX_LOGS_TO_WRITE = 100;
int logs_written = 0;
while (logs_written++ < MAX_LOGS_TO_WRITE && message_queue.Pop(entry)) {
write_logs(entry);
}
});
}
~Impl() {
running = false;
message_cv.notify_one();
backend_thread.join();
}
std::atomic_bool running{true};
std::mutex message_mutex, writing_mutex;
std::condition_variable message_cv;
std::thread backend_thread;
std::vector<std::unique_ptr<Backend>> backends;
Common::MPSCQueue<Log::Entry> message_queue;
Filter filter;
};
void ConsoleBackend::Write(const Entry& entry) {
PrintMessage(entry);
}
void ColorConsoleBackend::Write(const Entry& entry) {
PrintColoredMessage(entry);
}
// _SH_DENYWR allows read only access to the file for other programs.
// It is #defined to 0 on other platforms
FileBackend::FileBackend(const std::string& filename)
: file(filename, "w", _SH_DENYWR), bytes_written(0) {}
void FileBackend::Write(const Entry& entry) {
// prevent logs from going over the maximum size (in case its spamming and the user doesn't
// know)
constexpr size_t MAX_BYTES_WRITTEN = 50 * 1024L * 1024L;
if (!file.IsOpen() || bytes_written > MAX_BYTES_WRITTEN) {
return;
}
bytes_written += file.WriteString(FormatLogMessage(entry) + '\n');
if (entry.log_level >= Level::Error) {
file.Flush();
}
}
/// Macro listing all log classes. Code should define CLS and SUB as desired before invoking this.
#define ALL_LOG_CLASSES() \
CLS(Log) \
@ -132,15 +259,26 @@ Entry CreateEntry(Class log_class, Level log_level, const char* filename, unsign
return entry;
}
static Filter* filter = nullptr;
void SetGlobalFilter(const Filter& filter) {
Impl::Instance().SetGlobalFilter(filter);
}
void SetFilter(Filter* new_filter) {
filter = new_filter;
void AddBackend(std::unique_ptr<Backend> backend) {
Impl::Instance().AddBackend(std::move(backend));
}
void RemoveBackend(const std::string& backend_name) {
Impl::Instance().RemoveBackend(backend_name);
}
Backend* GetBackend(const std::string& backend_name) {
return Impl::Instance().GetBackend(backend_name);
}
void LogMessage(Class log_class, Level log_level, const char* filename, unsigned int line_num,
const char* function, const char* format, ...) {
if (filter && !filter->CheckMessage(log_class, log_level))
auto filter = Impl::Instance().GetGlobalFilter();
if (!filter.CheckMessage(log_class, log_level))
return;
std::array<char, 4 * 1024> formatting_buffer;
va_list args;
@ -150,17 +288,19 @@ void LogMessage(Class log_class, Level log_level, const char* filename, unsigned
Entry entry = CreateEntry(log_class, log_level, filename, line_num, function,
std::string(formatting_buffer.data()));
PrintColoredMessage(entry);
Impl::Instance().PushEntry(std::move(entry));
}
void FmtLogMessageImpl(Class log_class, Level log_level, const char* filename,
unsigned int line_num, const char* function, const char* format,
const fmt::format_args& args) {
if (filter && !filter->CheckMessage(log_class, log_level))
auto filter = Impl::Instance().GetGlobalFilter();
if (!filter.CheckMessage(log_class, log_level))
return;
Entry entry =
CreateEntry(log_class, log_level, filename, line_num, function, fmt::vformat(format, args));
PrintColoredMessage(entry);
Impl::Instance().PushEntry(std::move(entry));
}
} // namespace Log

View file

@ -6,8 +6,11 @@
#include <chrono>
#include <cstdarg>
#include <memory>
#include <string>
#include <utility>
#include "common/file_util.h"
#include "common/logging/filter.h"
#include "common/logging/log.h"
namespace Log {
@ -34,6 +37,80 @@ struct Entry {
Entry& operator=(const Entry& o) = default;
};
/**
* Interface for logging backends. As loggers can be created and removed at runtime, this can be
* used by a frontend for adding a custom logging backend as needed
*/
class Backend {
public:
virtual ~Backend() = default;
virtual void SetFilter(const Filter& new_filter) {
filter = new_filter;
}
virtual const char* GetName() const = 0;
virtual void Write(const Entry& entry) = 0;
private:
Filter filter;
};
/**
* Backend that writes to stderr without any color commands
*/
class ConsoleBackend : public Backend {
public:
static const char* Name() {
return "console";
}
const char* GetName() const override {
return Name();
}
void Write(const Entry& entry) override;
};
/**
* Backend that writes to stderr and with color
*/
class ColorConsoleBackend : public Backend {
public:
static const char* Name() {
return "color_console";
}
const char* GetName() const override {
return Name();
}
void Write(const Entry& entry) override;
};
/**
* Backend that writes to a file passed into the constructor
*/
class FileBackend : public Backend {
public:
explicit FileBackend(const std::string& filename);
static const char* Name() {
return "file";
}
const char* GetName() const override {
return Name();
}
void Write(const Entry& entry) override;
private:
FileUtil::IOFile file;
size_t bytes_written;
};
void AddBackend(std::unique_ptr<Backend> backend);
void RemoveBackend(const std::string& backend_name);
Backend* GetBackend(const std::string& backend_name);
/**
* Returns the name of the passed log class as a C-string. Subclasses are separated by periods
* instead of underscores as in the enumeration.
@ -49,5 +126,10 @@ const char* GetLevelName(Level log_level);
Entry CreateEntry(Class log_class, Level log_level, const char* filename, unsigned int line_nr,
const char* function, std::string message);
void SetFilter(Filter* filter);
/**
* The global filter will prevent any messages from even being processed if they are filtered. Each
* backend can have a filter, but if the level is lower than the global filter, the backend will
* never get the message
*/
void SetGlobalFilter(const Filter& filter);
} // namespace Log

View file

@ -484,5 +484,4 @@ const char* TrimSourcePath(const char* path, const char* root) {
}
return path;
}
} // namespace Common

View file

@ -4,14 +4,13 @@
#include "audio_core/dsp_interface.h"
#include "core/core.h"
#include "core/frontend/emu_window.h"
#include "core/gdbstub/gdbstub.h"
#include "core/hle/service/hid/hid.h"
#include "core/hle/service/ir/ir.h"
#include "core/settings.h"
#include "video_core/video_core.h"
#include "core/frontend/emu_window.h"
namespace Settings {
Values values = {};

View file

@ -129,8 +129,6 @@ struct Values {
float bg_green;
float bg_blue;
std::string log_filter;
// Audio
std::string sink_id;
bool enable_audio_stretching;
@ -143,6 +141,7 @@ struct Values {
// Debugging
bool use_gdbstub;
u16 gdbstub_port;
std::string log_filter;
// Movie
std::string movie_play;