Swift test output format

(Keith Smiley) #1

I noticed recently that when you use the --parallel flag with swift test, depending on the environment, specifically on some CI providers, you can end up with some pretty gnarly output:

 0% []
 0% []
 0% []
 0% []
 1% []
 1% []
 1% []
 1% []
 2% []
 2% []

I was hoping to be able to work around this by redirect stdout, or stderr, but then if you have test failures, both this progress output and the failures go to the same stream.

It seems like there are a few possible ways to fix this:

  1. Change progress and test failure output to go to different streams
  2. Introduce some sort of --quiet flag you can pass to swift test that would exclude this progress output, and for non-parallel tests, probably exclude everything but failures (like xcpretty)
  3. Try to fix the parallel test output logic to handle whatever configurations we're hitting here

I'd be happy to take a stab at the implementation but I wanted to gauge what people thought would be the right solution before working on it. Thoughts?

(Pierpaolo Frasa) #2

I remember briefly looking at the code for swift test because I thought that having some way of adding pluggable test formatters (like e.g. RSpec) would be helpful. I seem to remember that one problem was that swift test is basically just calling xctest which prints to stdout and/or stderr itself; this is basically just redirected (e.g. see here). So any fundamental output issue would probably have to be fixed in xctest.

(Ankit Aggarwal) #3

That is very weird. Do you know the reason for the broken output? It should be displaying the test name after the percentage.

I think what you're looking for is the single line progress bar. It is minimal and outputs only the failures:

╭─ankit@stardust.local ~/workspace/packages/Yams  ‹master*›
╰─➤  TERM=dumb swift test --parallel                                                                                                       1 ↵
0.. 10.. 20.. 30.. 40.. 50.. 60.. 70.. 80.. 90.. OK
Test Suite 'Selected tests' started at 2018-07-24 08:25:12.958
Test Suite 'YamsPackageTests.xctest' started at 2018-07-24 08:25:12.959
Test Suite 'EmitterTests' started at 2018-07-24 08:25:12.959
Test Case '-[YamsTests.EmitterTests testScalar]' started.
/Users/ankit/workspace/packages/Yams/Tests/YamsTests/EmitterTests.swift:31: error: -[YamsTests.EmitterTests testScalar] : failed - Dummy failure
Test Case '-[YamsTests.EmitterTests testScalar]' failed (0.165 seconds).
Test Suite 'EmitterTests' failed at 2018-07-24 08:25:13.123.
	 Executed 1 test, with 1 failure (0 unexpected) in 0.165 (0.165) seconds
Test Suite 'YamsPackageTests.xctest' failed at 2018-07-24 08:25:13.123.
	 Executed 1 test, with 1 failure (0 unexpected) in 0.165 (0.165) seconds
Test Suite 'Selected tests' failed at 2018-07-24 08:25:13.123.
	 Executed 1 test, with 1 failure (0 unexpected) in 0.165 (0.165) seconds

This progress bar is selected when then terminal is "dumb" but I think it'll be good if we also allowed user to pick the progress bar from the command line. I think it would also be awesome if SwiftPM emitted some sort of summary at the end, listing the tests which failed.

(Daniel Dunbar) #4

That type of thing can happen when the printed output is wrapping, so that the line erasure doesn't work properly.

(Ankit Aggarwal) #5

That is supposed to be a non-tty progress bar. It doesn't output any terminal control characters.

(Keith Smiley) #6

I'm not exactly sure when this happens, but I assume in this case they're capturing output from a reasonable terminal periodically. For what it's worth we have a similar problem (not with SwiftPM) with our internal jenkins instances as well with the awscli and some other tools. We opt to disable all progress indicators on CI for this reason.

(Keith Smiley) #7

At least for the parallel case, output is entirely controlled by SwiftPM (from here). It looks like we also have the ability to do the same for the normal XCTest mode if we wanted too (from here)

(Ankit Aggarwal) #8

FWIW, you can also simulate serial testing in parallel mode with num-workers = 1 to get these progress bars.

(Pierpaolo Frasa) #9

Well, the way I see it, swift test just prints test.output. But the output is set by the xctest process. Maybe I'm misunderstanding something, though.

(Unless you mean that it's swift test that actually does the printing - this is true, but it doesn't seem like it controls the specific output format.)

(Keith Smiley) #10

The progress bar is SwiftPM specific, and not coming from XCTest: https://github.com/apple/swift-package-manager/blob/353522ab8cc9ae36ca68581f6faf03f7848c6d9a/Sources/Commands/SwiftTestTool.swift#L594-L597

(Yonas Kolb) #11

Slightly off topic but somewhat relatedly, the output of swift test also does not get formatted by xcpretty, though I'm not sure why. (As in swift test | xcpretty).
Not sure if it's related.

(Ankit Aggarwal) #12

I filed a bug on xctest for providing parsable output: https://bugs.swift.org/browse/SR-8436

(Keith Smiley) #13

This case with xcpretty is actually because swiftpm outputs test output to stderr, not stdout. So you need to run swift test 2>&1 | xcpretty