[lit] Implement support of per test timeout in lit.

This should work with ShTest (executed externally or internally) and GTest
test formats.

To set the timeout a new option ``--timeout=`` has
been added which specifies the maximum run time of an individual test
in seconds. By default this 0 which causes no timeout to be enforced.

The timeout can also be set from a lit configuration file by modifying
the ``lit_config.maxIndividualTestTime`` property.

To implement a timeout we now require the psutil Python module if a
 timeout is requested. This dependency is confined to the newly added
 ``lit.util.killProcessAndChildren()``. A note has been added into the
 TODO document describing how we can remove the dependency on the
 ``pustil`` module in the future. It would be nice to remove this
 immediately but that is a lot more work and Daniel Dunbar believes it is
better that we get a working implementation first and then improve it.

To avoid breaking the existing behaviour the psutil module will not be
imported if no timeout is requested.

The included testcases are derived from test cases provided by
 Jonathan Roelofs which were in an previous attempt to add a per test
 timeout to lit (http://reviews.llvm.org/D6584). Thanks Jonathan!

Reviewers: ddunbar, jroelofs, cmatthews, MatzeB

Subscribers: cmatthews, llvm-commits

Differential Revision: http://reviews.llvm.org/D14706

llvm-svn: 256471

10 files changed, 279 insertions, 0 deletions

diff --git a/llvm/utils/lit/tests/Inputs/googletest-timeout/DummySubDir/OneTest b/llvm/utils/lit/tests/Inputs/googletest-timeout/DummySubDir/OneTest
new file mode 100755
index 00000000000..f3a90ff4cd6
--- /dev/null
+++ b/llvm/utils/lit/tests/Inputs/googletest-timeout/DummySubDir/OneTest
@@ -0,0 +1,35 @@
+#!/usr/bin/env python
+
+import sys
+import time
+
+if len(sys.argv) != 2:
+    raise ValueError("unexpected number of args")
+
+if sys.argv[1] == "--gtest_list_tests":
+    print("""\
+FirstTest.
+  subTestA
+  subTestB
+  subTestC
+""")
+    sys.exit(0)
+elif not sys.argv[1].startswith("--gtest_filter="):
+    raise ValueError("unexpected argument: %r" % (sys.argv[1]))
+
+test_name = sys.argv[1].split('=',1)[1]
+if test_name == 'FirstTest.subTestA':
+    print('I am subTest A, I PASS')
+    print('[  PASSED  ] 1 test.')
+    sys.exit(0)
+elif test_name == 'FirstTest.subTestB':
+    print('I am subTest B, I am slow')
+    time.sleep(6)
+    print('[  PASSED  ] 1 test.')
+    sys.exit(0)
+elif test_name == 'FirstTest.subTestC':
+    print('I am subTest C, I will hang')
+    while True:
+        pass
+else:
+    raise SystemExit("error: invalid test name: %r" % (test_name,))
diff --git a/llvm/utils/lit/tests/Inputs/googletest-timeout/lit.cfg b/llvm/utils/lit/tests/Inputs/googletest-timeout/lit.cfg
new file mode 100644
index 00000000000..bf8a4db2bf9
--- /dev/null
+++ b/llvm/utils/lit/tests/Inputs/googletest-timeout/lit.cfg
@@ -0,0 +1,9 @@
+import lit.formats
+config.name = 'googletest-timeout'
+config.test_format = lit.formats.GoogleTest('DummySubDir', 'Test')
+
+configSetTimeout = lit_config.params.get('set_timeout', '0')
+
+if configSetTimeout == '1':
+    # Try setting the max individual test time in the configuration
+    lit_config.maxIndividualTestTime = 1
diff --git a/llvm/utils/lit/tests/Inputs/shtest-timeout/infinite_loop.py b/llvm/utils/lit/tests/Inputs/shtest-timeout/infinite_loop.py
new file mode 100644
index 00000000000..55720479d33
--- /dev/null
+++ b/llvm/utils/lit/tests/Inputs/shtest-timeout/infinite_loop.py
@@ -0,0 +1,10 @@
+# RUN: %{python} %s
+from __future__ import print_function
+
+import time
+import sys
+
+print("Running infinite loop")
+sys.stdout.flush() # Make sure the print gets flushed so it appears in lit output.
+while True:
+    pass
diff --git a/llvm/utils/lit/tests/Inputs/shtest-timeout/lit.cfg b/llvm/utils/lit/tests/Inputs/shtest-timeout/lit.cfg
new file mode 100644
index 00000000000..81b4a12120d
--- /dev/null
+++ b/llvm/utils/lit/tests/Inputs/shtest-timeout/lit.cfg
@@ -0,0 +1,32 @@
+# -*- Python -*-
+import os
+import sys
+
+import lit.formats
+
+config.name = 'per_test_timeout'
+
+shellType = lit_config.params.get('external', '1')
+
+if shellType == '0':
+    lit_config.note('Using internal shell')
+    externalShell = False
+else:
+    lit_config.note('Using external shell')
+    externalShell = True
+
+configSetTimeout = lit_config.params.get('set_timeout', '0')
+
+if configSetTimeout == '1':
+    # Try setting the max individual test time in the configuration
+    lit_config.maxIndividualTestTime = 1
+
+config.test_format = lit.formats.ShTest(execute_external=externalShell)
+config.suffixes = ['.py']
+
+config.test_source_root = os.path.dirname(__file__)
+config.test_exec_root = config.test_source_root
+config.target_triple = '(unused)'
+src_root = os.path.join(config.test_source_root, '..')
+config.environment['PYTHONPATH'] = src_root
+config.substitutions.append(('%{python}', sys.executable))
diff --git a/llvm/utils/lit/tests/Inputs/shtest-timeout/quick_then_slow.py b/llvm/utils/lit/tests/Inputs/shtest-timeout/quick_then_slow.py
new file mode 100644
index 00000000000..b81fbe5a8bf
--- /dev/null
+++ b/llvm/utils/lit/tests/Inputs/shtest-timeout/quick_then_slow.py
@@ -0,0 +1,24 @@
+# RUN: %{python} %s quick
+# RUN: %{python} %s slow
+from __future__ import print_function
+
+import time
+import sys
+
+if len(sys.argv) != 2:
+    print("Wrong number of args")
+    sys.exit(1)
+
+mode =  sys.argv[1]
+
+if mode == 'slow':
+    print("Running in slow mode")
+    sys.stdout.flush() # Make sure the print gets flushed so it appears in lit output.
+    time.sleep(6)
+    sys.exit(0)
+elif mode == 'quick':
+    print("Running in quick mode")
+    sys.exit(0)
+else:
+    print("Unrecognised mode {}".format(mode))
+    sys.exit(1)
diff --git a/llvm/utils/lit/tests/Inputs/shtest-timeout/short.py b/llvm/utils/lit/tests/Inputs/shtest-timeout/short.py
new file mode 100644
index 00000000000..424b7092d83
--- /dev/null
+++ b/llvm/utils/lit/tests/Inputs/shtest-timeout/short.py
@@ -0,0 +1,6 @@
+# RUN: %{python} %s
+from __future__ import print_function
+
+import sys
+
+print("short program")
diff --git a/llvm/utils/lit/tests/Inputs/shtest-timeout/slow.py b/llvm/utils/lit/tests/Inputs/shtest-timeout/slow.py
new file mode 100644
index 00000000000..2dccd633136
--- /dev/null
+++ b/llvm/utils/lit/tests/Inputs/shtest-timeout/slow.py
@@ -0,0 +1,9 @@
+# RUN: %{python} %s
+from __future__ import print_function
+
+import time
+import sys
+
+print("Running slow program")
+sys.stdout.flush() # Make sure the print gets flushed so it appears in lit output.
+time.sleep(6)
diff --git a/llvm/utils/lit/tests/googletest-timeout.py b/llvm/utils/lit/tests/googletest-timeout.py
new file mode 100644
index 00000000000..46acf32b3a6
--- /dev/null
+++ b/llvm/utils/lit/tests/googletest-timeout.py
@@ -0,0 +1,29 @@
+# REQUIRES: python-psutil
+
+# Check that the per test timeout is enforced when running GTest tests.
+#
+# RUN: not %{lit} -j 1 -v %{inputs}/googletest-timeout --timeout=1 > %t.cmd.out
+# RUN: FileCheck < %t.cmd.out %s
+
+# Check that the per test timeout is enforced when running GTest tests via
+# the configuration file
+#
+# RUN: not %{lit} -j 1 -v %{inputs}/googletest-timeout \
+# RUN: --param set_timeout=1 > %t.cfgset.out 2> %t.cfgset.err
+# RUN: FileCheck < %t.cfgset.out %s
+
+# CHECK: -- Testing:
+# CHECK: PASS: googletest-timeout :: DummySubDir/OneTest/FirstTest.subTestA
+# CHECK: TIMEOUT: googletest-timeout :: DummySubDir/OneTest/FirstTest.subTestB
+# CHECK: TIMEOUT: googletest-timeout :: DummySubDir/OneTest/FirstTest.subTestC
+# CHECK: Expected Passes    : 1
+# CHECK: Individual Timeouts: 2
+
+# Test per test timeout via a config file and on the command line.
+# The value set on the command line should override the config file.
+# RUN: not %{lit} -j 1 -v %{inputs}/googletest-timeout \
+# RUN: --param set_timeout=1 --timeout=2 > %t.cmdover.out 2> %t.cmdover.err
+# RUN: FileCheck < %t.cmdover.out %s
+# RUN: FileCheck --check-prefix=CHECK-CMDLINE-OVERRIDE-ERR < %t.cmdover.err %s
+
+# CHECK-CMDLINE-OVERRIDE-ERR: Forcing timeout to be 2 seconds
diff --git a/llvm/utils/lit/tests/lit.cfg b/llvm/utils/lit/tests/lit.cfg
index 2111b72748b..4b38241d5a7 100644
--- a/llvm/utils/lit/tests/lit.cfg
+++ b/llvm/utils/lit/tests/lit.cfg
@@ -43,3 +43,12 @@ if lit_config.params.get('check-coverage', None):
 # Add a feature to detect the Python version.
 config.available_features.add("python%d.%d" % (sys.version_info[0],
                                                   sys.version_info[1]))
+
+# Add a feature to detect if psutil is available
+try:
+    import psutil
+    lit_config.note('Found python psutil module')
+    config.available_features.add("python-psutil")
+except ImportError:
+    lit_config.warning('Could not import psutil. Some tests will be skipped and'
+                       ' the --timeout command line argument will not work.')
diff --git a/llvm/utils/lit/tests/shtest-timeout.py b/llvm/utils/lit/tests/shtest-timeout.py
new file mode 100644
index 00000000000..e6b2947a4f7
--- /dev/null
+++ b/llvm/utils/lit/tests/shtest-timeout.py
@@ -0,0 +1,116 @@
+# REQUIRES: python-psutil
+
+# Test per test timeout using external shell
+# RUN: not %{lit} \
+# RUN: %{inputs}/shtest-timeout/infinite_loop.py \
+# RUN: %{inputs}/shtest-timeout/quick_then_slow.py \
+# RUN: %{inputs}/shtest-timeout/short.py \
+# RUN: %{inputs}/shtest-timeout/slow.py \
+# RUN: -j 1 -v --debug --timeout 1 --param external=1 > %t.extsh.out 2> %t.extsh.err
+# RUN: FileCheck --check-prefix=CHECK-OUT-COMMON < %t.extsh.out %s
+# RUN: FileCheck --check-prefix=CHECK-EXTSH-ERR < %t.extsh.err %s
+#
+# CHECK-EXTSH-ERR: Using external shell
+
+# Test per test timeout using internal shell
+# RUN: not %{lit} \
+# RUN: %{inputs}/shtest-timeout/infinite_loop.py \
+# RUN: %{inputs}/shtest-timeout/quick_then_slow.py \
+# RUN: %{inputs}/shtest-timeout/short.py \
+# RUN: %{inputs}/shtest-timeout/slow.py \
+# RUN: -j 1 -v --debug --timeout 1 --param external=0 > %t.intsh.out 2> %t.intsh.err
+# RUN: FileCheck  --check-prefix=CHECK-OUT-COMMON < %t.intsh.out %s
+# RUN: FileCheck --check-prefix=CHECK-INTSH-OUT < %t.intsh.out %s
+# RUN: FileCheck --check-prefix=CHECK-INTSH-ERR < %t.intsh.err %s
+#
+# CHECK-INTSH-OUT: TIMEOUT: per_test_timeout :: infinite_loop.py
+# CHECK-INTSH-OUT: Command 0 Reached Timeout: True
+# CHECK-INTSH-OUT: Command 0 Output:
+# CHECK-INTSH-OUT-NEXT: Running infinite loop
+
+
+# CHECK-INTSH-OUT: TIMEOUT: per_test_timeout :: quick_then_slow.py
+# CHECK-INTSH-OUT: Timeout: Reached timeout of 1 seconds
+# CHECK-INTSH-OUT: Command Output
+# CHECK-INTSH-OUT: Command 0 Reached Timeout: False
+# CHECK-INTSH-OUT: Command 0 Output:
+# CHECK-INTSH-OUT-NEXT: Running in quick mode
+# CHECK-INTSH-OUT: Command 1 Reached Timeout: True
+# CHECK-INTSH-OUT: Command 1 Output:
+# CHECK-INTSH-OUT-NEXT: Running in slow mode
+
+# CHECK-INTSH-OUT: TIMEOUT: per_test_timeout :: slow.py
+# CHECK-INTSH-OUT: Command 0 Reached Timeout: True
+# CHECK-INTSH-OUT: Command 0 Output:
+# CHECK-INTSH-OUT-NEXT: Running slow program
+
+# CHECK-INTSH-ERR: Using internal shell
+
+# Test per test timeout set via a config file rather than on the command line
+# RUN: not %{lit} \
+# RUN: %{inputs}/shtest-timeout/infinite_loop.py \
+# RUN: %{inputs}/shtest-timeout/quick_then_slow.py \
+# RUN: %{inputs}/shtest-timeout/short.py \
+# RUN: %{inputs}/shtest-timeout/slow.py \
+# RUN: -j 1 -v --debug --param external=0 \
+# RUN: --param set_timeout=1 > %t.cfgset.out 2> %t.cfgset.err
+# RUN: FileCheck --check-prefix=CHECK-OUT-COMMON  < %t.cfgset.out %s
+# RUN: FileCheck --check-prefix=CHECK-CFGSET-ERR < %t.cfgset.err %s
+#
+# CHECK-CFGSET-ERR: Using internal shell
+
+# CHECK-OUT-COMMON: TIMEOUT: per_test_timeout :: infinite_loop.py
+# CHECK-OUT-COMMON: Timeout: Reached timeout of 1 seconds
+# CHECK-OUT-COMMON: Command {{([0-9]+ )?}}Output
+# CHECK-OUT-COMMON: Running infinite loop
+
+# CHECK-OUT-COMMON: TIMEOUT: per_test_timeout :: quick_then_slow.py
+# CHECK-OUT-COMMON: Timeout: Reached timeout of 1 seconds
+# CHECK-OUT-COMMON: Command {{([0-9]+ )?}}Output
+# CHECK-OUT-COMMON: Running in quick mode
+# CHECK-OUT-COMMON: Running in slow mode
+
+# CHECK-OUT-COMMON: PASS: per_test_timeout :: short.py
+
+# CHECK-OUT-COMMON: TIMEOUT: per_test_timeout :: slow.py
+# CHECK-OUT-COMMON: Timeout: Reached timeout of 1 seconds
+# CHECK-OUT-COMMON: Command {{([0-9]+ )?}}Output
+# CHECK-OUT-COMMON: Running slow program
+
+# CHECK-OUT-COMMON: Expected Passes{{ *}}: 1
+# CHECK-OUT-COMMON: Individual Timeouts{{ *}}: 3
+
+# Test per test timeout via a config file and on the command line.
+# The value set on the command line should override the config file.
+# RUN: not %{lit} \
+# RUN: %{inputs}/shtest-timeout/infinite_loop.py \
+# RUN: %{inputs}/shtest-timeout/quick_then_slow.py \
+# RUN: %{inputs}/shtest-timeout/short.py \
+# RUN: %{inputs}/shtest-timeout/slow.py \
+# RUN: -j 1 -v --debug --param external=0 \
+# RUN: --param set_timeout=1 --timeout=2 > %t.cmdover.out 2> %t.cmdover.err
+# RUN: FileCheck --check-prefix=CHECK-CMDLINE-OVERRIDE-OUT  < %t.cmdover.out %s
+# RUN: FileCheck --check-prefix=CHECK-CMDLINE-OVERRIDE-ERR < %t.cmdover.err %s
+
+# CHECK-CMDLINE-OVERRIDE-ERR: Forcing timeout to be 2 seconds
+
+# CHECK-CMDLINE-OVERRIDE-OUT: TIMEOUT: per_test_timeout :: infinite_loop.py
+# CHECK-CMDLINE-OVERRIDE-OUT: Timeout: Reached timeout of 2 seconds
+# CHECK-CMDLINE-OVERRIDE-OUT: Command {{([0-9]+ )?}}Output
+# CHECK-CMDLINE-OVERRIDE-OUT: Running infinite loop
+
+# CHECK-CMDLINE-OVERRIDE-OUT: TIMEOUT: per_test_timeout :: quick_then_slow.py
+# CHECK-CMDLINE-OVERRIDE-OUT: Timeout: Reached timeout of 2 seconds
+# CHECK-CMDLINE-OVERRIDE-OUT: Command {{([0-9]+ )?}}Output
+# CHECK-CMDLINE-OVERRIDE-OUT: Running in quick mode
+# CHECK-CMDLINE-OVERRIDE-OUT: Running in slow mode
+
+# CHECK-CMDLINE-OVERRIDE-OUT: PASS: per_test_timeout :: short.py
+
+# CHECK-CMDLINE-OVERRIDE-OUT: TIMEOUT: per_test_timeout :: slow.py
+# CHECK-CMDLINE-OVERRIDE-OUT: Timeout: Reached timeout of 2 seconds
+# CHECK-CMDLINE-OVERRIDE-OUT: Command {{([0-9]+ )?}}Output
+# CHECK-CMDLINE-OVERRIDE-OUT: Running slow program
+
+# CHECK-CMDLINE-OVERRIDE-OUT: Expected Passes{{ *}}: 1
+# CHECK-CMDLINE-OVERRIDE-OUT: Individual Timeouts{{ *}}: 3