Default DEBUG_TYPE to the current filename for logging (#158494)

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.
This commit is contained in:
Mehdi Amini 2025-09-15 18:31:18 +02:00 committed by GitHub
parent 0a4b87dac4
commit 53cda13202
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
4 changed files with 128 additions and 61 deletions

View file

@ -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
<no output>
$ 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:

View file

@ -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<decltype(LevelOrType)>) { \
@ -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.

View file

@ -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<int>(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<int>(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();

View file

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