Simulate output for CI after the first parallel thread finishes

[calaway]

I'm having a problem when running parallel tests with the --serialize-stdout flag, where our CI times out due to receiving no stdout after the first parallel thread finishes, but before other threads are finished.

The simulate_output_for_ci method (from issue #512) fixes this issue up to the point when the first parallel thread finishes by printing a dot (.) to stdout every 60 seconds, but does not continue printing output after the first parallel thread finishes. I am proposing the dots should continue being printed to stdout until all parallel threads are finished.

An example of when this problem might occur. My CI times out after 5 minutes without output. I run parallel_rspec -n 2 spec and unfortunately get two very uneven groups of tests. The first group finishes in 6 minutes and does not time out because a dot is printed to stdout every 60 seconds up to that point. The second group takes 12 minutes total, but the CI times out 5 minutes after the first group finished due to no output in that time.

Unfortunately, I don't know how to write the code to make this happen, but in TDD fashion I believe I have written a failing test to illustrate the problem (more specifically, I have modified an existing test). This test can be used to develop the solution. As soon as it is passing the feature will be complete.

I would be happy to help write the code for this feature if it helps, but I would need some assistance getting started.

Thank you for all you do on this project. I really appreciate your time.

[calaway]

Here is the output for the failing test I wrote for this issue. Note the lack of simulated output after TEST1 but before TEST2.

$ rspec ./spec/integration_spec.rb:141
Run options: include {:focus=>true, :locations=>{"./spec/integration_spec.rb"=>[141]}}

Randomized with seed 21986
F

Failures:

  1) CLI can show simulated output when serializing stdout
     Failure/Error: expect(result).to match(/\.{5}.*TEST1.*\.{5}TEST2/m)

       expected "2 processes for 2 specs, ~ 1 specs per process\n.......\nTEST1\n.\n\nFinished in 1 second (files too...took 0.0963 seconds to load)\n1 example, 0 failures\n\n\n2 examples, 0 failures\n\nTook 2 seconds\n" to match /\.{5}.*TEST1.*\.{5}TEST2/m
       Diff:
       @@ -1,2 +1,19 @@
       -/\.{5}.*TEST1.*\.{5}TEST2/m
       +2 processes for 2 specs, ~ 1 specs per process
       +.......
       +TEST1
       +.
       +
       +Finished in 1 second (files took 0.0959 seconds to load)
       +1 example, 0 failures
       +
       +TEST2
       +.
       +
       +Finished in 2 seconds (files took 0.0963 seconds to load)
       +1 example, 0 failures
       +
       +
       +2 examples, 0 failures
       +
       +Took 2 seconds

     # ./spec/integration_spec.rb:146:in `block (2 levels) in <top (required)>'
     # ./spec/spec_helper.rb:194:in `block (2 levels) in <top (required)>'

Finished in 2.87 seconds (files took 0.11174 seconds to load)
1 example, 1 failure

Failed examples:

rspec ./spec/integration_spec.rb:141 # CLI can show simulated output when serializing stdout

[grosser]

sounds good! :)

... possibly stupid/simple fix would be to just run while true; do echo '.'; sleep 1; done &

[calaway]

Executing a simple shell script like that could be a good idea. I'm wondering if we can accomplish it from within the ruby code though.

Looking at the code a bit more I think this is the point where it's killing the simulate_output_for_ci. Is it possible that it's just killing that process a few lines too early? What would happen if we move that block after the map block ends?

[grosser]

yes, looks like it should get killed after the process is done

[grosser]

so after the .map finishes

[grosser]

maybe cleanest to do simulate_output_for_ci do ... to not add more if/else into the execute_in_parallel
method

make sure to check it's sane with 2+ parallel jobs where one stops early :)

[calaway]

This may be a naive approach, but I simply deleted the progress_indicator.exit command and it seems to have fixed the problem and seems to be working fine. It worked correctly when I tested it in my test suite, and all the tests are still passing. Is this a valid solution, or was that serving another purpose that I'm not aware of?

If it is good then I'd like to clean up and improve the test for it just a bit before merging it in.

[grosser]

I'd prefer to actually exit the indicator so it does not keep going forever if someone calls this from the ruby dsl and does not spill into test output

[calaway]

Good call.

I feel like I'm getting closer here. Now the progress indicator is being exited after the parallel processes. How does this look?

[calaway]

maybe cleanest to do simulate_output_for_ci do ... to not add more if/else into the execute_in_parallel method

If you can confirm that my current implementation looks good then I'll go ahead and refactor it to this suggestion.

I really appreciate your help with this.

[grosser]

looks good!

[calaway]

That refactor is ready now. If you like it then it should be good to go ahead and merge in. Please let me know if you have any suggestions or see any of my code that can be improved. I'll be happy to help.

[grosser]

2.27.1

[calaway]

I just updated my gem locally and it's working great!

Thank you for all your guidance on this. I really appreciate all you do in building and maintaining this gem. You have been great to work with.