[lit] Add configurable slowest-test limit to --time-tests (#208444)

The PR parameterizes `--time-tests`, which was hardcoded to 20 tests. We
now allow `--time-tests=N` or `--time-tests=all`.

The changes still honor the original behavior of `--time-tests`. The
parsing logic could be slightly simpler if `--time-tests` would always
require an explicit number of tests (like `-j`), but that would be a CLI
breaking change.

Author: mgcarrasco

llvm/docs/CommandGuide/lit.rst

@@ -254,11 +254,15 @@ EXECUTION OPTIONS
 
  Do not track elapsed wall time for each test.
 
-.. option:: --time-tests
+.. option:: --time-tests[=N|all]
 
- Track the wall time individual tests take to execute and includes the results
+ Track the wall time individual tests take to execute and include the results
  in the summary output.  This is useful for determining which tests in a test
- suite take the most time to execute.
+ suite take the most time to execute.  When enabled, lit prints a slowest-test
+ list and a histogram over all timed tests.  The slowest-test list defaults to
+ the 20 slowest tests, but can be limited with ``=N`` or expanded to every
+ timed test with ``=all``.  The headings report how many tests are listed, for
+ example ``Slowest Tests (N of M):`` and ``Test Times (M):``.
 
 .. _selection-options:
 

llvm/utils/lit/lit/cl_arguments.py

@@ -55,6 +55,10 @@ def setOutputLevel(cls, namespace, dest, value):
             setattr(namespace, "test_output", value)
 
 
+_TIME_TESTS_OPT = "--time-tests"
+_TIME_TESTS_SLOWEST_DEFAULT = 20
+_TIME_TESTS_PREFIX = f"{_TIME_TESTS_OPT}="
+
 class AliasAction(argparse.Action):
     def __init__(self, option_strings, dest, nargs=None, **kwargs):
         self.expansion = kwargs.pop("alias", None)
@@ -382,9 +386,12 @@ def parse_args():
         action="store_true",
     )
     execution_test_time_group.add_argument(
-        "--time-tests",
-        help="Track elapsed wall time for each test printed in a histogram",
+        _TIME_TESTS_OPT,
+        help="Track elapsed wall time for each test and print a histogram; "
+        "optionally limit the slowest-test list with =N or report all with =all "
+        f"(default slowest count: {_TIME_TESTS_SLOWEST_DEFAULT})",
         action="store_true",
+        default=None,
     )
 
     selection_group = parser.add_argument_group("Test Selection")
@@ -515,8 +522,21 @@ def parse_args():
 
     # LIT is special: environment variables override command line arguments.
     env_args = shlex.split(os.environ.get("LIT_OPTS", ""))
-    args = sys.argv[1:] + env_args
+    try:
+        # --time-tests is preprocessed here: bare --time-tests defaults to 20,
+        # and --time-tests=N / --time-tests=all set the slowest-test limit.
+        # Values must use = (e.g. --time-tests=all), since `lit --time-tests all`
+        # could mean "show all slow tests" or "run the test directory all".
+        args, time_tests = _extract_time_tests_args(sys.argv[1:] + env_args)
+    except argparse.ArgumentTypeError as exc:
+        parser.error(str(exc))
     opts = parser.parse_args(args)
+    opts.time_tests = time_tests
+
+    if opts.time_tests is not None and opts.skip_test_time_recording:
+        parser.error(
+            f"argument --skip-test-time-recording: not allowed with argument {_TIME_TESTS_OPT}"
+        )
 
     # Validate command line options
     if opts.incremental:
@@ -555,6 +575,28 @@ def _positive_int(arg):
     return _int(arg, "positive", lambda i: i > 0)
 
 
+def _time_tests_count(arg):
+    if arg.lower() == "all":
+        return "all"
+    return _positive_int(arg)
+
+
+def _extract_time_tests_args(args):
+    processed = []
+    time_tests = None
+    for arg in args:
+        if arg == _TIME_TESTS_OPT:
+            time_tests = _TIME_TESTS_SLOWEST_DEFAULT
+        elif arg.startswith(_TIME_TESTS_PREFIX):
+            value = arg[len(_TIME_TESTS_PREFIX) :]
+            if not value:
+                raise _error(f"argument {_TIME_TESTS_OPT} requires a value after '='")
+            time_tests = _time_tests_count(value)
+        else:
+            processed.append(arg)
+    return processed, time_tests
+
+
 def _non_negative_int(arg):
     return _int(arg, "non-negative", lambda i: i >= 0)
 

llvm/utils/lit/lit/main.py

@@ -127,7 +127,7 @@ def main(builtin_params={}):
     )
 
     if opts.time_tests:
-        print_histogram(discovered_tests)
+        print_histogram(discovered_tests, opts.time_tests)
 
     print_results(discovered_tests, elapsed, opts)
 
@@ -315,12 +315,12 @@ def execute_in_tmp_dir(run, lit_config):
                 )
 
 
-def print_histogram(tests):
+def print_histogram(tests, slowest_limit):
     test_times = [
         (t.getFullName(), t.result.elapsed) for t in tests if t.result.elapsed
     ]
     if test_times:
-        lit.util.printHistogram(test_times, title="Tests")
+        lit.util.printHistogram(test_times, slowest_limit, title="Tests")
 
 
 def print_results(tests, elapsed, opts):

llvm/utils/lit/lit/util.py

@@ -158,8 +158,13 @@ def whichTools(tools, paths):
     return None
 
 
-def printHistogram(items, title="Items"):
+def printHistogram(items, slowest_limit, title="Items"):
     items.sort(key=lambda item: item[1])
+    total = len(items)
+    if slowest_limit == "all":
+        slowest_count = total
+    else:
+        slowest_count = min(slowest_limit, total)
 
     maxValue = max([v for _, v in items])
 
@@ -180,11 +185,11 @@ def printHistogram(items, title="Items"):
 
     barW = 40
     hr = "-" * (barW + 34)
-    print("Slowest %s:" % title)
+    print("Slowest %s (%d of %d):" % (title, slowest_count, total))
     print(hr)
-    for name, value in reversed(items[-20:]):
+    for name, value in reversed(items[-slowest_count:]):
         print("%.2fs: %s" % (value, name))
-    print("\n%s Times:" % title)
+    print("\nTest Times (%d):" % total)
     print(hr)
     pDigits = int(math.ceil(math.log(maxValue, 10)))
     pfDigits = max(0, 3 - pDigits)

llvm/utils/lit/tests/Inputs/time-tests/b.txt

@@ -0,0 +1 @@
+# RUN: true

llvm/utils/lit/tests/Inputs/time-tests/c.txt

@@ -0,0 +1 @@
+# RUN: true

llvm/utils/lit/tests/time-tests.py

@@ -3,13 +3,53 @@
 # RUN: %{lit-no-order-opt} --skip-test-time-recording %{inputs}/time-tests
 # RUN: not ls %{inputs}/time-tests/.lit_test_times.txt
 
-## Check that --time-tests generates a printed histogram.
+## Check that --time-tests (default 20 tests) generates a printed histogram.
+# The slowest-test entries are matched with -DAG in any order to avoid
+# performance-wise flakiness from relying on exact execution-time ordering.
 
 # RUN: %{lit-no-order-opt} --time-tests %{inputs}/time-tests > %t.out
-# RUN: FileCheck < %t.out %s
+# RUN: FileCheck --check-prefix=DEFAULT < %t.out %s
 # RUN: rm %{inputs}/time-tests/.lit_test_times.txt
 
-# CHECK:      Tests Times:
-# CHECK-NEXT: --------------------------------------------------------------------------
-# CHECK-NEXT: [    Range    ] :: [               Percentage               ] :: [Count]
-# CHECK-NEXT: --------------------------------------------------------------------------
+# DEFAULT:      Slowest Tests (3 of 3):
+# DEFAULT-DAG:  {{[0-9.]+}}s: time-tests :: a.txt
+# DEFAULT-DAG:  {{[0-9.]+}}s: time-tests :: b.txt
+# DEFAULT-DAG:  {{[0-9.]+}}s: time-tests :: c.txt
+# DEFAULT:        Test Times (3):
+# DEFAULT-NEXT: --------------------------------------------------------------------------
+# DEFAULT-NEXT: [    Range    ] :: [               Percentage               ] :: [Count]
+# DEFAULT-NEXT: --------------------------------------------------------------------------
+
+## Check that --time-tests=1 limits the slowest-test list.
+
+# RUN: %{lit-no-order-opt} --time-tests=1 %{inputs}/time-tests > %t.one.out
+# RUN: FileCheck --check-prefix=ONE < %t.one.out %s
+# RUN: rm %{inputs}/time-tests/.lit_test_times.txt
+
+# ONE:       Slowest Tests (1 of 3):
+# ONE-COUNT-1: {{[0-9.]+}}s: time-tests ::
+# ONE:         Test Times (3):
+
+## Check that --time-tests=all reports every timed test.
+
+# RUN: %{lit-no-order-opt} --time-tests=all %{inputs}/time-tests > %t.all.out
+# RUN: FileCheck --check-prefix=ALL < %t.all.out %s
+# RUN: rm %{inputs}/time-tests/.lit_test_times.txt
+
+# ALL:      Slowest Tests (3 of 3):
+# ALL-DAG:  {{[0-9.]+}}s: time-tests :: a.txt
+# ALL-DAG:  {{[0-9.]+}}s: time-tests :: b.txt
+# ALL-DAG:  {{[0-9.]+}}s: time-tests :: c.txt
+# ALL:        Test Times (3):
+
+## Check that invalid --time-tests values are rejected.
+
+# RUN: not %{lit-no-order-opt} --time-tests=0 %{inputs}/time-tests 2>&1 | FileCheck %s --check-prefix=INVALID
+
+# INVALID: requires positive integer
+
+## Check that malformed --time-tests values with extra '=' are rejected.
+
+# RUN: not %{lit-no-order-opt} --time-tests=all=foo %{inputs}/time-tests 2>&1 | FileCheck %s --check-prefix=MALFORMED
+
+# MALFORMED: requires positive integer, but found 'all=foo'