From a6e32eb0c26277c71c586aba457df5daaf2a71ba Mon Sep 17 00:00:00 2001 From: Bill Hoffman Date: Wed, 6 Sep 2017 12:03:40 -0400 Subject: CTest: Split out labels and subproject labels in summary output This commit splits out the reporting of labels and labels used for sub projects. If a label is a sub project label it will not be included in the label summary. To implement this the commit creates PrintLabelOrSubprojectSummary which is able to do the work of both PrintLabelSummary and PrintSubprojectSummary avoiding code duplication. --- Source/CTest/cmCTestTestHandler.cxx | 133 ++++++--------------- Source/CTest/cmCTestTestHandler.h | 3 +- .../CTestConfigCTestScript-stdout.txt | 3 + .../CTestScriptVariable-stdout.txt | 3 + .../CTestScriptVariableCommandLine-stdout.txt | 3 + .../ModuleVariableCTestConfig-stdout.txt | 3 + .../ModuleVariableCTestConfigNoSummary-stdout.txt | 1 - 7 files changed, 49 insertions(+), 100 deletions(-) diff --git a/Source/CTest/cmCTestTestHandler.cxx b/Source/CTest/cmCTestTestHandler.cxx index 18d9346..24c1857 100644 --- a/Source/CTest/cmCTestTestHandler.cxx +++ b/Source/CTest/cmCTestTestHandler.cxx @@ -535,14 +535,13 @@ int cmCTestTestHandler::ProcessHandler() << static_cast(percent + .5f) << "% tests passed, " << failed.size() << " tests failed out of " << total << std::endl); - - if (!this->CTest->GetLabelsForSubprojects().empty() && - this->CTest->GetSubprojectSummary()) { - this->PrintSubprojectSummary(); - } else if (this->CTest->GetLabelSummary()) { - this->PrintLabelSummary(); + if ((!this->CTest->GetLabelsForSubprojects().empty() && + this->CTest->GetSubprojectSummary())) { + this->PrintLabelOrSubprojectSummary(true); + } + if (this->CTest->GetLabelSummary()) { + this->PrintLabelOrSubprojectSummary(false); } - char realBuf[1024]; sprintf(realBuf, "%6.2f sec", clock_finish - clock_start); cmCTestOptionalLog(this->CTest, HANDLER_OUTPUT, @@ -620,96 +619,32 @@ int cmCTestTestHandler::ProcessHandler() return 0; } -void cmCTestTestHandler::PrintLabelSummary() -{ - cmCTestTestHandler::ListOfTests::iterator it = this->TestList.begin(); - std::map labelTimes; - std::map labelCounts; - std::set labels; - // initialize maps - std::string::size_type maxlen = 0; - for (; it != this->TestList.end(); ++it) { - cmCTestTestProperties& p = *it; - if (!p.Labels.empty()) { - for (std::vector::iterator l = p.Labels.begin(); - l != p.Labels.end(); ++l) { - if ((*l).size() > maxlen) { - maxlen = (*l).size(); - } - labels.insert(*l); - labelTimes[*l] = 0; - labelCounts[*l] = 0; - } - } - } - cmCTestTestHandler::TestResultsVector::iterator ri = - this->TestResults.begin(); - // fill maps - for (; ri != this->TestResults.end(); ++ri) { - cmCTestTestResult& result = *ri; - cmCTestTestProperties& p = *result.Properties; - if (!p.Labels.empty()) { - for (std::vector::iterator l = p.Labels.begin(); - l != p.Labels.end(); ++l) { - labelTimes[*l] += result.ExecutionTime; - ++labelCounts[*l]; - } - } - } - // now print times - if (!labels.empty()) { - cmCTestOptionalLog(this->CTest, HANDLER_OUTPUT, "\nLabel Time Summary:", - this->Quiet); - } - for (std::set::const_iterator i = labels.begin(); - i != labels.end(); ++i) { - std::string label = *i; - label.resize(maxlen + 3, ' '); - - char buf[1024]; - sprintf(buf, "%6.2f sec", labelTimes[*i]); - - std::ostringstream labelCountStr; - labelCountStr << "(" << labelCounts[*i] << " test"; - if (labelCounts[*i] > 1) { - labelCountStr << "s"; - } - labelCountStr << ")"; - - cmCTestOptionalLog(this->CTest, HANDLER_OUTPUT, "\n" - << label << " = " << buf << " " - << labelCountStr.str(), - this->Quiet); - if (this->LogFile) { - *this->LogFile << "\n" << *i << " = " << buf << "\n"; - } - } - if (!labels.empty()) { - if (this->LogFile) { - *this->LogFile << "\n"; - } - cmCTestOptionalLog(this->CTest, HANDLER_OUTPUT, "\n", this->Quiet); - } -} - -void cmCTestTestHandler::PrintSubprojectSummary() +void cmCTestTestHandler::PrintLabelOrSubprojectSummary(bool doSubProject) { + // collect subproject labels std::vector subprojects = this->CTest->GetLabelsForSubprojects(); - - cmCTestTestHandler::ListOfTests::iterator it = this->TestList.begin(); std::map labelTimes; std::map labelCounts; std::set labels; - // initialize maps std::string::size_type maxlen = 0; - for (; it != this->TestList.end(); ++it) { + // initialize maps + for (cmCTestTestHandler::ListOfTests::iterator it = this->TestList.begin(); + it != this->TestList.end(); ++it) { cmCTestTestProperties& p = *it; for (std::vector::iterator l = p.Labels.begin(); l != p.Labels.end(); ++l) { + // first check to see if the current label is a subproject label + bool isSubprojectLabel = false; std::vector::iterator subproject = std::find(subprojects.begin(), subprojects.end(), *l); if (subproject != subprojects.end()) { + isSubprojectLabel = true; + } + // if we are doing sub projects and this label is one, then use it + // if we are not doing sub projects and the label is not one use it + if ((doSubProject && isSubprojectLabel) || + (!doSubProject && !isSubprojectLabel)) { if ((*l).size() > maxlen) { maxlen = (*l).size(); } @@ -719,26 +654,32 @@ void cmCTestTestHandler::PrintSubprojectSummary() } } } - cmCTestTestHandler::TestResultsVector::iterator ri = - this->TestResults.begin(); // fill maps - for (; ri != this->TestResults.end(); ++ri) { + for (cmCTestTestHandler::TestResultsVector::iterator ri = + this->TestResults.begin(); + ri != this->TestResults.end(); ++ri) { cmCTestTestResult& result = *ri; cmCTestTestProperties& p = *result.Properties; for (std::vector::iterator l = p.Labels.begin(); l != p.Labels.end(); ++l) { - std::vector::iterator subproject = - std::find(subprojects.begin(), subprojects.end(), *l); - if (subproject != subprojects.end()) { + // only use labels found in labels + if (labels.find(*l) != labels.end()) { labelTimes[*l] += result.ExecutionTime; ++labelCounts[*l]; } } } + // if no labels are found return and print nothing + if (labels.empty()) { + return; + } // now print times - if (!labels.empty()) { + if (doSubProject) { cmCTestOptionalLog(this->CTest, HANDLER_OUTPUT, "\nSubproject Time Summary:", this->Quiet); + } else { + cmCTestOptionalLog(this->CTest, HANDLER_OUTPUT, "\nLabel Time Summary:", + this->Quiet); } for (std::set::const_iterator i = labels.begin(); i != labels.end(); ++i) { @@ -754,7 +695,6 @@ void cmCTestTestHandler::PrintSubprojectSummary() labelCountStr << "s"; } labelCountStr << ")"; - cmCTestOptionalLog(this->CTest, HANDLER_OUTPUT, "\n" << label << " = " << buf << " " << labelCountStr.str(), @@ -763,13 +703,12 @@ void cmCTestTestHandler::PrintSubprojectSummary() *this->LogFile << "\n" << *i << " = " << buf << "\n"; } } - if (!labels.empty()) { - if (this->LogFile) { - *this->LogFile << "\n"; - } - cmCTestOptionalLog(this->CTest, HANDLER_OUTPUT, "\n", this->Quiet); + if (this->LogFile) { + *this->LogFile << "\n"; } + cmCTestOptionalLog(this->CTest, HANDLER_OUTPUT, "\n", this->Quiet); } + void cmCTestTestHandler::CheckLabelFilterInclude(cmCTestTestProperties& it) { // if not using Labels to filter then return diff --git a/Source/CTest/cmCTestTestHandler.h b/Source/CTest/cmCTestTestHandler.h index 965552c..4c5b55f 100644 --- a/Source/CTest/cmCTestTestHandler.h +++ b/Source/CTest/cmCTestTestHandler.h @@ -232,8 +232,7 @@ private: */ virtual void GenerateDartOutput(cmXMLWriter& xml); - void PrintLabelSummary(); - void PrintSubprojectSummary(); + void PrintLabelOrSubprojectSummary(bool isSubProject); /** * Run the tests for a directory and any subdirectories diff --git a/Tests/RunCMake/ctest_labels_for_subprojects/CTestConfigCTestScript-stdout.txt b/Tests/RunCMake/ctest_labels_for_subprojects/CTestConfigCTestScript-stdout.txt index ae00e51..e3be144 100644 --- a/Tests/RunCMake/ctest_labels_for_subprojects/CTestConfigCTestScript-stdout.txt +++ b/Tests/RunCMake/ctest_labels_for_subprojects/CTestConfigCTestScript-stdout.txt @@ -4,4 +4,7 @@ Subproject Time Summary: MyExperimentalFeature += +[0-9.]+ sec \(5 tests\) MyProductionCode += +[0-9.]+ sec \(1 test\) + +Label Time Summary: +NotASubproject += +[0-9.]+ sec \(6 tests\) ++ Total Test time \(real\) = +[0-9.]+ sec diff --git a/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariable-stdout.txt b/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariable-stdout.txt index ae00e51..e3be144 100644 --- a/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariable-stdout.txt +++ b/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariable-stdout.txt @@ -4,4 +4,7 @@ Subproject Time Summary: MyExperimentalFeature += +[0-9.]+ sec \(5 tests\) MyProductionCode += +[0-9.]+ sec \(1 test\) + +Label Time Summary: +NotASubproject += +[0-9.]+ sec \(6 tests\) ++ Total Test time \(real\) = +[0-9.]+ sec diff --git a/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariableCommandLine-stdout.txt b/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariableCommandLine-stdout.txt index a78a99a..20c6c86 100644 --- a/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariableCommandLine-stdout.txt +++ b/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariableCommandLine-stdout.txt @@ -3,4 +3,7 @@ Subproject Time Summary: MyThirdPartyDependency += +[0-9.]+ sec \(1 test\) + +Label Time Summary: +NotASubproject += +[0-9.]+ sec \(1 test\) ++ Total Test time \(real\) = +[0-9.]+ sec diff --git a/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfig-stdout.txt b/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfig-stdout.txt index 01851fd..bec6b14 100644 --- a/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfig-stdout.txt +++ b/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfig-stdout.txt @@ -3,4 +3,7 @@ Subproject Time Summary: MySubproject += +[0-9.]+ sec \(2 tests\) + +Label Time Summary: +NotASubproject += +[0-9.]+ sec \(1 test\) ++ Total Test time \(real\) = +[0-9.]+ sec diff --git a/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfigNoSummary-stdout.txt b/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfigNoSummary-stdout.txt index 0209bfe..1ac5530 100644 --- a/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfigNoSummary-stdout.txt +++ b/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfigNoSummary-stdout.txt @@ -1,7 +1,6 @@ 67% tests passed, 1 tests failed out of 3 + Label Time Summary: -MySubproject += +[0-9.]+ sec \(2 tests\) NotASubproject += +[0-9.]+ sec \(1 test\) + Total Test time \(real\) = +[0-9.]+ sec -- cgit v0.12 From 5b829c89b8cdb5b8f908dcd4849a37a183b0971c Mon Sep 17 00:00:00 2001 From: Bill Hoffman Date: Wed, 6 Sep 2017 12:07:08 -0400 Subject: CTest: Weight reported test times by PROCESSORS in summaries This commit changes the times reported by labels and subprojects to be weighted by the PROCESSORS property. It is reported with `sec*proc` instead of just `sec`. --- Source/CTest/cmCTestTestHandler.cxx | 4 ++-- Tests/RunCMake/CTestCommandLine/LabelCount-stdout.txt | 4 ++-- .../ctest_labels_for_subprojects/CTestConfigCTestScript-stdout.txt | 6 +++--- .../ctest_labels_for_subprojects/CTestScriptVariable-stdout.txt | 6 +++--- .../CTestScriptVariableCommandLine-stdout.txt | 4 ++-- .../ModuleVariableCMakeLists-stdout.txt | 2 +- .../ModuleVariableCTestConfig-stdout.txt | 4 ++-- .../ModuleVariableCTestConfigNoSummary-stdout.txt | 2 +- .../ModuleVariableCommandLine-stdout.txt | 2 +- 9 files changed, 17 insertions(+), 17 deletions(-) diff --git a/Source/CTest/cmCTestTestHandler.cxx b/Source/CTest/cmCTestTestHandler.cxx index 24c1857..9962c49 100644 --- a/Source/CTest/cmCTestTestHandler.cxx +++ b/Source/CTest/cmCTestTestHandler.cxx @@ -664,7 +664,7 @@ void cmCTestTestHandler::PrintLabelOrSubprojectSummary(bool doSubProject) l != p.Labels.end(); ++l) { // only use labels found in labels if (labels.find(*l) != labels.end()) { - labelTimes[*l] += result.ExecutionTime; + labelTimes[*l] += result.ExecutionTime * result.Properties->Processors; ++labelCounts[*l]; } } @@ -687,7 +687,7 @@ void cmCTestTestHandler::PrintLabelOrSubprojectSummary(bool doSubProject) label.resize(maxlen + 3, ' '); char buf[1024]; - sprintf(buf, "%6.2f sec", labelTimes[*i]); + sprintf(buf, "%6.2f sec*proc", labelTimes[*i]); std::ostringstream labelCountStr; labelCountStr << "(" << labelCounts[*i] << " test"; diff --git a/Tests/RunCMake/CTestCommandLine/LabelCount-stdout.txt b/Tests/RunCMake/CTestCommandLine/LabelCount-stdout.txt index 7fe04eb..9cfe41c 100644 --- a/Tests/RunCMake/CTestCommandLine/LabelCount-stdout.txt +++ b/Tests/RunCMake/CTestCommandLine/LabelCount-stdout.txt @@ -1,7 +1,7 @@ 100% tests passed, 0 tests failed out of 4 + +Label Time Summary: -+'bar' = +[0-9.]+ sec \(3 tests\) -+'foo' = +[0-9.]+ sec \(1 test\) ++'bar' = +[0-9.]+ sec\*proc \(3 tests\) ++'foo' = +[0-9.]+ sec\*proc \(1 test\) + Total Test time \(real\) = +[0-9.]+ sec diff --git a/Tests/RunCMake/ctest_labels_for_subprojects/CTestConfigCTestScript-stdout.txt b/Tests/RunCMake/ctest_labels_for_subprojects/CTestConfigCTestScript-stdout.txt index e3be144..05b484d 100644 --- a/Tests/RunCMake/ctest_labels_for_subprojects/CTestConfigCTestScript-stdout.txt +++ b/Tests/RunCMake/ctest_labels_for_subprojects/CTestConfigCTestScript-stdout.txt @@ -1,10 +1,10 @@ 17% tests passed, 5 tests failed out of 6 + Subproject Time Summary: -MyExperimentalFeature += +[0-9.]+ sec \(5 tests\) -MyProductionCode += +[0-9.]+ sec \(1 test\) +MyExperimentalFeature += +[0-9.]+ sec\*proc \(5 tests\) +MyProductionCode += +[0-9.]+ sec\*proc \(1 test\) + Label Time Summary: -NotASubproject += +[0-9.]+ sec \(6 tests\) +NotASubproject += +[0-9.]+ sec\*proc \(6 tests\) + Total Test time \(real\) = +[0-9.]+ sec diff --git a/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariable-stdout.txt b/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariable-stdout.txt index e3be144..05b484d 100644 --- a/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariable-stdout.txt +++ b/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariable-stdout.txt @@ -1,10 +1,10 @@ 17% tests passed, 5 tests failed out of 6 + Subproject Time Summary: -MyExperimentalFeature += +[0-9.]+ sec \(5 tests\) -MyProductionCode += +[0-9.]+ sec \(1 test\) +MyExperimentalFeature += +[0-9.]+ sec\*proc \(5 tests\) +MyProductionCode += +[0-9.]+ sec\*proc \(1 test\) + Label Time Summary: -NotASubproject += +[0-9.]+ sec \(6 tests\) +NotASubproject += +[0-9.]+ sec\*proc \(6 tests\) + Total Test time \(real\) = +[0-9.]+ sec diff --git a/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariableCommandLine-stdout.txt b/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariableCommandLine-stdout.txt index 20c6c86..c2c1bc7 100644 --- a/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariableCommandLine-stdout.txt +++ b/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariableCommandLine-stdout.txt @@ -1,9 +1,9 @@ 0% tests passed, 1 tests failed out of 1 + Subproject Time Summary: -MyThirdPartyDependency += +[0-9.]+ sec \(1 test\) +MyThirdPartyDependency += +[0-9.]+ sec\*proc \(1 test\) + Label Time Summary: -NotASubproject += +[0-9.]+ sec \(1 test\) +NotASubproject += +[0-9.]+ sec\*proc \(1 test\) + Total Test time \(real\) = +[0-9.]+ sec diff --git a/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCMakeLists-stdout.txt b/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCMakeLists-stdout.txt index b5d76a9..3567a92 100644 --- a/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCMakeLists-stdout.txt +++ b/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCMakeLists-stdout.txt @@ -1,6 +1,6 @@ 50% tests passed, 1 tests failed out of 2 + Subproject Time Summary: -MySubproject += +[0-9.]+ sec \(2 tests\) +MySubproject += +[0-9.]+ sec\*proc \(2 tests\) + Total Test time \(real\) = +[0-9.]+ sec diff --git a/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfig-stdout.txt b/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfig-stdout.txt index bec6b14..3a71022 100644 --- a/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfig-stdout.txt +++ b/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfig-stdout.txt @@ -1,9 +1,9 @@ 67% tests passed, 1 tests failed out of 3 + Subproject Time Summary: -MySubproject += +[0-9.]+ sec \(2 tests\) +MySubproject += +[0-9.]+ sec\*proc \(2 tests\) + Label Time Summary: -NotASubproject += +[0-9.]+ sec \(1 test\) +NotASubproject += +[0-9.]+ sec\*proc \(1 test\) + Total Test time \(real\) = +[0-9.]+ sec diff --git a/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfigNoSummary-stdout.txt b/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfigNoSummary-stdout.txt index 1ac5530..1146bfe 100644 --- a/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfigNoSummary-stdout.txt +++ b/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfigNoSummary-stdout.txt @@ -1,6 +1,6 @@ 67% tests passed, 1 tests failed out of 3 + Label Time Summary: -NotASubproject += +[0-9.]+ sec \(1 test\) +NotASubproject += +[0-9.]+ sec\*proc \(1 test\) + Total Test time \(real\) = +[0-9.]+ sec diff --git a/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCommandLine-stdout.txt b/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCommandLine-stdout.txt index b5d76a9..3567a92 100644 --- a/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCommandLine-stdout.txt +++ b/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCommandLine-stdout.txt @@ -1,6 +1,6 @@ 50% tests passed, 1 tests failed out of 2 + Subproject Time Summary: -MySubproject += +[0-9.]+ sec \(2 tests\) +MySubproject += +[0-9.]+ sec\*proc \(2 tests\) + Total Test time \(real\) = +[0-9.]+ sec -- cgit v0.12 From b2242ea9641cd09d94aaf77a33345100cc3a3def Mon Sep 17 00:00:00 2001 From: Bill Hoffman Date: Wed, 6 Sep 2017 13:51:12 -0400 Subject: Help: Update documentation for PROCESSORS test property This updates the documentation for the PROCESSORS test property to show how it will affect the summary output for labels and sub projects. --- Help/prop_test/PROCESSORS.rst | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/Help/prop_test/PROCESSORS.rst b/Help/prop_test/PROCESSORS.rst index 763b6d0..a1211fb 100644 --- a/Help/prop_test/PROCESSORS.rst +++ b/Help/prop_test/PROCESSORS.rst @@ -1,8 +1,13 @@ PROCESSORS ---------- -How many process slots this test requires +Set to specify how many process slots this test requires. Denotes the number of processors that this test will require. This is typically used for MPI tests, and should be used in conjunction with -the ctest_test PARALLEL_LEVEL option. +the :command:`ctest_test` ``PARALLEL_LEVEL`` option. + +This will also be used to display a weighted test timing result in label and +subproject summaries in the command line output of :manual:`ctest(1)`. The wall +clock time for the test run will be multiplied by this property to give a +better idea of how much cpu resource CTest allocated for the test. -- cgit v0.12