[lit] Drop "Script:", make -v and -a imply -vv

This patch and D156954 were discussed in
<https://discourse.llvm.org/t/rfc-improving-lits-debug-output/72839>.

**Motivation**: -a shows output from all tests, and -v shows output
from just failed tests.  Without this patch, that output from each
test includes a section called "Script:", which includes all shell
commands that lit has computed from RUN directives and will attempt to
run for that test.  The effect of -vv (which also implies -v if
neither -a or -v is specified) is to extend that output with shell
commands as they are executing so you can easily see which one failed.

For example, when using lit's internal shell and -vv:

```
Script:
--
: 'RUN: at line 1'; echo hello world
: 'RUN: at line 2'; 3c40 hello world
: 'RUN: at line 3'; echo hello world
--
Exit Code: 127

Command Output (stdout):
--
$ ":" "RUN: at line 1"
$ "echo" "hello" "world"
hello world

$ ":" "RUN: at line 2"
$ "3c40" "hello" "world"
'3c40': command not found
error: command failed with exit status: 127

--
```

Notice that all shell commands that actually execute appear in the
output twice, once for "Script:" and once for -vv.  Especially for
tests with many RUN directives, the result is noisy.  When searching
through the output for a particular shell command, it is easy to get
lost and mistake shell commands under "Script:" for shell commands
that actually executed.

**Change**: With this patch, a test's output changes in two ways.
First, the "Script:" section is never shown.  Second, omitting -vv no
longer disables printing of shell commands as they execute.  That is,
-a and -v imply -vv, and so -vv is deprecated as it is just an alias
for -v.

**Secondary motivation**: We are also working to introduce a PYTHON
directive, which can appear between RUN directives.  How should PYTHON
directives be represented in the "Script:" section, which has
previously been just a shell script?  We could probably think of
something, but adding info about PYTHON directive execution in the -vv
trace seems more straight-forward and more useful.

(This patch also removes a confusing point in the -vv documentation:
at least when using bash as an external shell, -vv echoes commands to
the shell's stderr not stdout.)

Reviewed By: awarzynski, Endill, ldionne, MaskRay

Differential Revision: https://reviews.llvm.org/D154984

Author: jdenny-ornl

llvm/docs/CommandGuide/lit.rst

@@ -94,21 +94,20 @@ OUTPUT OPTIONS
  Show more information on test failures, for example the entire test output
  instead of just the test result.
 
+ Each command is printed before it is executed. This can be valuable for
+ debugging test failures, as the last printed command is the one that failed.
+ Moreover, :program:`lit` inserts a no-op command (``:`` in the case of bash)
+ with argument ``'RUN: at line N'`` before each command pipeline, and those
+ no-op commands are also printed to help you locate the source line of the
+ failed command.
+
 .. option:: -vv, --echo-all-commands
 
- On test failure, echo all commands to stdout as they are being executed.
- This can be valuable for debugging test failures, as the last echoed command
- will be the one which has failed.
- :program:`lit` normally inserts a no-op command (``:`` in the case of bash)
- with argument ``'RUN: at line N'`` before each command pipeline, and this
- option also causes those no-op commands to be echoed to stdout to help you
- locate the source line of the failed command.
- This option implies ``--verbose``.
+ Deprecated alias for -v.
 
 .. option:: -a, --show-all
 
- Show more information about all tests, for example the entire test
- commandline and output.
+ Enable -v, but for all tests not just failed tests.
 
 .. option:: --no-progress-bar
 

llvm/utils/lit/lit/LitConfig.py

@@ -36,7 +36,6 @@ def __init__(
         config_prefix=None,
         maxIndividualTestTime=0,
         parallelism_groups={},
-        echo_all_commands=False,
         per_test_coverage=False,
     ):
         # The name of the test runner.
@@ -87,7 +86,6 @@ def __init__(
 
         self.maxIndividualTestTime = maxIndividualTestTime
         self.parallelism_groups = parallelism_groups
-        self.echo_all_commands = echo_all_commands
         self.per_test_coverage = per_test_coverage
 
     @property

llvm/utils/lit/lit/TestRunner.py

@@ -1095,10 +1095,7 @@ def executeScript(test, litConfig, tmpBase, commands, cwd):
                 commands[i] = match.expand(
                     "echo '\\1' > nul && " if command else "echo '\\1' > nul"
                 )
-        if litConfig.echo_all_commands:
-            f.write("@echo on\n")
-        else:
-            f.write("@echo off\n")
+        f.write("@echo on\n")
         f.write("\n@if %ERRORLEVEL% NEQ 0 EXIT\n".join(commands))
     else:
         for i, ln in enumerate(commands):
@@ -1108,8 +1105,7 @@ def executeScript(test, litConfig, tmpBase, commands, cwd):
                 commands[i] = match.expand(": '\\1'; \\2" if command else ": '\\1'")
         if test.config.pipefail:
             f.write(b"set -o pipefail;" if mode == "wb" else "set -o pipefail;")
-        if litConfig.echo_all_commands:
-            f.write(b"set -x;" if mode == "wb" else "set -x;")
+        f.write(b"set -x;" if mode == "wb" else "set -x;")
         if sys.version_info > (3, 0) and mode == "wb":
             f.write(bytes("{ " + "; } &&\n{ ".join(commands) + "; }", "utf-8"))
         else:
@@ -2035,14 +2031,19 @@ def parseIntegratedTestScript(test, additional_parsers=[], require_script=True):
 
 def _runShTest(test, litConfig, useExternalSh, script, tmpBase):
     def runOnce(execdir):
+        # script is modified below (for litConfig.per_test_coverage, and for
+        # %dbg expansions).  runOnce can be called multiple times, but applying
+        # the modifications multiple times can corrupt script, so always modify
+        # a copy.
+        scriptCopy = script[:]
         # Set unique LLVM_PROFILE_FILE for each run command
         if litConfig.per_test_coverage:
             # Extract the test case name from the test object, and remove the
             # file extension.
             test_case_name = test.path_in_suite[-1]
             test_case_name = test_case_name.rsplit(".", 1)[0]
             coverage_index = 0  # Counter for coverage file index
-            for i, ln in enumerate(script):
+            for i, ln in enumerate(scriptCopy):
                 match = re.fullmatch(kPdbgRegex, ln)
                 if match:
                     dbg = match.group(1)
@@ -2054,12 +2055,12 @@ def runOnce(execdir):
                 command = f"export LLVM_PROFILE_FILE={profile}; {command}"
                 if match:
                     command = buildPdbgCommand(dbg, command)
-                script[i] = command
+                scriptCopy[i] = command
 
         if useExternalSh:
-            res = executeScript(test, litConfig, tmpBase, script, execdir)
+            res = executeScript(test, litConfig, tmpBase, scriptCopy, execdir)
         else:
-            res = executeScriptInternal(test, litConfig, tmpBase, script, execdir)
+            res = executeScriptInternal(test, litConfig, tmpBase, scriptCopy, execdir)
         if isinstance(res, lit.Test.Result):
             return res
 
@@ -2079,14 +2080,7 @@ def runOnce(execdir):
     # Re-run failed tests up to test.allowed_retries times.
     execdir = os.path.dirname(test.getExecPath())
     attempts = test.allowed_retries + 1
-    scriptInit = script
     for i in range(attempts):
-        # runOnce modifies script, but applying the modifications again to the
-        # result can corrupt script, so we restore the original upon a retry.
-        # A cleaner solution would be for runOnce to encapsulate operating on a
-        # copy of script, but we actually want it to modify the original script
-        # so we can print the modified version under "Script:" below.
-        script = scriptInit[:]
         res = runOnce(execdir)
         if isinstance(res, lit.Test.Result):
             return res
@@ -2101,7 +2095,7 @@ def runOnce(execdir):
         status = Test.FLAKYPASS
 
     # Form the output log.
-    output = """Script:\n--\n%s\n--\nExit Code: %d\n""" % ("\n".join(script), exitCode)
+    output = f"Exit Code: {exitCode}\n"
 
     if timeoutInfo is not None:
         output += """Timeout: %s\n""" % (timeoutInfo,)

llvm/utils/lit/lit/cl_arguments.py

@@ -72,22 +72,23 @@ def parse_args():
         "-v",
         "--verbose",
         dest="showOutput",
-        help="Show test output for failures",
+        help="For failed tests, show all output. For example, each command is"
+        " printed before it is executed, so the last printed command is the one"
+        " that failed.",
         action="store_true",
     )
     format_group.add_argument(
         "-vv",
         "--echo-all-commands",
-        dest="echoAllCommands",
+        dest="showOutput",
+        help="Deprecated alias for -v.",
         action="store_true",
-        help="Echo all commands as they are executed to stdout. In case of "
-        "failure, last command shown will be the failing one.",
     )
     format_group.add_argument(
         "-a",
         "--show-all",
         dest="showAllOutput",
-        help="Display all commandlines and output",
+        help="Enable -v, but for all tests not just failed tests.",
         action="store_true",
     )
     format_group.add_argument(
@@ -299,9 +300,6 @@ def parse_args():
     opts = parser.parse_args(args)
 
     # Validate command line options
-    if opts.echoAllCommands:
-        opts.showOutput = True
-
     if opts.incremental:
         print(
             "WARNING: --incremental is deprecated. Failing tests now always run first."

llvm/utils/lit/lit/main.py

@@ -40,7 +40,6 @@ def main(builtin_params={}):
         order=opts.order,
         params=params,
         config_prefix=opts.configPrefix,
-        echo_all_commands=opts.echoAllCommands,
         per_test_coverage=opts.per_test_coverage,
     )
 

llvm/utils/lit/tests/Inputs/shtest-if-else/test.txt

@@ -1,92 +1,148 @@
-# CHECK: -- Testing:{{.*}}
-# CHECK-NEXT: PASS: shtest-if-else :: test.txt (1 of 1)
-# CHECK-NEXT: Script:
-# CHECK-NEXT: --
+#       CHECK: -- Testing:{{.*}}
+#  CHECK-NEXT: PASS: shtest-if-else :: test.txt (1 of 1)
+#  CHECK-NEXT: Exit Code: 0
+# CHECK-EMPTY:
+#  CHECK-NEXT: Command Output (stdout):
+#  CHECK-NEXT: --
 
 # RUN: %if feature %{ echo "test-1" %}
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-1]]'; echo "test-1"
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-1]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: test-1
+# CHECK-EMPTY:
 
 # If %else is not present it is treated like %else %{%}. Empty commands
 # are ignored.
 #
 # RUN: %if nofeature %{ echo "fail" %}
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-1]]'
-# CHECK-NOT: fail
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-1]]"
+#   CHECK-NOT: fail
 
 # RUN: %if nofeature %{ echo "fail" %} %else %{ echo "test-2" %}
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-1]]'; echo "test-2"
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-1]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: test-2
+# CHECK-EMPTY:
 
 # Spaces inside curly braces are not ignored
 #
 # RUN: echo test-%if feature %{ 3 %} %else %{ fail %}-test
 # RUN: echo test-%if feature %{ 4 4 %} %else %{ fail %}-test
 # RUN: echo test-%if nofeature %{ fail %} %else %{ 5 5 %}-test
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-3]]'; echo test- 3 -test
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-3]]'; echo test- 4 4 -test
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-3]]'; echo test- 5 5 -test
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-3]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: test- 3 -test
+# CHECK-EMPTY:
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-6]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: test- 4 4 -test
+# CHECK-EMPTY:
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-9]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: test- 5 5 -test
+# CHECK-EMPTY:
 
 # Escape line breaks for multi-line expressions
 #
 # RUN: %if feature  \
 # RUN:   %{ echo     \
 # RUN:     "test-5" \
 # RUN:   %}
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-4]]'; echo "test-5"
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-4]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: test-5
+# CHECK-EMPTY:
 
 # RUN: %if nofeature       \
 # RUN:   %{ echo "fail" %}   \
 # RUN: %else               \
 # RUN:   %{ echo "test-6" %}
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-4]]'; echo "test-6"
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-4]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: test-6
+# CHECK-EMPTY:
 
 # RUN: echo "test%if feature %{%} %else %{%}-7"
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-1]]'; echo "test-7"
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-1]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: test-7
+# CHECK-EMPTY:
 
 # Escape %if. Without %if..%else context '%{' and '%}' are treated
 # literally.
 #
 # RUN: echo %%if feature %{ echo "test-8" %}
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-1]]'; echo %if feature %{ echo "test-8" %}
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-1]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: %if feature %{ echo test-8 %}
+# CHECK-EMPTY:
 
 # Nested expressions are supported:
 #
 # RUN: echo %if feature %{ %if feature %{ %if nofeature %{"fail"%} %else %{"test-9"%} %} %}
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-1]]'; echo "test-9"
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-1]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: test-9
+# CHECK-EMPTY:
 
 # Binary expression evaluation and regex match can be used as
 # conditions.
 #
 # RUN: echo %if feature && !nofeature %{ "test-10" %}
 # RUN: echo %if feature && nofeature %{ "fail" %} %else %{ "test-11" %}
 # RUN: echo %if {{fea.+}} %{ "test-12" %} %else %{ "fail" %}
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-3]]'; echo "test-10"
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-3]]'; echo "test-11"
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-3]]'; echo "test-12"
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-3]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: test-10
+# CHECK-EMPTY:
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-6]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: test-11
+# CHECK-EMPTY:
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-9]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: test-12
+# CHECK-EMPTY:
 
 # Spaces between %if and %else are ignored. If there is no %else -
 # space after %if %{...%} is not ignored.
 #
 # RUN: echo XX %if feature %{YY%} ZZ
 # RUN: echo AA %if feature %{BB%} %else %{CC%} DD
 # RUN: echo AA %if nofeature %{BB%} %else %{CC%} DD
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-3]]'; echo XX YY ZZ
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-3]]'; echo AA BB DD
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-3]]'; echo AA CC DD
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-3]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: XX YY ZZ
+# CHECK-EMPTY:
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-6]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: AA BB DD
+# CHECK-EMPTY:
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-9]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: AA CC DD
+# CHECK-EMPTY:
 
 # '{' and '}' can be used without escaping
 #
 # RUN: %if feature %{echo {}%}
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-1]]'; echo {}
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-1]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: {}
+# CHECK-EMPTY:
 
 # Spaces are not required
 #
 # RUN: echo %if feature%{"ok"%}%else%{"fail"%}
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-1]]'; echo "ok"
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-1]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: ok
+# CHECK-EMPTY:
 
 # Substitutions with braces are handled correctly
 #
 # RUN: echo %{sub} %if feature%{test-%{sub}%}%else%{"fail"%}
-# CHECK-NEXT: {{^.*'RUN}}: at line [[#@LINE-1]]'; echo ok test-ok
-
-# CHECK-NEXT: --
-# CHECK-NEXT: Exit Code: 0
+#  CHECK-NEXT: {{^.*"RUN}}: at line [[#@LINE-1]]"
+#       CHECK: # command output:
+#  CHECK-NEXT: ok test-ok
+# CHECK-EMPTY: