From c94f7bbacce7d975a82e0235dfee39bc61ba80b7 Mon Sep 17 00:00:00 2001 From: Mehdi Amini Date: Sun, 14 Sep 2025 08:10:00 -0700 Subject: [PATCH] Default DEBUG_TYPE to the current filename for logging This makes it optional to define a debug type and uses the current FileName instead. This both reduced the size of the prefix printed by LDBG() and makes it possible to pass a filename to `--debug-only` to filter on. --- llvm/docs/ProgrammersManual.rst | 29 +++-- llvm/include/llvm/Support/DebugLog.h | 25 +--- llvm/unittests/Support/DebugLogTest.cpp | 120 ++++++++++++++---- .../IR/test-pattern-logging-listener.mlir | 15 ++- 4 files changed, 128 insertions(+), 61 deletions(-) diff --git a/llvm/docs/ProgrammersManual.rst b/llvm/docs/ProgrammersManual.rst index 0fa91bcfe2d10..602922fcb3b9c 100644 --- a/llvm/docs/ProgrammersManual.rst +++ b/llvm/docs/ProgrammersManual.rst @@ -1169,7 +1169,8 @@ It also supports a `level` argument to control the verbosity of the output. LDBG(2) << "I am here!"; -A ``DEBUG_TYPE`` macro should be defined in the file before using ``LDBG()``. +A ``DEBUG_TYPE`` macro may optionally be defined in the file before using +``LDBG()``, otherwise the file name is used as the debug type. The file name and line number are automatically added to the output, as well as a terminating newline. @@ -1180,7 +1181,7 @@ The debug output can be enabled by passing the ``-debug`` command line argument. $ opt < a.bc > /dev/null -mypass $ opt < a.bc > /dev/null -mypass -debug - [my-pass:2] MyPass.cpp:123 I am here! + [my-pass MyPass.cpp:123 2] I am here! While `LDBG()` is useful to add debug output to your code, there are cases where you may need to guard a block of code with a debug check. The @@ -1222,29 +1223,29 @@ Fine grained debug info with ``DEBUG_TYPE`` and the ``-debug-only`` option Sometimes you may find yourself in a situation where enabling ``-debug`` just turns on **too much** information (such as when working on the code generator). If you want to enable debug information with more fine-grained control, you -should define the ``DEBUG_TYPE`` macro and use the ``-debug-only`` option as -follows: +can control the debug type and level with associate with each logging statement +as follows: .. code-block:: c++ - #define DEBUG_TYPE "foo" + #define DEBUG_TYPE "foo" // Optional: the file name is used instead if not defined LDBG(2) << "Hello,"; // DEBUG_TYPE can be overridden locally, here with "bar" LDBG("bar", 3) << "'bar' debug type"; -A more fine-grained control can be achieved by passing the ``-debug-only`` -command line argument: +A more fine-grained control of the output can be achieved by passing the +``-debug-only`` command line argument: .. code-block:: none $ opt < a.bc > /dev/null -mypass -debug-only=foo - [foo:2] MyPass.cpp:123 Hello, + [foo MyPass.cpp:123 2] Hello, $ opt < a.bc > /dev/null -mypass -debug-only=foo,bar - [foo:2] MyPass.cpp:123 Hello, - [bar:3] MyPass.cpp:124 World! + [foo MyPass.cpp:123 2] Hello, + [bar MyPass.cpp:124 3] World! $ opt < a.bc > /dev/null -mypass -debug-only=bar - [bar:3] MyPass.cpp:124 World! + [bar MyPass.cpp:124 3] World! The debug-only argument is a comma separated list of debug types and levels. The level is an optional integer setting the maximum debug level to enable: @@ -1252,9 +1253,9 @@ The level is an optional integer setting the maximum debug level to enable: .. code-block:: none $ opt < a.bc > /dev/null -mypass -debug-only=foo:2,bar:2 - [foo:2] MyPass.cpp:123 Hello, + [foo MyPass.cpp:123 2] Hello, $ opt < a.bc > /dev/null -mypass -debug-only=foo:1,bar:3 - [bar:3] MyPass.cpp:124 World! + [bar MyPass.cpp:124 3] World! Instead of opting in specific debug types, the ``-debug-only`` option also works to filter out debug output for specific debug types, by omitting the @@ -1263,7 +1264,7 @@ level (or setting it to 0): .. code-block:: none $ opt < a.bc > /dev/null -mypass -debug-only=foo: - [bar:3] MyPass.cpp:124 World! + [bar MyPass.cpp:124 3] World! $ opt < a.bc > /dev/null -mypass -debug-only=bar:0,foo: diff --git a/llvm/include/llvm/Support/DebugLog.h b/llvm/include/llvm/Support/DebugLog.h index c1e1648c3b546..7025ca149ace1 100644 --- a/llvm/include/llvm/Support/DebugLog.h +++ b/llvm/include/llvm/Support/DebugLog.h @@ -196,22 +196,10 @@ constexpr ::llvm::StringRef strip_quotes(const char *Str) { return S; } -/// Fail compilation if DEBUG_TYPE is not defined. -/// This is a workaround for GCC <=12 and clang <=16 which do not support -/// static_assert in templated constexpr functions. -#if (defined(__GNUC__) && !defined(__clang__) && __GNUC__ <= 12) || \ - (defined(__clang__) && __clang_major__ <= 16) -#define MISSING_DEBUG_TYPE() \ - extern void missing_DEBUG_TYPE(void); \ - missing_DEBUG_TYPE(); -#else -#define MISSING_DEBUG_TYPE() static_assert(false, "DEBUG_TYPE is not defined"); -#endif - /// Helper to provide the default level (=1) or type (=DEBUG_TYPE). This is used /// when a single argument is passed to LDBG() (or LDBG_OS()), if it is an -/// integer we return DEBUG_TYPE and if it is a string we return 1. This fails -/// with a static_assert if we pass an integer and DEBUG_TYPE is not defined. +/// integer we return DEBUG_TYPE and if it is a string we return 1. +/// When DEBUG_TYPE is not defined, we return the current file name instead. #define LDBG_GET_DEFAULT_TYPE_OR_LEVEL(LEVEL_OR_TYPE) \ [](auto LevelOrType) { \ if constexpr (std::is_integral_v) { \ @@ -219,7 +207,7 @@ constexpr ::llvm::StringRef strip_quotes(const char *Str) { if constexpr (DebugType[0] == '"') { \ return ::llvm::impl::strip_quotes(DebugType); \ } else { \ - MISSING_DEBUG_TYPE(); \ + return __LLVM_FILE_NAME__; \ } \ } else { \ return 1; \ @@ -331,9 +319,10 @@ static LLVM_ATTRIBUTE_UNUSED std::string computePrefix(StringRef DebugType, const char *File, int Line, int Level) { std::string Prefix; raw_string_ostream OsPrefix(Prefix); - if (!DebugType.empty()) - OsPrefix << "[" << DebugType << ":" << Level << "] "; - OsPrefix << File << ":" << Line << " "; + OsPrefix << "["; + if (!DebugType.empty() && DebugType != File) + OsPrefix << DebugType << " "; + OsPrefix << File << ":" << Line << " " << Level << "] "; return OsPrefix.str(); } /// Overload allowing to swap the order of the DebugType and Level arguments. diff --git a/llvm/unittests/Support/DebugLogTest.cpp b/llvm/unittests/Support/DebugLogTest.cpp index da3851ed86b35..4df5a809d11aa 100644 --- a/llvm/unittests/Support/DebugLogTest.cpp +++ b/llvm/unittests/Support/DebugLogTest.cpp @@ -28,7 +28,7 @@ TEST(DebugLogTest, Basic) { std::string str; raw_string_ostream os(str); LDGB_STREAM_LEVEL_AND_TYPE(os, "", 0) << "NoType"; - EXPECT_FALSE(StringRef(os.str()).starts_with('[')); + EXPECT_TRUE(StringRef(os.str()).starts_with('[')); EXPECT_TRUE(StringRef(os.str()).ends_with("NoType\n")); } @@ -77,8 +77,8 @@ TEST(DebugLogTest, BasicWithLevel) { for (int level : llvm::seq(0, 4)) LDBG_STREAM_LEVEL_TYPE_FILE_AND_LINE(os, level, type, type, level) << level; - EXPECT_EQ(os.str(), "[A:0] A:0 0\n[A:1] A:1 1\n[A:2] A:2 2\n[A:3] A:3 " - "3\n[B:0] B:0 0\n[B:1] B:1 1\n[C:0] C:0 0\n"); + EXPECT_EQ(os.str(), "[A:0 0] 0\n[A:1 1] 1\n[A:2 2] 2\n[A:3 3] 3\n[B:0 0] " + "0\n[B:1 1] 1\n[C:0 0] 0\n"); } TEST(DebugLogTest, NegativeLevel) { @@ -92,9 +92,10 @@ TEST(DebugLogTest, NegativeLevel) { raw_string_ostream os(str); for (auto type : {"A", "B"}) for (int level : llvm::seq(0, 2)) - LDBG_STREAM_LEVEL_TYPE_FILE_AND_LINE(os, level, type, type, level) + LDBG_STREAM_LEVEL_TYPE_FILE_AND_LINE( + os, level, type, (std::string(type) + ".cpp").c_str(), level) << level; - EXPECT_EQ(os.str(), "[A:0] A:0 0\n[B:0] B:0 0\n[B:1] B:1 1\n"); + EXPECT_EQ(os.str(), "[A A.cpp:0 0] 0\n[B B.cpp:0 0] 0\n[B B.cpp:1 1] 1\n"); } TEST(DebugLogTest, StreamPrefix) { @@ -141,35 +142,71 @@ TEST(DebugLogTest, LDBG_MACROS) { #define LDBG_STREAM DebugOs #define DEBUG_TYPE "A" LDBG() << "Hello, world!"; - ExpectedOs << "[A:1] " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) - << " Hello, world!\n"; + ExpectedOs << "[A " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) + << " 1] Hello, world!\n"; EXPECT_EQ(DebugOs.str(), ExpectedOs.str()); Str.clear(); StrExpected.clear(); // Test with a level, no type. LDBG(2) << "Hello, world!"; - ExpectedOs << "[A:2] " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) - << " Hello, world!\n"; + ExpectedOs << "[A " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) + << " 2] Hello, world!\n"; EXPECT_EQ(DebugOs.str(), ExpectedOs.str()); Str.clear(); StrExpected.clear(); -// Now the type will be explicit, check we don't use DEBUG_TYPE. +// Now check when we don't use DEBUG_TYPE, the file name is implicitly used +// instead. #undef DEBUG_TYPE + // Repeat the tests above, they won't match since the debug types defined + // above don't match the file name. + LDBG() << "Hello, world!"; + EXPECT_EQ(DebugOs.str(), ""); + Str.clear(); + StrExpected.clear(); + + // Test with a level, no type. + LDBG(2) << "Hello, world!"; + EXPECT_EQ(DebugOs.str(), ""); + Str.clear(); + StrExpected.clear(); + + // Now enable the debug types that match the file name. + auto fileNameAndLevel = std::string(__LLVM_FILE_NAME__) + ":3"; + static const char *DT2[] = {fileNameAndLevel.c_str(), "B:2"}; + setCurrentDebugTypes(DT2, sizeof(DT2) / sizeof(DT2[0])); + + // Repeat the tests above, they should match now. + + LDBG() << "Hello, world!"; + ExpectedOs << "[" << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) + << " 1] Hello, world!\n"; + EXPECT_EQ(DebugOs.str(), ExpectedOs.str()); + Str.clear(); + StrExpected.clear(); + + // Test with a level, no type. + LDBG(2) << "Hello, world!"; + ExpectedOs << "[" << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) + << " 2] Hello, world!\n"; + EXPECT_EQ(DebugOs.str(), ExpectedOs.str()); + Str.clear(); + StrExpected.clear(); + // Test with a type LDBG("B") << "Hello, world!"; - ExpectedOs << "[B:1] " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) - << " Hello, world!\n"; + ExpectedOs << "[B " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) + << " 1] Hello, world!\n"; EXPECT_EQ(DebugOs.str(), ExpectedOs.str()); Str.clear(); StrExpected.clear(); // Test with a type and a level LDBG("B", 2) << "Hello, world!"; - ExpectedOs << "[B:2] " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) - << " Hello, world!\n"; + ExpectedOs << "[B " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) + << " 2] Hello, world!\n"; EXPECT_EQ(DebugOs.str(), ExpectedOs.str()); Str.clear(); StrExpected.clear(); @@ -181,6 +218,8 @@ TEST(DebugLogTest, LDBG_MACROS) { // Test with a level not enabled. LDBG("B", 3) << "Hello, world!"; EXPECT_EQ(DebugOs.str(), ""); + LDBG(__LLVM_FILE_NAME__, 4) << "Hello, world!"; + EXPECT_EQ(DebugOs.str(), ""); } TEST(DebugLogTest, LDBG_OS_MACROS) { @@ -195,35 +234,70 @@ TEST(DebugLogTest, LDBG_OS_MACROS) { #define LDBG_STREAM DebugOs #define DEBUG_TYPE "A" LDBG_OS([](raw_ostream &Os) { Os << "Hello, world!"; }); - ExpectedOs << "[A:1] " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) - << " Hello, world!\n"; + ExpectedOs << "[A " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) + << " 1] Hello, world!\n"; EXPECT_EQ(DebugOs.str(), ExpectedOs.str()); Str.clear(); StrExpected.clear(); // Test with a level, no type. LDBG_OS(2, [](raw_ostream &Os) { Os << "Hello, world!"; }); - ExpectedOs << "[A:2] " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) - << " Hello, world!\n"; + ExpectedOs << "[A " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) + << " 2] Hello, world!\n"; EXPECT_EQ(DebugOs.str(), ExpectedOs.str()); Str.clear(); StrExpected.clear(); -// Now the type will be explicit, check we don't use DEBUG_TYPE. +// Now check when we don't use DEBUG_TYPE, the file name is implicitly used +// instead. #undef DEBUG_TYPE + // Repeat the tests above, they won't match since the debug types defined + // above don't match the file name. + LDBG_OS([](raw_ostream &Os) { Os << "Hello, world!"; }); + EXPECT_EQ(DebugOs.str(), ""); + Str.clear(); + StrExpected.clear(); + + // Test with a level, no type. + LDBG_OS(2, [](raw_ostream &Os) { Os << "Hello, world!"; }); + EXPECT_EQ(DebugOs.str(), ""); + Str.clear(); + StrExpected.clear(); + + // Now enable the debug types that match the file name. + auto fileNameAndLevel = std::string(__LLVM_FILE_NAME__) + ":3"; + static const char *DT2[] = {fileNameAndLevel.c_str(), "B:2"}; + setCurrentDebugTypes(DT2, sizeof(DT2) / sizeof(DT2[0])); + + // Repeat the tests above, they should match now. + LDBG_OS([](raw_ostream &Os) { Os << "Hello, world!"; }); + ExpectedOs << "[" << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) + << " 1] Hello, world!\n"; + EXPECT_EQ(DebugOs.str(), ExpectedOs.str()); + Str.clear(); + StrExpected.clear(); + + // Test with a level, no type. + LDBG_OS(2, [](raw_ostream &Os) { Os << "Hello, world!"; }); + ExpectedOs << "[" << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) + << " 2] Hello, world!\n"; + EXPECT_EQ(DebugOs.str(), ExpectedOs.str()); + Str.clear(); + StrExpected.clear(); + // Test with a type. LDBG_OS("B", [](raw_ostream &Os) { Os << "Hello, world!"; }); - ExpectedOs << "[B:1] " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) - << " Hello, world!\n"; + ExpectedOs << "[B " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) + << " 1] Hello, world!\n"; EXPECT_EQ(DebugOs.str(), ExpectedOs.str()); Str.clear(); StrExpected.clear(); // Test with a type and a level LDBG_OS("B", 2, [](raw_ostream &Os) { Os << "Hello, world!"; }); - ExpectedOs << "[B:2] " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) - << " Hello, world!\n"; + ExpectedOs << "[B " << __LLVM_FILE_NAME__ << ":" << (__LINE__ - 1) + << " 2] Hello, world!\n"; EXPECT_EQ(DebugOs.str(), ExpectedOs.str()); Str.clear(); StrExpected.clear(); diff --git a/mlir/test/IR/test-pattern-logging-listener.mlir b/mlir/test/IR/test-pattern-logging-listener.mlir index d3d42e3c9a500..d7d9120655596 100644 --- a/mlir/test/IR/test-pattern-logging-listener.mlir +++ b/mlir/test/IR/test-pattern-logging-listener.mlir @@ -1,6 +1,6 @@ // REQUIRES: asserts // RUN: mlir-opt %s --test-walk-pattern-rewrite-driver \ -// RUN: --allow-unregistered-dialect --debug-only=pattern-logging-listener 2>&1 | FileCheck %s +// RUN: --debug-only=pattern-logging-listener 2>&1 | FileCheck %s // Check that when replacing an op with a new op, we get appropriate // pattern-logging lines. The use of check same is to avoid the complexity of @@ -8,15 +8,18 @@ // {anonymous_namespace} vs `anonymous_namespace` (and maybe others?) on the // various platforms. -// CHECK: [pattern-logging-listener:1] +// Changing the reference output here need to also plan on updating the post-processing +// script here: https://github.com/llvm/mlir-www/blob/main/.github%2Fworkflows%2Fmain.yml#L71-L72 + +// CHECK: [pattern-logging-listener PatternLoggingListener.cpp:10 1] // CHECK-SAME: ::ReplaceWithNewOp | notifyOperationInserted | test.new_op -// CHECK: [pattern-logging-listener:1] +// CHECK: [pattern-logging-listener PatternLoggingListener.cpp:31 1] // CHECK-SAME: ::ReplaceWithNewOp | notifyOperationReplaced (with values) | test.replace_with_new_op -// CHECK: [pattern-logging-listener:1] +// CHECK: [pattern-logging-listener PatternLoggingListener.cpp:17 1] // CHECK-SAME: ::ReplaceWithNewOp | notifyOperationModified | arith.addi -// CHECK: [pattern-logging-listener:1] +// CHECK: [pattern-logging-listener PatternLoggingListener.cpp:17 1] // CHECK-SAME: ::ReplaceWithNewOp | notifyOperationModified | arith.addi -// CHECK: [pattern-logging-listener:1] +// CHECK: [pattern-logging-listener PatternLoggingListener.cpp:38 1] // CHECK-SAME: ::ReplaceWithNewOp | notifyOperationErased | test.replace_with_new_op func.func @replace_with_new_op() -> i32 { %a = "test.replace_with_new_op"() : () -> (i32)