search

KnapsackPro / knapsack_pro-ruby

Knapsack Pro gem splits tests across parallel CI nodes and makes sure that tests run in optimal time
https://knapsackpro.com
MIT License
132 stars 27 forks source link

Queue mode causes rspec_junit_formatter to produce invalid XML when a node runs a spec with all examples commented out. #175

Closed cccCody closed 8 months ago

cccCody commented 2 years ago

This looks similar to https://github.com/KnapsackPro/knapsack_pro-ruby/issues/40, but we have applied the fix from that thread, and this persists. We've also previously had a similar issue that I filed as https://github.com/KnapsackPro/knapsack_pro-ruby/issues/171 that turned out to be caused by specs calling Kernel#exit, but we've since cleaned those up, and are still seeing JUnit XML issues with a new pattern.

This time, we see invalid XML generated when reporting on specs that run in queue mode immediately after another spec that has been entirely commented out. It doesn't always happen, but it has killed 5 builds for us this week. In the example I'm including here, it first runs spec/features/posts/rsvp_spec.rb, which has been temporarily commented out:

D, [2022-08-31T19:55:30.478298 #24812] DEBUG -- : [knapsack_pro] {"queue_name"=>"2796:8c3e59cb04b0ae2e857330d792c31576", "build_subset_id"=>nil, "test_files"=>[{"path"=>"spec/features/posts/rsvp_spec.rb", "time_execution"=>0.0}]}
I, [2022-08-31T19:55:30.478651 #24812]  INFO -- : [knapsack_pro] To retry the last batch of tests fetched from the API Queue, please run the following command on your machine. (If you use the `-- order random` option, remember to add correct `--seed 123` that you can find at the end of the RSpec output.)
I, [2022-08-31T19:55:30.478688 #24812]  INFO -- : [knapsack_pro] bundle exec rspec --format documentation --format RspecJunitFormatter --out tmp/junit/rspec.xml --failure-exit-code 0  --default-path spec "spec/features/posts/rsvp_spec.rb"
No examples found.

...then asks for more tests from the queue, and gets assigned spec/features/phone_sized_spec.rb, which it runs:

D, [2022-08-31T19:55:30.713903 #24812] DEBUG -- : [knapsack_pro] {"queue_name"=>"2796:8c3e59cb04b0ae2e857330d792c31576", "build_subset_id"=>nil, "test_files"=>[{"path"=>"spec/features/phone_sized_spec.rb", "time_execution"=>3138.279317547999}]}
I, [2022-08-31T19:55:30.714145 #24812]  INFO -- : [knapsack_pro] To retry the last batch of tests fetched from the API Queue, please run the following command on your machine. (If you use the `-- order random` option, remember to add correct `--seed 123` that you can find at the end of the RSpec output.)
I, [2022-08-31T19:55:30.714180 #24812]  INFO -- : [knapsack_pro] bundle exec rspec --format documentation --format RspecJunitFormatter --out tmp/junit/rspec.xml --failure-exit-code 0  --default-path spec "spec/features/phone_sized_spec.rb"

...it asks for more tests and then finishes when there are none left:

D, [2022-08-31T20:50:49.743891 #24812] DEBUG -- : [knapsack_pro] {"queue_name"=>"2796:8c3e59cb04b0ae2e857330d792c31576", "build_subset_id"=>nil, "test_files"=>[]}
Knapsack Pro Queue finished!

...then when jenkins tries to parse the JUnit XML, it fails on:

Failed to read test report file /home/ubuntu/workspace/T-453_path-to-pro-styling-issues/tmp/junit/node_2-rspec_final_results.xml
org.dom4j.DocumentException: Error on line 117 of document  : Content is not allowed in trailing section.
    at org.dom4j.io.SAXReader.read(SAXReader.java:511)
    at org.dom4j.io.SAXReader.read(SAXReader.java:392)
    at hudson.tasks.junit.SuiteResult.parse(SuiteResult.java:177)
    at hudson.tasks.junit.TestResult.parse(TestResult.java:384)
    at hudson.tasks.junit.TestResult.parsePossiblyEmpty(TestResult.java:314)
    at hudson.tasks.junit.TestResult.parse(TestResult.java:256)
    at hudson.tasks.junit.TestResult.parse(TestResult.java:242)
    at hudson.tasks.junit.TestResult.parse(TestResult.java:220)
    at hudson.tasks.junit.TestResult.<init>(TestResult.java:174)
    at hudson.tasks.junit.JUnitParser$ParseResultCallable.invoke(JUnitParser.java:176)
    at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3502)
    at hudson.remoting.UserRequest.perform(UserRequest.java:212)
    at hudson.remoting.UserRequest.perform(UserRequest.java:54)
    at hudson.remoting.Request$2.run(Request.java:369)
    at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: org.xml.sax.SAXParseException; lineNumber: 117; columnNumber: 1; Content is not allowed in trailing section.
    at java.xml/com.sun.org.apache.xerces.internal.util.ErrorHandlerWrapper.createSAXParseException(ErrorHandlerWrapper.java:204)
...

Attachments:

Screen Shot 2022-09-01 at 1 33 20 PM

ArturT commented 2 years ago

That's an interesting observation.

It looks like an attempt to run commented out test file via RSpec::Core::Runner in knapsack_pro Queue Mode is causing the issue for https://github.com/sj26/rspec_junit_formatter gem to generate XML report.

I guess the rspec_junit_formatter gem does not play well with RSpec::Core::Runner when RSpec has not loaded any spec examples (the spec file is commented out so no test examples and that's the only spec file provided to RSpec::Core::Runner).

Maybe we should report this to rspec_junit_formatter maintainers or try to reproduce it on a smaller scale.

I used to prepare a small example of how to use RSpec::Core::Runner: https://github.com/ArturT/rspec-test-examples/blob/1a92e907ec8af5bd909ffee40a9d923ec968cc05/run_tests.rb#L9 You could try to load commented out spec file and add rspec_junit_formatter gem to see if you can reproduce the problem. If we manage to get that, we could ask for help from rspec_junit_formatter maintainers to troubleshoot the problem with generating XML report.

ArturT commented 1 year ago

@cccCody Would you be able to help reproduce this, or can we assume it's not relevant anymore, and we could close the issue?

cccCody commented 1 year ago

Sorry, I didn't see this until now, but this issue just popped up again for us. I'm happy to help you reproduce it. What would you need from us? It does seem like it could be an issue with rspec_junit_formatter

ArturT commented 1 year ago

Please make sure you use the latest version of the knapsack_pro gem. I'll try to look into it when I'm back from holidays. If this blocks you and you need help sooner please contact our support team via email.

ArturT commented 1 year ago

I'm happy to help you reproduce it. What would you need from us?

@cccCody Can you use this script https://github.com/ArturT/rspec-test-examples/blob/1a92e907ec8af5bd909ffee40a9d923ec968cc05/run_tests.rb#L9 and enable rspec_junit_formatter for it.

Please run your tests with it or prepare an example specs that show when the junit xml report is broken. We could use it to reproduce problem and maybe show it to rspec_junit_formatter maintainers. 

cli_args = ['spec/example_spec.rb[1:1]', 'spec/example2_spec.rb']
start_runner(cli_args)

cli_args = ['spec/commented_out_spec.rb'] # this most likely would cause issue to generate junit xml report
start_runner(cli_args)

cli_args = ['spec/example_spec.rb[1:2]', 'spec/example3_spec.rb']
start_runner(cli_args)
martin-nef commented 8 months ago

We're facing a similar issue with the latest version of knapsack_pro gem, running in queue mode. rspec_junit_formatter just stops outputting the results XML file without any errors.

We run it like so, with with KNAPSACK_PRO_FIXED_QUEUE_SPLIT=true env var set:

bundle exec rake "knapsack_pro:queue:rspec[--force-color --format RSpec::Ci::Prettify::Formatter --format RspecJunitFormatter --out /tmp/ci_artifacts/rspec_launchable_temp_${CI_NODE_INDEX}.xml]"

And we have the after_subset_hook set up, as per the guide:

      TMP_RSPEC_XML_REPORT =
        "/tmp/ci_artifacts/rspec_launchable_temp_#{ENV['CI_NODE_INDEX']}.xml".freeze
      # move results to FINAL_RSPEC_XML_REPORT so the results won't
      # accumulate with duplicated xml tags in TMP_RSPEC_XML_REPORT
      FINAL_RSPEC_XML_REPORT =
        "/tmp/ci_artifacts/rspec_launchable_#{ENV['CI_NODE_INDEX']}.xml".freeze

      KnapsackPro::Hooks::Queue.after_subset_queue do
        if File.exist?(TMP_RSPEC_XML_REPORT)
          FileUtils.mv(TMP_RSPEC_XML_REPORT, FINAL_RSPEC_XML_REPORT)
        end
      end

Rolling back to 4.1.0 seems to work (can't use any versions in between, due to the issue where the RAILS_ENV=test env var is set by knapsack, which breaks some of our tests)

ArturT commented 8 months ago

Thanks for reporting the issue. @martin-nef Did you upgrade the knapsack_pro gem from 4.1.0 to 6.0.4? Have you skipped 5.x?

Are you able to reproduce the issue on 6.0.4? Is it happening all the time or just randomly?

I tried to reproduce the issue with this integration tests, but I could not: https://github.com/KnapsackPro/knapsack_pro-ruby/commit/229869b41ac9825d9c057b7dc9ef359ffb4e573e

This integration test is part of a new big change we are working on for 7.0.0 release. I hope 7.0.0 will solve the issue, but I need help verifying that.

Could you create a feature branch in your project and test this PR: https://github.com/KnapsackPro/knapsack_pro-ruby/pull/237

# Gemfile
gem 'knapsack_pro', github: 'KnapsackPro/knapsack_pro-ruby', branch: 'refactor-queue-rspec-runner'

and follow migration https://github.com/KnapsackPro/knapsack_pro-ruby/blob/refactor-queue-rspec-runner/CHANGELOG.md#700 to get rid of the KnapsackPro::Hooks::Queue.after_subset_queue hook.

Is the issue gone?

(can't use any versions in between, due to the issue where the RAILS_ENV=test env var is set by knapsack, which breaks some of our tests)

RAILS_ENV=test is set here https://github.com/KnapsackPro/knapsack_pro-ruby/blob/c8baeee271cfed76408921b71ec2dd8bd596b795/lib/tasks/queue/rspec.rake#L8

You can use rspec_go rake task to skip that:

bundle exec rake knapsack_pro:queue:rspec_go
ArturT commented 8 months ago

We have released version 7.0.0 of the knapsack_pro gem. This version has many improvements in Queue Mode for RSpec.

It should solve issues with JUnit XML reports.

@martin-nef @cccCody Please update the knapsack_pro gem version.

Please find the migration steps at the following link: https://github.com/KnapsackPro/knapsack_pro-ruby/blob/master/CHANGELOG.md#700

Remove the following code if you use Queue Mode and the rspec_junit_formatter gem to generate JUnit XML or JSON reports:

# REMOVE THE FOLLOWING CODE

# spec_helper.rb or rails_helper.rb
TMP_REPORT = "tmp/rspec_#{ENV['KNAPSACK_PRO_CI_NODE_INDEX']}.xml"
FINAL_REPORT = "tmp/final_rspec_#{ENV['KNAPSACK_PRO_CI_NODE_INDEX']}.xml"

KnapsackPro::Hooks::Queue.after_subset_queue do |queue_id, subset_queue_id|
  if File.exist?(TMP_REPORT)
    FileUtils.mv(TMP_REPORT, FINAL_REPORT)
  end
end

Learn more about using Knapsack Pro with RSpec formatters and using Knapsack Pro with CircleCI in the docs.

Please re-open the issue if you still encounter any problems. Thank you.