Logging: Don't overwrite LDEBUG verbosity in Release builds

Preserve the configured logging verbosity unless the user actually
changes it, rather than capping it to LINFO on release builds.

Rename LogManager::m_level to m_effective_level and distinguish between
the config and effective level in various function/variable names.

Make m_effective_level atomic to prevent data races when setting the
effective log level from the config changed callback.
This commit is contained in:
Dentomologist 2025-09-11 16:38:07 -07:00
parent 79614956f3
commit 2d48043b61
7 changed files with 96 additions and 50 deletions

View File

@ -419,7 +419,7 @@ Java_org_dolphinemu_dolphinemu_NativeLibrary_GetDefaultGraphicsBackendConfigName
JNIEXPORT jint JNICALL Java_org_dolphinemu_dolphinemu_NativeLibrary_GetMaxLogLevel(JNIEnv*, jclass)
{
return static_cast<jint>(Common::Log::MAX_LOGLEVEL);
return static_cast<jint>(Common::Log::MAX_EFFECTIVE_LOGLEVEL);
}
JNIEXPORT void JNICALL Java_org_dolphinemu_dolphinemu_NativeLibrary_WipeJitBlockProfilingData(

View File

@ -25,7 +25,7 @@
#define DEBUG_ASSERT_MSG(_t_, _a_, _fmt_, ...) \
do \
{ \
if constexpr (Common::Log::MAX_LOGLEVEL >= Common::Log::LogLevel::LDEBUG) \
if constexpr (Common::Log::MAX_EFFECTIVE_LOGLEVEL >= Common::Log::LogLevel::LDEBUG) \
ASSERT_MSG(_t_, _a_, _fmt_ __VA_OPT__(, ) __VA_ARGS__); \
} while (0)
@ -45,6 +45,6 @@
#define DEBUG_ASSERT(_a_) \
do \
{ \
if constexpr (Common::Log::MAX_LOGLEVEL >= Common::Log::LogLevel::LDEBUG) \
if constexpr (Common::Log::MAX_EFFECTIVE_LOGLEVEL >= Common::Log::LogLevel::LDEBUG) \
ASSERT(_a_); \
} while (0)

View File

@ -82,9 +82,9 @@ enum class LogLevel : int
};
#if defined(_DEBUG) || defined(DEBUGFAST)
constexpr auto MAX_LOGLEVEL = Common::Log::LogLevel::LDEBUG;
constexpr auto MAX_EFFECTIVE_LOGLEVEL = Common::Log::LogLevel::LDEBUG;
#else
constexpr auto MAX_LOGLEVEL = Common::Log::LogLevel::LINFO;
constexpr auto MAX_EFFECTIVE_LOGLEVEL = Common::Log::LogLevel::LINFO;
#endif // logging
static const char LOG_LEVEL_TO_CHAR[7] = "-NEWID";
@ -114,7 +114,7 @@ void GenericLogFmt(LogLevel level, LogType type, const char* file, int line, con
#define GENERIC_LOG_FMT(t, v, format, ...) \
do \
{ \
if (v <= Common::Log::MAX_LOGLEVEL) \
if (v <= Common::Log::MAX_EFFECTIVE_LOGLEVEL) \
{ \
/* Use a macro-like name to avoid shadowing warnings */ \
constexpr auto GENERIC_LOG_FMT_N = Common::CountFmtReplacementFields(format); \

View File

@ -4,6 +4,7 @@
#include "Common/Logging/LogManager.h"
#include <algorithm>
#include <atomic>
#include <chrono>
#include <cstdarg>
#include <cstring>
@ -156,9 +157,7 @@ LogManager::LogManager()
RegisterListener(LogListener::CONSOLE_LISTENER, std::make_unique<ConsoleListener>());
// Set up log listeners
LogLevel verbosity = Config::Get(LOGGER_VERBOSITY);
SetLogLevel(verbosity);
SetEffectiveLogLevel();
EnableListener(LogListener::FILE_LISTENER, Config::Get(LOGGER_WRITE_TO_FILE));
EnableListener(LogListener::CONSOLE_LISTENER, Config::Get(LOGGER_WRITE_TO_CONSOLE));
EnableListener(LogListener::LOG_WINDOW_LISTENER, Config::Get(LOGGER_WRITE_TO_WINDOW));
@ -170,9 +169,15 @@ LogManager::LogManager()
}
m_path_cutoff_point = DeterminePathCutOffPoint();
m_config_changed_callback_id =
Config::AddConfigChangedCallback([this]() { SetEffectiveLogLevel(); });
}
LogManager::~LogManager() = default;
LogManager::~LogManager()
{
Config::RemoveConfigChangedCallback(m_config_changed_callback_id);
}
void LogManager::SaveSettings()
{
@ -183,7 +188,6 @@ void LogManager::SaveSettings()
IsListenerEnabled(LogListener::CONSOLE_LISTENER));
Config::SetBaseOrCurrent(LOGGER_WRITE_TO_WINDOW,
IsListenerEnabled(LogListener::LOG_WINDOW_LISTENER));
Config::SetBaseOrCurrent(LOGGER_VERBOSITY, GetLogLevel());
for (const auto& container : m_log)
{
@ -228,14 +232,22 @@ void LogManager::LogWithFullPath(LogLevel level, LogType type, const char* file,
}
}
LogLevel LogManager::GetLogLevel() const
LogLevel LogManager::GetEffectiveLogLevel() const
{
return m_level;
return m_effective_level.load(std::memory_order_relaxed);
}
void LogManager::SetLogLevel(LogLevel level)
void LogManager::SetConfigLogLevel(const LogLevel level)
{
m_level = std::clamp(level, LogLevel::LNOTICE, MAX_LOGLEVEL);
Config::SetBaseOrCurrent(LOGGER_VERBOSITY, level);
SetEffectiveLogLevel();
}
void LogManager::SetEffectiveLogLevel()
{
const LogLevel clamped_level =
std::clamp(Config::Get(LOGGER_VERBOSITY), LogLevel::LNOTICE, MAX_EFFECTIVE_LOGLEVEL);
m_effective_level.store(clamped_level, std::memory_order_relaxed);
}
void LogManager::SetEnable(LogType type, bool enable)
@ -245,7 +257,7 @@ void LogManager::SetEnable(LogType type, bool enable)
bool LogManager::IsEnabled(LogType type, LogLevel level) const
{
return m_log[type].m_enable && GetLogLevel() >= level;
return m_log[type].m_enable && GetEffectiveLogLevel() >= level;
}
std::vector<LogManager::LogContainer> LogManager::GetLogTypes()

View File

@ -4,17 +4,25 @@
#pragma once
#include <array>
#include <atomic>
#include <cstdarg>
#include <memory>
#include <string>
#include <vector>
#include "Common/BitSet.h"
#include "Common/Config/Config.h"
#include "Common/EnumMap.h"
#include "Common/Logging/Log.h"
namespace Common::Log
{
// This variable should only be read to update the effective log level, and its base layer should
// only be set when the user selects a new verbosity. Everything else should use the effective log
// level instead. When running a release build this prevents overwriting the LDEBUG config value
// with the clamped LINFO level.
extern const Config::Info<LogLevel> LOGGER_VERBOSITY;
// pure virtual interface
class LogListener
{
@ -52,8 +60,9 @@ public:
void LogWithFullPath(LogLevel level, LogType type, const char* file, int line,
const char* message);
LogLevel GetLogLevel() const;
void SetLogLevel(LogLevel level);
// Use this function instead of LOGGER_VERBOSITY to determine which logs should be printed.
LogLevel GetEffectiveLogLevel() const;
void SetConfigLogLevel(LogLevel level);
void SetEnable(LogType type, bool enable);
bool IsEnabled(LogType type, LogLevel level = LogLevel::LNOTICE) const;
@ -78,8 +87,10 @@ private:
LogManager& operator=(LogManager&&) = delete;
static std::string GetTimestamp();
void SetEffectiveLogLevel();
LogLevel m_level;
std::atomic<LogLevel> m_effective_level;
Config::ConfigChangedCallbackID m_config_changed_callback_id;
EnumMap<LogContainer, LAST_LOG_TYPE> m_log{};
std::array<std::unique_ptr<LogListener>, LogListener::NUMBER_OF_LISTENERS> m_listeners{};
BitSet32 m_listener_ids;

View File

@ -329,8 +329,11 @@ static void VLogInfo(std::string_view format, fmt::format_args args)
return;
const bool use_internal_log = s_use_internal_log.load(std::memory_order_relaxed);
if (Common::Log::MAX_LOGLEVEL < Common::Log::LogLevel::LINFO && !use_internal_log)
return;
if constexpr (Common::Log::MAX_EFFECTIVE_LOGLEVEL < Common::Log::LogLevel::LINFO)
{
if (!use_internal_log)
return;
}
std::string text = fmt::vformat(format, args);
INFO_LOG_FMT(ACTIONREPLAY, "{}", text);

View File

@ -3,6 +3,8 @@
#include "DolphinQt/Config/LogConfigWidget.h"
#include <array>
#include <QCheckBox>
#include <QGroupBox>
#include <QListWidget>
@ -11,6 +13,7 @@
#include <QVBoxLayout>
#include "Common/FileUtil.h"
#include "Common/Logging/Log.h"
#include "Common/Logging/LogManager.h"
#include "Core/ConfigManager.h"
@ -47,7 +50,10 @@ void LogConfigWidget::CreateWidgets()
m_verbosity_warning = new QRadioButton(tr("Warning"));
m_verbosity_info = new QRadioButton(tr("Info"));
m_verbosity_debug = new QRadioButton(tr("Debug"));
m_verbosity_debug->setVisible(Common::Log::MAX_LOGLEVEL == Common::Log::LogLevel::LDEBUG);
if constexpr (Common::Log::MAX_EFFECTIVE_LOGLEVEL < Common::Log::LogLevel::LDEBUG)
{
m_verbosity_debug->setVisible(false);
}
auto* outputs = new QGroupBox(tr("Logger Outputs"));
auto* outputs_layout = new QVBoxLayout;
@ -97,12 +103,47 @@ void LogConfigWidget::CreateWidgets()
void LogConfigWidget::ConnectWidgets()
{
// Configuration
connect(m_verbosity_notice, &QRadioButton::toggled, this, &LogConfigWidget::SaveSettings);
connect(m_verbosity_error, &QRadioButton::toggled, this, &LogConfigWidget::SaveSettings);
connect(m_verbosity_warning, &QRadioButton::toggled, this, &LogConfigWidget::SaveSettings);
connect(m_verbosity_info, &QRadioButton::toggled, this, &LogConfigWidget::SaveSettings);
connect(m_verbosity_debug, &QRadioButton::toggled, this, &LogConfigWidget::SaveSettings);
using Common::Log::LogLevel;
using ButtonLevelPair = std::pair<QRadioButton*, LogLevel>;
const std::array button_level_pairs = {ButtonLevelPair{m_verbosity_notice, LogLevel::LNOTICE},
ButtonLevelPair{m_verbosity_error, LogLevel::LERROR},
ButtonLevelPair{m_verbosity_warning, LogLevel::LWARNING},
ButtonLevelPair{m_verbosity_info, LogLevel::LINFO},
ButtonLevelPair{m_verbosity_debug, LogLevel::LDEBUG}};
for (const auto& [button, level] : button_level_pairs)
{
connect(button, &QRadioButton::clicked, [level](const bool checked) {
if (checked)
{
auto* const log_manager = Common::Log::LogManager::GetInstance();
log_manager->SetConfigLogLevel(level);
}
});
}
const auto update_verbosity_boldness = [button_level_pairs]() {
auto* const log_manager = Common::Log::LogManager::GetInstance();
const LogLevel effective_level = log_manager->GetEffectiveLogLevel();
for (const auto& [button, level] : button_level_pairs)
{
QFont font = button->font();
if (level == effective_level)
{
const bool is_base_layer_active =
Config::GetActiveLayerForConfig(Common::Log::LOGGER_VERBOSITY) ==
Config::LayerType::Base;
font.setBold(!is_base_layer_active);
button->setChecked(true);
}
else
{
font.setBold(false);
}
button->setFont(font);
}
};
connect(&Settings::Instance(), &Settings::ConfigChanged, this, update_verbosity_boldness);
connect(m_out_file, &QCheckBox::toggled, this, &LogConfigWidget::SaveSettings);
connect(m_out_console, &QCheckBox::toggled, this, &LogConfigWidget::SaveSettings);
@ -137,7 +178,7 @@ void LogConfigWidget::LoadSettings()
setFloating(settings.value(QStringLiteral("logconfigwidget/floating")).toBool());
// Config - Verbosity
const Common::Log::LogLevel verbosity = log_manager->GetLogLevel();
const Common::Log::LogLevel verbosity = log_manager->GetEffectiveLogLevel();
m_verbosity_notice->setChecked(verbosity == Common::Log::LogLevel::LNOTICE);
m_verbosity_error->setChecked(verbosity == Common::Log::LogLevel::LERROR);
m_verbosity_warning->setChecked(verbosity == Common::Log::LogLevel::LWARNING);
@ -174,29 +215,8 @@ void LogConfigWidget::SaveSettings()
settings.setValue(QStringLiteral("logconfigwidget/geometry"), saveGeometry());
settings.setValue(QStringLiteral("logconfigwidget/floating"), isFloating());
// Config - Verbosity
auto verbosity = Common::Log::LogLevel::LNOTICE;
if (m_verbosity_notice->isChecked())
verbosity = Common::Log::LogLevel::LNOTICE;
if (m_verbosity_error->isChecked())
verbosity = Common::Log::LogLevel::LERROR;
if (m_verbosity_warning->isChecked())
verbosity = Common::Log::LogLevel::LWARNING;
if (m_verbosity_info->isChecked())
verbosity = Common::Log::LogLevel::LINFO;
if (m_verbosity_debug->isChecked())
verbosity = Common::Log::LogLevel::LDEBUG;
auto* const log_manager = Common::Log::LogManager::GetInstance();
// Config - Verbosity
log_manager->SetLogLevel(verbosity);
// Config - Outputs
log_manager->EnableListener(Common::Log::LogListener::FILE_LISTENER, m_out_file->isChecked());
log_manager->EnableListener(Common::Log::LogListener::CONSOLE_LISTENER,