Merge pull request #13939 from Dentomologist/logging_avoid_overwriting_debug_verbosity_in_release_builds

Logging: Don't overwrite LDEBUG level in Release builds

Source/Android/jni/MainAndroid.cpp

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

Source/Core/Common/Assert.h

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

Source/Core/Common/Logging/Log.h

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

Source/Core/Common/Logging/LogManager.cpp

@@ -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);
+  SetEffectiveLogLevel();
-
-  SetLogLevel(verbosity);
   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()

Source/Core/Common/Logging/LogManager.h

@@ -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;
+  // Use this function instead of LOGGER_VERBOSITY to determine which logs should be printed.
-  void SetLogLevel(LogLevel level);
+  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;

Source/Core/Core/ActionReplay.cpp

@@ -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)
+  if constexpr (Common::Log::MAX_EFFECTIVE_LOGLEVEL < Common::Log::LogLevel::LINFO)
-    return;
+  {
+    if (!use_internal_log)
+      return;
+  }
 
   std::string text = fmt::vformat(format, args);
   INFO_LOG_FMT(ACTIONREPLAY, "{}", text);

Source/Core/DolphinQt/Config/LogConfigWidget.cpp

@@ -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
+  using Common::Log::LogLevel;
-  connect(m_verbosity_notice, &QRadioButton::toggled, this, &LogConfigWidget::SaveSettings);
+  using ButtonLevelPair = std::pair<QRadioButton*, LogLevel>;
-  connect(m_verbosity_error, &QRadioButton::toggled, this, &LogConfigWidget::SaveSettings);
+  const std::array button_level_pairs = {ButtonLevelPair{m_verbosity_notice, LogLevel::LNOTICE},
-  connect(m_verbosity_warning, &QRadioButton::toggled, this, &LogConfigWidget::SaveSettings);
+                                         ButtonLevelPair{m_verbosity_error, LogLevel::LERROR},
-  connect(m_verbosity_info, &QRadioButton::toggled, this, &LogConfigWidget::SaveSettings);
+                                         ButtonLevelPair{m_verbosity_warning, LogLevel::LWARNING},
-  connect(m_verbosity_debug, &QRadioButton::toggled, this, &LogConfigWidget::SaveSettings);
+                                         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,