From 4e6e1ce054b942ebba713abfe4f39abbedd86ea3 Mon Sep 17 00:00:00 2001
From: Vadim Zeitlin <vadim@wxwidgets.org>
Date: Thu, 14 Apr 2022 01:18:44 +0100
Subject: [PATCH] Show debug log messages on the console in the test when
 enabled

Using LogEnabler in wxFileSystemWatcher test case still didn't show
anything even in case of unexpected failures because debug messages
didn't appear in the test output.

Fix this by using a custom log target which shows the debug (and trace)
messages on stderr, instead of using the debug output for them, even
under MSW.

Also make LogEnabler public, and rename it to a more unique name, as it
could be useful in the other tests too.
---
 tests/fswatcher/fswatchertest.cpp | 25 +----------
 tests/test.cpp                    | 73 ++++++++++++++++++++++++++++---
 tests/testprec.h                  | 19 ++++++++
 3 files changed, 87 insertions(+), 30 deletions(-)

diff --git a/tests/fswatcher/fswatchertest.cpp b/tests/fswatcher/fswatchertest.cpp
index eb16020d4a..75d092cf86 100644
--- a/tests/fswatcher/fswatchertest.cpp
+++ b/tests/fswatcher/fswatchertest.cpp
@@ -34,27 +34,6 @@
 // local functions
 // ----------------------------------------------------------------------------
 
-#if wxUSE_LOG
-// Logging is disabled by default when running the tests, but sometimes it can
-// be helpful to see the errors in case of unexpected failure, so this class
-// re-enables logs in its scope.
-//
-// It's a counterpart to wxLogNull.
-class LogEnabler
-{
-public:
-    LogEnabler() : m_wasEnabled(wxLog::EnableLogging(true)) { }
-    ~LogEnabler() { wxLog::EnableLogging(m_wasEnabled); }
-
-private:
-    const bool m_wasEnabled;
-
-    wxDECLARE_NO_COPY_CLASS(LogEnabler);
-};
-#else // !wxUSE_LOG
-class LogEnabler { };
-#endif // wxUSE_LOG/!wxUSE_LOG
-
 // class generating file system events
 class EventGenerator
 {
@@ -161,7 +140,7 @@ public:
         ms_watchDir.AppendDir("fswatcher_test");
         REQUIRE(!ms_watchDir.DirExists());
 
-        LogEnabler enableLogs;
+        TestLogEnabler enableLogs;
         REQUIRE(ms_watchDir.Mkdir());
 
         REQUIRE(ms_watchDir.DirExists());
@@ -176,7 +155,7 @@ public:
         // just to be really sure we know what we remove
         REQUIRE( ms_watchDir.GetDirs().Last() == "fswatcher_test" );
 
-        LogEnabler enableLogs;
+        TestLogEnabler enableLogs;
         CHECK( ms_watchDir.Rmdir(wxPATH_RMDIR_RECURSIVE) );
 
         ms_watchDir = wxFileName();
diff --git a/tests/test.cpp b/tests/test.cpp
index fa13f1fc58..b9e2f8c96e 100644
--- a/tests/test.cpp
+++ b/tests/test.cpp
@@ -188,6 +188,71 @@ CATCH_TRANSLATE_EXCEPTION(TestAssertFailure& e)
 
 #endif // wxDEBUG_LEVEL
 
+#if wxUSE_LOG
+
+// Custom log target used while running the tests.
+class TestLogger : public wxLog
+{
+public:
+    TestLogger()
+    {
+        // Use standard time-stamp instead of the locale-specific one and show
+        // milliseconds too.
+        wxLog::SetTimestamp("%Y-%m-%d %H:%M:%S.%l");
+    }
+
+    // This is used by TestLogEnabler to enable logging all messages.
+    static int ms_enableCount;
+
+protected:
+    virtual void DoLogRecord(wxLogLevel level,
+                             const wxString& msg,
+                             const wxLogRecordInfo& info) wxOVERRIDE
+    {
+        // If logging was explicitly enabled, show everything on the console.
+        //
+        // Otherwise we only show trace messages as they are not given by
+        // default and can be only activated by setting WXTRACE.
+        if ( ms_enableCount || level == wxLOG_Trace )
+        {
+            wxString ts;
+            TimeStampMS(&ts, info.timestampMS);
+
+            const wxString levels[] =
+            {
+                "Fatal", "Error", "Warning",
+                "Message", "Status", "Info",
+                "Debug", "Trace", "Progress"
+            };
+            wxString prefix;
+            if ( level < WXSIZEOF(levels) )
+                prefix = levels[level];
+            else
+                prefix.Printf("Level %d", level);
+
+            m_out.Output(wxString::Format("[%s] %s: %s", ts, prefix, msg));
+        }
+    }
+
+    wxMessageOutputStderr m_out;
+};
+
+// By default, normal logging is disabled as it would interfere with the normal
+// test output.
+int TestLogger::ms_enableCount = 0;
+
+TestLogEnabler::TestLogEnabler()
+{
+    TestLogger::ms_enableCount++;
+}
+
+TestLogEnabler::~TestLogEnabler()
+{
+    TestLogger::ms_enableCount--;
+}
+
+#endif // wxUSE_LOG
+
 #if wxUSE_GUI
     typedef wxApp TestAppBase;
     typedef wxGUIAppTraits TestAppTraitsBase;
@@ -602,13 +667,7 @@ bool TestApp::ProcessEvent(wxEvent& event)
 int TestApp::RunTests()
 {
 #if wxUSE_LOG
-    // Switch off logging to avoid interfering with the tests output unless
-    // WXTRACE is set, as otherwise setting it would have no effect while
-    // running the tests.
-    if ( !wxGetEnv(wxASCII_STR("WXTRACE"), NULL) )
-        wxLog::EnableLogging(false);
-    else
-        wxLog::SetTimestamp("%Y-%m-%d %H:%M:%S.%l");
+    delete wxLog::SetActiveTarget(new TestLogger);
 #endif
 
     // Cast is needed under MSW where Catch also provides an overload taking
diff --git a/tests/testprec.h b/tests/testprec.h
index ef38886526..e26630271e 100644
--- a/tests/testprec.h
+++ b/tests/testprec.h
@@ -148,6 +148,25 @@ extern bool IsAutomaticTest();
 
 extern bool IsRunningUnderXVFB();
 
+#if wxUSE_LOG
+// Logging is disabled by default when running the tests, but sometimes it can
+// be helpful to see the errors in case of unexpected failure, so this class
+// re-enables logs in its scope.
+//
+// It's a counterpart to wxLogNull.
+class TestLogEnabler
+{
+public:
+    TestLogEnabler();
+    ~TestLogEnabler();
+
+private:
+    wxDECLARE_NO_COPY_CLASS(TestLogEnabler);
+};
+#else // !wxUSE_LOG
+class TestLogEnabler { };
+#endif // wxUSE_LOG/!wxUSE_LOG
+
 #if wxUSE_GUI
 
 // Return true if the UI tests are enabled, used by WXUISIM_TEST().