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.

17 files changed, 153 insertions, 0 deletions

diff --git a/Help/manual/cmake-properties.7.rst b/Help/manual/cmake-properties.7.rst
index d6618fe890..9051ca066e 100644
--- a/Help/manual/cmake-properties.7.rst
+++ b/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
 
diff --git a/Help/prop_test/TIMEOUT_AFTER_MATCH.rst b/Help/prop_test/TIMEOUT_AFTER_MATCH.rst
new file mode 100644
index 0000000000..a191a9cc88
--- /dev/null
+++ b/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.
diff --git a/Source/CTest/cmCTestRunTest.cxx b/Source/CTest/cmCTestRunTest.cxx
index d108592f62..7f3a07728c 100644
--- a/Source/CTest/cmCTestRunTest.cxx
+++ b/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)
       {
diff --git a/Source/CTest/cmCTestTestHandler.cxx b/Source/CTest/cmCTestTestHandler.cxx
index b6a4819a08..59ed98eb02 100644
--- a/Source/CTest/cmCTestTestHandler.cxx
+++ b/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)));
+                }
+              }
+            }
           }
         }
       }
diff --git a/Source/CTest/cmCTestTestHandler.h b/Source/CTest/cmCTestTestHandler.h
index c635430d99..d12c2b6437 100644
--- a/Source/CTest/cmCTestTestHandler.h
+++ b/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;
diff --git a/Source/CTest/cmProcess.cxx b/Source/CTest/cmProcess.cxx
index 0c25f4050f..6441886486 100644
--- a/Source/CTest/cmProcess.cxx
+++ b/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()
 {
diff --git a/Source/CTest/cmProcess.h b/Source/CTest/cmProcess.h
index eddeeabe88..c9fd859996 100644
--- a/Source/CTest/cmProcess.h
+++ b/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();
 
diff --git a/Tests/RunCMake/CMakeLists.txt b/Tests/RunCMake/CMakeLists.txt
index 588f3a122a..7e7ed45a98 100644
--- a/Tests/RunCMake/CMakeLists.txt
+++ b/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)
diff --git a/Tests/RunCMake/CTestTimeoutAfterMatch/CMakeLists.txt.in b/Tests/RunCMake/CTestTimeoutAfterMatch/CMakeLists.txt.in
new file mode 100644
index 0000000000..e9592f6d17
--- /dev/null
+++ b/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}")
diff --git a/Tests/RunCMake/CTestTimeoutAfterMatch/CTestConfig.cmake.in b/Tests/RunCMake/CTestTimeoutAfterMatch/CTestConfig.cmake.in
new file mode 100644
index 0000000000..58b11afaf0
--- /dev/null
+++ b/Tests/RunCMake/CTestTimeoutAfterMatch/CTestConfig.cmake.in
@@ -0,0 +1 @@
+set(CTEST_PROJECT_NAME "TimeoutAfterMatch@CASE_NAME@")
diff --git a/Tests/RunCMake/CTestTimeoutAfterMatch/MissingArg1-stderr.txt b/Tests/RunCMake/CTestTimeoutAfterMatch/MissingArg1-stderr.txt
new file mode 100644
index 0000000000..7766c68a9d
--- /dev/null
+++ b/Tests/RunCMake/CTestTimeoutAfterMatch/MissingArg1-stderr.txt
@@ -0,0 +1 @@
+TIMEOUT_AFTER_MATCH expects two arguments, found 1
diff --git a/Tests/RunCMake/CTestTimeoutAfterMatch/MissingArg2-stderr.txt b/Tests/RunCMake/CTestTimeoutAfterMatch/MissingArg2-stderr.txt
new file mode 100644
index 0000000000..7766c68a9d
--- /dev/null
+++ b/Tests/RunCMake/CTestTimeoutAfterMatch/MissingArg2-stderr.txt
@@ -0,0 +1 @@
+TIMEOUT_AFTER_MATCH expects two arguments, found 1
diff --git a/Tests/RunCMake/CTestTimeoutAfterMatch/RunCMakeTest.cmake b/Tests/RunCMake/CTestTimeoutAfterMatch/RunCMakeTest.cmake
new file mode 100644
index 0000000000..ee4db839f7
--- /dev/null
+++ b/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\"")
diff --git a/Tests/RunCMake/CTestTimeoutAfterMatch/ShouldPass-stdout.txt b/Tests/RunCMake/CTestTimeoutAfterMatch/ShouldPass-stdout.txt
new file mode 100644
index 0000000000..89aae56a5a
--- /dev/null
+++ b/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$
diff --git a/Tests/RunCMake/CTestTimeoutAfterMatch/ShouldTimeout-stdout.txt b/Tests/RunCMake/CTestTimeoutAfterMatch/ShouldTimeout-stdout.txt
new file mode 100644
index 0000000000..c031eb03fe
--- /dev/null
+++ b/Tests/RunCMake/CTestTimeoutAfterMatch/ShouldTimeout-stdout.txt
@@ -0,0 +1 @@
+1 - SleepFor1Second \(Timeout\)
diff --git a/Tests/RunCMake/CTestTimeoutAfterMatch/SleepFor1Second.cmake b/Tests/RunCMake/CTestTimeoutAfterMatch/SleepFor1Second.cmake
new file mode 100644
index 0000000000..82c2a444fa
--- /dev/null
+++ b/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)
diff --git a/Tests/RunCMake/CTestTimeoutAfterMatch/test.cmake.in b/Tests/RunCMake/CTestTimeoutAfterMatch/test.cmake.in
new file mode 100644
index 0000000000..d049c9ff0b
--- /dev/null
+++ b/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()