From 9aa4640792bd99b232abfe826b0cb0ae72f6644a Mon Sep 17 00:00:00 2001 From: Wouter Klouwen Date: Sat, 2 Feb 2019 09:06:36 +0000 Subject: cmake: add command line options to output script profiling data For users of CMake who want to optimize their scripts if they take a while to run, this commit adds the ability to output profiling data. To enable this output, it adds the two command line parameters to select the output path and format. This commit adds the first profiling format of type ``google-trace``, which is the output is a JSON file containing Duration events as per the Google Trace Format specification: https://docs.google.com/document/d/1CvAClvFfyA5R- PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview# --- Help/manual/cmake.1.rst | 14 +++ Help/release/dev/profiling.rst | 9 ++ Source/CMakeLists.txt | 1 + Source/cmMakefile.cxx | 16 ++- Source/cmMakefileProfilingData.cxx | 113 +++++++++++++++++++++ Source/cmMakefileProfilingData.h | 29 ++++++ Source/cmake.cxx | 57 +++++++++++ Source/cmake.h | 12 +++ Source/cmakemain.cxx | 6 ++ .../RunCMake/CommandLine/ProfilingTest-check.cmake | 18 ++++ Tests/RunCMake/CommandLine/ProfilingTest.cmake | 1 + Tests/RunCMake/CommandLine/RunCMakeTest.cmake | 22 ++++ .../CommandLine/profiling-all-params-result.txt | 1 + .../CommandLine/profiling-all-params-stderr.txt | 1 + .../profiling-invalid-format-result.txt | 1 + .../profiling-invalid-format-stderr.txt | 1 + .../profiling-missing-format-result.txt | 1 + .../profiling-missing-format-stderr.txt | 1 + .../profiling-missing-output-result.txt | 1 + .../profiling-missing-output-stderr.txt | 1 + 20 files changed, 304 insertions(+), 2 deletions(-) create mode 100644 Help/release/dev/profiling.rst create mode 100644 Source/cmMakefileProfilingData.cxx create mode 100644 Source/cmMakefileProfilingData.h create mode 100644 Tests/RunCMake/CommandLine/ProfilingTest-check.cmake create mode 100644 Tests/RunCMake/CommandLine/ProfilingTest.cmake create mode 100644 Tests/RunCMake/CommandLine/profiling-all-params-result.txt create mode 100644 Tests/RunCMake/CommandLine/profiling-all-params-stderr.txt create mode 100644 Tests/RunCMake/CommandLine/profiling-invalid-format-result.txt create mode 100644 Tests/RunCMake/CommandLine/profiling-invalid-format-stderr.txt create mode 100644 Tests/RunCMake/CommandLine/profiling-missing-format-result.txt create mode 100644 Tests/RunCMake/CommandLine/profiling-missing-format-stderr.txt create mode 100644 Tests/RunCMake/CommandLine/profiling-missing-output-result.txt create mode 100644 Tests/RunCMake/CommandLine/profiling-missing-output-stderr.txt diff --git a/Help/manual/cmake.1.rst b/Help/manual/cmake.1.rst index 44b1f2f..429cba4 100644 --- a/Help/manual/cmake.1.rst +++ b/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=`` + Used in conjuction with ``--profiling-format`` to output to a given path. + +``--profiling-format=`` + 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 diff --git a/Help/release/dev/profiling.rst b/Help/release/dev/profiling.rst new file mode 100644 index 0000000..ab180f0 --- /dev/null +++ b/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. diff --git a/Source/CMakeLists.txt b/Source/CMakeLists.txt index 24370aa..467abe9 100644 --- a/Source/CMakeLists.txt +++ b/Source/CMakeLists.txt @@ -354,6 +354,7 @@ set(SRCS cmMakefileTargetGenerator.cxx cmMakefileExecutableTargetGenerator.cxx cmMakefileLibraryTargetGenerator.cxx + cmMakefileProfilingData.cxx cmMakefileUtilityTargetGenerator.cxx cmMessageType.h cmMessenger.cxx diff --git a/Source/cmMakefile.cxx b/Source/cmMakefile.cxx index 94d99b7..76c559f 100644 --- a/Source/cmMakefile.cxx +++ b/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(); diff --git a/Source/cmMakefileProfilingData.cxx b/Source/cmMakefileProfilingData.cxx new file mode 100644 index 0000000..ea64132 --- /dev/null +++ b/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 +#include +#include +#include + +#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(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::steady_clock::now().time_since_epoch()) + .count()); + v["pid"] = static_cast(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::steady_clock::now().time_since_epoch()) + .count()); + v["pid"] = static_cast(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!"); + } +} diff --git a/Source/cmMakefileProfilingData.h b/Source/cmMakefileProfilingData.h new file mode 100644 index 0000000..1babd97 --- /dev/null +++ b/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 +#include + +#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 JsonWriter; +}; +#endif diff --git a/Source/cmake.cxx b/Source/cmake.cxx index f4b9f16..29ed61d 100644 --- a/Source/cmake.cxx +++ b/Source/cmake.cxx @@ -9,6 +9,7 @@ #include #include #include +#include #include #include @@ -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& 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& 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& 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(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(this->ProfilingOutput); +} +#endif diff --git a/Source/cmake.h b/Source/cmake.h index 35425ec..58769fd 100644 --- a/Source/cmake.h +++ b/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&); void AppendExtraGeneratorsDocumentation(std::vector&); + +#if !defined(CMAKE_BOOTSTRAP) + std::unique_ptr ProfilingOutput; +#endif }; #define CMAKE_STANDARD_OPTIONS_TABLE \ diff --git a/Source/cmakemain.cxx b/Source/cmakemain.cxx index 494d5d9..90d8ea6 100644 --- a/Source/cmakemain.cxx +++ b/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=", "Output data for profiling CMake scripts." }, + { "--profiling-output=", + "Select an output path for the profiling data enabled through " + "--profiling-format." }, +# endif { nullptr, nullptr } }; diff --git a/Tests/RunCMake/CommandLine/ProfilingTest-check.cmake b/Tests/RunCMake/CommandLine/ProfilingTest-check.cmake new file mode 100644 index 0000000..19ece86 --- /dev/null +++ b/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() diff --git a/Tests/RunCMake/CommandLine/ProfilingTest.cmake b/Tests/RunCMake/CommandLine/ProfilingTest.cmake new file mode 100644 index 0000000..837f4bf --- /dev/null +++ b/Tests/RunCMake/CommandLine/ProfilingTest.cmake @@ -0,0 +1 @@ +# This file is intentionally left blank diff --git a/Tests/RunCMake/CommandLine/RunCMakeTest.cmake b/Tests/RunCMake/CommandLine/RunCMakeTest.cmake index 087ef21..41f13db 100644 --- a/Tests/RunCMake/CommandLine/RunCMakeTest.cmake +++ b/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) diff --git a/Tests/RunCMake/CommandLine/profiling-all-params-result.txt b/Tests/RunCMake/CommandLine/profiling-all-params-result.txt new file mode 100644 index 0000000..d00491f --- /dev/null +++ b/Tests/RunCMake/CommandLine/profiling-all-params-result.txt @@ -0,0 +1 @@ +1 diff --git a/Tests/RunCMake/CommandLine/profiling-all-params-stderr.txt b/Tests/RunCMake/CommandLine/profiling-all-params-stderr.txt new file mode 100644 index 0000000..6b5c373 --- /dev/null +++ b/Tests/RunCMake/CommandLine/profiling-all-params-stderr.txt @@ -0,0 +1 @@ +^.*Could not start profiling: Unable to open: /no/such/file.txt$ diff --git a/Tests/RunCMake/CommandLine/profiling-invalid-format-result.txt b/Tests/RunCMake/CommandLine/profiling-invalid-format-result.txt new file mode 100644 index 0000000..d00491f --- /dev/null +++ b/Tests/RunCMake/CommandLine/profiling-invalid-format-result.txt @@ -0,0 +1 @@ +1 diff --git a/Tests/RunCMake/CommandLine/profiling-invalid-format-stderr.txt b/Tests/RunCMake/CommandLine/profiling-invalid-format-stderr.txt new file mode 100644 index 0000000..459bc3a --- /dev/null +++ b/Tests/RunCMake/CommandLine/profiling-invalid-format-stderr.txt @@ -0,0 +1 @@ +^.*Invalid format specified for --profiling-format$ diff --git a/Tests/RunCMake/CommandLine/profiling-missing-format-result.txt b/Tests/RunCMake/CommandLine/profiling-missing-format-result.txt new file mode 100644 index 0000000..d00491f --- /dev/null +++ b/Tests/RunCMake/CommandLine/profiling-missing-format-result.txt @@ -0,0 +1 @@ +1 diff --git a/Tests/RunCMake/CommandLine/profiling-missing-format-stderr.txt b/Tests/RunCMake/CommandLine/profiling-missing-format-stderr.txt new file mode 100644 index 0000000..459bc3a --- /dev/null +++ b/Tests/RunCMake/CommandLine/profiling-missing-format-stderr.txt @@ -0,0 +1 @@ +^.*Invalid format specified for --profiling-format$ diff --git a/Tests/RunCMake/CommandLine/profiling-missing-output-result.txt b/Tests/RunCMake/CommandLine/profiling-missing-output-result.txt new file mode 100644 index 0000000..d00491f --- /dev/null +++ b/Tests/RunCMake/CommandLine/profiling-missing-output-result.txt @@ -0,0 +1 @@ +1 diff --git a/Tests/RunCMake/CommandLine/profiling-missing-output-stderr.txt b/Tests/RunCMake/CommandLine/profiling-missing-output-stderr.txt new file mode 100644 index 0000000..9ab0c8f --- /dev/null +++ b/Tests/RunCMake/CommandLine/profiling-missing-output-stderr.txt @@ -0,0 +1 @@ +^.*--profiling-format specified but no --profiling-output!$ -- cgit v0.12