[lit] Report line number for failed RUN command

(Relands r330755 (reverted in r330848) with fix for PR37239.)

When debugging test failures with -vv (or -v in the case of the
internal shell), this makes it easier to locate the RUN line that
failed.  For example, clang's test/Driver/linux-ld.c has 892 total RUN
lines, and clang's test/Driver/arm-cortex-cpus.c has 424 RUN lines
after concatenation for line continuations.

When reading the generated shell script, this also makes it easier to
locate the RUN line that produced each command.

To support reporting RUN line numbers in the case of the internal
shell, this patch extends the internal shell to support the null
command, ":", except pipelines are not supported.

To support reporting RUN line numbers in the case of windows cmd.exe
as the external shell, this patch extends -vv to set "echo on" instead
of "echo off" in bat files.  (Support for windows cmd.exe as a lit
external shell will likely be dropped later, but I found out too
late.)

Reviewed By: delcypher,	asmith, stella.stamenova, jmorse, lebedev.ri, rnk

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

llvm-svn: 333584
This commit is contained in:
Joel E. Denny 2018-05-30 19:42:27 +00:00
parent c1cd826248
commit b6423479a1
17 changed files with 190 additions and 17 deletions

View File

@ -85,6 +85,10 @@ OUTPUT OPTIONS
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``.
.. option:: -a, --show-all

View File

@ -40,6 +40,17 @@ kUseCloseFDs = not kIsWindows
kAvoidDevNull = kIsWindows
kDevNull = "/dev/null"
# A regex that matches %dbg(ARG), which lit inserts at the beginning of each
# run command pipeline such that ARG specifies the pipeline's source line
# number. lit later expands each %dbg(ARG) to a command that behaves as a null
# command in the target shell so that the line number is seen in lit's verbose
# mode.
#
# This regex captures ARG. ARG must not contain a right parenthesis, which
# terminates %dbg. ARG must not contain quotes, in which ARG might be enclosed
# during expansion.
kPdbgRegex = '%dbg\(([^)\'"]*)\)'
class ShellEnvironment(object):
"""Mutable shell environment containing things like CWD and env vars.
@ -789,6 +800,13 @@ def _executeShCmd(cmd, shenv, results, timeoutHelper):
results.append(cmdResult)
return cmdResult.exitCode
if cmd.commands[0].args[0] == ':':
if len(cmd.commands) != 1:
raise InternalShellError(cmd.commands[0], "Unsupported: ':' "
"cannot be part of a pipeline")
results.append(ShellCommandResult(cmd.commands[0], '', '', 0, False))
return 0;
procs = []
default_stdin = subprocess.PIPE
stderrTempFiles = []
@ -981,6 +999,7 @@ def _executeShCmd(cmd, shenv, results, timeoutHelper):
return exitCode
def executeScriptInternal(test, litConfig, tmpBase, commands, cwd):
commands = applySubstitutions(commands, [(kPdbgRegex, ": '\\1'")])
cmds = []
for ln in commands:
try:
@ -1051,7 +1070,7 @@ def executeScriptInternal(test, litConfig, tmpBase, commands, cwd):
out += 'error: command reached timeout: %s\n' % (
str(result.timeoutReached),)
return out, err, exitCode, timeoutInfo
return out, err, exitCode, timeoutInfo, commands
def executeScript(test, litConfig, tmpBase, commands, cwd):
bashPath = litConfig.getBashPath()
@ -1066,9 +1085,15 @@ def executeScript(test, litConfig, tmpBase, commands, cwd):
mode += 'b' # Avoid CRLFs when writing bash scripts.
f = open(script, mode)
if isWin32CMDEXE:
f.write('@echo off\n')
f.write('\nif %ERRORLEVEL% NEQ 0 EXIT\n'.join(commands))
commands = applySubstitutions(commands, [(kPdbgRegex,
"echo '\\1' > nul")])
if litConfig.echo_all_commands:
f.write('@echo on\n')
else:
f.write('@echo off\n')
f.write('\n@if %ERRORLEVEL% NEQ 0 EXIT\n'.join(commands))
else:
commands = applySubstitutions(commands, [(kPdbgRegex, ": '\\1'")])
if test.config.pipefail:
f.write('set -o pipefail;')
if litConfig.echo_all_commands:
@ -1093,9 +1118,9 @@ def executeScript(test, litConfig, tmpBase, commands, cwd):
out, err, exitCode = lit.util.executeCommand(command, cwd=cwd,
env=test.config.environment,
timeout=litConfig.maxIndividualTestTime)
return (out, err, exitCode, None)
return (out, err, exitCode, None, commands)
except lit.util.ExecuteCommandTimeoutException as e:
return (e.out, e.err, e.exitCode, e.msg)
return (e.out, e.err, e.exitCode, e.msg, commands)
def parseIntegratedTestScriptCommands(source_path, keywords):
"""
@ -1215,14 +1240,14 @@ def getDefaultSubstitutions(test, tmpDir, tmpBase, normalize_slashes=False):
])
return substitutions
def applySubstitutions(script, substitutions):
def applySubstitutions(script, substitutions, escapeForWindows=False):
"""Apply substitutions to the script. Allow full regular expression syntax.
Replace each matching occurrence of regular expression pattern a with
substitution b in line ln."""
def processLine(ln):
# Apply substitutions
for a,b in substitutions:
if kIsWindows:
if kIsWindows and escapeForWindows:
b = b.replace("\\","\\\\")
ln = re.sub(a, b, ln)
@ -1301,7 +1326,9 @@ class IntegratedTestKeywordParser(object):
self.parser = parser
if kind == ParserKind.COMMAND:
self.parser = self._handleCommand
self.parser = lambda line_number, line, output: \
self._handleCommand(line_number, line, output,
self.keyword)
elif kind == ParserKind.LIST:
self.parser = self._handleList
elif kind == ParserKind.BOOLEAN_EXPR:
@ -1332,7 +1359,7 @@ class IntegratedTestKeywordParser(object):
return (not line.strip() or output)
@staticmethod
def _handleCommand(line_number, line, output):
def _handleCommand(line_number, line, output, keyword):
"""A helper for parsing COMMAND type keywords"""
# Trim trailing whitespace.
line = line.rstrip()
@ -1351,6 +1378,14 @@ class IntegratedTestKeywordParser(object):
else:
if output is None:
output = []
pdbg = "%dbg({keyword} at line {line_number})".format(
keyword=keyword,
line_number=line_number)
assert re.match(kPdbgRegex + "$", pdbg), \
"kPdbgRegex expected to match actual %dbg usage"
line = "{pdbg} && {real_command}".format(
pdbg=pdbg,
real_command=line)
output.append(line)
return output
@ -1489,7 +1524,7 @@ def _runShTest(test, litConfig, useExternalSh, script, tmpBase):
if isinstance(res, lit.Test.Result):
return res
out,err,exitCode,timeoutInfo = res
out,err,exitCode,timeoutInfo,script = res
if exitCode == 0:
status = Test.PASS
else:
@ -1530,7 +1565,7 @@ def executeShTest(test, litConfig, useExternalSh,
substitutions = list(extra_substitutions)
substitutions += getDefaultSubstitutions(test, tmpDir, tmpBase,
normalize_slashes=useExternalSh)
script = applySubstitutions(script, substitutions)
script = applySubstitutions(script, substitutions, True)
# Re-run failed tests up to test_retry_attempts times.
attempts = 1

View File

@ -0,0 +1,6 @@
# These commands must run under both bash and windows cmd.exe (with GnuWin32
# tools).
# RUN: true
# RUN: false
# RUN: true

View File

@ -0,0 +1,12 @@
# These commands must run under both bash and windows cmd.exe (with GnuWin32
# tools).
# RUN: echo 'foo bar' \
# RUN: | FileCheck %s
# RUN: echo \
# RUN: 'foo baz' \
# RUN: | FileCheck %s
# RUN: echo 'foo bar' \
# RUN: | FileCheck %s
# CHECK: foo bar

View File

@ -0,0 +1,2 @@
import lit.formats
config.test_format = lit.formats.ShTest(execute_external=True)

View File

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

View File

@ -0,0 +1,11 @@
# RUN: : first line continued \
# RUN: to second line
# RUN: echo 'foo bar' \
# RUN: | FileCheck %s
# RUN: echo \
# RUN: 'foo baz' \
# RUN: | FileCheck %s
# RUN: echo 'foo bar' \
# RUN: | FileCheck %s
# CHECK: foo bar

View File

@ -0,0 +1,2 @@
import lit.formats
config.test_format = lit.formats.ShTest(execute_external=False)

View File

@ -0,0 +1,2 @@
config.name = 'shtest-run-at-line'
config.suffixes = ['.txt']

View File

@ -0,0 +1,3 @@
# Check error on an unsupported ":". (cannot be part of a pipeline)
#
# RUN: : | echo "hello"

View File

@ -71,3 +71,14 @@ for attribute in ('llvm_tools_dir', 'lit_tools_dir'):
if directory:
path = os.path.pathsep.join((directory, path))
config.environment['PATH'] = path
# These substitutions are needed only in tests where the external shell is used
# and could be either bash or windows cmd.exe. Substitutions are expected to
# be expanded in double quotes.
isWin32CMDEXE = lit_config.isWindows and not lit_config.getBashPath()
if isWin32CMDEXE:
config.substitutions.append(('%{pdbg0}', "echo '"))
config.substitutions.append(('%{pdbg1}', "' > nul"))
else:
config.substitutions.append(('%{pdbg0}', ": '"))
config.substitutions.append(('%{pdbg1}', "'"))

View File

@ -8,7 +8,7 @@
#
# END.
# CHECK: Failing Tests (26)
# CHECK: Failing Tests (27)
# CHECK: Failing Tests (1)
# CHECK: Failing Tests (2)
# CHECK: error: Setting --max-failures to 0 does not have any effect.

View File

@ -39,6 +39,7 @@
#
# CHECK: Command Output (stdout):
# CHECK-NEXT: --
# CHECK-NEXT: $ ":" "RUN: at line 1"
# CHECK-NEXT: $ "printf"
# CHECK-NEXT: # command output:
# CHECK-NEXT: line 1: failed test output on stdout

View File

@ -16,12 +16,15 @@
#
# CHECK: Command Output
# CHECK-NEXT: --
# CHECK-NEXT: $ ":" "RUN: at line 1"
# CHECK-NEXT: $ "true"
# CHECK-NEXT: $ ":" "RUN: at line 2"
# CHECK-NEXT: $ "echo" "hi"
# CHECK-NEXT: # command output:
# CHECK-NEXT: hi
#
# CHECK: $ "wc" "missing-file"
# CHECK: $ ":" "RUN: at line 3"
# CHECK-NEXT: $ "wc" "missing-file"
# CHECK-NEXT: # redirected output from '{{.*(/|\\\\)}}basic.txt.tmp.out':
# CHECK-NEXT: missing-file{{.*}} No such file or directory
# CHECK: note: command had no output on stdout or stderr

View File

@ -0,0 +1,70 @@
# Check that -vv makes the line number of the failing RUN command clear.
# (-v is actually sufficient in the case of the internal shell.)
#
# RUN: not %{lit} -j 1 -vv %{inputs}/shtest-run-at-line > %t.out
# RUN: FileCheck --input-file %t.out -Dpdbg0="%{pdbg0}" -Dpdbg1="%{pdbg1}" %s
#
# END.
# CHECK: Testing: 4 tests
# 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-LABEL: FAIL: shtest-run-at-line :: external-shell/basic.txt
# CHECK: Script:
# CHECK: [[pdbg0]]RUN: at line 4[[pdbg1]] && true
# CHECK-NEXT: [[pdbg0]]RUN: at line 5[[pdbg1]] && false
# CHECK-NEXT: [[pdbg0]]RUN: at line 6[[pdbg1]] && 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: [[pdbg0]]RUN: at line 4[[pdbg1]] && echo 'foo bar' | FileCheck
# CHECK-NEXT: [[pdbg0]]RUN: at line 6[[pdbg1]] && echo 'foo baz' | FileCheck
# CHECK-NEXT: [[pdbg0]]RUN: at line 9[[pdbg1]] && 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

View File

@ -26,6 +26,14 @@
# CHECK: error: command failed with exit status: 1
# CHECK: ***
# CHECK: FAIL: shtest-shell :: colon-error.txt
# CHECK: *** TEST 'shtest-shell :: colon-error.txt' FAILED ***
# CHECK: $ ":"
# CHECK: # command stderr:
# CHECK: Unsupported: ':' cannot be part of a pipeline
# CHECK: error: command failed with exit status: 127
# CHECK: ***
# CHECK: FAIL: shtest-shell :: diff-error-0.txt
# CHECK: *** TEST 'shtest-shell :: diff-error-0.txt' FAILED ***
# CHECK: $ "diff" "diff-error-0.txt" "diff-error-0.txt"
@ -153,7 +161,7 @@
#
# CHECK: FAIL: shtest-shell :: error-1.txt
# CHECK: *** TEST 'shtest-shell :: error-1.txt' FAILED ***
# CHECK: shell parser error on: 'echo "missing quote'
# CHECK: shell parser error on: ': \'RUN: at line 3\' && echo "missing quote'
# CHECK: ***
# CHECK: FAIL: shtest-shell :: error-2.txt
@ -219,4 +227,4 @@
# CHECK: PASS: shtest-shell :: sequencing-0.txt
# CHECK: XFAIL: shtest-shell :: sequencing-1.txt
# CHECK: PASS: shtest-shell :: valid-shell.txt
# CHECK: Failing Tests (26)
# CHECK: Failing Tests (27)

View File

@ -99,8 +99,8 @@ class TestIntegratedTestKeywordParser(unittest.TestCase):
cmd_parser = self.get_parser(parsers, 'MY_RUN:')
value = cmd_parser.getValue()
self.assertEqual(len(value), 2) # there are only two run lines
self.assertEqual(value[0].strip(), 'baz')
self.assertEqual(value[1].strip(), 'foo bar')
self.assertEqual(value[0].strip(), "%dbg(MY_RUN: at line 4) && baz")
self.assertEqual(value[1].strip(), "%dbg(MY_RUN: at line 7) && foo bar")
def test_custom(self):
parsers = self.make_parsers()