Slow framework unit test failure (~5s)

Question

Created Oct ’21

Replies 9

Boosts 7

Views 3.4k

Participants 9

Starting from Xcode 12.4 (I think), failing unit tests in framework targets take about 5 seconds to complete. Successful tests complete almost instantly (as expected).

For example, the following test:

    func testExampleFailure() {
        XCTFail()
    }

Takes 4.356 seconds to execute on my 2019 MacBook Pro:

Test Case '-[FrameworkTests.FrameworkTests testExampleFailure]' failed (4.356 seconds).

This seems to only affect unit tests in Framework targets (unit tests for App targets are unaffected). I have also tested this in fresh Framework template projects across multiple Macs, so it appears to be an Xcode bug.

I'd hoped Xcode 13 would fix this issue, but it persists for me on Monterey. Perhaps someone could suggest a workaround?

Boost

Answer 1

mallman OP

Jan ’22

I'm seeing the same behavior. It's a big hit to productivity, and of course it discourages running the test suite. Have you had any luck figuring this out?

0

Answer 2

DTS Engineer OP

Apple

Jan ’22

It’s possible that this is the test infrastructure capturing log info, as discussed in this thread.

Share and Enjoy
—
Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

0

Answer 3

applezac OP

Apr ’22

No luck - it still occurs in Version 13.3.1. I reported this to Apple last October (FB9726940).

It also appears to affect Swift Package targets, and even occurs in Xcode Cloud test failures.

The one interesting thing is that it only occurs if you set My Mac or My Mac Catalyst as the run destintation (which is obviously the default for a framework that only imports Foundation). If you choose an iOS simulator, the problem is resolved.

Clearing the system log as discussed in the thread Quinn “The Eskimo!” linked to has no effect on the problem.

0

Answer 4

mh175 OP

Jul ’22

Exact same issue - Swift Package with Mac as run destination takes ~5s complete a failing test with only a single XCTFail() statement in the whole test. Switching to iOS fixes the issue.

0

Answer 5

applezac OP

Aug ’22

For any Apple engineers tracking this issue, it is still present on Ventura 13.0 Beta (22A5321d) and Xcode 14 (Version 14.0 beta 5 14A5294e).

1

Answer 6

pi80223 OP

Aug ’22

Hmm... I just found out that I can set the "Build Configuration" to "Release" in the "Test" action and the pause is disappearing. Might be some default option which is set in the "Debug" configuration? Sorry... it seems that if you simply fiddle around enough, Xcode is somehow caching stuff... at least it is definitely not consistent in speed.

Whenever I modify the tests (e.g. add an XCTFail in a different place) it takes again 5s to show up.

0

Answer 7

Apple Designer OP

Apple

Sep ’22

You can stop XCTest from collecting test diagnostics when it encounters a failure or error in 1 of 2 ways:

From within the test plan. You can set the Collect test diagnostics on failure setting to Never
Or from the Command-line, with the flag -collect-test-diagnostics never

The command line setting overrides the test plan setting, so opposing values have a deterministic behavior. For example, if you set the test plan to Always but the commandline to Never, then test diagnostics are not collected.

1

Answer 8

crumbs OP

Oct ’22

Doesn't help in my case either. Also I'd prefer to not create test plans for each package, as I have quite a lot of packages. It would be nice if it would be performant out of the box.

On the upside, on my M1 Macbook Pro the delay is only 2 secs. But it's still very noticeable and gets in the way of quick change/test cycles.

Edit: This was meant as a comment to the proposed solution.

0

Answer 9

crumbs OP

Oct ’22

This is a call graph from a slow test run:

    +       ! 442 XCTAssertEqual<A>(_:_:_:file:line:)  (in libXCTestSwiftSupport.dylib) + 96  [0x101727e30]
    +       !   442 XCTAssertEqual<A>(_:_:_:file:line:)  (in libXCTestSwiftSupport.dylib) + 1308  [0x10172b5ac]
    +       !     442 _XCTPreformattedFailureHandler  (in XCTestCore) + 148  [0x10092018c]
    +       !       442 _XCTFailureHandler  (in XCTestCore) + 1276  [0x10091ffa4]
    +       !         442 -[XCTestCase(XCTIssueHandling) handleIssue:]  (in XCTestCore) + 224  [0x10090d440]
    +       !           442 -[XCTestCase _enqueuePrimaryThreadBlock:]  (in XCTestCore) + 148  [0x100946744]
    +       !             442 -[XCTestCase _dequeuePrimaryThreadWork]  (in XCTestCore) + 340  [0x1009443fc]
    +       !               442 __44-[XCTestCase(XCTIssueHandling) handleIssue:]_block_invoke  (in XCTestCore) + 24  [0x10090d478]
    +       !                 442 -[XCTestCase recordIssue:]  (in XCTestCore) + 948  [0x100943140]
    +       !                   442 -[XCTestCase(XCTDeprecated) recordFailureWithDescription:inFile:atLine:expected:]  (in XCTestCore) + 256  [0x10094e3cc]
    +       !                     442 -[XCTestCase(XCTIssueHandling) _recordIssue:]  (in XCTestCore) + 212  [0x10090d9a0]
    +       !                       442 -[XCTestCase(XCTIssueHandling) _enqueueIssue:]  (in XCTestCore) + 172  [0x10090da7c]
    +       !                         442 -[XCTestCase _dequeuePrimaryThreadWork]  (in XCTestCore) + 124  [0x100944324]
    +       !                           442 -[XCTestCase(XCTIssueHandling) _dequeueIssues]  (in XCTestCore) + 328  [0x10090dc7c]
    +       !                             442 -[XCTestCase(XCTIssueHandling) _handleIssue:]  (in XCTestCore) + 520  [0x10090df2c]
    +       !                               442 -[XCTSourceCodeFrame symbolInfoWithError:]  (in XCTestCore) + 148  [0x100911538]
    +       !                                 442 -[XCTInProcessSymbolicationService symbolInfoForAddressInCurrentProcess:error:]  (in XCTestCore) + 588  [0x100901378]
    +       !                                   434 +[XCTSymbolicationService _symbolInfoForAddress:symbolOwner:symbolicationFunctions:allowedImageNames:error:]  (in XCTestCore) + 244  [0x100900944]
    +       !                                   | 434 CSSymbolOwnerGetSymbolWithAddress  (in CoreSymbolicationDT) + 52  [0x100701fc4]
    +       !                                   |   434 CSCppSymbolOwner::_fault_data_purging_empty(bool)  (in CoreSymbolicationDT) + 48  [0x100720394]
    +       !                                   |     434 CSCppSymbolOwnerCache::data_for_symbol_owner(CSCppSymbolOwner*, bool)  (in CoreSymbolicationDT) + 312  [0x100721c54]
    +       !                                   |       434 CSCppSymbolOwnerCache::create_symbol_owner_data(CSCppSymbolOwner*, CSCppDsymData*)  (in CoreSymbolicationDT) + 428  [0x100721450]
    +       !                                   |         434 create_symbol_owner_data2(CSCppSymbolOwner*, CSCppDsymData*)  (in CoreSymbolicationDT) + 204  [0x10072187c]
    +       !                                   |           434 CSCppSymbolOwnerData* create_symbol_owner_data_arch_specific<SizeAndEndianness<Pointer64, LittleEndian> >(CSCppSymbolOwner*, CSCppDsymData*)  (in CoreSymbolicationDT) + 444  [0x1007316e8]
    +       !                                   |             434 dsym_data_for_symbol_owner(CSCppSymbolOwner const*, void const*, void const*, void const*, void const*)  (in CoreSymbolicationDT) + 360  [0x1006f91ec]
    +       !                                   |               434 DBGCopyFullDSYMURLForUUIDWithOptions  (in DebugSymbolsDT) + 80  [0x10040bef8]
    +       !                                   |                 434 CopyDSYMURLForUUIDWithOptions(__CFUUID const*, void const*, void const*, void const*, void const*)  (in DebugSymbolsDT) + 1024  [0x10040bad4]
    +       !                                   |                   434 WaitForSpotlightQueryToReachState(SpotlightQueryState, int, __CFArray const*)  (in DebugSymbolsDT) + 272  [0x10040a454]
    +       !                                   |                     434 _pthread_cond_wait  (in libsystem_pthread.dylib) + 1236  [0x1a3a0883c]
    +       !                                   |                       434 __psynch_cvwait  (in libsystem_kernel.dylib) + 8  [0x1a39ce270]

0