Merge topic 'show_weighted_times'

b2242ea9 Help: Update documentation for PROCESSORS test property
5b829c89 CTest: Weight reported test times by PROCESSORS in summaries
a6e32eb0 CTest: Split out labels and subproject labels in summary output

Acked-by: Kitware Robot <kwrobot@kitware.com>
Merge-request: !1226

11 files changed, 69 insertions, 115 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.
diff --git a/Source/CTest/cmCTestTestHandler.cxx b/Source/CTest/cmCTestTestHandler.cxx
index 18d9346..9962c49 100644
--- a/Source/CTest/cmCTestTestHandler.cxx
+++ b/Source/CTest/cmCTestTestHandler.cxx
@@ -535,14 +535,13 @@ int cmCTestTestHandler::ProcessHandler()
                  << static_cast<int>(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<std::string, double> labelTimes;
-  std::map<std::string, int> labelCounts;
-  std::set<std::string> 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<std::string>::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<std::string>::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<std::string>::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<std::string> subprojects =
     this->CTest->GetLabelsForSubprojects();
-
-  cmCTestTestHandler::ListOfTests::iterator it = this->TestList.begin();
   std::map<std::string, double> labelTimes;
   std::map<std::string, int> labelCounts;
   std::set<std::string> 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<std::string>::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<std::string>::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<std::string>::iterator l = p.Labels.begin();
          l != p.Labels.end(); ++l) {
-      std::vector<std::string>::iterator subproject =
-        std::find(subprojects.begin(), subprojects.end(), *l);
-      if (subproject != subprojects.end()) {
-        labelTimes[*l] += result.ExecutionTime;
+      // only use labels found in labels
+      if (labels.find(*l) != labels.end()) {
+        labelTimes[*l] += result.ExecutionTime * result.Properties->Processors;
         ++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<std::string>::const_iterator i = labels.begin();
        i != labels.end(); ++i) {
@@ -746,7 +687,7 @@ void cmCTestTestHandler::PrintSubprojectSummary()
     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";
@@ -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/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 ae00e51..05b484d 100644
--- a/Tests/RunCMake/ctest_labels_for_subprojects/CTestConfigCTestScript-stdout.txt
+++ b/Tests/RunCMake/ctest_labels_for_subprojects/CTestConfigCTestScript-stdout.txt
@@ -1,7 +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\*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 ae00e51..05b484d 100644
--- a/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariable-stdout.txt
+++ b/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariable-stdout.txt
@@ -1,7 +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\*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 a78a99a..c2c1bc7 100644
--- a/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariableCommandLine-stdout.txt
+++ b/Tests/RunCMake/ctest_labels_for_subprojects/CTestScriptVariableCommandLine-stdout.txt
@@ -1,6 +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\*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 01851fd..3a71022 100644
--- a/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfig-stdout.txt
+++ b/Tests/RunCMake/ctest_labels_for_subprojects/ModuleVariableCTestConfig-stdout.txt
@@ -1,6 +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\*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 0209bfe..1146bfe 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\)
+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