Nimble: Observation Delay Causes Issues

[ashfurrow]

In #271, @paweldudek fixed a problem where registering a test observer too early causes the XCTest internal setup to perform incorrectly. This solution works, but has introduced a problem when updating Quick's Nimble version. It seems like the slight delay introduced using dispatch_async causes the Quick test for the number of ObjC tests performed to fail.

Kif had a similar issue, check out the Quick PR for more discussion on background + possible solutions. @phatblat has a theory.

[phatblat]

I don't really know anything, I just have theories.

I did a bit of swizzling to get a better sense of the observers in play relating to #271 and found the following:

• XCTestLog
• _TtC6Nimble22CurrentTestCaseTracker (aka Nimble.CurrentTestCaseTracker)
• _XCTestDriverTestObserver

XCTestLog

This one is responsible for writing test output to stdout. If it doesn't get added as an observer, there is almost no output.

It is the first observer added to the XCTestObservationCenter.observers array. While debugging in Xcode, I found it's actually added through the _addLegacyTestObserver: private method (swizzled version in the stack trace below) in response to CurrentTestCaseTracker calling sharedTestObservationCenter before adding itself as an observer.

I'm confused how #271 was a timing issue as XCTestLog is always added first, but things could be different when Quick and Nimble are invoked from the command line vs from the Xcode GUI with debugger attached.

Quick Test Failure

The failing test in Quick/Quick#507 is testFailureSpecFailureCountIsEqualToTheNumberOfFailingExamples. It is expecting 2 failures, but none are reported.

/Users/distiller/Quick/Sources/QuickTests/FunctionalTests/FailureTests+ObjC.m:58: ((result.failureCount) equal to (2)) failed: ("0") is not equal to ("2"):

55 
56 - (void)testFailureSpecFailureCountIsEqualToTheNumberOfFailingExamples {
57     XCTestRun *result = qck_runSpec([FunctionalTests_FailureSpec_ObjC class]);
58     XCTAssertEqual(result.failureCount, 2);
       ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
59 }
60 

The swift side of CurrentTestCaseTracker is responsible for recording these failures using the currentTestCase tracked through the XCTestObservation calls to testCaseWillStart and testCaseDidFinish. What's interesting about testFailureSpecFailureCountIsEqualToTheNumberOfFailingExamples is that it is run quite differently than the other Quick tests, a new XCTestSuite is constructed and run explicitly.

Theory

Somehow I think CurrentTestCaseTracker isn't getting hooked in correctly in some cases when the tests are invoked from xctool. Running Quick's tests through xcodebuild on the command line works fine as well as through the GUI.

[phatblat]

I think I have this backwards. Maybe the root cause is the same as #271 - no output.

If I prevent XCTestLog from registering as an observer, there's almost no output, but the Xcode GUI still reports that all the tests pass. I suspect that's because it's using _XCTestDriverTestObserver to monitor the tests. Blocking only _XCTestDriverTestObserver I see test progress in the console, but Xcode reports that the tests failed with the following error.

Test target Quick-OSXTests encountered an error (Early unexpected exit, operation never finished bootstrapping - no restart will be attempted)

If xcodebuild is also using this _XCTestDriverTestObserver to determine success vs. failure, then the real difference is the output, which xctool depends on.

• :white_check_mark: Xcode GUI
• :white_check_mark: xcodebuild
• :no_entry_sign: xctool

So, perhaps the XCTestLog is the culprit and it's somehow getting fouled up due to this separate test suite.

I'll do some experiments to see if there are other hooks we can use to get CurrentTestCaseTracker wired up without borking XCTestLog.

[phatblat]

OK, this is ugly, but it works. Moving the CurrentTestCaseTracker observer registration from +load into my swizzled _addLegacyTestObserver: method, but after XCTestLog registers, appears to do the trick. All the Quick tests pass when invoked from xctool.

I don't really know what I'm doing and don't like the idea of swizzling since it's so fragile. Does anyone know of any other XCTest framework hooks that we can move this CurrentTestCaseTracker observer registration to?

[jeffh]

@briancroom: Would all this be resolved if we just removed CurrentTestCaseTracker and converted all file references from String to StaticString?

[phatblat]

@jeffh I tried that first, but the @objc(untilFile:line:action:) method can't be exported to Objective-C with StaticString in the signature. Is there any way to bridge from a String to StaticString?

[jeffh]

Ah I see, sadly I don't think so. There's not an explicit separation in C. :frowning:

[briancroom]

Yeah.. unfortunately the CurrentTestCaseTracker was the least-bad workaround that I could produce for the StaticString issue, since we have to stick with String on Apple platforms to maintain Objective-C support. Some context is here. (It's worth noting, though, that StaticString may not be around forever. See Joe Groff's comment)

This morning @idoru and I spent some time thinking about approaches to this issue for Cedar which was experiencing the exact same issue. The best solution we came up with is effectively the same thing that @phatblat is proposing here, with the slight adjustment that we swizzled both -_addLegacyTestObserver: and the normal -addTestObserver: in hopes of reducing the chance of breakage with future Xcode versions. It's not a very satisfying solution, but it seems to do the job.

Regarding additional XCTest framework hooks, it is possible for spec bundles to use the NSPrincipalClass key in their Info.plist to specify a class which will be instantiated before tests begin to execute. This is an officially supported hook for adding test observers. This isn't a great solution though either because it requires users of Nimble to perform additional setup steps before the framework can be used.

[phatblat]

I vote for safety-checked swizzling over requiring users to register a NSPrincipalClass.

[ashfurrow]

Sounds like this was fixed in #278, are we okay to close?

[phatblat]

Yep

[ashfurrow]

Fab!