Skip to content

[llvm][Timer] Don't print timers in TimerGroup when all Timers are removed #131026

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Mar 12, 2025

Conversation

aeubanks
Copy link
Contributor

Only print them on TimerGroup destruction (or eagerly when TimerGroup::printAll() is called).

We should be able to destroy all Timers in a TimerGroup while delaying printing the stored TimeRecords.

…moved

Only print them on TimerGroup destruction (or eagerly when TimerGroup::printAll() is called).

We should be able to destroy all Timers in a TimerGroup while delaying printing the stored TimeRecords.
@llvmbot
Copy link
Member

llvmbot commented Mar 12, 2025

@llvm/pr-subscribers-llvm-support

Author: Arthur Eubanks (aeubanks)

Changes

Only print them on TimerGroup destruction (or eagerly when TimerGroup::printAll() is called).

We should be able to destroy all Timers in a TimerGroup while delaying printing the stored TimeRecords.


Full diff: https://github.com/llvm/llvm-project/pull/131026.diff

2 Files Affected:

  • (modified) llvm/lib/Support/Timer.cpp (+5-8)
  • (modified) llvm/unittests/Support/TimerTest.cpp (+17-1)
diff --git a/llvm/lib/Support/Timer.cpp b/llvm/lib/Support/Timer.cpp
index 089dae2886f22..eca726828c697 100644
--- a/llvm/lib/Support/Timer.cpp
+++ b/llvm/lib/Support/Timer.cpp
@@ -284,6 +284,11 @@ TimerGroup::~TimerGroup() {
   while (FirstTimer)
     removeTimer(*FirstTimer);
 
+  if (!TimersToPrint.empty()) {
+    std::unique_ptr<raw_ostream> OutStream = CreateInfoOutputFile();
+    PrintQueuedTimers(*OutStream);
+  }
+
   // Remove the group from the TimerGroupList.
   sys::SmartScopedLock<true> L(timerLock());
   *Prev = Next;
@@ -305,14 +310,6 @@ void TimerGroup::removeTimer(Timer &T) {
   *T.Prev = T.Next;
   if (T.Next)
     T.Next->Prev = T.Prev;
-
-  // Print the report when all timers in this group are destroyed if some of
-  // them were started.
-  if (FirstTimer || TimersToPrint.empty())
-    return;
-
-  std::unique_ptr<raw_ostream> OutStream = CreateInfoOutputFile();
-  PrintQueuedTimers(*OutStream);
 }
 
 void TimerGroup::addTimer(Timer &T) {
diff --git a/llvm/unittests/Support/TimerTest.cpp b/llvm/unittests/Support/TimerTest.cpp
index 5686b394e16cd..612fd7231da70 100644
--- a/llvm/unittests/Support/TimerTest.cpp
+++ b/llvm/unittests/Support/TimerTest.cpp
@@ -66,4 +66,20 @@ TEST(Timer, CheckIfTriggered) {
   EXPECT_FALSE(T1.hasTriggered());
 }
 
-} // end anon namespace
+TEST(Timer, TimerGroupTimerDestructed) {
+  testing::internal::CaptureStderr();
+
+  {
+    TimerGroup TG("tg", "desc");
+    {
+      Timer T1("T1", "T1", TG);
+      T1.startTimer();
+      T1.stopTimer();
+    }
+    EXPECT_TRUE(testing::internal::GetCapturedStderr().empty());
+    testing::internal::CaptureStderr();
+  }
+  EXPECT_FALSE(testing::internal::GetCapturedStderr().empty());
+}
+
+} // namespace

@aeubanks aeubanks merged commit 1cfca53 into llvm:main Mar 12, 2025
10 of 12 checks passed
@aeubanks aeubanks deleted the timer branch March 12, 2025 23:20
@llvm-ci
Copy link
Collaborator

llvm-ci commented Mar 13, 2025

LLVM Buildbot has detected a new failure on builder premerge-monolithic-linux running on premerge-linux-1 while building llvm at step 7 "test-build-unified-tree-check-all".

Full details are available at: https://lab.llvm.org/buildbot/#/builders/153/builds/25569

Here is the relevant piece of the build log for the reference
Step 7 (test-build-unified-tree-check-all) failure: test (failure)
******************** TEST 'BOLT :: X86/icf-safe-test1.test' FAILED ********************
Exit Code: 1

Command Output (stderr):
--
RUN: at line 5: /build/buildbot/premerge-monolithic-linux/build/bin/llvm-mc -filetype=obj -triple x86_64-unknown-linux /build/buildbot/premerge-monolithic-linux/llvm-project/bolt/test/X86/icf-safe-test1.test -o /build/buildbot/premerge-monolithic-linux/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp1.o
+ /build/buildbot/premerge-monolithic-linux/build/bin/llvm-mc -filetype=obj -triple x86_64-unknown-linux /build/buildbot/premerge-monolithic-linux/llvm-project/bolt/test/X86/icf-safe-test1.test -o /build/buildbot/premerge-monolithic-linux/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp1.o
RUN: at line 6: /build/buildbot/premerge-monolithic-linux/build/bin/clang  --target=x86_64-unknown-linux-gnu -fPIE -fuse-ld=lld -Wl,--unresolved-symbols=ignore-all -Wl,--build-id=none -pie --target=x86_64-unknown-linux-gnu -nostdlib /build/buildbot/premerge-monolithic-linux/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp1.o -o /build/buildbot/premerge-monolithic-linux/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.exe -Wl,-q
+ /build/buildbot/premerge-monolithic-linux/build/bin/clang --target=x86_64-unknown-linux-gnu -fPIE -fuse-ld=lld -Wl,--unresolved-symbols=ignore-all -Wl,--build-id=none -pie --target=x86_64-unknown-linux-gnu -nostdlib /build/buildbot/premerge-monolithic-linux/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp1.o -o /build/buildbot/premerge-monolithic-linux/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.exe -Wl,-q
ld.lld: warning: cannot find entry symbol _start; not setting start address
RUN: at line 7: /build/buildbot/premerge-monolithic-linux/build/bin/llvm-bolt --runtime-instrumentation-lib=/build/buildbot/premerge-monolithic-linux/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_instr.a --runtime-hugify-lib=/build/buildbot/premerge-monolithic-linux/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_hugify.a --no-threads /build/buildbot/premerge-monolithic-linux/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.exe --icf -debug-only=bolt-icf         -o /build/buildbot/premerge-monolithic-linux/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.bolt 2>&1 | /build/buildbot/premerge-monolithic-linux/build/bin/FileCheck --check-prefix=ICFCHECK /build/buildbot/premerge-monolithic-linux/llvm-project/bolt/test/X86/icf-safe-test1.test
+ /build/buildbot/premerge-monolithic-linux/build/bin/llvm-bolt --runtime-instrumentation-lib=/build/buildbot/premerge-monolithic-linux/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_instr.a --runtime-hugify-lib=/build/buildbot/premerge-monolithic-linux/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_hugify.a --no-threads /build/buildbot/premerge-monolithic-linux/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.exe --icf -debug-only=bolt-icf -o /build/buildbot/premerge-monolithic-linux/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.bolt
+ /build/buildbot/premerge-monolithic-linux/build/bin/FileCheck --check-prefix=ICFCHECK /build/buildbot/premerge-monolithic-linux/llvm-project/bolt/test/X86/icf-safe-test1.test
RUN: at line 9: /build/buildbot/premerge-monolithic-linux/build/bin/llvm-bolt --runtime-instrumentation-lib=/build/buildbot/premerge-monolithic-linux/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_instr.a --runtime-hugify-lib=/build/buildbot/premerge-monolithic-linux/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_hugify.a --no-threads /build/buildbot/premerge-monolithic-linux/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.exe --icf=safe -debug-only=bolt-icf         -o /build/buildbot/premerge-monolithic-linux/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.bolt 2>&1 | /build/buildbot/premerge-monolithic-linux/build/bin/FileCheck --check-prefix=SAFEICFCHECK /build/buildbot/premerge-monolithic-linux/llvm-project/bolt/test/X86/icf-safe-test1.test
+ /build/buildbot/premerge-monolithic-linux/build/bin/FileCheck --check-prefix=SAFEICFCHECK /build/buildbot/premerge-monolithic-linux/llvm-project/bolt/test/X86/icf-safe-test1.test
+ /build/buildbot/premerge-monolithic-linux/build/bin/llvm-bolt --runtime-instrumentation-lib=/build/buildbot/premerge-monolithic-linux/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_instr.a --runtime-hugify-lib=/build/buildbot/premerge-monolithic-linux/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_hugify.a --no-threads /build/buildbot/premerge-monolithic-linux/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.exe --icf=safe -debug-only=bolt-icf -o /build/buildbot/premerge-monolithic-linux/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.bolt
/build/buildbot/premerge-monolithic-linux/llvm-project/bolt/test/X86/icf-safe-test1.test:21:22: error: SAFEICFCHECK-NEXT: is not on the line after the previous match
# SAFEICFCHECK-NEXT: ===---------
                     ^
<stdin>:18:1: note: 'next' match was here
===-------------------------------------------------------------------------===
^
<stdin>:11:47: note: previous match ended here
BOLT-DEBUG: folding barSubFunc into fooSubFunc
                                              ^
<stdin>:12:1: note: non-matching line after previous match is here
BOLT-DEBUG: ICF iteration 2...
^

Input file: <stdin>
Check file: /build/buildbot/premerge-monolithic-linux/llvm-project/bolt/test/X86/icf-safe-test1.test

-dump-input=help explains the following input dump.

Input was:
<<<<<<
         .
         .
         .
        13: BOLT-INFO: ICF folded 1 out of 6 functions in 3 passes. 0 functions had jump tables. 
        14: BOLT-INFO: Removing all identical functions will save 0.00 KB of code space. Folded functions were called 0 times based on profile. 
        15: BOLT-DEBUG: skipping function with reference taken barAddFunc 
        16: BOLT-DEBUG: ICF iteration 1... 
        17: BOLT-INFO: no .got section found 
        18: ===-------------------------------------------------------------------------=== 
next:21     !~~~~~~~~~~~                                                                     error: match on wrong line
        19:  Miscellaneous Ungrouped Timers 
        20: ===-------------------------------------------------------------------------=== 
        21:  
        22:  ---User Time--- --System Time-- --User+System-- ---Wall Time--- --- Name --- 
...

@llvm-ci
Copy link
Collaborator

llvm-ci commented Mar 13, 2025

LLVM Buildbot has detected a new failure on builder bolt-x86_64-ubuntu-nfc running on bolt-worker while building llvm at step 8 "test-build-bolt-check-bolt".

Full details are available at: https://lab.llvm.org/buildbot/#/builders/92/builds/15241

Here is the relevant piece of the build log for the reference
Step 8 (test-build-bolt-check-bolt) failure: test (failure)
******************** TEST 'BOLT :: X86/icf-safe-test1.test' FAILED ********************
Exit Code: 1

Command Output (stderr):
--
RUN: at line 5: /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/bin/llvm-mc -filetype=obj -triple x86_64-unknown-linux /home/worker/bolt-worker2/llvm-project/bolt/test/X86/icf-safe-test1.test -o /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp1.o
+ /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/bin/llvm-mc -filetype=obj -triple x86_64-unknown-linux /home/worker/bolt-worker2/llvm-project/bolt/test/X86/icf-safe-test1.test -o /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp1.o
RUN: at line 6: /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/bin/clang  --target=x86_64-unknown-linux-gnu -fPIE -fuse-ld=lld -Wl,--unresolved-symbols=ignore-all -Wl,--build-id=none -pie --target=x86_64-unknown-linux-gnu -nostdlib /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp1.o -o /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.exe -Wl,-q
+ /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/bin/clang --target=x86_64-unknown-linux-gnu -fPIE -fuse-ld=lld -Wl,--unresolved-symbols=ignore-all -Wl,--build-id=none -pie --target=x86_64-unknown-linux-gnu -nostdlib /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp1.o -o /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.exe -Wl,-q
ld.lld: warning: cannot find entry symbol _start; not setting start address
RUN: at line 7: /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/bin/llvm-bolt --runtime-instrumentation-lib=/home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_instr.a --runtime-hugify-lib=/home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_hugify.a --no-threads /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.exe --icf -debug-only=bolt-icf         -o /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.bolt 2>&1 | /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/bin/FileCheck --check-prefix=ICFCHECK /home/worker/bolt-worker2/llvm-project/bolt/test/X86/icf-safe-test1.test
+ /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/bin/llvm-bolt --runtime-instrumentation-lib=/home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_instr.a --runtime-hugify-lib=/home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_hugify.a --no-threads /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.exe --icf -debug-only=bolt-icf -o /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.bolt
+ /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/bin/FileCheck --check-prefix=ICFCHECK /home/worker/bolt-worker2/llvm-project/bolt/test/X86/icf-safe-test1.test
RUN: at line 9: /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/bin/llvm-bolt --runtime-instrumentation-lib=/home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_instr.a --runtime-hugify-lib=/home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_hugify.a --no-threads /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.exe --icf=safe -debug-only=bolt-icf         -o /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.bolt 2>&1 | /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/bin/FileCheck --check-prefix=SAFEICFCHECK /home/worker/bolt-worker2/llvm-project/bolt/test/X86/icf-safe-test1.test
+ /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/bin/llvm-bolt --runtime-instrumentation-lib=/home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_instr.a --runtime-hugify-lib=/home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/bolt_rt-bins/lib/libbolt_rt_hugify.a --no-threads /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.exe --icf=safe -debug-only=bolt-icf -o /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/tools/bolt/test/X86/Output/icf-safe-test1.test.tmp.bolt
+ /home/worker/bolt-worker2/bolt-x86_64-ubuntu-nfc/build/bin/FileCheck --check-prefix=SAFEICFCHECK /home/worker/bolt-worker2/llvm-project/bolt/test/X86/icf-safe-test1.test
/home/worker/bolt-worker2/llvm-project/bolt/test/X86/icf-safe-test1.test:21:22: error: SAFEICFCHECK-NEXT: is not on the line after the previous match
# SAFEICFCHECK-NEXT: ===---------
                     ^
<stdin>:18:1: note: 'next' match was here
===-------------------------------------------------------------------------===
^
<stdin>:11:47: note: previous match ended here
BOLT-DEBUG: folding barSubFunc into fooSubFunc
                                              ^
<stdin>:12:1: note: non-matching line after previous match is here
BOLT-DEBUG: ICF iteration 2...
^

Input file: <stdin>
Check file: /home/worker/bolt-worker2/llvm-project/bolt/test/X86/icf-safe-test1.test

-dump-input=help explains the following input dump.

Input was:
<<<<<<
         .
         .
         .
        13: BOLT-INFO: ICF folded 1 out of 6 functions in 3 passes. 0 functions had jump tables. 
        14: BOLT-INFO: Removing all identical functions will save 0.00 KB of code space. Folded functions were called 0 times based on profile. 
        15: BOLT-DEBUG: skipping function with reference taken barAddFunc 
        16: BOLT-DEBUG: ICF iteration 1... 
        17: BOLT-INFO: no .got section found 
        18: ===-------------------------------------------------------------------------=== 
next:21     !~~~~~~~~~~~                                                                     error: match on wrong line
        19:  Miscellaneous Ungrouped Timers 
        20: ===-------------------------------------------------------------------------=== 
        21:  
        22:  ---User Time--- --System Time-- --User+System-- ---Wall Time--- --- Name --- 
...

frederik-h pushed a commit to frederik-h/llvm-project that referenced this pull request Mar 18, 2025
…moved (llvm#131026)

Only print them on TimerGroup destruction (or eagerly when
TimerGroup::printAll() is called).

We should be able to destroy all Timers in a TimerGroup while delaying
printing the stored TimeRecords.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants