ControllerDebug: Remove singleton in favor of categorized logging

CMakeLists.txt

@@ -475,7 +475,6 @@ add_library(mixxx-lib STATIC EXCLUDE_FROM_ALL
   src/control/controlpushbutton.cpp
   src/control/controlttrotary.cpp
   src/controllers/controller.cpp
-  src/controllers/controllerdebug.cpp
   src/controllers/controllerenumerator.cpp
   src/controllers/controllerinputmappingtablemodel.cpp
   src/controllers/controllerlearningeventfilter.cpp

src/control/controlobjectscript.cpp

@@ -1,11 +1,10 @@
 #include "control/controlobjectscript.h"
 
-#include "controllers/controllerdebug.h"
 #include "moc_controlobjectscript.cpp"
 
 ControlObjectScript::ControlObjectScript(
         const ConfigKey& key, const RuntimeLoggingCategory& logger, QObject* pParent)
-        : ControlProxy(key, pParent, ControllerDebug::controlFlags()),
+        : ControlProxy(key, pParent, ControlFlag::AllowMissingOrInvalid),
           m_logger(logger) {
 }
 

src/controllers/bulk/bulkcontroller.cpp

@@ -3,7 +3,6 @@
 #include <libusb.h>
 
 #include "controllers/bulk/bulksupported.h"
-#include "controllers/controllerdebug.h"
 #include "controllers/defs_controllers.h"
 #include "moc_bulkcontroller.cpp"
 #include "util/time.h"

src/controllers/controller.cpp

@@ -4,7 +4,6 @@
 #include <QJSValue>
 #include <QRegularExpression>
 
-#include "controllers/controllerdebug.h"
 #include "controllers/defs_controllers.h"
 #include "moc_controller.cpp"
 #include "util/screensaver.h"

src/controllers/hid/hidcontroller.cpp

@@ -2,7 +2,6 @@
 
 #include <hidapi.h>
 
-#include "controllers/controllerdebug.h"
 #include "controllers/defs_controllers.h"
 #include "controllers/hid/legacyhidcontrollermappingfilehandler.h"
 #include "moc_hidcontroller.cpp"

src/controllers/midi/hss1394controller.cpp

@@ -1,6 +1,5 @@
 #include "controllers/midi/hss1394controller.h"
 
-#include "controllers/controllerdebug.h"
 #include "controllers/midi/midiutils.h"
 #include "moc_hss1394controller.cpp"
 #include "util/time.h"

src/controllers/midi/midicontroller.cpp

@@ -1,7 +1,6 @@
 #include "controllers/midi/midicontroller.h"
 
 #include "control/controlobject.h"
-#include "controllers/controllerdebug.h"
 #include "controllers/defs_controllers.h"
 #include "controllers/midi/midiutils.h"
 #include "defs_urls.h"

src/controllers/midi/midioutputhandler.cpp

@@ -3,7 +3,6 @@
 #include <QtDebug>
 
 #include "control/controlobject.h"
-#include "controllers/controllerdebug.h"
 #include "controllers/midi/midicontroller.h"
 #include "moc_midioutputhandler.cpp"
 

src/controllers/midi/portmidicontroller.cpp

@@ -1,6 +1,5 @@
 #include "controllers/midi/portmidicontroller.h"
 
-#include "controllers/controllerdebug.h"
 #include "controllers/midi/midiutils.h"
 #include "moc_portmidicontroller.cpp"
 

src/controllers/scripting/controllerscriptenginebase.cpp

@@ -2,7 +2,6 @@
 
 #include "control/controlobject.h"
 #include "controllers/controller.h"
-#include "controllers/controllerdebug.h"
 #include "controllers/scripting/colormapperjsproxy.h"
 #include "errordialoghandler.h"
 #include "mixer/playermanager.h"

src/controllers/scripting/legacy/controllerscriptenginelegacy.cpp

@@ -2,7 +2,6 @@
 
 #include "control/controlobject.h"
 #include "controllers/controller.h"
-#include "controllers/controllerdebug.h"
 #include "controllers/scripting/colormapperjsproxy.h"
 #include "controllers/scripting/legacy/controllerscriptinterfacelegacy.h"
 #include "errordialoghandler.h"
@@ -150,7 +149,7 @@ bool ControllerScriptEngineLegacy::initialize() {
     } else { // m_pController is nullptr in tests.
         args << QJSValue();
     }
-    args << QJSValue(ControllerDebug::isEnabled());
+    args << QJSValue(m_logger().isDebugEnabled());
     if (!callFunctionOnObjects(m_scriptFunctionPrefixes, "init", args, true)) {
         shutdown();
         return false;

src/controllers/scripting/legacy/controllerscriptinterfacelegacy.cpp

@@ -2,7 +2,6 @@
 
 #include "control/controlobject.h"
 #include "control/controlobjectscript.h"
-#include "controllers/controllerdebug.h"
 #include "controllers/scripting/legacy/controllerscriptenginelegacy.h"
 #include "controllers/scripting/legacy/scriptconnectionjsproxy.h"
 #include "mixer/playermanager.h"
@@ -123,7 +122,7 @@ void ControllerScriptInterfaceLegacy::setValue(
 
     if (coScript != nullptr) {
         ControlObject* pControl = ControlObject::getControl(
-                coScript->getKey(), ControllerDebug::controlFlags());
+                coScript->getKey(), ControlFlag::AllowMissingOrInvalid);
         if (pControl &&
                 !m_st.ignore(
                         pControl, coScript->getParameterForValue(newValue))) {
@@ -154,7 +153,7 @@ void ControllerScriptInterfaceLegacy::setParameter(
 
     if (coScript != nullptr) {
         ControlObject* pControl = ControlObject::getControl(
-                coScript->getKey(), ControllerDebug::controlFlags());
+                coScript->getKey(), ControlFlag::AllowMissingOrInvalid);
         if (pControl && !m_st.ignore(pControl, newParameter)) {
             coScript->setParameter(newParameter);
         }
@@ -501,7 +500,7 @@ void ControllerScriptInterfaceLegacy::timerEvent(QTimerEvent* event) {
 void ControllerScriptInterfaceLegacy::softTakeover(
         const QString& group, const QString& name, bool set) {
     ControlObject* pControl = ControlObject::getControl(
-            ConfigKey(group, name), ControllerDebug::controlFlags());
+            ConfigKey(group, name), ControlFlag::AllowMissingOrInvalid);
     if (!pControl) {
         return;
     }
@@ -515,7 +514,7 @@ void ControllerScriptInterfaceLegacy::softTakeover(
 void ControllerScriptInterfaceLegacy::softTakeoverIgnoreNextValue(
         const QString& group, const QString& name) {
     ControlObject* pControl = ControlObject::getControl(
-            ConfigKey(group, name), ControllerDebug::controlFlags());
+            ConfigKey(group, name), ControlFlag::AllowMissingOrInvalid);
     if (!pControl) {
         return;
     }

src/test/controllerscriptenginelegacy_test.cpp

@@ -8,7 +8,6 @@
 
 #include "control/controlobject.h"
 #include "control/controlpotmeter.h"
-#include "controllers/controllerdebug.h"
 #include "controllers/softtakeover.h"
 #include "preferences/usersettings.h"
 #include "test/mixxxtest.h"
@@ -36,7 +35,6 @@ class ControllerScriptEngineLegacyTest : public MixxxTest {
         QThread::currentThread()->setObjectName("Main");
         cEngine = new ControllerScriptEngineLegacy(nullptr, logger);
         cEngine->initialize();
-        ControllerDebug::setTesting(true);
     }
 
     void TearDown() override {
@@ -82,29 +80,17 @@ TEST_F(ControllerScriptEngineLegacyTest, setValue) {
 }
 
 TEST_F(ControllerScriptEngineLegacyTest, getValue_InvalidKey) {
-    ControllerDebug::setEnabled(false);
-    ControllerDebug::setTesting(false);
     EXPECT_TRUE(evaluateAndAssert("engine.getValue('', '');"));
     EXPECT_TRUE(evaluateAndAssert("engine.getValue('', 'invalid');"));
     EXPECT_TRUE(evaluateAndAssert("engine.getValue('[Invalid]', '');"));
-    ControllerDebug::setTesting(true);
-    ControllerDebug::setEnabled(true);
 }
 
 TEST_F(ControllerScriptEngineLegacyTest, setValue_InvalidControl) {
-    ControllerDebug::setEnabled(false);
-    ControllerDebug::setTesting(false);
     EXPECT_TRUE(evaluateAndAssert("engine.setValue('[Nothing]', 'nothing', 1.0);"));
-    ControllerDebug::setTesting(true);
-    ControllerDebug::setEnabled(true);
 }
 
 TEST_F(ControllerScriptEngineLegacyTest, getValue_InvalidControl) {
-    ControllerDebug::setEnabled(false);
-    ControllerDebug::setTesting(false);
     EXPECT_TRUE(evaluateAndAssert("engine.getValue('[Nothing]', 'nothing');"));
-    ControllerDebug::setTesting(true);
-    ControllerDebug::setEnabled(true);
 }
 
 TEST_F(ControllerScriptEngineLegacyTest, setValue_IgnoresNaN) {

src/util/cmdlineargs.cpp

@@ -19,7 +19,7 @@
 
 CmdlineArgs::CmdlineArgs()
         : m_startInFullscreen(false), // Initialize vars
-          m_midiDebug(false),
+          m_controllerDebug(false),
           m_developer(false),
           m_safeMode(false),
           m_debugAssertBreak(false),
@@ -325,7 +325,7 @@ bool CmdlineArgs::parse(const QStringList& arguments, CmdlineArgs::ParseMode mod
         m_timelinePath = parser.value(timelinePathDeprecated);
     }
 
-    m_midiDebug = parser.isSet(controllerDebug) || parser.isSet(controllerDebugDeprecated);
+    m_controllerDebug = parser.isSet(controllerDebug) || parser.isSet(controllerDebugDeprecated);
     m_developer = parser.isSet(developer);
     m_qml = parser.isSet(qml);
     m_safeMode = parser.isSet(safeMode) || parser.isSet(safeModeDeprecated);

src/util/cmdlineargs.h

@@ -31,7 +31,9 @@ class CmdlineArgs final {
 
     const QList<QString>& getMusicFiles() const { return m_musicFiles; }
     bool getStartInFullscreen() const { return m_startInFullscreen; }
-    bool getMidiDebug() const { return m_midiDebug; }
+    bool getControllerDebug() const {
+        return m_controllerDebug;
+    }
     bool getDeveloper() const { return m_developer; }
     bool getQml() const {
         return m_qml;
@@ -70,7 +72,7 @@ class CmdlineArgs final {
 
     QList<QString> m_musicFiles;    // List of files to load into players at startup
     bool m_startInFullscreen;       // Start in fullscreen mode
-    bool m_midiDebug;
+    bool m_controllerDebug;
     bool m_developer; // Developer Mode
     bool m_qml;
     bool m_safeMode;

src/util/logging.cpp

@@ -13,7 +13,6 @@
 #include <QTextStream>
 #include <QThread>
 
-#include "controllers/controllerdebug.h"
 #include "util/assert.h"
 #include "util/cmdlineargs.h"
 #include "util/compatibility/qmutex.h"
@@ -29,6 +28,20 @@ QMutex s_mutexStdErr;
 // The file handle for Mixxx's log file.
 QFile s_logfile;
 
+QLoggingCategory::CategoryFilter oldCategoryFilter = nullptr;
+
+void controllerDebugCategoryFilter(QLoggingCategory* category) {
+    // Configure controller.*.input/output category here, otherwise forward to to default filter.
+    constexpr char controllerPrefix[] = "controller.";
+    const char* categoryName = category->categoryName();
+    if (qstrncmp(categoryName, controllerPrefix, sizeof(controllerPrefix) - 1) == 0) {
+        category->setEnabled(QtDebugMsg, true);
+    } else {
+        oldCategoryFilter(category);
+        category->setEnabled(QtDebugMsg, false);
+    }
+}
+
 // The log level.
 // Whether to break on debug assertions.
 bool s_debugAssertBreak = false;
@@ -236,6 +249,12 @@ namespace mixxx {
 
 namespace {
 
+bool isControllerIoLoggingCategory(const QString& categoryName) {
+    return categoryName.startsWith("controller") &&
+            (categoryName.endsWith("input") ||
+                    categoryName.endsWith("output"));
+}
+
 // Debug message handler which outputs to stderr and a logfile,
 // prepending the thread name, log category, and log level.
 void handleMessage(
@@ -245,15 +264,11 @@ void handleMessage(
     const char* levelName = nullptr;
     WriteFlags writeFlags = WriteFlag::None;
     bool isDebugAssert = false;
-    bool isControllerDebug = false;
+    const QString categoryName(context.category);
     switch (type) {
     case QtDebugMsg:
         levelName = "Debug";
-        isControllerDebug =
-                input.startsWith(QLatin1String(
-                        ControllerDebug::kLogMessagePrefix));
-        if (isControllerDebug ||
-                Logging::enabled(LogLevel::Debug)) {
+        if (Logging::enabled(LogLevel::Debug)) {
             writeFlags |= WriteFlag::StdErr;
             writeFlags |= WriteFlag::File;
         }
@@ -263,8 +278,12 @@ void handleMessage(
         // TODO: Remove the following line.
         // Do not write debug log messages into log file if log level
         // Debug is not enabled starting with release 2.4.0! Until then
-        // write debug messages unconditionally into the log file
-        writeFlags |= WriteFlag::File;
+        // write debug messages into the log file, but skip controller I/O
+        // to avoid flooding the log file.
+        // Skip expensive string comparisons if WriteFLag::File is already set.
+        if (!writeFlags.testFlag(WriteFlag::File) && !isControllerIoLoggingCategory(categoryName)) {
+            writeFlags |= WriteFlag::File;
+        }
         break;
     case QtInfoMsg:
         levelName = "Info";
@@ -384,6 +403,14 @@ void Logging::initialize(
             "*.debug=true\n"
             "qt.*.debug=false");
 #endif
+
+    if (CmdlineArgs::Instance().getControllerDebug()) {
+        setLogLevel(LogLevel::Debug);
+        // This looks weird, but it's the proposed workaround for this 6 year
+        // old bug: https://bugreports.qt.io/browse/QTBUG-49704
+        oldCategoryFilter = QLoggingCategory::installFilter(nullptr);
+        QLoggingCategory::installFilter(controllerDebugCategoryFilter);
+    }
 }
 
 // static