Fastlane-plugin-test_center: test center massively duplicates tests by 32 times

[lilyball]

New Issue Checklist

• [ ] Updated fastlane-plugin-test_center to the latest version (I'm on 3.11.6)
• [X] I read the README.md
• [X] I reviewed the example(s) for the action(s) I am using
• [X] I have removed any sensitive data such as passwords, authentication tokens, or anything else I do not want to world to see

Issue Description

I've got an 87MB fastlane output log in my hands showing multi_scan being asked to test 96 test suites, and somehow coming up with 7287 tests for each of its 4 workers to run. The scan summary alone takes up almost 17MB just to print, because the only_testing line is 480246 characters long (and every line of the summary is padded to match the longest line).

I split apart worker 1's only_testing line and sorted it, and there's massive-but-inconsistent duplication in the tests. For example, each test in the AccountMenuUITests suite is only included once, but each test in the ActionCheermotesUITestCollectionsTests suite is included 46 times. It turns out there's only 224 unique tests in here, so the tests were duplicated an average of 32.5 times. I'm pretty sure every test in a given suite has the same amount of duplication.

I did check, each suite was only listed once on the input to multi_scan. And the order in which the suites were listed doesn't seem to correlate with how much duplication occurred.

This was discovered because each worker failed on its xcodebuild line with Argument list too long - fork failed. Not particularly surprising, I don't think even Big Sur with its increased argument length limit supports 556kB of arguments.

Complete output when running fastlane, including the stack trace and command used

There's no way I can possibly include that. It's 87MB. The list of duplicated test names alone is half a MB. If there's anything in particular I can extract from the log that would be helpful, let me know.

Here's the multi_scan summary at least:

+-------------------------+--------------------------------------------------+
|                Summary for multi_scan (test_center v3.11.6)                |
+-------------------------+--------------------------------------------------+
| quit_simulators         | true                                             |
| try_count               | 2                                                |
| batch_count             | 1                                                |
| parallel_testrun_count  | 4                                                |
| testrun_completed_block | #<Proc:0x00007f90a8c4e650@Fastfile:405 (lambda)> |
+-------------------------+--------------------------------------------------+

Environment

I can't include the full environment (nor can I easily run that from the CI machine that actually invoked fastlane) but the parameters passed to multi_scan were

{
    :buildlog_path=>"fastlane/logs/scan/",
    :derived_data_path=>"fastlane/DerivedData",
    :output_directory=>"/path/to/fastlane/test_output/TargetUI",
    :output_types=>"html,junit,xcresult",
    :scheme=>"TargetUITests",
    :xcargs=>"TW_RUN_CLANG_STATIC_ANALYZER=NO TW_TREAT_CLANG_STATIC_ANALYZER_WARNINGS_AS_ERRORS=NO COMPILER_INDEX_STORE_ENABLE=NO -sdk iphonesimulator",
    :fail_build=>false,
    :include_simulator_logs=>true,
    :quit_simulators=>true,
    :try_count=>2,
    :batch_count=>1,
    :parallel_testrun_count=>4,
    :testrun_completed_block=>#<Proc:0x00007f90a8c4e650@Fastfile:405 (lambda)>,
    :only_testing=>[
        # 96 unique test suites
    ],
    :device=>"iPhone 8"
}

[lyndsey-ferguson]

I wrote a bunch of my thoughts that are invalid (and I deleted) as I read more and more of your report.

You have 224 unique tests. 96 testsuites.

Somehow, many of the tests are being duplicated.

[lyndsey-ferguson]

Some questions (and please cause this to fail right away with fail_build: true):

1. If you remove the :parallel_testrun_count option, does the duplication occur?
2. Does this duplication happen on the first run for each worker? (perhaps there is something happening when trying to figure out which tests to run next)

If that doesn't give me any clues, I'm at a loss right now to figure out what to do next. Maybe create a sample project that models yours and see what happens 🤷 . Perhaps if I let my subconscious chew on it over night I'll come up with ideas: that's usually what happens.

[lyndsey-ferguson]

Even though I didn't understand your finding at first, some of my early thoughts are something to worry about; if someone does have 24,000 tests, and each worker does try to run 6000 tests each, this thing will fall apart.

[lilyball]

Looking at the ordering of the duplicated tests, I think the tests were duplicated at the test suite level, and most of the time all the duplications occur in one block (e.g. all tests for a given suite are listed, then the sequence repeats N times). And the suites are all traversed in alphabetical order. But in the case where one test suite is a subclass of another, the subclass suite can be repeated later at the point where the superclass is listed.

For example, I have a suite FooSuite, and a subclass of that suite AltFooSuite. The subclass redeclares both tests from the superclass (but with different local configuration; in this case the subclass is running the tests with an experiment flag flipped). And the subclass is alphabetically first, so it shows up by itself, with one repeat:

AltFooSuite/testFooBar
AltFooSuite/testFoo
AltFooSuite/testFooBar
AltFooSuite/testFoo

over 3800 lines later, the superclass suite shows up, repeated ~40 times. And each time it's listed, the subclass suite is listed too:

FooSuite/testFooBar
FooSuite/testFoo
AltFooSuite/testFooBar
AltFooSuite/testFoo
FooSuite/testFooBar
FooSuite/testFoo
AltFooSuite/testFooBar
AltFooSuite/testFoo
… repeating another ~40 times

I've found this pattern with another superclass/subclass pair, though in this the superclass is alphabetically first, the subclass occurs after the superclass on each repeat, and the subclass doesn't get its own block elsewhere, quite possibly because the subclass isn't supposed to be in this batch at all (this batch apparently only includes suites A-E, the subclass is later in the alphabet).

However, even if superclass/superclass pairs were a problem, that doesn't explain the massive duplication of everything else.

I'm also not sure why this occurred now.

[lilyball]

Another quirk: The PR that this job was associated with introduced yet another subclass/superclass pair (actually two but only one is remarkable). This time the subclass doesn't redeclare any superclass tests at all (it's just using some other stuff from the superclass), and the subclass's name is not suffixed by the superclass's name like the other pairs were. In fact, the subclass's name is suffixed by an unrelated test class (the name in this case is based on the feature flag). And in the test case list, it's grouped with that unrelated class.

By this I mean the PR introduces the following:

class DiscoverUITests: XCTestCase {} // this actually already existed, just here for context
class DiscoverVerticalUITests: DiscoverUITests {} // this breaks the naming seen with other pairs

class FeedbackUITests: XCTestCase {} // again this one already existed
class FeedbackDiscoverVerticalUITests: FeedbackUITests {} // note how the suffix is the unrelated class

and FeedbackDiscoverVerticalUITests is also the class that does not redeclare its superclass tests but rather declares a brand new one.

And in the test list I see

DiscoverUITests/testOne
DiscoverUITests/testTwo
DiscoverUITests/testThree
DiscoverUITests/testOne
DiscoverUITests/testTwo
DiscoverUITests/testThree
… suite is repeated N times
DiscoverVerticalUITests/testOne
DiscoverVerticalUITests/testTwo
DiscoverVerticalUITests/testThree
FeedbackDiscoverVerticalUITests/testFoo
DiscoverVerticalUITests/testOne
DiscoverVerticalUITests/testTwo
DiscoverVerticalUITests/testThree
FeedbackDiscoverVerticalUITests/testFoo
… suites are repeated N times

So it looks like the grouping here and inclusion of subclasses is actually related to the _naming_ of the classes rather than the actual class hierarchy.

[lilyball]

I’m done working for the day but I’ll look into your request for testing again with modified parameters tomorrow.

[lyndsey-ferguson]

@lilyball hold off on my request. I'm putting together a test for your case as I have a suspicion that the TestCenter::Helper::TestCollector#expand_testsuites_to_tests is working incorrectly based off of the notes that you provided above.

[lilyball]

@testables_tests[testable][index] = known_tests.select { |known_test| known_test.include?(testsuite) }

Assuming that known_test is a String (which I think it is) that would certainly explain why BarSuite is pulling in FooBarSuite's tests too.

known_tests += xctestrun_known_tests[testable]

If the list of testables includes duplicates this will duplicate the tests too, though I believe testable in this case is the suite name and we're not passing in any duplicated suite names.

Also since xctestrun_known_tests is a method, I have a suspicion this is re-parsing all known tests anew for every suite, which seems very wasteful.

[lyndsey-ferguson]

Yes exactly. As it has been a while since I looked at this code, I don't remember how it works. So, I'm writing up comments, asking questions to myself, and answering the questions to make sure I understand everything before making changes.

[lyndsey-ferguson]

testable is the xcodeproj name for the test target. So, if your test target was "AllMyTests" and it built "AllMyTests.xctest", it would be the first part of a test identifier. The testsuite is the second part. "AllMyTests/FrenchdoorUITests". The last part of the identifier would be the individual testcases "AllMyTests/FrenchdoorUITests/testThatDoorClosesWithoutSqueaking".

[lyndsey-ferguson]

What I'm wondering is why is there +=. If the code is supposed to grab the tests from a testable, why can I not just grab the matching tests in known_tests that have the same testsuite?

[lyndsey-ferguson]

@lilyball can you modify your Pluginfile per my instructions below, run bundle install, and then run your fastlane again (with the --verbose flag)?

Pluginfile:

gem 'fastlane-plugin-test_center', :git => "https://github.com/lyndsey-ferguson/fastlane-plugin-test_center.git", :branch => "issue-268-massive-duplication-of-tests"

If there are still problems, please let me know and attach the console output as a text file to this issue (makes it easier for me to review). If it works, please let me know.

[lyndsey-ferguson]

I just realized that there is a problem with the code if a test identifier of the format testsuite/testcase is provided. Should not affect you though.

[lyndsey-ferguson]

Ok, I fixed it.

[lilyball]

I'll test the fix today and let you know.

[lilyball]

I'm finally testing it now, sorry for the delay. It's actually building, which is very encouraging, but it did print out the Getting tests from xctestrun file at … and Found the following tests: … logs 98 times, which I guess means once for every suite (since I passed 98 suites to it), though each time it found the same set of tests. And it printed out 482 tests, with no duplicates, so that's encouraging.

[lyndsey-ferguson]

Ok, so it works, but it is wastefully getting tests multiple times from the xctestrun file. It could be accessing it outside of the method I changed. I can update that particular function to get the tests once for each xctestrun file.

[lyndsey-ferguson]

Thank you @lilyball, I appreciate your collaboration on this.

[lilyball]

The fastlane job finished executing; 2 tests failed, but that's not the fault of the plugin (heck, flaky tests are a big reason why we're using your plugin in the first place). Worker 1 was only passed 114 tests, which is definitely a lot better than the 7287 tests previously.

It looks like the fix works, except for the duplication of parsing the xctestrun file.

[lyndsey-ferguson]

Would you mind trying again to confirm my fix which will prevent the same xctestrun file from being read multiple times? The commit SHA in your Gemfile.lock should be b57ab9cbfc9695b48927a19c03e47b91691e5c0b

[lilyball]

It's still building but from the output I can see it only parsed the xctestrun file once instead of 98 times, and it produced the same list of 482 tests.

[lyndsey-ferguson]

Fixed in v3.13.2