CTest: Optionally use a secondary test timeout after matching output

Allow a test N seconds to complete after we detect a matching line in
its output.  Activate this behavior with a new TIMEOUT_AFTER_MATCH test
property.

Help/manual/cmake-properties.7.rst

@@ -303,6 +303,7 @@ Properties on Tests
    /prop_test/RUN_SERIAL
    /prop_test/SKIP_RETURN_CODE
    /prop_test/TIMEOUT
+   /prop_test/TIMEOUT_AFTER_MATCH
    /prop_test/WILL_FAIL
    /prop_test/WORKING_DIRECTORY
 

Help/prop_test/TIMEOUT_AFTER_MATCH.rst

@@ -0,0 +1,37 @@
+TIMEOUT_AFTER_MATCH
+-------------------
+
+Change a test's timeout duration after a matching line is encountered
+in its output.
+
+Usage
+^^^^^
+
+.. code-block:: cmake
+
+ add_test(mytest ...)
+ set_property(TEST mytest PROPERTY TIMEOUT_AFTER_MATCH "${seconds}" "${regex}")
+
+Description
+^^^^^^^^^^^
+
+Allow a test ``seconds`` to complete after ``regex`` is encountered in
+its output.
+
+When the test outputs a line that matches ``regex`` its start time is
+reset to the current time and its timeout duration is changed to
+``seconds``.  Prior to this, the timeout duration is determined by the
+:prop_test:`TIMEOUT` property or the :variable:`CTEST_TEST_TIMEOUT`
+variable if either of these are set.
+
+:prop_test:`TIMEOUT_AFTER_MATCH` is useful for avoiding spurious
+timeouts when your test must wait for some system resource to become
+available before it can execute.  Set :prop_test:`TIMEOUT` to a longer
+duration that accounts for resource acquisition and use
+:prop_test:`TIMEOUT_AFTER_MATCH` to control how long the actual test
+is allowed to run.
+
+If the required resource can be controlled by CTest you should use
+:prop_test:`RESOURCE_LOCK` instead of :prop_test:`TIMEOUT_AFTER_MATCH`.
+This property should be used when only the test itself can determine
+when its required resources are available.

Source/CTest/cmCTestRunTest.cxx

@@ -64,6 +64,28 @@ bool cmCTestRunTest::CheckOutput()
                  this->GetIndex() << ": " << line << std::endl);
       this->ProcessOutput += line;
       this->ProcessOutput += "\n";
+
+      // Check for TIMEOUT_AFTER_MATCH property.
+      if (!this->TestProperties->TimeoutRegularExpressions.empty())
+        {
+        std::vector<std::pair<cmsys::RegularExpression,
+          std::string> >::iterator regIt;
+        for ( regIt = this->TestProperties->TimeoutRegularExpressions.begin();
+              regIt != this->TestProperties->TimeoutRegularExpressions.end();
+              ++ regIt )
+          {
+          if ( regIt->first.find(this->ProcessOutput.c_str()) )
+            {
+            cmCTestLog(this->CTest, HANDLER_VERBOSE_OUTPUT,
+                       "Test timeout changed to " <<
+                       this->TestProperties->AlternateTimeout << std::endl);
+            this->TestProcess->ResetStartTime();
+            this->TestProcess->ChangeTimeout(
+              this->TestProperties->AlternateTimeout);
+            break;
+            }
+          }
+        }
       }
     else // if(p == cmsysProcess_Pipe_Timeout)
       {

Source/CTest/cmCTestTestHandler.cxx

@@ -2254,6 +2254,31 @@ bool cmCTestTestHandler::SetTestsProperties(
             {
             rtit->Directory = val;
             }
+          if ( key == "TIMEOUT_AFTER_MATCH" )
+            {
+            std::vector<std::string> propArgs;
+            cmSystemTools::ExpandListArgument(val, propArgs);
+            if (propArgs.size() != 2)
+              {
+              cmCTestLog(this->CTest, WARNING,
+                "TIMEOUT_AFTER_MATCH expects two arguments, found " <<
+                propArgs.size() << std::endl);
+              }
+            else
+              {
+              rtit->AlternateTimeout = atof(propArgs[0].c_str());
+              std::vector<std::string> lval;
+              cmSystemTools::ExpandListArgument(propArgs[1], lval);
+              std::vector<std::string>::iterator crit;
+              for ( crit = lval.begin(); crit != lval.end(); ++ crit )
+                {
+                rtit->TimeoutRegularExpressions.push_back(
+                  std::pair<cmsys::RegularExpression, std::string>(
+                    cmsys::RegularExpression(crit->c_str()),
+                    std::string(*crit)));
+                }
+              }
+            }
           }
         }
       }

Source/CTest/cmCTestTestHandler.h

@@ -104,6 +104,8 @@ public:
                           std::string> > ErrorRegularExpressions;
     std::vector<std::pair<cmsys::RegularExpression,
                           std::string> > RequiredRegularExpressions;
+    std::vector<std::pair<cmsys::RegularExpression,
+                          std::string> > TimeoutRegularExpressions;
     std::map<std::string, std::string> Measurements;
     bool IsInBasedOnREOptions;
     bool WillFail;
@@ -112,6 +114,7 @@ public:
     bool RunSerial;
     double Timeout;
     bool ExplicitTimeout;
+    double AlternateTimeout;
     int Index;
     //Requested number of process slots
     int Processors;

Source/CTest/cmProcess.cxx

@@ -262,6 +262,16 @@ int cmProcess::ReportStatus()
 
 }
 
+void cmProcess::ChangeTimeout(double t)
+{
+  this->Timeout = t;
+  cmsysProcess_SetTimeout(this->Process, this->Timeout);
+}
+
+void cmProcess::ResetStartTime()
+{
+  cmsysProcess_ResetStartTime(this->Process);
+}
 
 int cmProcess::GetExitException()
 {

Source/CTest/cmProcess.h

@@ -32,6 +32,8 @@ public:
   void SetCommandArguments(std::vector<std::string> const& arg);
   void SetWorkingDirectory(const char* dir) { this->WorkingDirectory = dir;}
   void SetTimeout(double t) { this->Timeout = t;}
+  void ChangeTimeout(double t);
+  void ResetStartTime();
   // Return true if the process starts
   bool StartProcess();
 

Tests/RunCMake/CMakeLists.txt

@@ -217,6 +217,7 @@ add_RunCMake_test(alias_targets)
 add_RunCMake_test(interface_library)
 add_RunCMake_test(no_install_prefix)
 add_RunCMake_test(configure_file)
+add_RunCMake_test(CTestTimeoutAfterMatch)
 
 find_package(Qt4 QUIET)
 find_package(Qt5Core QUIET)

Tests/RunCMake/CTestTimeoutAfterMatch/CMakeLists.txt.in

@@ -0,0 +1,6 @@
+cmake_minimum_required(VERSION 3.4)
+project(TimeoutAfterMatch NONE)
+include(CTest)
+add_test(NAME SleepFor1Second COMMAND "${CMAKE_COMMAND}" -P ${CMAKE_SOURCE_DIR}/SleepFor1Second.cmake)
+set_property(TEST SleepFor1Second PROPERTY TIMEOUT 30)
+set_property(TEST SleepFor1Second PROPERTY TIMEOUT_AFTER_MATCH "${arg1}" "${arg2}")

Tests/RunCMake/CTestTimeoutAfterMatch/CTestConfig.cmake.in

@@ -0,0 +1 @@
+set(CTEST_PROJECT_NAME "TimeoutAfterMatch@CASE_NAME@")

Tests/RunCMake/CTestTimeoutAfterMatch/MissingArg1-stderr.txt

@@ -0,0 +1 @@
+TIMEOUT_AFTER_MATCH expects two arguments, found 1

Tests/RunCMake/CTestTimeoutAfterMatch/MissingArg2-stderr.txt

@@ -0,0 +1 @@
+TIMEOUT_AFTER_MATCH expects two arguments, found 1

Tests/RunCMake/CTestTimeoutAfterMatch/RunCMakeTest.cmake

@@ -0,0 +1,11 @@
+include(RunCTest)
+
+function(run_ctest_TimeoutAfterMatch CASE_NAME)
+  set(CASE_PROPERTY_ARGS "${ARGN}")
+  run_ctest(${CASE_NAME})
+endfunction()
+
+run_ctest_TimeoutAfterMatch(MissingArg1 "\"-Darg2=Test started\"")
+run_ctest_TimeoutAfterMatch(MissingArg2 "\"-Darg1=2\"")
+run_ctest_TimeoutAfterMatch(ShouldTimeout "\"-Darg1=1\" \"-Darg2=Test started\"")
+run_ctest_TimeoutAfterMatch(ShouldPass "\"-Darg1=15\" \"-Darg2=Test started\"")

Tests/RunCMake/CTestTimeoutAfterMatch/ShouldPass-stdout.txt

@@ -0,0 +1,6 @@
+    Start 1: SleepFor1Second
+1/1 Test #1: SleepFor1Second ..................   Passed +[0-9.]+ sec
++
+100% tests passed, 0 tests failed out of 1
++
+Total Test time \(real\) = +[0-9.]+ sec$

Tests/RunCMake/CTestTimeoutAfterMatch/ShouldTimeout-stdout.txt

@@ -0,0 +1 @@
+1 - SleepFor1Second \(Timeout\)

Tests/RunCMake/CTestTimeoutAfterMatch/SleepFor1Second.cmake

@@ -0,0 +1,4 @@
+execute_process(COMMAND "${CMAKE_COMMAND}" -E echo "Gathering required resources")
+execute_process(COMMAND "${CMAKE_COMMAND}" -E sleep 2)
+execute_process(COMMAND "${CMAKE_COMMAND}" -E echo "Test started")
+execute_process(COMMAND "${CMAKE_COMMAND}" -E sleep 1)

Tests/RunCMake/CTestTimeoutAfterMatch/test.cmake.in

@@ -0,0 +1,21 @@
+cmake_minimum_required(VERSION 3.4)
+
+set(CTEST_SITE                          "test-site")
+set(CTEST_BUILD_NAME                    "test-build-name")
+set(CTEST_SOURCE_DIRECTORY              "@RunCMake_BINARY_DIR@/@CASE_NAME@")
+set(CTEST_BINARY_DIRECTORY              "@RunCMake_BINARY_DIR@/@CASE_NAME@-build")
+set(CTEST_CMAKE_GENERATOR               "@RunCMake_GENERATOR@")
+set(CTEST_CMAKE_GENERATOR_PLATFORM      "@RunCMake_GENERATOR_PLATFORM@")
+set(CTEST_CMAKE_GENERATOR_TOOLSET       "@RunCMake_GENERATOR_TOOLSET@")
+set(CTEST_BUILD_CONFIGURATION           "$ENV{CMAKE_CONFIG_TYPE}")
+
+configure_file(
+  "@RunCMake_SOURCE_DIR@/SleepFor1Second.cmake"
+  "${CTEST_SOURCE_DIRECTORY}/SleepFor1Second.cmake"
+  COPYONLY)
+
+set(options @CASE_PROPERTY_ARGS@)
+
+ctest_start(Experimental)
+ctest_configure(OPTIONS "${options}")
+ctest_test()