Index: llvm/utils/lit/lit/LitConfig.py =================================================================== --- llvm/utils/lit/lit/LitConfig.py +++ llvm/utils/lit/lit/LitConfig.py @@ -7,6 +7,7 @@ import lit.Test import lit.formats import lit.TestingConfig +import lit.OutputSettings import lit.util # LitConfig must be a new style class for properties to work @@ -26,7 +27,9 @@ params, config_prefix = None, maxIndividualTestTime = 0, parallelism_groups = {}, - echo_all_commands = False): + runWithCommandOutput = False, + scriptOutputStyle = lit.OutputSettings.NoScript, + commandOutputStyle = lit.OutputSettings.OnlyFailingCommand): # The name of the test runner. self.progname = progname # The items to add to the PATH environment variable. @@ -65,7 +68,9 @@ self.maxIndividualTestTime = maxIndividualTestTime self.parallelism_groups = parallelism_groups - self.echo_all_commands = echo_all_commands + self.runWithCommandOutput = runWithCommandOutput + self.scriptOutputStyle = scriptOutputStyle + self.commandOutputStyle = commandOutputStyle @property def maxIndividualTestTime(self): Index: llvm/utils/lit/lit/OutputSettings.py =================================================================== --- /dev/null +++ llvm/utils/lit/lit/OutputSettings.py @@ -0,0 +1,77 @@ +# TODO(python3): Could be an enum +class ScriptOutputStyle: + def __init__(self, name, full): + self.name = name + + def __repr__(self): + return '%s(%r)' % (self.__class__.__name__, self.name) + +NoScript = ScriptOutputStyle("None", False) +FullScript = ScriptOutputStyle("Full", True) +FullScriptWithHighlighting = ScriptOutputStyle("FullWithHighlighting", True) + +# Consider a script +# +# ``` +# RUN: true +# RUN: false +# RUN: true +# ``` +# +# FullScript will show the whole thing, without highlighting. +# FullScriptWithHighlighting will show something like +# +# ``` +# Script: +# -- +# : 'RUN: at line 1'; true +# : 'RUN: at line 2'; false +# **: 'RUN: at line 3'; true** +# -- +# ``` +# (The ** indicates colored output) + +# TODO(python3): Could be enum +class CommandOutputStyle: + def __init__(self, name): + self.name = name + + def __repr__(self): + return '%s(%r)' % (self.__class__.__name__, self.name) + +NoCommand = CommandOutputStyle("None") +OnlyFailingCommand = CommandOutputStyle("OnlyFailing") +UpToAndIncludingFailingCommand = CommandOutputStyle("UpToAndIncluding") + +# Consider a script +# +# ``` +# RUN: true +# RUN: false +# RUN: true +# ``` +# +# OnlyFailingCommand will show something like +# +# ``` +# Command output (stderr, truncated) +# -- +# + : 'RUN: at line 2' +# + false +# -- +# NOTE: The failure might depend on preceding RUN lines. +# Use --verbose to see preceding RUN lines and outputs. +# ``` +# +# UpToAndIncludingFailingCommand will show something like +# +# ``` +# Command Output (stderr): +# -- +# + : 'RUN: at line 1' +# + true +# **+ : 'RUN: at line 2' +# + false** +# -- +# ``` +# (The ** indicates colored output) Index: llvm/utils/lit/lit/TestRunner.py =================================================================== --- llvm/utils/lit/lit/TestRunner.py +++ llvm/utils/lit/lit/TestRunner.py @@ -17,6 +17,8 @@ except ImportError: from io import StringIO +from lit.ProgressBar import TerminalController +import lit.OutputSettings as OutputSettings from lit.ShCommands import GlobItem, Command import lit.ShUtil as ShUtil import lit.Test as Test @@ -959,7 +961,7 @@ if isWin32CMDEXE: for i, ln in enumerate(commands): commands[i] = re.sub(kPdbgRegex, "echo '\\1' > nul && ", ln) - if litConfig.echo_all_commands: + if litConfig.runWithCommandOutput: f.write('@echo on\n') else: f.write('@echo off\n') @@ -969,7 +971,7 @@ commands[i] = re.sub(kPdbgRegex, ": '\\1'; ", ln) if test.config.pipefail: f.write(b'set -o pipefail;' if mode == 'wb' else 'set -o pipefail;') - if litConfig.echo_all_commands: + if litConfig.runWithCommandOutput: 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')) @@ -1475,6 +1477,132 @@ return script +def locateLastFailingRunLine(outputStr): + """ + Tries to locate the last run line in 'outputStr' and returns a pair of: + - The index immediately after the preceding newline + (i.e. the start of the RUN line). + - The matched string itself, including the number at the end, + starting with 'RUN' (shell-specific prefix is skipped). + + Returns (-1, None) on failure. + """ + # The first attempt is more complicated than simply finding the last + # 'RUN: at line'; the latter is more likely to lead to mistakes + # when the command output itself has a 'RUN: at line' due to something + # else (possibly because we are testing lit itself). + # + # However, this is not perfect either :(. For example, if an external shell + # prepends line numbers on 'set +x', then this will fail. + + error = (-1, None) + runStr = "RUN: at line" + firstRunStrStart = outputStr.find(runStr) + if firstRunStrStart == -1: + return error + # Use the first RUN line to create a regex for searching. + nlIdx = outputStr[:firstRunStrStart].rfind('\n') + firstRunLineStart = 0 if nlIdx == -1 else nlIdx + 1 + firstRunStrEnd = firstRunStrStart + len(runStr) + runLineRegex = ('(' + re.escape(outputStr[firstRunLineStart:firstRunStrEnd]) + + ' [0-9]+)') + + def reversedMatches(regex, s): + return reversed(list(re.finditer(regex, s))) + + for runLine in reversedMatches(runLineRegex, outputStr): + # trim the shell-specific prefix + delta = firstRunStrStart - firstRunLineStart + return (runLine.start(), runLine.group(0)[delta:]) + + # The complicated method didn't work, try something simple instead. + simpleRunLineRegex = '(' + re.escape(runStr)+ ' [0-9]+)' + for runLine in reversedMatches(simpleRunLineRegex, outputStr): + nlIdx = outputStr[:runLine.start()].rfind('\n') + runLineStart = 0 if nlIdx == -1 else nlIdx + return (runLineStart, runLine.group(0)) + + # weird, we should've at least gotten the first run line... + return error + +def highlightFailingText(text): + term = TerminalController() + return term.render('${BOLD}${RED}%s${NORMAL}' % text) + +def createScriptOutput(litConfig, scriptLines, cmdOutput, status, exitCode): + def makeOutput(outputLines): + return ("""Script:\n--\n%s\n--\nExit Code: %d\n""" + % ('\n'.join(outputLines), exitCode)) + + def defaultOutput(): + return makeOutput(scriptLines) + + def splitOnSubstr(strList, substr): + for i, s in enumerate(strList): + if substr in s: + return (strList[:i], s, strList[i+1:]) + return (None, None, None) + + def highlightedOutput(): + _, lastRunLine = locateLastFailingRunLine(cmdOutput) + if lastRunLine is None: + return defaultOutput() + (pre, failingLine, post) = splitOnSubstr(scriptLines, lastRunLine) + if failingLine is None: + return defaultOutput() + return makeOutput(pre + [highlightFailingText(failingLine)] + post) + + if litConfig.scriptOutputStyle == OutputSettings.NoScript: + return "" + elif (litConfig.scriptOutputStyle == OutputSettings.FullScript + or not status.isFailure + or (not cmdOutput)): + return defaultOutput() + else: + assert(litConfig.scriptOutputStyle + == OutputSettings.FullScriptWithHighlighting) + return highlightedOutput() + +def createCommandOutput(litConfig, cmdOutput, streamName, testStatus): + def makeOutput(outputStr, isTruncated=False): + if isTruncated: + formatStr = """Command Output (%s, truncated):\n--\n%s\n--\n""" + formatStr += ( + "(NOTE: The failure may depend on preceding RUN lines.\n" + " Use --verbose to see preceding RUN lines and outputs.)\n") + else: + formatStr = """Command Output (%s):\n--\n%s\n--\n""" + return formatStr % (streamName, outputStr) + + def defaultOutput(): + return makeOutput(cmdOutput) + + def failingCommandOnlyOutput(): + lineStart, runLineStr = locateLastFailingRunLine(cmdOutput) + # maybe there was an error, or maybe we are not truncating anything + if runLineStr is None or lineStart == 0: + return defaultOutput() + return makeOutput(cmdOutput[lineStart:], isTruncated=True) + + def allCommandsHighlightingFailingOutput(): + lineStart, runLineStr = locateLastFailingRunLine(cmdOutput) + # maybe there was an error, or maybe we are not truncating anything + if runLineStr is None or lineStart == 0: + return defaultOutput() + return makeOutput(cmdOutput[:lineStart] + + highlightFailingText(cmdOutput[lineStart:]), + isTruncated=False) + + if litConfig.commandOutputStyle == OutputSettings.NoCommand: + return "" + elif not testStatus.isFailure: + return defaultOutput() + elif litConfig.commandOutputStyle == OutputSettings.OnlyFailingCommand: + return failingCommandOnlyOutput() + else: + assert(litConfig.commandOutputStyle + == OutputSettings.UpToAndIncludingFailingCommand) + return allCommandsHighlightingFailingOutput() def _runShTest(test, litConfig, useExternalSh, script, tmpBase): def runOnce(execdir): @@ -1516,8 +1644,9 @@ status = Test.FLAKYPASS # Form the output log. - output = """Script:\n--\n%s\n--\nExit Code: %d\n""" % ( - '\n'.join(script), exitCode) + output = createScriptOutput(litConfig, script, + out if out else err, + status, exitCode) if timeoutInfo is not None: output += """Timeout: %s\n""" % (timeoutInfo,) @@ -1525,9 +1654,9 @@ # Append the outputs, if present. if out: - output += """Command Output (stdout):\n--\n%s\n--\n""" % (out,) + output += createCommandOutput(litConfig, out, "stdout", status) if err: - output += """Command Output (stderr):\n--\n%s\n--\n""" % (err,) + output += createCommandOutput(litConfig, err, "stderr", status) return lit.Test.Result(status, output) Index: llvm/utils/lit/lit/cl_arguments.py =================================================================== --- llvm/utils/lit/lit/cl_arguments.py +++ llvm/utils/lit/lit/cl_arguments.py @@ -3,6 +3,7 @@ import shlex import sys +import lit.OutputSettings as OutputSettings import lit.reports import lit.util @@ -42,17 +43,21 @@ help="Suppress no error output", action="store_true") format_group.add_argument("-s", "--succinct", - help="Reduce amount of output", + help="Reduce amount of output." + " Additionally, show a progress bar," + " unless --no-progress-bar is specified.", action="store_true") format_group.add_argument("-v", "--verbose", - dest="showOutput", - help="Show test output for failures", + help="Show test output for failures." + " The last command under 'Output' is the failing one." + " All substituted commands are shown under 'Script'," + " including any commands after the failing command." + " The failing lines are highlighted based on heuristics.", action="store_true") format_group.add_argument("-vv", "--echo-all-commands", dest="echoAllCommands", 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.") + help="alias for -v (for backwards compatibility)") format_group.add_argument("-a", "--show-all", dest="showAllOutput", help="Display all commandlines and output", @@ -163,9 +168,30 @@ args = sys.argv[1:] + env_args opts = parser.parse_args(args) - # Validate command line options - if opts.echoAllCommands: - opts.showOutput = True + # default output settings + opts.showOutputOnFailure = True + opts.scriptOutputStyle = OutputSettings.NoScript + opts.commandOutputStyle = OutputSettings.OnlyFailingCommand + opts.runWithCommandOutput = True + + if opts.quiet: + opts.showOutputOnFailure = False + opts.commandOutputStyle = OutputSettings.NoCommand + elif opts.verbose or opts.echoAllCommands: + opts.scriptOutputStyle = OutputSettings.FullScriptWithHighlighting + opts.commandOutputStyle = OutputSettings.UpToAndIncludingFailingCommand + + # preserve old behavior by (re)setting this last + if opts.showAllOutput: + opts.scriptOutputStyle = OutputSettings.FullScript + opts.commandOutputStyle = OutputSettings.UpToAndIncludingFailingCommand + + # If we call out to an external shell, we ask for all output, + # regardless of whether we're display all commands that were run, + # or only the last command (that might've failed). + opts.runWithCommandOutput = ( + opts.commandOutputStyle == OutputSettings.UpToAndIncludingFailingCommand + or opts.commandOutputStyle == OutputSettings.OnlyFailingCommand) # TODO(python3): Could be enum if opts.shuffle: Index: llvm/utils/lit/lit/display.py =================================================================== --- llvm/utils/lit/lit/display.py +++ llvm/utils/lit/lit/display.py @@ -69,7 +69,7 @@ self.completed, self.tests)) # Show the test failure output, if requested. - if (test.isFailure() and self.opts.showOutput) or \ + if (test.isFailure() and self.opts.showOutputOnFailure) or \ self.opts.showAllOutput: if test.isFailure(): print("%s TEST '%s' FAILED %s" % ('*'*20, test.getFullName(), Index: llvm/utils/lit/lit/main.py =================================================================== --- llvm/utils/lit/lit/main.py +++ llvm/utils/lit/lit/main.py @@ -36,7 +36,9 @@ isWindows=is_windows, params=params, config_prefix=opts.configPrefix, - echo_all_commands=opts.echoAllCommands) + runWithCommandOutput=opts.runWithCommandOutput, + scriptOutputStyle=opts.scriptOutputStyle, + commandOutputStyle=opts.commandOutputStyle) discovered_tests = lit.discovery.find_tests_for_inputs(lit_config, opts.test_paths) if not discovered_tests: Index: llvm/utils/lit/tests/shtest-format.py =================================================================== --- llvm/utils/lit/tests/shtest-format.py +++ llvm/utils/lit/tests/shtest-format.py @@ -18,7 +18,12 @@ # CHECK-NEXT: line 2: failed test output on stdout # CHECK: Command Output (stderr): # CHECK-NEXT: -- -# CHECK-NEXT: cat{{(\.exe)?}}: {{cannot open does-not-exist|does-not-exist: No such file or directory}} +# CHECK-NEXT: 'RUN: at line 3' +# +# Skipping some lines... +# +# CHECK: 'RUN: at line 5' +# CHECK: cat{{(\.exe)?}}: {{cannot open does-not-exist|does-not-exist: No such file or directory}} # CHECK: -- # CHECK: FAIL: shtest-format :: external_shell/fail_with_bad_encoding.txt Index: llvm/utils/lit/tests/shtest-run-at-line.py =================================================================== --- llvm/utils/lit/tests/shtest-run-at-line.py +++ llvm/utils/lit/tests/shtest-run-at-line.py @@ -1,70 +1,132 @@ -# Check that -vv makes the line number of the failing RUN command clear. -# (-v is actually sufficient in the case of the internal shell.) +# Check that the default terse output shows only the failing +# line in the output, and doesn't show the script. # -# RUN: not %{lit} -j 1 -vv %{inputs}/shtest-run-at-line > %t.out -# RUN: FileCheck --input-file %t.out %s +# RUN: not %{lit} -j 1 %{inputs}/shtest-run-at-line > %t-terse.out +# RUN: FileCheck --input-file %t-terse.out %s --check-prefix=TERSE + +# Check that --verbose outputs both Script and Command Output. +# +# RUN: not %{lit} -j 1 --verbose %{inputs}/shtest-run-at-line > %t-verbose.out +# RUN: FileCheck --input-file %t-verbose.out %s --check-prefix=VERBOSE # # END. +# In the case of the external shell, we check for only RUN lines in stderr in +# case some shell implementations format "set -x" output differently. -# CHECK: Testing: 4 tests +################################################################################ +# Checking lines for terse output +# TERSE-LABEL: FAIL: shtest-run-at-line :: external-shell/basic.txt -# In the case of the external shell, we check for only RUN lines in stderr in -# case some shell implementations format "set -x" output differently. +# TERSE-NOT: Script: -# CHECK-LABEL: FAIL: shtest-run-at-line :: external-shell/basic.txt - -# CHECK: Script: -# CHECK: RUN: at line 4{{.*}} true -# CHECK-NEXT: RUN: at line 5{{.*}} false -# CHECK-NEXT: RUN: at line 6{{.*}} true - -# CHECK: RUN: at line 4 -# CHECK: RUN: at line 5 -# CHECK-NOT: RUN - -# CHECK-LABEL: FAIL: shtest-run-at-line :: external-shell/line-continuation.txt - -# CHECK: Script: -# CHECK: RUN: at line 4{{.*}} echo 'foo bar' | FileCheck -# CHECK-NEXT: RUN: at line 6{{.*}} echo 'foo baz' | FileCheck -# CHECK-NEXT: RUN: at line 9{{.*}} echo 'foo bar' | FileCheck - -# CHECK: RUN: at line 4 -# CHECK: RUN: at line 6 -# CHECK-NOT: RUN - - -# CHECK-LABEL: FAIL: shtest-run-at-line :: internal-shell/basic.txt - -# CHECK: Script: -# CHECK: : 'RUN: at line 1'; true -# CHECK-NEXT: : 'RUN: at line 2'; false -# CHECK-NEXT: : 'RUN: at line 3'; true - -# CHECK: Command Output (stdout) -# CHECK: $ ":" "RUN: at line 1" -# CHECK-NEXT: $ "true" -# CHECK-NEXT: $ ":" "RUN: at line 2" -# CHECK-NEXT: $ "false" -# CHECK-NOT: RUN - -# CHECK-LABEL: FAIL: shtest-run-at-line :: internal-shell/line-continuation.txt - -# CHECK: Script: -# CHECK: : 'RUN: at line 1'; : first line continued to second line -# CHECK-NEXT: : 'RUN: at line 3'; echo 'foo bar' | FileCheck -# CHECK-NEXT: : 'RUN: at line 5'; echo 'foo baz' | FileCheck -# CHECK-NEXT: : 'RUN: at line 8'; echo 'foo bar' | FileCheck - -# CHECK: Command Output (stdout) -# CHECK: $ ":" "RUN: at line 1" -# CHECK-NEXT: $ ":" "first" "line" "continued" "to" "second" "line" -# CHECK-NEXT: $ ":" "RUN: at line 3" -# CHECK-NEXT: $ "echo" "foo bar" -# CHECK-NEXT: $ "FileCheck" "{{.*}}" -# CHECK-NEXT: $ ":" "RUN: at line 5" -# CHECK-NEXT: $ "echo" "foo baz" -# CHECK-NEXT: $ "FileCheck" "{{.*}}" -# CHECK-NOT: RUN +# TERSE: Command Output (stderr, truncated) +# TERSE: -- +# TERSE-NOT: RUN: at line 4 +# TERSE-NOT: true +# TERSE: RUN: at line 5 +# TERSE: false +# TERSE-NOT: RUN +# TERSE: NOTE: The failure may depend on preceding RUN lines. + +# TERSE-LABEL: FAIL: shtest-run-at-line :: external-shell/line-continuation.txt + +# TERSE-NOT: Script: + +# TERSE: Command Output (stderr, truncated) +# TERSE-NOT: RUN: at line 4 +# TERSE: RUN: at line 6 +# TERSE: echo 'foo baz' +# TERSE: FileCheck +# TERSE-NOT: RUN +# TERSE: NOTE: The failure may depend on preceding RUN lines. + +# TERSE-LABEL: FAIL: shtest-run-at-line :: internal-shell/basic.txt + +# TERSE-NOT: Script: + +# TERSE: Command Output (stdout, truncated) +# TERSE-NOT: $ ":" "RUN: at line 1" +# TERSE: $ ":" "RUN: at line 2" +# TERSE-NEXT: $ "false" +# TERSE-NOT: RUN +# TERSE: NOTE: The failure may depend on preceding RUN lines. + +# TERSE-LABEL: FAIL: shtest-run-at-line :: internal-shell/line-continuation.txt + +# TERSE-NOT: Script: + +# TERSE: Command Output (stdout, truncated) +# TERSE-NOT: $ ":" "RUN: at line 1" +# TERSE-NOT: $ ":" "RUN: at line 3" +# TERSE: $ ":" "RUN: at line 5" +# TERSE-NEXT: $ "echo" "foo baz" +# TERSE-NEXT: $ "FileCheck" "{{.*}}" +# TERSE-NOT: RUN +# TERSE: (NOTE: The failure may depend on preceding RUN lines. +# TERSE-NEXT: Use --verbose to see preceding RUN lines and outputs.) + +################################################################################ +# Checking lines for verbose output + +# VERBOSE: Testing: 4 tests + +# VERBOSE-LABEL: FAIL: shtest-run-at-line :: external-shell/basic.txt + +# VERBOSE: Script: +# VERBOSE: RUN: at line 4{{.*}} true +# VERBOSE-NEXT: RUN: at line 5{{.*}} false +# VERBOSE-NEXT: RUN: at line 6{{.*}} true + +# VERBOSE: RUN: at line 4 +# VERBOSE: RUN: at line 5 +# VERBOSE-NOT: RUN: at line 6 +# VERBOSE-NOT: (NOTE: The failure may depend on preceding RUN lines. + +# VERBOSE-LABEL: FAIL: shtest-run-at-line :: external-shell/line-continuation.txt + +# VERBOSE: Script: +# VERBOSE: RUN: at line 4{{.*}} echo 'foo bar' | FileCheck +# VERBOSE-NEXT: RUN: at line 6{{.*}} echo 'foo baz' | FileCheck +# VERBOSE-NEXT: RUN: at line 9{{.*}} echo 'foo bar' | FileCheck + +# VERBOSE: RUN: at line 4 +# VERBOSE: RUN: at line 6 +# VERBOSE-NOT: RUN +# VERBOSE-NOT: (NOTE: The failure may depend on preceding RUN lines. + +# VERBOSE-LABEL: FAIL: shtest-run-at-line :: internal-shell/basic.txt + +# VERBOSE: Script: +# VERBOSE: : 'RUN: at line 1'; true +# VERBOSE-NEXT: : 'RUN: at line 2'; false +# VERBOSE-NEXT: : 'RUN: at line 3'; true + +# VERBOSE: Command Output (stdout) +# VERBOSE: $ ":" "RUN: at line 1" +# VERBOSE-NEXT: $ "true" +# VERBOSE-NEXT: $ ":" "RUN: at line 2" +# VERBOSE-NEXT: $ "false" +# VERBOSE-NOT: RUN +# VERBOSE-NOT: (NOTE: The failure may depend on preceding RUN lines. + +# VERBOSE-LABEL: FAIL: shtest-run-at-line :: internal-shell/line-continuation.txt + +# VERBOSE: Script: +# VERBOSE: : 'RUN: at line 1'; : first line continued to second line +# VERBOSE-NEXT: : 'RUN: at line 3'; echo 'foo bar' | FileCheck +# VERBOSE-NEXT: : 'RUN: at line 5'; echo 'foo baz' | FileCheck +# VERBOSE-NEXT: : 'RUN: at line 8'; echo 'foo bar' | FileCheck + +# VERBOSE: Command Output (stdout) +# VERBOSE: $ ":" "RUN: at line 1" +# VERBOSE-NEXT: $ ":" "first" "line" "continued" "to" "second" "line" +# VERBOSE-NEXT: $ ":" "RUN: at line 3" +# VERBOSE-NEXT: $ "echo" "foo bar" +# VERBOSE-NEXT: $ "FileCheck" "{{.*}}" +# VERBOSE-NEXT: $ ":" "RUN: at line 5" +# VERBOSE-NEXT: $ "echo" "foo baz" +# VERBOSE-NEXT: $ "FileCheck" "{{.*}}" +# VERBOSE-NOT: RUN +# VERBOSE-NOT: (NOTE: The failure may depend on preceding RUN lines.