This is an archive of the discontinued LLVM Phabricator instance.

[lit] Improve test output from lit's internal shell
ClosedPublic

Authored by jdenny on Aug 2 2023, 5:29 PM.

Details

Summary

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

Motivation

D154984 removes the "Script:" section that lit prints along with a test's output, and it makes -v and -a imply -vv. For example, after D154984, the "Script:" section below is never shown, but -v is enough to produce the execution trace following it:

Script:
--
: 'RUN: at line 1'; echo hello | FileCheck bogus.txt && echo success
--
Exit Code: 2

Command Output (stdout):
--
$ ":" "RUN: at line 1"
$ "echo" "hello"
# command output:
hello

$ "FileCheck" "bogus.txt"
# command stderr:
Could not open check file 'bogus.txt': No such file or directory

error: command failed with exit status: 2

--

In the D154984 review, some reviewers point out that they have been using the "Script:" section for copying and pasting a test's shell commands to a terminal window. The shell commands as printed in the execution trace can be harder to copy and paste for the following reasons:

  • They drop redirections and break apart RUN lines at &&, |, etc.
  • They add $ at the start of every command, which makes it hard to copy and paste multiple commands in bulk.
  • Command stdout, stderr, etc. are interleaved with the commands and are not clearly delineated.
  • They don't always use proper shell quoting. Instead, they blindly enclose all command-line arguments in double quotes.

Changes

D154984 plus this patch converts the above example into:

Exit Code: 2

Command Output (stdout):
--
# RUN: at line 1
echo hello | FileCheck bogus-file.txt && echo success
# executed command: echo hello
# .---command stdout------------
# | hello
# `-----------------------------
# executed command: FileCheck bogus-file.txt
# .---command stderr------------
# | Could not open check file 'bogus-file.txt': No such file or directory
# `-----------------------------
# error: command failed with exit status: 2

--

Thus, this patch addresses the above issues as follows:

  • The entire execution trace can be copied and pasted in bulk to a terminal for correct execution of the RUN lines, which are printed intact as they appeared in the original RUN lines except lit substitutions are expanded. Everything else in the execution trace appears in shell comments so it has no effect in a terminal.
  • Each of the RUN line's commands is repeated (in shell comments) as it executes to show (1) that the command actually executed (e.g., echo success above didn't) and (2) what stdout, stderr, non-zero exit status, and output files are associated with the command, if any. Shell quoting in the command is now correct and minimal but is not necessarily the original shell quoting from the RUN line.
  • The start and end of the contents of stdout, stderr, or an output file is now delineated clearly in the trace.

To help produce some of the above output, this patch extends lit's internal shell with a built-in @echo command. It's like echo except lit suppresses the normal execution trace for @echo and just prints its stdout directly. For now, @echo isn't documented for use in lit tests.

Without this patch, libcxx's custom lit test format tries to parse the stdout from lit.TestRunner.executeScriptInternal (which runs lit's internal shell) to extract the stdout and stderr produced by shell commands, and that parse no longer works after the above changes. This patch makes a small adjustment to lit.TestRunner.executeScriptInternal so libcxx can just request stdout and stderr without an execution trace.

(As a minor drive-by fix that came up in testing: lit's internal not command now always produces a numeric exit status and never True.)

Caveat

This patch only makes the above changes for lit's internal shell. In most cases, we do not know how to force external shells (e.g., bash, sh, window's cmd) to produce execution traces in the manner we want.

To configure a test suite to use lit's internal shell (which is usually better for test portability than external shells anyway), add this to the test suite's lit.cfg or other configuration file:

config.test_format = lit.formats.ShTest(execute_external=False)

Diff Detail

Event Timeline

jdenny created this revision.Aug 2 2023, 5:29 PM
Herald added a project: Restricted Project. · View Herald TranscriptAug 2 2023, 5:29 PM
Herald added a subscriber: delcypher. · View Herald Transcript
jdenny requested review of this revision.Aug 2 2023, 5:29 PM
Herald added a project: Restricted Project. · View Herald Transcript
MaskRay accepted this revision.Aug 3 2023, 9:46 AM

Thank you for the nice summary! I just read the internal implementation the other day and glanced at the change. This change is reasonable and the test coverage looks great.
The new built-in @echo probably should be mentioned in the summary/commit message as well.

This revision is now accepted and ready to land.Aug 3 2023, 9:46 AM
jdenny updated this revision to Diff 546981.Aug 3 2023, 1:09 PM

Rebased.

jdenny edited the summary of this revision. (Show Details)Aug 3 2023, 1:32 PM
jdenny added a comment.Aug 3 2023, 1:36 PM

Thank you for the nice summary! I just read the internal implementation the other day and glanced at the change. This change is reasonable and the test coverage looks great.

Thanks for the review.

In case anyone missed it, before this lands, we'll need consensus on D154984, and there was a request to do an RFC for that purpose. I wanted to have this patch to address concerns about D154984 first.

The new built-in @echo probably should be mentioned in the summary/commit message as well.

Good idea. Done.

Thank you so much! This fully addresses the concerns that I raised in https://reviews.llvm.org/D154984.

jdenny updated this revision to Diff 547990.Aug 7 2023, 4:35 PM
jdenny edited the summary of this revision. (Show Details)

Improve test coverage for new behavior. Fix issues that revealed:

  • Drive-by fix that came up in testing: internal not cmd sometimes produced exit status of True. Fixed that to be 1.
  • Instead of # command line, add # preamble command line before command lines from preamble_commands.
  • When expanding %dbg(...), don't modify the original script. Otherwise, upon every retry (due to ALLOW_RETRIES), we keep prepending the generic # command line to it as if there was no %dbg(...).
  • Assert that %dbg(...) is never missing. ninja check-lit doesn't fail this assert. CI testing will hopefully answer this question for all other uses.
  • If @echo has any unexpected results, instead of failing a generic assertion and losing the specific diagnostic, enable the normal execution trace as if it's echo.
jdenny added a comment.Aug 7 2023, 4:40 PM

Thank you so much! This fully addresses the concerns that I raised in https://reviews.llvm.org/D154984.

Thanks for confirming.

jdenny updated this revision to Diff 548233.Aug 8 2023, 8:12 AM

D154987's pre-commit CI discovered that libcxx's custom lit test format doesn't always use %dbg(...) on commands. Chances are that there are other test suites in the same boat. Eliminate the associated assertion and todo in this patch.

MaskRay accepted this revision.Aug 8 2023, 5:31 PM
jdenny updated this revision to Diff 548628.Aug 9 2023, 8:14 AM
jdenny edited the summary of this revision. (Show Details)

D154987's pre-commit CI revealed another issue with libcxx. This update tries to fix that. See changes to the patch summary for details.

Now that libcxx is modified by this patch, we should see any additional libcxx pre-commit CI failures here. I've tried to run check-cxx on my machine, but it takes hours, and many tests are expected fails or excluded, so I've only checked some cases.

Sorry for the churn.

MaskRay accepted this revision.Aug 17 2023, 1:39 PM

I saw only one bit of feedback from the RFC that affects this patch. That is, theoretically, a windows user might wish to adjust the shell comment sequence that lit's internal shell uses in its execution trace. This feature might help with copying multiple command lines at once from that trace and pasting them into any of the various shells that people use in windows. However, people seemed fine to wait to do that in a separate patch if an actual user who cares about that use case speaks up.

At this point, I think we're just waiting on D154984 to be accepted.

@ldionne In the meantime, if it hasn't happened already, it might be good for a libcxx person to review the libcxx changes in this patch.

awarzynski accepted this revision.Aug 27 2023, 7:53 AM

LGTM, thank you for addressing my comments!

jdenny edited the summary of this revision. (Show Details)Aug 29 2023, 8:50 AM
Herald added a project: Restricted Project. · View Herald TranscriptAug 29 2023, 9:01 AM
Herald added a reviewer: Restricted Project. · View Herald Transcript
dyung added a subscriber: dyung.Aug 29 2023, 11:16 AM

@jdenny I am the owner of the llvm-clang-x86_64-sie-win bot, let me know if you need any help to fix the failures from your change.

@jdenny I am the owner of the llvm-clang-x86_64-sie-win bot, let me know if you need any help to fix the failures from your change.

Thanks for pinging me, and sorry for all the trouble. I think I nearly have a final fix and expect to push within a few minutes.

@jdenny I am the owner of the llvm-clang-x86_64-sie-win bot, let me know if you need any help to fix the failures from your change.

Thanks for pinging me, and sorry for all the trouble. I think I nearly have a final fix and expect to push within a few minutes.

Getting close, the last failure just seems to be due to the path separators '/' vs. '\' being explicitly checked for.

Getting close, the last failure just seems to be due to the path separators '/' vs. '\' being explicitly checked for.

Yes. By now, I really ought to remember that one when writing tests.

OK, I landed these additional commits to fix various issues (shell quoting and / vs \) in lit tests running in windows:

Those commits fix lit's tests but do not change lit itself. See the commit logs there for details.

Sorry it took me a while.

@jdenny I am the owner of the llvm-clang-x86_64-sie-win bot, let me know if you need any help to fix the failures from your change.

One thing all bot maintainers might consider doing is adding the following to the environment:

export FILECHECK_OPTS='-dump-input-filter=all -vv -color'

As discussed in f254bbf23374190c88a2b1a5f163622fbec9a936, this provides a lot more info for debugging test fails. For the sake of users running tests locally who want less verbose output, it's not the FileCheck default. However, it's easy for them to run again with the above when needed. It's not easy to do that for CI on a system you don't own.

(Of course, you might drop -color if color doesn't render well.)

Just a suggestion.

I see some feedback on Windows build issues and some followups. Yesterday libc++'s precommit CI for Windows started to fail, the first build is https://buildkite.com/llvm-project/libcxx-ci/builds/29307

This is the relevant part of the log

C:\Users\ContainerAdministrator\AppData\Local\Temp\buildkite-script-1445266630.bat
+ set -o pipefail
+ unset LANG
+ unset LC_ALL
+ unset LC_COLLATE
++ basename libcxx/utils/ci/run-buildbot
+ PROGNAME=run-buildbot
+ [[ 1 == 0 ]]
+ [[ 1 -gt 0 ]]
+ case ${1} in
+ BUILDER=clang-cl-dll
+ shift
+ [[ 0 -gt 0 ]]
++ git rev-parse --show-toplevel
+ MONOREPO_ROOT=C:/ws/src
+ BUILD_DIR=C:/ws/src/build/clang-cl-dll
+ INSTALL_DIR=C:/ws/src/build/clang-cl-dll/install
+ xcrun --find ninja
+ which ninja
++ which ninja
+ NINJA=/c/ProgramData/chocolatey/bin/ninja
+ '[' -z '' ']'
+ xcrun --find cmake
+ CMAKE=cmake
+ '[' -z '' ']'
+ ENABLE_CLANG_TIDY=Off
+ '[' -n '' ']'
+ cmake --version
libcxx/utils/ci/run-buildbot: line 195: cmake: command not found
🚨 Error: The command exited with status 127
user command error: exit status 127

Could this be caused by your changes?

I see some feedback on Windows build issues and some followups. Yesterday libc++'s precommit CI for Windows started to fail, the first build is https://buildkite.com/llvm-project/libcxx-ci/builds/29307

This is the relevant part of the log

+ cmake --version
libcxx/utils/ci/run-buildbot: line 195: cmake: command not found
🚨 Error: The command exited with status 127
user command error: exit status 127

Could this be caused by your changes?

I doubt that's related - that error happens before execution even reaches any part of the lit scripts. I would bring this up with @goncharov - it seems like the base image on the runners has been updated to one that doesn't have cmake available (or in $PATH).

I doubt that's related

Agreed. Thanks.

I see some feedback on Windows build issues and some followups. Yesterday libc++'s precommit CI for Windows started to fail, the first build is https://buildkite.com/llvm-project/libcxx-ci/builds/29307

This is the relevant part of the log

+ cmake --version
libcxx/utils/ci/run-buildbot: line 195: cmake: command not found
🚨 Error: The command exited with status 127
user command error: exit status 127

Could this be caused by your changes?

I doubt that's related - that error happens before execution even reaches any part of the lit scripts. I would bring this up with @goncharov - it seems like the base image on the runners has been updated to one that doesn't have cmake available (or in $PATH).

Was not certain, but since it was just after the patch landed and there were followups for Windows and I didn't look at all of them. I'll ask @goncharov.

jdenny updated this revision to Diff 556793.EditedSep 14 2023, 9:42 AM

Rebased onto the most recent version of D154984.

Due to the changes from the current patch, updated expected results in a few lit tests brought in by the above rebase.

Adjusted lit's -v docs not to talk about no-op commands like : because this patch changes lit's internal shell not to use that. PR #65267 (edit: that's now PR #66408) proposes to change support for external sh-like shells similarly.

Folded in all fixup commits that I landed when trying to land this patch the first time. They were all tweaks in lit's test suite for portability to windows:

Applied python formatting suggestions from darker.

I don't think this patch requires another review before I land it, but of course reviewers are welcome to comment. I will wait to re-land it along with PR #65267 (edit: that's now PR #66408), which still requires more work and review.