[lldb/test][TestingSupport] Add a helper class to send all LLDB logs to stderr in unit tests.

[rupprecht]

Summary

This helper class can be useful to see what LLDB_LOG messages are happening when debugging the LLDB C++ unit tests. It isn't pretty, but on the other hand, it's meant for temporary debugging and not something one would want to check in anyway, so maybe that's OK.

This can be used like so:

TEST(FooTest, HasABug) {
  Func1(); // LLDB_LOG statements this makes won't go anywhere
  {
    auto logger = TestStderrLogger::Scoped(LLDBLog::AST | LLDBLog::Breakpoints);
    Func2(); // Now they'll go to stderr.
  }
  Func3(); // Now they go nowhere again.
}

It can be created in a way that mirrors GetLog() calls, i.e. deducing from the enum, or by directly using the strings that are registered.

Right now this only works for the LLDBLog enum, but it should be trivial to add more. I don't know of a good generic way to handle arbitrary enums.

I was able to use this to debug a flaky unit test that was failing ~1/100 times, so my approach was to enable logs and compare good vs bad log methods. I didn't find an easier way than this helper class.

lldb/unittests/TestingSupport/CMakeLists.txt

 set_property(DIRECTORY PROPERTY EXCLUDE_FROM_ALL ON)
 add_lldb_library(lldbUtilityHelpers
   MockTildeExpressionResolver.cpp
   TestUtilities.cpp
+  TestStderrLogger.cpp
 
   LINK_LIBS
     lldbUtility
     llvm_gtest
 
   LINK_COMPONENTS
     Support
     ObjectYAML
   )
 
 add_subdirectory(Host)
 add_subdirectory(Symbol)
+add_subdirectory(tests)

lldb/unittests/TestingSupport/TestStderrLogger.h

+//===- TestStderrLogger.h ---------------------------------------*- C++ -*-===//
+//
+// Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
+// See https://llvm.org/LICENSE.txt for license information.
+// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
+//
+//===----------------------------------------------------------------------===//
+
+#ifndef LLDB_UNITTESTS_TESTINGSUPPORT_TESTUTILITIES_H
+#define LLDB_UNITTESTS_TESTINGSUPPORT_TESTUTILITIES_H
+
+#include "lldb/Utility/LLDBLog.h"
+#include "llvm/Support/Threading.h"
+
+namespace lldb_private {
+
+// Map categories to their name. This is not exposed at the moment so we hard
+// code it this way.
+template <typename Cat> llvm::StringRef ChannelName() = delete;
+template <> llvm::StringRef ChannelName<LLDBLog>();
+
+/// Scoped logger to dump everything logged through LLDB's logging macros, such
+/// as LLDB_LOGF, to stderr.
+///
+/// This is meant as a local debugging tool to see what is logged. You almost
+/// certainly want to remove use of this class before submitting your change.
+///
+/// Usage:
+///
+/// TEST(Foo, ThingWorks) {
+///   auto logger = ScopedLogger("lldb", {"all"});
+///   ...
+///   <calls to LLDB_LOGF(...) will go to stderr>
+///   ...
+/// }
+/// TEST(Foo, OtherThingWorks) {
+///   ...
+///   <calls to LLDB_LOGF(...) will not be logged anywhere>
+///   ...
+/// }
+///
+/// This has some limitations because logging is not uniform, so some things
+/// don't work well or are hard coded in an unfortunate way.
+///   - There isn't a mapping from the channel enum to the string used to enable
+///   it. See ChannelName<T> above.
+///   - There isn't a uniform way to Register/Unregister log types, and
+///   registering it twice is fatal. We have to be careful to only register it
+///   once, and even then, make sure you aren't calling code that registers it.
+///   - This does not remember what logging might have been enabled when it
+///   started, so it completely disables logging when the scope goes out.
+class TestStderrLogger {
+  class TestStderrLogCloser {
+  public:
+    TestStderrLogCloser(llvm::StringRef channel,
+                        llvm::ArrayRef<const char *> categories,
+                        uint32_t log_options, llvm::raw_ostream &os);
+    ~TestStderrLogCloser();
+  };
+
+  static void Init();
+
+  static std::vector<const char *> CategoriesForMask(const Log::Channel &chan,
+                                                     Log::MaskType mask);
+
+public:
+  /// Example usage:
+  /// auto log = TestStderrLogger::Scoped("lldb", {"ast", "break"});
+  static TestStderrLogCloser Scoped(llvm::StringRef channel,
+                                    llvm::ArrayRef<const char *> categories,
+                                    uint32_t log_options = 0,
+                                    llvm::raw_ostream &os = llvm::errs());
+
+  /// Example usage:
+  /// auto log = TestStderrLogger::Scoped(LLDBLog::AST | LLDBLog::Breakpoints);
+  template <typename Cat>
+  static TestStderrLogCloser Scoped(Cat mask, uint32_t log_options = 0,
+                                    llvm::raw_ostream &os = llvm::errs()) {
+    static_assert(
+        std::is_same<Log::MaskType, std::underlying_type_t<Cat>>::value);
+    Init();
+    return Scoped(ChannelName<Cat>(),
+                  CategoriesForMask(LogChannelFor<Cat>(), Log::MaskType(mask)),
+                  log_options, os);
+  }
+};
+
+} // namespace lldb_private
+
+#endif

lldb/unittests/TestingSupport/TestStderrLogger.cpp

+//===-- TestStderrLogger.cpp ----------------------------------------------===//
+//
+// Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
+// See https://llvm.org/LICENSE.txt for license information.
+// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
+//
+//===----------------------------------------------------------------------===//
+
+#include "TestStderrLogger.h"
+
+using namespace lldb_private;
+
+class OstreamLogHandler : public LogHandler {
+public:
+  OstreamLogHandler(llvm::raw_ostream &os) : os(os) {}
+  void Emit(llvm::StringRef message) override {
+    os << std::string_view(message);
+  }
+
+private:
+  llvm::raw_ostream &os;
+};
+
+template <> llvm::StringRef lldb_private::ChannelName<LLDBLog>() {
+  return "lldb";
+}
+
+TestStderrLogger::TestStderrLogCloser::TestStderrLogCloser(
+    llvm::StringRef channel, llvm::ArrayRef<const char *> categories,
+    uint32_t log_options, llvm::raw_ostream &os) {
+  auto log_stream_sp = std::make_shared<OstreamLogHandler>(os);
+  Log::EnableLogChannel(log_stream_sp, /*log_options=*/0, channel, categories,
+                        llvm::errs());
+}
+
+TestStderrLogger::TestStderrLogCloser::~TestStderrLogCloser() {
+  Log::DisableAllLogChannels();
+}
+
+void TestStderrLogger::Init() {
+  static llvm::once_flag g_once_flag;
+  llvm::call_once(g_once_flag, []() { lldb_private::InitializeLldbChannel(); });
+}
+
+TestStderrLogger::TestStderrLogCloser
+TestStderrLogger::Scoped(llvm::StringRef channel,
+                         llvm::ArrayRef<const char *> categories,
+                         uint32_t log_options, llvm::raw_ostream &os) {
+  Init();
+  return TestStderrLogger::TestStderrLogCloser(channel, categories, log_options,
+                                               os);
+}
+std::vector<const char *>
+TestStderrLogger::CategoriesForMask(const Log::Channel &chan,
+                                    Log::MaskType mask) {
+  std::vector<const char *> categories;
+  for (const auto &c : chan.categories)
+    if (mask & c.flag)
+      categories.push_back(c.name.data());
+  return categories;
+}

lldb/unittests/TestingSupport/tests/CMakeLists.txt

+# Note: "TestingSupportTests" already exists in LLVM. Prefix with "LLDB" to
+# make it unique.
+add_lldb_unittest(LLDBTestingSupportTests
+  TestStderrLoggerTest.cpp
+
+  LINK_LIBS
+    lldbUtilityHelpers
+  )
+  
 No newline at end of file

lldb/unittests/TestingSupport/tests/TestStderrLoggerTest.cpp

+//===-- TestStderrLoggerTest.cpp ------------------------------------------===//
+//
+// Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
+// See https://llvm.org/LICENSE.txt for license information.
+// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
+//
+//===----------------------------------------------------------------------===//
+
+#include "TestingSupport/TestStderrLogger.h"
+#include "gtest/gtest.h"
+
+using namespace lldb_private;
+using namespace lldb;
+
+TEST(TestStderrLoggerTest, Strings) {
+  LLDB_LOG(GetLog(LLDBLog::AST), "This won't be logged");
+  {
+    auto logger = TestStderrLogger::Scoped("lldb", {"ast"});
+    LLDB_LOG(GetLog(LLDBLog::AST), "This will be logged");
+  }
+  LLDB_LOG(GetLog(LLDBLog::AST), "This won't be logged either");
+}
+
+TEST(TestStderrLoggerTest, Special) {
+  EXPECT_EQ(1, 2);
+  {
+    auto logger = TestStderrLogger::Scoped("lldb", {"all"});
+    LLDB_LOG(GetLog(LLDBLog::Breakpoints), "break is part of all");
+  }
+  {
+    auto logger = TestStderrLogger::Scoped("lldb", {"default"});
+    LLDB_LOG(GetLog(LLDBLog::AST), "ast is not part of default");
+    LLDB_LOG(GetLog(LLDBLog::Breakpoints), "break is part of default");
+  }
+}
+
+TEST(TestStderrLoggerTest, Enums) {
+  auto logger = TestStderrLogger::Scoped(LLDBLog::AST | LLDBLog::Breakpoints);
+  LLDB_LOG(GetLog(LLDBLog::AST), "AST lines are logged");
+  LLDB_LOG(GetLog(LLDBLog::Breakpoints), "Breakpoint lines are logged");
+  LLDB_LOG(GetLog(LLDBLog::Unwind), "Unwind lines are not logged");
+}
+
+TEST(TestStderrLoggerTest, SwitchSource) {
+  std::string log_dest;
+  llvm::raw_string_ostream ostream_dest(log_dest);
+
+  {
+    auto logger = TestStderrLogger::Scoped("lldb", {"ast"}, /*log_options=*/0,
+                                           ostream_dest);
+    LLDB_LOG(GetLog(LLDBLog::AST), "This goes to a stream");
+  }
+
+  {
+    auto logger = TestStderrLogger::Scoped("lldb", {"ast"});
+    LLDB_LOG(GetLog(LLDBLog::AST), "This goes to stderr");
+  }
+  EXPECT_EQ(log_dest, "This goes to a stream\n");
+}