Merge topic 'profiling'

9aa4640792 cmake: add command line options to output script profiling data

Acked-by: Kitware Robot <kwrobot@kitware.com>
Acked-by: Ben Boeckel <ben.boeckel@kitware.com>
Acked-by: Pavel Solodovnikov <hellyeahdominate@gmail.com>
Acked-by: Leonid Pospelov <pospelovlm@yandex.ru>
Acked-by: Cristian Adam <cristian.adam@gmail.com>
Merge-request: !2760

Help/manual/cmake.1.rst

@@ -356,6 +356,20 @@ Options
  in :variable:`CMAKE_SOURCE_DIR` and :variable:`CMAKE_BINARY_DIR`.
  This flag tells CMake to warn about other files as well.
 
+``--profiling-output=<path>``
+ Used in conjuction with ``--profiling-format`` to output to a given path.
+
+``--profiling-format=<file>``
+ Enable the output of profiling data of CMake script in the given format.
+
+ This can aid performance analysis of CMake scripts executed. Third party
+ applications should be used to process the output into human readable format.
+
+ Currently supported values are:
+ ``google-trace`` Outputs in Google Trace Format, which can be parsed by the
+ about:tracing tab of Google Chrome or using a plugin for a tool like Trace
+ Compass.
+
 .. _`Build Tool Mode`:
 
 Build a Project

Help/release/dev/profiling.rst

@@ -0,0 +1,9 @@
+cmake-profiling
+---------------
+
+* Add support for profiling of CMake scripts through the parameters
+  ``--profiling-output`` and ``--profiling-format``. These options can
+  be used by users to gain insight into the performance of their scripts.
+
+  The first supported output format is ``google-trace`` which is a format
+  supported by Google Chrome's ``about:tracing`` tab.

Source/CMakeLists.txt

@@ -354,6 +354,7 @@ set(SRCS
   cmMakefileTargetGenerator.cxx
   cmMakefileExecutableTargetGenerator.cxx
   cmMakefileLibraryTargetGenerator.cxx
+  cmMakefileProfilingData.cxx
   cmMakefileUtilityTargetGenerator.cxx
   cmMessageType.h
   cmMessenger.cxx

Source/cmMakefile.cxx

@@ -60,6 +60,7 @@
 #include "cmake.h"
 
 #ifndef CMAKE_BOOTSTRAP
+#  include "cmMakefileProfilingData.h"
 #  include "cmVariableWatch.h"
 #endif
 
@@ -372,19 +373,30 @@ void cmMakefile::PrintCommandTrace(const cmListFileFunction& lff) const
 class cmMakefileCall
 {
 public:
-  cmMakefileCall(cmMakefile* mf, cmCommandContext const& cc,
+  cmMakefileCall(cmMakefile* mf, cmListFileFunction const& lff,
                  cmExecutionStatus& status)
     : Makefile(mf)
   {
     cmListFileContext const& lfc = cmListFileContext::FromCommandContext(
-      cc, this->Makefile->StateSnapshot.GetExecutionListFile());
+      lff, this->Makefile->StateSnapshot.GetExecutionListFile());
     this->Makefile->Backtrace = this->Makefile->Backtrace.Push(lfc);
     ++this->Makefile->RecursionDepth;
     this->Makefile->ExecutionStatusStack.push_back(&status);
+#if !defined(CMAKE_BOOTSTRAP)
+    if (this->Makefile->GetCMakeInstance()->IsProfilingEnabled()) {
+      this->Makefile->GetCMakeInstance()->GetProfilingOutput().StartEntry(lff,
+                                                                          lfc);
+    }
+#endif
   }
 
   ~cmMakefileCall()
   {
+#if !defined(CMAKE_BOOTSTRAP)
+    if (this->Makefile->GetCMakeInstance()->IsProfilingEnabled()) {
+      this->Makefile->GetCMakeInstance()->GetProfilingOutput().StopEntry();
+    }
+#endif
     this->Makefile->ExecutionStatusStack.pop_back();
     --this->Makefile->RecursionDepth;
     this->Makefile->Backtrace = this->Makefile->Backtrace.Pop();

Source/cmMakefileProfilingData.cxx

@@ -0,0 +1,113 @@
+/* Distributed under the OSI-approved BSD 3-Clause License.  See accompanying
+   file Copyright.txt or https://cmake.org/licensing for details.  */
+#include "cmMakefileProfilingData.h"
+
+#include <chrono>
+#include <cstdint>
+#include <stdexcept>
+#include <vector>
+
+#include "cmsys/FStream.hxx"
+#include "cmsys/SystemInformation.hxx"
+
+#include "cm_jsoncpp_value.h"
+#include "cm_jsoncpp_writer.h"
+
+#include "cmListFileCache.h"
+#include "cmStringAlgorithms.h"
+#include "cmSystemTools.h"
+
+cmMakefileProfilingData::cmMakefileProfilingData(
+  const std::string& profileStream)
+{
+  std::ios::openmode omode = std::ios::out | std::ios::trunc;
+  this->ProfileStream.open(profileStream.c_str(), omode);
+  Json::StreamWriterBuilder wbuilder;
+  this->JsonWriter =
+    std::unique_ptr<Json::StreamWriter>(wbuilder.newStreamWriter());
+  if (!this->ProfileStream.good()) {
+    throw std::runtime_error(std::string("Unable to open: ") + profileStream);
+  }
+
+  this->ProfileStream << "[";
+};
+
+cmMakefileProfilingData::~cmMakefileProfilingData() noexcept
+{
+  if (this->ProfileStream.good()) {
+    try {
+      this->ProfileStream << "]";
+      this->ProfileStream.close();
+    } catch (...) {
+      cmSystemTools::Error("Error writing profiling output!");
+    }
+  }
+}
+
+void cmMakefileProfilingData::StartEntry(const cmListFileFunction& lff,
+                                         cmListFileContext const& lfc)
+{
+  /* Do not try again if we previously failed to write to output. */
+  if (!this->ProfileStream.good()) {
+    return;
+  }
+
+  try {
+    if (this->ProfileStream.tellp() > 1) {
+      this->ProfileStream << ",";
+    }
+    cmsys::SystemInformation info;
+    Json::Value v;
+    v["ph"] = "B";
+    v["name"] = lff.Name.Original;
+    v["cat"] = "cmake";
+    v["ts"] = uint64_t(std::chrono::duration_cast<std::chrono::microseconds>(
+                         std::chrono::steady_clock::now().time_since_epoch())
+                         .count());
+    v["pid"] = static_cast<int>(info.GetProcessId());
+    v["tid"] = 0;
+    Json::Value argsValue;
+    if (!lff.Arguments.empty()) {
+      std::string args;
+      for (const auto& a : lff.Arguments) {
+        args += (args.empty() ? "" : " ") + a.Value;
+      }
+      argsValue["functionArgs"] = args;
+    }
+    argsValue["location"] = lfc.FilePath + ":" + std::to_string(lfc.Line);
+    v["args"] = argsValue;
+
+    this->JsonWriter->write(v, &this->ProfileStream);
+  } catch (std::ios_base::failure& fail) {
+    cmSystemTools::Error(
+      cmStrCat("Failed to write to profiling output: ", fail.what()));
+  } catch (...) {
+    cmSystemTools::Error("Error writing profiling output!");
+  }
+}
+
+void cmMakefileProfilingData::StopEntry()
+{
+  /* Do not try again if we previously failed to write to output. */
+  if (!this->ProfileStream.good()) {
+    return;
+  }
+
+  try {
+    this->ProfileStream << ",";
+    cmsys::SystemInformation info;
+    Json::Value v;
+    v["ph"] = "E";
+    v["ts"] = uint64_t(std::chrono::duration_cast<std::chrono::microseconds>(
+                         std::chrono::steady_clock::now().time_since_epoch())
+                         .count());
+    v["pid"] = static_cast<int>(info.GetProcessId());
+    v["tid"] = 0;
+    this->JsonWriter->write(v, &this->ProfileStream);
+  } catch (std::ios_base::failure& fail) {
+    cmSystemTools::Error(
+      cmStrCat("Failed to write to profiling output:", fail.what()));
+  } catch (...) {
+    cmSystemTools::Error("Error writing profiling output!");
+  }
+}

Source/cmMakefileProfilingData.h

@@ -0,0 +1,29 @@
+/* Distributed under the OSI-approved BSD 3-Clause License.  See accompanying
+   file Copyright.txt or https://cmake.org/licensing for details.  */
+#ifndef cmMakefileProfilingData_h
+#define cmMakefileProfilingData_h
+#include <memory>
+#include <string>
+
+#include "cmsys/FStream.hxx"
+
+namespace Json {
+class StreamWriter;
+}
+
+class cmListFileContext;
+struct cmListFileFunction;
+
+class cmMakefileProfilingData
+{
+public:
+  cmMakefileProfilingData(const std::string&);
+  ~cmMakefileProfilingData() noexcept;
+  void StartEntry(const cmListFileFunction& lff, cmListFileContext const& lfc);
+  void StopEntry();
+
+private:
+  cmsys::ofstream ProfileStream;
+  std::unique_ptr<Json::StreamWriter> JsonWriter;
+};
+#endif

Source/cmake.cxx

@@ -9,6 +9,7 @@
 #include <initializer_list>
 #include <iostream>
 #include <sstream>
+#include <stdexcept>
 #include <utility>
 
 #include <cm/memory>
@@ -39,6 +40,9 @@
 #include "cmLinkLineComputer.h"
 #include "cmLocalGenerator.h"
 #include "cmMakefile.h"
+#if !defined(CMAKE_BOOTSTRAP)
+#  include "cmMakefileProfilingData.h"
+#endif
 #include "cmMessenger.h"
 #include "cmState.h"
 #include "cmStateDirectory.h"
@@ -613,6 +617,10 @@ void cmake::SetArgs(const std::vector<std::string>& args)
 {
   bool haveToolset = false;
   bool havePlatform = false;
+#if !defined(CMAKE_BOOTSTRAP)
+  std::string profilingFormat;
+  std::string profilingOutput;
+#endif
   for (unsigned int i = 1; i < args.size(); ++i) {
     std::string const& arg = args[i];
     if (arg.find("-H", 0) == 0 || arg.find("-S", 0) == 0) {
@@ -839,6 +847,20 @@ void cmake::SetArgs(const std::vector<std::string>& args)
         return;
       }
       this->SetGlobalGenerator(std::move(gen));
+#if !defined(CMAKE_BOOTSTRAP)
+    } else if (arg.find("--profiling-format", 0) == 0) {
+      profilingFormat = arg.substr(strlen("--profiling-format="));
+      if (profilingFormat.empty()) {
+        cmSystemTools::Error("No format specified for --profiling-format");
+      }
+    } else if (arg.find("--profiling-output", 0) == 0) {
+      profilingOutput = arg.substr(strlen("--profiling-output="));
+      profilingOutput = cmSystemTools::CollapseFullPath(profilingOutput);
+      cmSystemTools::ConvertToUnixSlashes(profilingOutput);
+      if (profilingOutput.empty()) {
+        cmSystemTools::Error("No path specified for --profiling-output");
+      }
+#endif
     }
     // no option assume it is the path to the source or an existing build
     else {
@@ -856,6 +878,29 @@ void cmake::SetArgs(const std::vector<std::string>& args)
     }
   }
 
+#if !defined(CMAKE_BOOTSTRAP)
+  if (!profilingOutput.empty() || !profilingFormat.empty()) {
+    if (profilingOutput.empty()) {
+      cmSystemTools::Error(
+        "--profiling-format specified but no --profiling-output!");
+      return;
+    }
+    if (profilingFormat == "google-trace") {
+      try {
+        this->ProfilingOutput =
+          cm::make_unique<cmMakefileProfilingData>(profilingOutput);
+      } catch (std::runtime_error& e) {
+        cmSystemTools::Error(
+          cmStrCat("Could not start profiling: ", e.what()));
+        return;
+      }
+    } else {
+      cmSystemTools::Error("Invalid format specified for --profiling-format");
+      return;
+    }
+  }
+#endif
+
   const bool haveSourceDir = !this->GetHomeDirectory().empty();
   const bool haveBinaryDir = !this->GetHomeOutputDirectory().empty();
 
@@ -2952,3 +2997,15 @@ void cmake::SetDeprecatedWarningsAsErrors(bool b)
                       " and functions.",
                       cmStateEnums::INTERNAL);
 }
+
+#if !defined(CMAKE_BOOTSTRAP)
+cmMakefileProfilingData& cmake::GetProfilingOutput()
+{
+  return *(this->ProfilingOutput);
+}
+
+bool cmake::IsProfilingEnabled() const
+{
+  return static_cast<bool>(this->ProfilingOutput);
+}
+#endif

Source/cmake.h

@@ -34,6 +34,9 @@ class cmFileTimeCache;
 class cmGlobalGenerator;
 class cmGlobalGeneratorFactory;
 class cmMakefile;
+#if !defined(CMAKE_BOOTSTRAP)
+class cmMakefileProfilingData;
+#endif
 class cmMessenger;
 class cmVariableWatch;
 struct cmDocumentationEntry;
@@ -549,6 +552,11 @@ public:
 
   bool GetRegenerateDuringBuild() const { return this->RegenerateDuringBuild; }
 
+#if !defined(CMAKE_BOOTSTRAP)
+  cmMakefileProfilingData& GetProfilingOutput();
+  bool IsProfilingEnabled() const;
+#endif
+
 protected:
   void RunCheckForUnusedVariables();
   int HandleDeleteCacheVariables(const std::string& var);
@@ -657,6 +665,10 @@ private:
 
   void AppendGlobalGeneratorsDocumentation(std::vector<cmDocumentationEntry>&);
   void AppendExtraGeneratorsDocumentation(std::vector<cmDocumentationEntry>&);
+
+#if !defined(CMAKE_BOOTSTRAP)
+  std::unique_ptr<cmMakefileProfilingData> ProfilingOutput;
+#endif
 };
 
 #define CMAKE_STANDARD_OPTIONS_TABLE                                          \

Source/cmakemain.cxx

@@ -93,6 +93,12 @@ const char* cmDocumentationOptions[][2] = {
   { "--check-system-vars",
     "Find problems with variable usage in system "
     "files." },
+#  if !defined(CMAKE_BOOTSTRAP)
+  { "--profiling-format=<fmt>", "Output data for profiling CMake scripts." },
+  { "--profiling-output=<file>",
+    "Select an output path for the profiling data enabled through "
+    "--profiling-format." },
+#  endif
   { nullptr, nullptr }
 };
 

Tests/RunCMake/CommandLine/ProfilingTest-check.cmake

@@ -0,0 +1,18 @@
+if (NOT EXISTS ${ProfilingTestOutput})
+  set(RunCMake_TEST_FAILED "Expected ${ProfilingTestOutput} to exists")
+endif()
+
+file(READ "${ProfilingTestOutput}" JSON_HEADER LIMIT 2)
+if (NOT JSON_HEADER MATCHES "^\\[{")
+  set(RunCMake_TEST_FAILED "Expected valid JSON start")
+  return()
+endif()
+
+file(SIZE "${ProfilingTestOutput}" OUTPUT_SIZE)
+math(EXPR END_OFFSET "${OUTPUT_SIZE} -2 ")
+
+file(READ "${ProfilingTestOutput}" JSON_TRAILER OFFSET ${END_OFFSET})
+if (NOT JSON_TRAILER MATCHES "^}]$")
+  set(RunCMake_TEST_FAILED "Expected valid JSON end")
+  return()
+endif()

Tests/RunCMake/CommandLine/ProfilingTest.cmake

@@ -0,0 +1 @@
+# This file is intentionally left blank

Tests/RunCMake/CommandLine/RunCMakeTest.cmake

@@ -697,3 +697,25 @@ function(run_llvm_rc)
   unset(LLVMRC_RESULT)
 endfunction()
 run_llvm_rc()
+
+set(RunCMake_TEST_OPTIONS --profiling-output=/no/such/file.txt --profiling-format=google-trace)
+run_cmake(profiling-all-params)
+unset(RunCMake_TEST_OPTIONS)
+
+set(RunCMake_TEST_OPTIONS --profiling-output=/no/such/file.txt --profiling-format=invalid-format)
+run_cmake(profiling-invalid-format)
+unset(RunCMake_TEST_OPTIONS)
+
+set(RunCMake_TEST_OPTIONS --profiling-output=/no/such/file.txt)
+run_cmake(profiling-missing-format)
+unset(RunCMake_TEST_OPTIONS)
+
+set(RunCMake_TEST_OPTIONS --profiling-format=google-trace)
+run_cmake(profiling-missing-output)
+unset(RunCMake_TEST_OPTIONS)
+
+set(RunCMake_TEST_BINARY_DIR "${RunCMake_BINARY_DIR}/profiling-test")
+set(ProfilingTestOutput ${RunCMake_TEST_BINARY_DIR}/output.json)
+set(RunCMake_TEST_OPTIONS --profiling-format=google-trace --profiling-output=${ProfilingTestOutput})
+run_cmake(ProfilingTest)
+unset(RunCMake_TEST_OPTIONS)

Tests/RunCMake/CommandLine/profiling-all-params-result.txt

@@ -0,0 +1 @@
+1

Tests/RunCMake/CommandLine/profiling-all-params-stderr.txt

@@ -0,0 +1 @@
+^.*Could not start profiling: Unable to open: /no/such/file.txt$

Tests/RunCMake/CommandLine/profiling-invalid-format-result.txt

@@ -0,0 +1 @@
+1

Tests/RunCMake/CommandLine/profiling-invalid-format-stderr.txt

@@ -0,0 +1 @@
+^.*Invalid format specified for --profiling-format$

Tests/RunCMake/CommandLine/profiling-missing-format-result.txt

@@ -0,0 +1 @@
+1

Tests/RunCMake/CommandLine/profiling-missing-format-stderr.txt

@@ -0,0 +1 @@
+^.*Invalid format specified for --profiling-format$

Tests/RunCMake/CommandLine/profiling-missing-output-result.txt

@@ -0,0 +1 @@
+1

Tests/RunCMake/CommandLine/profiling-missing-output-stderr.txt

@@ -0,0 +1 @@
+^.*--profiling-format specified but no --profiling-output!$