[clang][deps] Print timing information

[jansvoboda11]

Summary

This patch adds new -print-timing option to clang-scan-deps. It measures the wall and process time taken to scan dependencies for the compilation database. This provides more representative data compared to measuring the timing for the whole tool invocation, since that includes parsing and generating JSON files, which can be significant for larger inputs.

[akyrtzi]

Could you also add a -terse option, to avoid printing the full dependency info, if you mainly want to get the timing? Something like this:

T.stopTimer();
if (PrintTiming)
  llvm::errs() << llvm::format(
      "clang-scan-deps timing: %0.2fs wall, %0.2fs process\n",
      T.getTotalTime().getWallTime(), T.getTotalTime().getProcessTime());

if (Terse) {
  if (Format == ScanningOutputFormat::Full) {
    llvm::errs() << "num modules: " << FD->getNumModules() << '\n';
  }

  return HadErrors;
}

Where getNumModules() is

size_t getNumModules() const {
  return Modules.size();
}

So you still get some very high-level info but not the whole dump of info.

[akyrtzi]

Could you also add a -terse option, to avoid printing the full dependency info

Note I added something like this in https://reviews.llvm.org/D148369, so ignore it for this patch.

clang/test/ClangScanDeps/print-timing.c

+// RUN: rm -rf %t && mkdir %t
+// RUN: split-file %s %t
+
+// 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
+
+//--- cdb.json
+[]

clang/tools/clang-scan-deps/ClangScanDeps.cpp

 #include "clang/Tooling/DependencyScanning/DependencyScanningService.h"
 #include "clang/Tooling/DependencyScanning/DependencyScanningTool.h"
 #include "clang/Tooling/DependencyScanning/DependencyScanningWorker.h"
 #include "clang/Tooling/JSONCompilationDatabase.h"
 #include "llvm/ADT/STLExtras.h"
 #include "llvm/ADT/Twine.h"
 #include "llvm/Support/CommandLine.h"
 #include "llvm/Support/FileUtilities.h"
+#include "llvm/Support/Format.h"
 #include "llvm/Support/InitLLVM.h"
 #include "llvm/Support/JSON.h"
 #include "llvm/Support/LLVMDriver.h"
 #include "llvm/Support/Program.h"
 #include "llvm/Support/Signals.h"
 #include "llvm/Support/ThreadPool.h"
 #include "llvm/Support/Threading.h"
+#include "llvm/Support/Timer.h"
 #include "llvm/TargetParser/Host.h"
 #include <mutex>
 #include <optional>
 #include <thread>
 
 #include "Opts.inc"
 
 using namespace clang;

 static bool EagerLoadModules;
 static unsigned NumThreads = 0;
 static std::string CompilationDB;
 static std::string ModuleName;
 static std::vector<std::string> ModuleDepTargets;
 static bool DeprecatedDriverCommand;
 static ResourceDirRecipeKind ResourceDirRecipe;
 static bool Verbose;
+static bool PrintTiming;
 static std::vector<const char *> CommandLine;
 
 #ifndef NDEBUG
 static constexpr bool DoRoundTripDefault = true;
 #else
 static constexpr bool DoRoundTripDefault = false;
 #endif
 
if (!Kind) {
                    << ": for the --resource-dir-recipe option: Cannot find "
                       "option named '"
                    << A->getValue() << "'\n";
       std::exit(1);
     }
     ResourceDirRecipe = *Kind;
   }
 
+  PrintTiming = Args.hasArg(OPT_print_timing);
+
   Verbose = Args.hasArg(OPT_verbose);
 
   RoundTripArgs = Args.hasArg(OPT_round_trip_args);
 
   if (auto *A = Args.getLastArgNoClaim(OPT_DASH_DASH))
     CommandLine.insert(CommandLine.end(), A->getValues().begin(),
                        A->getValues().end());
 }
int clang_scan_deps_main(int argc, char **argv, const llvm::ToolContext &) {
 
   if (Format == ScanningOutputFormat::Full)
     FD.emplace(ModuleName.empty() ? Inputs.size() : 0);
 
   if (Verbose) {
     llvm::outs() << "Running clang-scan-deps on " << Inputs.size()
                  << " files using " << Pool.getThreadCount() << " workers\n";
   }
+
+  llvm::Timer T;
+  T.startTimer();
+
   for (unsigned I = 0; I < Pool.getThreadCount(); ++I) {
     Pool.async([&, I]() {
       llvm::StringSet<> AlreadySeenModules;
       while (auto MaybeInputIndex = GetNextInputIndex()) {
         size_t LocalIndex = *MaybeInputIndex;
         const tooling::CompileCommand *Input = &Inputs[LocalIndex];
         std::string Filename = std::move(Input->Filename);
         std::string CWD = std::move(Input->Directory);
Pool.async([&, I]() {
                                           LocalIndex, DependencyOS, Errs))
             HadErrors = true;
         }
       }
     });
   }
   Pool.wait();
 
+  T.stopTimer();
+  if (PrintTiming)
+    llvm::errs() << llvm::format(
+        "clang-scan-deps timing: %0.2fs wall, %0.2fs process\n",
+        T.getTotalTime().getWallTime(), T.getTotalTime().getProcessTime());
+
   if (RoundTripArgs)
     if (FD && FD->roundTripCommands(llvm::errs()))
       HadErrors = true;
 
   if (Format == ScanningOutputFormat::Full)
     FD->printFullOutput(llvm::outs());
   else if (Format == ScanningOutputFormat::P1689)
     PD.printDependencies(llvm::outs());
 
   return HadErrors;
 }

clang/tools/clang-scan-deps/Opts.td

 defm compilation_database : Eq<"compilation-database", "Compilation database">;
 defm module_name : Eq<"module-name", "the module of which the dependencies are to be computed">;
 defm dependency_target : Eq<"dependency-target", "The names of dependency targets for the dependency file">;
 
 def deprecated_driver_command : F<"deprecated-driver-command", "use a single driver command to build the tu (deprecated)">;
 
 defm resource_dir_recipe : Eq<"resource-dir-recipe", "How to produce missing '-resource-dir' argument">;
 
+def print_timing : F<"print-timing", "Print timing information">;
+
 def verbose : F<"v", "Use verbose output">;
 
 def round_trip_args : F<"round-trip-args", "verify that command-line arguments are canonical by parsing and re-serializing">;
 
 def DASH_DASH : Option<["--"], "", KIND_REMAINING_ARGS>;
 No newline at end of file