Slow framework unit test failure (~5s)

Question

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?

2.9k

Posted by

Lemontine

Reply

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?

—
mallman
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.

—
applezac
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.

—
mh175

Answer 1

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"

Posted by

eskimo

Add a Comment

Answer 2

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).

Posted by

applezac

What a pain... I wanted to give TDD another try and hit this VERY OLD issue. Its crazy that there are not more people complaining about it. Nobody is really doing TDD 😉

—
pi80223

Add a Comment

Answer 3

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.

Posted by

Developer Tools Engineer

It does not help on my macOS framework project. The delay persists! TDD becomes inefficient like this. It seems as if the diagnostic are still collected but not bundled.

—
pi80223
This did not solve the issue for me either.

—
Lemontine
Confusing. 1) no help docs from xcodebuild. 2)

xcodebuild test -project MyProject.xcodeproj -scheme ConfigTests -destination platform='iOS Simulator,name=iPhone 14,OS=16.1' -collect-test-diagnostics never

xcodebuild: error: option -collect-test-diagnostics requires one of two values: on-failure or never

xcodebuild test -project MyProject.xcodeproj -scheme ConfigTests -destination platform='iOS Simulator,name=iPhone 14,OS=16.1' -collect-test-diagnostics never Xcode14.1Workaround=YES

—
benblechman

Add a Comment

Answer 4

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.

Posted by

crumbs

Add a Comment

Answer 5

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]

Posted by

crumbs

Add a Comment

Slow framework unit test failure (~5s)

Replies