ENH: Count tests while they go. Also in the logs report more stuff like elapsed time etc.

Source/cmCTest.cxx

@@ -20,7 +20,6 @@
 #include "cmLocalGenerator.h"
 #include "cmGlobalGenerator.h"
 #include <cmsys/Directory.hxx>
-#include "cmListFileCache.h"
 #include "cmGlob.h"
 
 #include "cmCTestSubmit.h"
@@ -1826,9 +1825,7 @@ void cmCTest::GenerateDartBuildOutput(std::ostream& os,
   this->EndXML(os);
 }
   
-void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed, 
+void cmCTest::GetListOfTests(tm_ListOfTests* testlist, bool memcheck)
-                             cmCTest::tm_VectorOfStrings &failed,
-                             bool memcheck, std::ostream* logfile)
 {
   // does the DartTestfile.txt exist ?
   if(!cmSystemTools::FileExists("DartTestfile.txt"))
@@ -1843,11 +1840,8 @@ void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed,
     return;
     }
 
-  int firstTest = 1;
-
   cmsys::RegularExpression ireg(this->m_IncludeRegExp.c_str());
   cmsys::RegularExpression ereg(this->m_ExcludeRegExp.c_str());
-  cmsys::RegularExpression dartStuff("(<DartMeasurement.*/DartMeasurement[a-zA-Z]*>)");
 
   cmListFileCache cache;
   cmListFile* listFile = cache.GetFileCache("DartTestfile.txt", false);
@@ -1856,11 +1850,11 @@ void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed,
     {
     const cmListFileFunction& lff = *f;
     const std::string& name = lff.m_Name;
-    const std::vector<cmListFileArgument>& args = lff.m_Arguments;
+    const tm_VectorOfListFileArgs& args = lff.m_Arguments;
     if (name == "SUBDIRS")
       {
       std::string cwd = cmSystemTools::GetCurrentWorkingDirectory();
-      for(std::vector<cmListFileArgument>::const_iterator j = args.begin();
+      for(tm_VectorOfListFileArgs::const_iterator j = args.begin();
         j != args.end(); ++j)
         {
         std::string nwd = cwd + "/";
@@ -1868,7 +1862,7 @@ void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed,
         if (cmSystemTools::FileIsDirectory(nwd.c_str()))
           {
           cmSystemTools::ChangeDirectory(nwd.c_str());
-          this->ProcessDirectory(passed, failed, memcheck, logfile);
+          this->GetListOfTests(testlist, memcheck);
           }
         }
       // return to the original directory
@@ -1877,9 +1871,10 @@ void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed,
 
     if (name == "ADD_TEST")
       {
+      const std::string& testname = args[0].Value;
       if (this->m_UseExcludeRegExp &&
         this->m_UseExcludeRegExpFirst &&
-          ereg.find(args[0].Value.c_str()))
+        ereg.find(testname.c_str()))
         {
         continue;
         }
@@ -1890,7 +1885,7 @@ void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed,
         for ( it = m_CustomMemCheckIgnore.begin(); 
           it != m_CustomMemCheckIgnore.end(); ++ it )
           {
-          if ( *it == args[0].Value )
+          if ( *it == testname )
             {
             found = true;
             break;
@@ -1912,7 +1907,7 @@ void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed,
         for ( it = m_CustomTestsIgnore.begin(); 
           it != m_CustomTestsIgnore.end(); ++ it )
           {
-          if ( *it == args[0].Value )
+          if ( *it == testname )
             {
             found = true;
             break;
@@ -1929,37 +1924,81 @@ void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed,
         }
 
 
-      if (this->m_UseIncludeRegExp && !ireg.find(args[0].Value.c_str()))
+      if (this->m_UseIncludeRegExp && !ireg.find(testname.c_str()))
         {
         continue;
         }
       if (this->m_UseExcludeRegExp &&
         !this->m_UseExcludeRegExpFirst &&
-        ereg.find(args[0].Value.c_str()))
+        ereg.find(testname.c_str()))
         {
         continue;
         }
 
+      cmCTestTestProperties test;
+      test.Name = testname;
+      test.Args = args;
+      test.Directory = cmSystemTools::GetCurrentWorkingDirectory();
+      testlist->push_back(test);
+      }
+    }
+}
+
+void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed, 
+                             cmCTest::tm_VectorOfStrings &failed,
+                             bool memcheck)
+{
+  cmsys::RegularExpression dartStuff("(<DartMeasurement.*/DartMeasurement[a-zA-Z]*>)");
+  tm_ListOfTests testlist;
+  this->GetListOfTests(&testlist, memcheck);
+  tm_ListOfTests::size_type tmsize = testlist.size();
+
+  std::ofstream ofs;
+  std::ofstream *olog = 0;
+  if ( !m_ShowOnly && tmsize > 0 && 
+    this->OpenOutputFile("Temporary", 
+      (memcheck?"LastMemCheck.xml":"LastTest.log"), ofs) )
+    {
+    olog = &ofs;
+    }
+
+  m_StartTest = ::CurrentTime();
+
+  if ( olog )
+    {
+    *olog << "Start testing: " << m_StartTest << std::endl
+      << "----------------------------------------------------------"
+      << std::endl;
+    }
+
+  int cnt = 0;
+  tm_ListOfTests::iterator it;
+  std::string last_directory = "";
+  for ( it = testlist.begin(); it != testlist.end(); it ++ )
+    {
+    cnt ++;
+    const std::string& testname = it->Name;
+    tm_VectorOfListFileArgs& args = it->Args;
     cmCTestTestResult cres;
     cres.m_Status = cmCTest::NOT_RUN;
 
-      if (firstTest)
+    if (last_directory != it->Directory)
       {
-        std::string nwd = cmSystemTools::GetCurrentWorkingDirectory();
       if ( m_Verbose )
         {
-          std::cerr << "Changing directory into " << nwd.c_str() << "\n";
+        std::cerr << "Changing directory into " 
+          << it->Directory.c_str() << "\n";
         }
-        firstTest = 0;
+      last_directory = it->Directory;
       }
-      cres.m_Name = args[0].Value;
+    cres.m_Name = testname;
     if ( m_ShowOnly )
       {
-        std::cout << args[0].Value << std::endl;
+      fprintf(stderr,"%3d/%3d Testing %-30s\n", cnt, tmsize, testname.c_str());
       }
     else
       {
-        fprintf(stderr,"Testing %-30s ",args[0].Value.c_str());
+      fprintf(stderr,"%3d/%3d Testing %-30s ", cnt, tmsize, testname.c_str());
       fflush(stderr);
       }
     //std::cerr << "Testing " << args[0] << " ... ";
@@ -1973,13 +2012,16 @@ void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed,
       {
       std::cerr << "Unable to find executable: " <<
         args[1].Value.c_str() << "\n";
+      if ( !m_ShowOnly )
+        {
         m_TestResults.push_back( cres ); 
-        failed.push_back(args[0].Value);
+        failed.push_back(testname);
         continue;
         }
+      }
 
     // add the arguments
-      std::vector<cmListFileArgument>::const_iterator j = args.begin();
+    tm_VectorOfListFileArgs::const_iterator j = args.begin();
     ++j;
     ++j;
     std::vector<const char*> arguments;
@@ -2010,8 +2052,6 @@ void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed,
     std::string output;
     int retVal = 0;
 
-      double clock_start, clock_finish;
-      clock_start = cmSystemTools::GetTime();
 
     if ( m_Verbose )
       {
@@ -2021,35 +2061,55 @@ void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed,
         std::cout << "Memory check command: " << memcheckcommand << std::endl;
         }
       }
-      if ( logfile )
+    if ( olog )
       {
-        *logfile << "Command: ";
+      *olog << cnt << "/" << tmsize 
+        << " Test: " << testname.c_str() << std::endl;
+      *olog << "Command: ";
       tm_VectorOfStrings::size_type ll;
       for ( ll = 0; ll < arguments.size()-1; ll ++ )
         {
-          *logfile << "\"" << arguments[ll] << "\" ";
+        *olog << "\"" << arguments[ll] << "\" ";
         }
-        *logfile 
+      *olog 
         << std::endl 
-          << "Directory: " << cmSystemTools::GetCurrentWorkingDirectory() << std::endl 
+        << "Directory: " << it->Directory << std::endl 
+        << "\"" << testname.c_str() << "\" start time: " 
+        << ::CurrentTime() << std::endl
         << "Output:" << std::endl 
         << "----------------------------------------------------------"
         << std::endl;
       }
     int res = 0;
+    double clock_start, clock_finish;
+    clock_start = cmSystemTools::GetTime();
+
     if ( !m_ShowOnly )
       {
-        res = this->RunTest(arguments, &output, &retVal, logfile);
+      res = this->RunTest(arguments, &output, &retVal, olog);
-        }
-      if ( logfile )
-        {
-        *logfile 
-          << "----------------------------------------------------------"
-          << std::endl << std::endl;
       }
 
     clock_finish = cmSystemTools::GetTime();
 
+    if ( olog )
+      {
+      double ttime = clock_finish - clock_start;
+      int hours = static_cast<int>(ttime / (60 * 60));
+      int minutes = static_cast<int>(ttime / 60) % 60;
+      int seconds = static_cast<int>(ttime) % 60;
+      char buffer[100];
+      sprintf(buffer, "%02d:%02d:%02d", hours, minutes, seconds);
+      *olog 
+        << "----------------------------------------------------------"
+        << std::endl
+        << "\"" << testname.c_str() << "\" end time: " 
+        << ::CurrentTime() << std::endl
+        << "\"" << testname.c_str() << "\" time elapsed: " 
+        << buffer << std::endl
+        << "----------------------------------------------------------"
+        << std::endl << std::endl;
+      }
+
     cres.m_ExecutionTime = (double)(clock_finish - clock_start);
     cres.m_FullCommandLine = testCommand;
 
@@ -2058,7 +2118,7 @@ void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed,
       if (res == cmsysProcess_State_Exited && retVal == 0)
         {
         fprintf(stderr,"   Passed\n");
-          passed.push_back(args[0].Value);
+        passed.push_back(testname);
         cres.m_Status = cmCTest::COMPLETED;
         }
       else
@@ -2105,7 +2165,7 @@ void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed,
           {
           fprintf(stderr,"***Failed\n");
           }
-          failed.push_back(args[0].Value);
+        failed.push_back(testname);
         }
       if (output != "")
         {
@@ -2129,6 +2189,11 @@ void cmCTest::ProcessDirectory(cmCTest::tm_VectorOfStrings &passed,
     cres.m_CompletionStatus = "Completed";
     m_TestResults.push_back( cres );
     }
+
+  m_EndTest = ::CurrentTime();
+  if ( olog )
+    {
+    *olog << "End testing: " << m_EndTest << std::endl;
     }
 }
 
@@ -2255,15 +2320,7 @@ int cmCTest::TestDirectory(bool memcheck)
   cmCTest::tm_VectorOfStrings failed;
   int total;
 
-  std::ofstream ofs;
+  this->ProcessDirectory(passed, failed, memcheck);
-  std::ofstream *olog = 0;
-  if ( this->OpenOutputFile("Temporary", (memcheck?"LastMemCheck.xml":"LastTest.log"), ofs) )
-    {
-    olog = &ofs;
-    }
-  m_StartTest = ::CurrentTime();
-  this->ProcessDirectory(passed, failed, memcheck, olog);
-  m_EndTest = ::CurrentTime();
 
   total = int(passed.size()) + int(failed.size());
 

Source/cmCTest.h

@@ -20,6 +20,7 @@
 
 
 #include "cmStandardIncludes.h"
+#include "cmListFileCache.h"
 
 class cmMakefile;
 
@@ -96,8 +97,7 @@ public:
    */
   void ProcessDirectory(tm_VectorOfStrings &passed, 
                         tm_VectorOfStrings &failed,
-                        bool memcheck,
+                        bool memcheck);
-                        std::ostream* logfile);
 
   /**
    * Find the executable for a test
@@ -243,6 +243,15 @@ private:
     std::string m_PostContext;
   };
 
+  typedef std::vector<cmListFileArgument> tm_VectorOfListFileArgs;
+  struct cmCTestTestProperties
+    {
+    cmStdString Name;
+    cmStdString Directory;
+    tm_VectorOfListFileArgs Args;
+    };
+  typedef std::vector<cmCTestTestProperties> tm_ListOfTests;
+
   // Some structures needed for cvs update
   struct StringPair : 
     public std::pair<std::string, std::string>{};
@@ -337,6 +346,11 @@ private:
 
   int ExecuteCommands(tm_VectorOfStrings& vec);
 
+  /**
+   * Get the list of tests in directory and subdirectories.
+   */
+  void cmCTest::GetListOfTests(tm_ListOfTests* testlist, bool memcheck);
+
   //! Reread the configuration file
   void UpdateCTestConfiguration();