[clang] 39303e2 - [clang][deps] Improve timing output (#113726)

[via cfe-commits]

Author: Jan Svoboda
Date: 2024-10-28T14:00:31-07:00
New Revision: 39303e24b6f628f3c080f1b54bd12383a55b9b3a

URL: https://github.com/llvm/llvm-project/commit/39303e24b6f628f3c080f1b54bd12383a55b9b3a
DIFF: https://github.com/llvm/llvm-project/commit/39303e24b6f628f3c080f1b54bd12383a55b9b3a.diff

LOG: [clang][deps] Improve timing output (#113726)

This patch adds the number of executed instructions into the timing
output, which provides more stable results compared to wall or process
time.

The format itself is also tweaked so that it's more amenable for direct
import into a spreadsheet editor.

Added: 
    

Modified: 
    clang/test/ClangScanDeps/print-timing.c
    clang/tools/clang-scan-deps/ClangScanDeps.cpp

Removed: 
    


################################################################################
diff  --git a/clang/test/ClangScanDeps/print-timing.c b/clang/test/ClangScanDeps/print-timing.c
index f27df1ebf732a9..fa2a433b955370 100644
--- a/clang/test/ClangScanDeps/print-timing.c
+++ b/clang/test/ClangScanDeps/print-timing.c
@@ -3,7 +3,8 @@
 
 // RUN: clang-scan-deps -compilation-database %t/cdb.json -print-timing > %t/result.json 2>%t/errs
 // RUN: cat %t/errs | FileCheck %s
-// CHECK: clang-scan-deps timing: {{[0-9]+}}.{{[0-9][0-9]}}s wall, {{[0-9]+}}.{{[0-9][0-9]}}s process
+// CHECK:      wall time [s]              process time [s]           instruction count
+// CHECK-NEXT: {{[0-9]+}}.{{([0-9]{4})}}  {{[0-9]+}}.{{([0-9]{4})}}  {{[0-9]+}}
 
 //--- cdb.json
 []

diff  --git a/clang/tools/clang-scan-deps/ClangScanDeps.cpp b/clang/tools/clang-scan-deps/ClangScanDeps.cpp
index 7d36cee7a22b39..f474b1346b1be1 100644
--- a/clang/tools/clang-scan-deps/ClangScanDeps.cpp
+++ b/clang/tools/clang-scan-deps/ClangScanDeps.cpp
@@ -1080,10 +1080,15 @@ int clang_scan_deps_main(int argc, char **argv, const llvm::ToolContext &) {
                  << NumExistsCalls << " exists() calls\n"
                  << NumIsLocalCalls << " isLocal() calls\n";
 
-  if (PrintTiming)
-    llvm::errs() << llvm::format(
-        "clang-scan-deps timing: %0.2fs wall, %0.2fs process\n",
-        T.getTotalTime().getWallTime(), T.getTotalTime().getProcessTime());
+  if (PrintTiming) {
+    llvm::errs() << "wall time [s]\t"
+                 << "process time [s]\t"
+                 << "instruction count\n";
+    const llvm::TimeRecord &R = T.getTotalTime();
+    llvm::errs() << llvm::format("%0.4f", R.getWallTime()) << "\t"
+                 << llvm::format("%0.4f", R.getProcessTime()) << "\t"
+                 << llvm::format("%llu", R.getInstructionsExecuted()) << "\n";
+  }
 
   if (RoundTripArgs)
     if (FD && FD->roundTripCommands(llvm::errs()))