XCTestExpectation Gotchas

By: Jeremy W. Sherman. Published: 19 Mar 2016. Categories: gotchas testing cocoa swift.

XCTestExpectation simplifies testing callback-style code, but some of its design choices make tests using it fragile unless they’re mitigated:

It explodes if everything works right but later than you expected.
It explodes if everything works right more than once.

This article presents two concrete mitigations:

Use weak references to ensure the expectation dies before it can cause you trouble.
Use a different promise API to do your waiting.

Contents:

A Quick Review
Example: We’ll Call You
- Kaboom: Missing the Window
- Kaboom: Calling Twice
What’s Wrong?
Avoiding These Assertions
Summary

A Quick Review

XCTestExpectation is the tool Apple’s unit testing framework XCTest provides for coping with asynchronous APIs.

It’s a promise/future with one purpose: to answer the question, “did it get filled in time?”

To use it, you ask the test case to create one or more:

let promise = expectationWithDescription("it'll happen, trust me")

wait a configurable amount of time for every outstanding expectation to get filled:

waitForExpectationsWithTimeout(maxWaitSeconds, handler: nil)

and log a test failure if time runs out before that happens:

Asynchronous wait failed: Exceeded timeout of 1 seconds, with unfulfilled expectations: “it’ll happen, trust me”.

It would have succeeded if it had been filled in time:

promise?.fulfill()

Example: We’ll Call You

You can’t use the XCTest framework from a Playground (rdar://problem/17839045), so you’ll need to throw this in a full-blown project:

Get the code from GitHub

class LateCallback: XCTestCase {
    let callBackDelay: NSTimeInterval = 2


    func testNotWaitingLongEnough() {
        let promiseToCallBack = expectationWithDescription("calls back")
        after(seconds: callBackDelay) { () -> Void in
            print("I knew you'd call!")
            promiseToCallBack.fulfill()
        }

        waitForExpectationsWithTimeout(callBackDelay / 2) { error in
            print("Aww, we timed out: \(error)")
        }
    }
}

Go ahead and run this. Everything works fine – for now:

Test Suite 'All tests' started at 2016-03-19 21:56:49.223
Test Suite 'Tests.xctest' started at 2016-03-19 21:56:49.225
Test Suite 'LateCallback' started at 2016-03-19 21:56:49.225
Test Case '-[Tests.LateCallback testNotWaitingLongEnough]' started.
Aww, we timed out: Optional(Error Domain=com.apple.XCTestErrorDomain Code=0 "The operation couldn’t be completed. (com.apple.XCTestErrorDomain error 0.)")
/Users/jeremy/Github/XCTestExpectationGotchas/Tests/LateCallback.swift:26: error: -[Tests.LateCallback testNotWaitingLongEnough] : Asynchronous wait failed: Exceeded timeout of 1 seconds, with unfulfilled expectations: "calls back".
Test Case '-[Tests.LateCallback testNotWaitingLongEnough]' failed (2.247 seconds).
Test Suite 'LateCallback' failed at 2016-03-19 21:56:51.473.
	 Executed 1 test, with 1 failure (0 unexpected) in 2.247 (2.248) seconds
Test Suite 'Tests.xctest' failed at 2016-03-19 21:56:51.474.
	 Executed 1 test, with 1 failure (0 unexpected) in 2.247 (2.249) seconds
Test Suite 'All tests' failed at 2016-03-19 21:56:51.474.
	 Executed 1 test, with 1 failure (0 unexpected) in 2.247 (2.251) seconds


Test session log:
	/var/folders/63/np5g0d5j54x1s0z12rf41wxm0000gp/T/com.apple.dt.XCTest-status/Session-2016-03-19_21:56:45-vfvzhb.log

Program ended with exit code: 1

Test suite kicks off, everything runs, the test fails due to a timeout while waiting for the expectation to be met, and the process exits. This is how XCTestExpectation is supposed to work.

Kaboom: Missing the Window

We only ran the one test, though. Let’s say you have more tests to run after this one.

We can fake this out by adding a new test method whose name sorts alphabetically after our testNotWaitingLongEnough test that runs the runloop for a bit before exiting.

Conveniently enough, XCTest happens to run tests in alphabetical order, so the test runner will run our first test, then run this second one, then exit.

Here’s our new test method:

    func testZzz() {
        print("Let's just wait a while…")
        let tillAfterCallBack = callBackDelay
        spin(forSeconds: tillAfterCallBack)
        print("Yawn, that was boring.")
    }

Let’s see what happens (or you can skip to the summary):

Test Suite 'All tests' started at 2016-03-19 22:19:31.796
Test Suite 'Tests.xctest' started at 2016-03-19 22:19:31.798
Test Suite 'LateCallback' started at 2016-03-19 22:19:31.798
Test Case '-[Tests.LateCallback testNotWaitingLongEnough]' started.
Aww, we timed out: Optional(Error Domain=com.apple.XCTestErrorDomain Code=0 "The operation couldn’t be completed. (com.apple.XCTestErrorDomain error 0.)")
/Users/jeremy/Github/XCTestExpectationGotchas/Tests/LateCallback.swift:16: error: -[Tests.LateCallback testNotWaitingLongEnough] : Asynchronous wait failed: Exceeded timeout of 1 seconds, with unfulfilled expectations: "calls back".
Test Case '-[Tests.LateCallback testNotWaitingLongEnough]' failed (2.202 seconds).
Test Case '-[Tests.LateCallback testZzz]' started.
Let's just wait a while…
2.0: finished waiting
I knew you'd call!
2016-03-19 22:19:34.001 xctest[92369:96447173] *** Assertion failure in -[XCTestExpectation fulfill], /Library/Caches/com.apple.xbs/Sources/XCTest/XCTest-9530/XCTestFramework/Classes/XCTestCase+AsynchronousTesting.m:451
2016-03-19 22:19:34.002 xctest[92369:96447173] *** Terminating app due to uncaught exception 'NSInternalInconsistencyException', reason: 'API violation - called -[XCTestExpectation fulfill] after the wait context has ended for calls back.'
*** First throw call stack:
(
	0   CoreFoundation                      0x00007fff897ec03c __exceptionPreprocess + 172
	1   libobjc.A.dylib                     0x00007fff8674276e objc_exception_throw + 43
	2   CoreFoundation                      0x00007fff897ebe1a +[NSException raise:format:arguments:] + 106
	3   Foundation                          0x00007fff8b98b99b -[NSAssertionHandler handleFailureInMethod:object:file:lineNumber:description:] + 195
	4   XCTest                              0x000000010006f149 -[XCTestExpectation fulfill] + 302
	5   Tests                               0x00000001006858ab _TFFC5Tests12LateCallback24testNotWaitingLongEnoughFS0_FT_T_U_FT_T_ + 203
	6   Tests                               0x0000000100685c4f _TFF5Tests5afterFT7secondsSd4callFT_T__T_U_FT_T_ + 367
	7   Tests                               0x0000000100685de7 _TTRXFo__dT__XFdCb__dT__ + 39
	8   libdispatch.dylib                   0x00007fff8301f700 _dispatch_call_block_and_release + 12
	9   libdispatch.dylib                   0x00007fff8301be73 _dispatch_client_callout + 8
	10  libdispatch.dylib                   0x00007fff8302d6a0 _dispatch_after_timer_callback + 77
	11  libdispatch.dylib                   0x00007fff8301be73 _dispatch_client_callout + 8
	12  libdispatch.dylib                   0x00007fff830284e6 _dispatch_source_latch_and_call + 721
	13  libdispatch.dylib                   0x00007fff8302093b _dispatch_source_invoke + 412
	14  libdispatch.dylib                   0x00007fff8302c5aa _dispatch_main_queue_callback_4CF + 416
	15  CoreFoundation                      0x00007fff8973f3f9 __CFRUNLOOP_IS_SERVICING_THE_MAIN_DISPATCH_QUEUE__ + 9
	16  CoreFoundation                      0x00007fff896fa68f __CFRunLoopRun + 2159
	17  CoreFoundation                      0x00007fff896f9bd8 CFRunLoopRunSpecific + 296
	18  Foundation                          0x00007fff8b953b29 -[NSRunLoop(NSRunLoop) runMode:beforeDate:] + 278
	19  Foundation                          0x00007fff8b971d9e -[NSRunLoop(NSRunLoop) runUntilDate:] + 108
	20  Tests                               0x0000000100685262 _TF5Tests4spinFT10forSecondsSd_T_ + 162
	21  Tests                               0x000000010068510f _TFC5Tests12LateCallback7testZzzfS0_FT_T_ + 207
	22  Tests                               0x00000001006852a2 _TToFC5Tests12LateCallback7testZzzfS0_FT_T_ + 34
	23  CoreFoundation                      0x00007fff896c37bc __invoking___ + 140
	24  CoreFoundation                      0x00007fff896c3612 -[NSInvocation invoke] + 290
	25  XCTest                              0x0000000100022598 __24-[XCTestCase invokeTest]_block_invoke_2 + 159
	26  XCTest                              0x000000010005602e -[XCTestContext performInScope:] + 184
	27  XCTest                              0x00000001000224e8 -[XCTestCase invokeTest] + 169
	28  XCTest                              0x0000000100022983 -[XCTestCase performTest:] + 443
	29  XCTest                              0x0000000100020654 -[XCTestSuite performTest:] + 377
	30  XCTest                              0x0000000100020654 -[XCTestSuite performTest:] + 377
	31  XCTest                              0x0000000100020654 -[XCTestSuite performTest:] + 377
	32  XCTest                              0x000000010000e892 __25-[XCTestDriver _runSuite]_block_invoke + 51
	33  XCTest                              0x0000000100033a1b -[XCTestObservationCenter _observeTestExecutionForBlock:] + 611
	34  XCTest                              0x000000010000e7db -[XCTestDriver _runSuite] + 408
	35  XCTest                              0x000000010000f38a -[XCTestDriver _checkForTestManager] + 696
	36  XCTest                              0x000000010005729f _XCTestMain + 628
	37  xctest                              0x0000000100001dca xctest + 7626
	38  libdyld.dylib                       0x00007fff8b25f5c9 start + 1
)
libc++abi.dylib: terminating with uncaught exception of type NSException
(lldb)

And now we’re sitting at the debugger. Oof, that smarts.

Take a look at what’s going on in that backtrace:

Our Zzz test is hanging out running the runloop.
The after(seconds:call:) finishes waiting and calls its callback.
The callback fulfills an expectation belonging to the (already finished, already failed) first test
This trips a “you’re holding it wrong” assertion in the test framework:

Terminating app due to uncaught exception ‘NSInternalInconsistencyException’, reason: ‘API violation - called -[XCTestExpectation fulfill] after the wait context has ended for calls back.’

You might run up against this in practice when writing integration tests against a live, but not always quick to respond, backend service.

Kaboom: Calling Twice

That’s not the only way things can go wrong.

What happens if our callback has at-least-once rather than exactly-once behavior, and happens to call back twice?

class DoubleCallback: XCTestCase {
    func testDoubleTheFulfillment() {
        let promiseToCallBack = expectationWithDescription("calls back")
        let callBackDelay: NSTimeInterval = 1

        twiceAfter(seconds: callBackDelay) {
            print("i hear you calling me")
            promiseToCallBack.fulfill()
        }

        let afterCallBack = 2 * callBackDelay
        waitForExpectationsWithTimeout(afterCallBack, handler: nil)
    }
}

This is what happens (or skip to the summary)

Test Suite 'Selected tests' started at 2016-03-19 22:38:09.451
Test Suite 'DoubleCallback' started at 2016-03-19 22:38:09.452
Test Case '-[Tests.DoubleCallback testDoubleTheFulfillment]' started.
1.0: finished waiting
now once
i hear you calling me
now twice
i hear you calling me
2016-03-19 22:38:10.567 xctest[93147:96490281] *** Assertion failure in -[XCTestExpectation fulfill], /Library/Caches/com.apple.xbs/Sources/XCTest/XCTest-9530/XCTestFramework/Classes/XCTestCase+AsynchronousTesting.m:450
2016-03-19 22:38:10.568 xctest[93147:96490281] *** Terminating app due to uncaught exception 'NSInternalInconsistencyException', reason: 'API violation - multiple calls made to -[XCTestExpectation fulfill] for calls back.'
*** First throw call stack:
(
	0   CoreFoundation                      0x00007fff897ec03c __exceptionPreprocess + 172
	1   libobjc.A.dylib                     0x00007fff8674276e objc_exception_throw + 43
	2   CoreFoundation                      0x00007fff897ebe1a +[NSException raise:format:arguments:] + 106
	3   Foundation                          0x00007fff8b98b99b -[NSAssertionHandler handleFailureInMethod:object:file:lineNumber:description:] + 195
	4   XCTest                              0x000000010006f0bb -[XCTestExpectation fulfill] + 160
	5   Tests                               0x0000000100795c6b _TFFC5Tests14DoubleCallback24testDoubleTheFulfillmentFS0_FT_T_U_FT_T_ + 203
	6   Tests                               0x0000000100795e05 _TFF5Tests10twiceAfterFT7secondsSd4callFT_T__T_U_FT_T_ + 389
	7   Tests                               0x0000000100794eff _TFF5Tests5afterFT7secondsSd4callFT_T__T_U_FT_T_ + 367
	8   Tests                               0x0000000100795097 _TTRXFo__dT__XFdCb__dT__ + 39
	9   libdispatch.dylib                   0x00007fff8301f700 _dispatch_call_block_and_release + 12
	10  libdispatch.dylib                   0x00007fff8301be73 _dispatch_client_callout + 8
	11  libdispatch.dylib                   0x00007fff8302d6a0 _dispatch_after_timer_callback + 77
	12  libdispatch.dylib                   0x00007fff8301be73 _dispatch_client_callout + 8
	13  libdispatch.dylib                   0x00007fff830284e6 _dispatch_source_latch_and_call + 721
	14  libdispatch.dylib                   0x00007fff8302093b _dispatch_source_invoke + 412
	15  libdispatch.dylib                   0x00007fff8302c5aa _dispatch_main_queue_callback_4CF + 416
	16  CoreFoundation                      0x00007fff8973f3f9 __CFRUNLOOP_IS_SERVICING_THE_MAIN_DISPATCH_QUEUE__ + 9
	17  CoreFoundation                      0x00007fff896fa68f __CFRunLoopRun + 2159
	18  CoreFoundation                      0x00007fff896f9bd8 CFRunLoopRunSpecific + 296
	19  Foundation                          0x00007fff8b953b29 -[NSRunLoop(NSRunLoop) runMode:beforeDate:] + 278
	20  XCTest                              0x000000010006e6e8 -[XCTestCase(AsynchronousTesting) waitForExpectationsWithTimeout:handler:] + 1083
	21  Tests                               0x00000001007954d6 _TFC5Tests14DoubleCallback24testDoubleTheFulfillmentfS0_FT_T_ + 614
	22  Tests                               0x0000000100795722 _TToFC5Tests14DoubleCallback24testDoubleTheFulfillmentfS0_FT_T_ + 34
	23  CoreFoundation                      0x00007fff896c37bc __invoking___ + 140
	24  CoreFoundation                      0x00007fff896c3612 -[NSInvocation invoke] + 290
	25  XCTest                              0x0000000100022598 __24-[XCTestCase invokeTest]_block_invoke_2 + 159
	26  XCTest                              0x000000010005602e -[XCTestContext performInScope:] + 184
	27  XCTest                              0x00000001000224e8 -[XCTestCase invokeTest] + 169
	28  XCTest                              0x0000000100022983 -[XCTestCase performTest:] + 443
	29  XCTest                              0x0000000100020654 -[XCTestSuite performTest:] + 377
	30  XCTest                              0x0000000100020654 -[XCTestSuite performTest:] + 377
	31  XCTest                              0x000000010000e892 __25-[XCTestDriver _runSuite]_block_invoke + 51
	32  XCTest                              0x0000000100033a1b -[XCTestObservationCenter _observeTestExecutionForBlock:] + 611
	33  XCTest                              0x000000010000e7db -[XCTestDriver _runSuite] + 408
	34  XCTest                              0x000000010000f38a -[XCTestDriver _checkForTestManager] + 696
	35  XCTest                              0x000000010005729f _XCTestMain + 628
	36  xctest                              0x0000000100001dca xctest + 7626
	37  libdyld.dylib                       0x00007fff8b25f5c9 start + 1
)
libc++abi.dylib: terminating with uncaught exception of type NSException
(lldb)

We trip yet another assertion in XCTest:

Terminating app due to uncaught exception ‘NSInternalInconsistencyException’, reason: ‘API violation - multiple calls made to -[XCTestExpectation fulfill] for calls back.’

This probably does indicate an actual error in the code calling the callback much of the time, but if it doesn’t, you’ll want to know about and be able to dodge this assertion, too.

What’s Wrong?

This double-callback scenario calls back twice in succession. But if there were a delay between the first and second call back, and the test runner happened to exit during that delay, you’d get a successful test run rather than crashing every time.

With a delay between callbacks, you’d only trip the assertion when other tests kept the test runner process running long enough.

This situation parallels that of the too-late callback: no problems till appear till something else runs out the clock.

This is tricky:

You won’t ever trip them when you’re banging away at whatever the latest test you’re working on is, because a test runner running just that async test will exit as soon as the wait-timer runs out, before the too-late/second callback can occur.
You might not even trip them when you run your whole test suite at first, because they might be the last test in the run or the tests that follow don’t run for long enough.

This is also obnoxious to run into: When an assertion trips, it bombs the entire test process. (Unwrapping an implicitly unwrapped optional to find a nil has the same effect.)

These assertions aren’t test failures that would allow testing to continue; instead, XCTest treats as programmer error:

Fulfilling a promise after its test has already finished
Filling an already-filled promise

To be fair, these cases are called out in the documentation for XCTestExpectation.fulfill():

Call -fulfill to mark an expectation as having been met. It’s an error to call -fulfill on an expectation that has already been fulfilled or when the test case that vended the expectation has already completed.

but the documentation isn’t explicit that “it’s an error” translates to “and it will bomb your whole test process”.

Avoiding These Assertions

In both cases, the problem is that we’re calling fulfill when we shouldn’t. So let’s not do that.

Let the Expectation Die With the Test

XCTest actually hangs on to the expectations it creates so it can collect them during the wait call.

Our test method doesn’t need yet another strong reference to the expectation; if we instead work with a weak reference in our callback closure, the expectation will die with our test, rather than lingering for us to trip over after the test has completed, and we’ll have turned our callback into a no-op.

First, neuter the time-bombed testNotWaitingLongEnough by prefixing its name with an x so it won’t get picked up by the test runner any more:

 class LateCallback: XCTestCase {
     let callBackDelay: NSTimeInterval = 2


-    func testNotWaitingLongEnough() {
+    func xtestNotWaitingLongEnough() {
         let promiseToCallBack = expectationWithDescription("calls back")
         after(seconds: callBackDelay) { () -> Void in

Now clone it, but this time, use a weak reference to the expectation:

    func testPreparedForNotWaitingLongEnough() {
        weak var promiseToCallBack = expectationWithDescription("calls back")
        after(seconds: callBackDelay) { () -> Void in
            guard let promise = promiseToCallBack else {
                print("too late, buckaroo")
                return
            }

            print("I knew you'd call!")
            promise.fulfill()
        }

        waitForExpectationsWithTimeout(callBackDelay / 2) { error in
            print("Aww, we timed out: \(error)")
        }
    }

Run the LateCallback suite again, and the logs now look like (or skip to the summary):

Test Suite 'Selected tests' started at 2016-03-19 23:19:19.980
Test Suite 'LateCallback' started at 2016-03-19 23:19:19.981
Test Case '-[Tests.LateCallback testPreparedForNotWaitingLongEnough]' started.
Aww, we timed out: Optional(Error Domain=com.apple.XCTestErrorDomain Code=0 "The operation couldn’t be completed. (com.apple.XCTestErrorDomain error 0.)")
/Users/jeremy/Github/XCTestExpectationGotchas/Tests/LateCallback.swift:34: error: -[Tests.LateCallback testPreparedForNotWaitingLongEnough] : Asynchronous wait failed: Exceeded timeout of 1 seconds, with unfulfilled expectations: "calls back".
Test Case '-[Tests.LateCallback testPreparedForNotWaitingLongEnough]' failed (1.945 seconds).
Test Case '-[Tests.LateCallback testZzz]' started.
Let's just wait a while…
2.0: finished waiting
too late, buckaroo
2.0: all done here
Yawn, that was boring.
Test Case '-[Tests.LateCallback testZzz]' passed (2.004 seconds).
Test Suite 'LateCallback' failed at 2016-03-19 23:19:23.932.
	 Executed 2 tests, with 1 failure (0 unexpected) in 3.950 (3.951) seconds


Test session log:
	/var/folders/63/np5g0d5j54x1s0z12rf41wxm0000gp/T/com.apple.dt.XCTest-status/Session-2016-03-19_23:19:16-QZf0lq.log

Test Suite 'Selected tests' failed at 2016-03-19 23:19:23.933.
	 Executed 2 tests, with 1 failure (0 unexpected) in 3.950 (3.953) seconds
Program ended with exit code: 1

Our testZzz runs to completion and passes, and the test process exits on its own terms reporting the one failure.

The late callback still happened, but by that time, promiseToCallBack had been zeroed, so we never called fulfill().

Assertion: Dodged!

Kill the Expectation Proactively

What about the double-callback case? We can use the same trick, only this time, we’ll want to proactively annihilate the expectation:

    func testSafelyDoubleTheFulfillment() {
        weak var promiseToCallBack = expectationWithDescription("calls back")
        let callBackDelay: NSTimeInterval = 1

        twiceAfter(seconds: callBackDelay) {
            guard let promise = promiseToCallBack else {
                print("once was enough, thanks!")
                return
            }

            promise.fulfill()
            promiseToCallBack = nil
        }

        let afterCallBack = 2 * callBackDelay
        waitForExpectationsWithTimeout(afterCallBack, handler: nil)
    }

With the unsafe test neutered via the prefix-x trick, running the test class gives (or skip to the summary):

Test Suite 'Selected tests' started at 2016-03-19 23:22:56.356
Test Suite 'DoubleCallback' started at 2016-03-19 23:22:56.357
Test Case '-[Tests.DoubleCallback testSafelyDoubleTheFulfillment]' started.
1.0: finished waiting


Test session log:
	/var/folders/63/np5g0d5j54x1s0z12rf41wxm0000gp/T/com.apple.dt.XCTest-status/Session-2016-03-19_23:22:51-14ywpS.log

now once
i hear you calling me
now twice
once was enough, thanks!
wasn't that nice?
1.0: all done here
Test Case '-[Tests.DoubleCallback testSafelyDoubleTheFulfillment]' passed (1.099 seconds).
Test Suite 'DoubleCallback' passed at 2016-03-19 23:22:57.457.
	 Executed 1 test, with 0 failures (0 unexpected) in 1.099 (1.100) seconds
Test Suite 'Selected tests' passed at 2016-03-19 23:22:57.458.
	 Executed 1 test, with 0 failures (0 unexpected) in 1.099 (1.102) seconds
Program ended with exit code: 0

Since we explicitly set the promise to nil, we only end up fulfilling it once. No harm, no foul.

Use a Different Promise API

If you’ve got an API written in terms of a promise/future library already, such as Deferred, then there’s no need to use XCTest’s promises:

class BringYourOwnPromises: XCTestCase {
    let anyDelay: NSTimeInterval = 1


    func testGettingAPony() {
        let futurePony = giveMeAPony(after: anyDelay)

        let longEnough = anyDelay + 1
        guard let pony = futurePony.wait(.Interval(longEnough)) else {
            XCTFail("no pony ;_;")
            return
        }

        print("we got a pony! \(pony)")
    }


    func testWhenImpatientNoPonyForYou() {
        let futurePony = giveMeAPony(after: anyDelay)

        guard let pony = futurePony.wait(.Now) else {
            print("no patience, no pony")
            return
        }

        XCTFail("we got a pony???! \(pony)")
    }


    func testZzzDoesNotCrash() {
        spin(forSeconds: 2 * anyDelay)
    }
}

Summary

Always assign your expectations to a weak reference, and then bail in your callback if it’s nil.
In the rare case where you expect your callback to be triggered more than once, you can avoid fulfilling by annihilating your weak reference after fulfilling it and then ignoring future calls.
- More likely, you know how many times you should be called, and you’ll want to fulfill the promise only on the last call. But the workaround is there if you need it.
If you’re already working with a promise-based API, you can skip XCTestExpectation and use whatever wait-and-see API is provided by that promise instead of XCTest’s own.
- This has the added advantage of linearizing your test code by eliminating the need to handle the delivered value in the closure (or manually shuttle it out to assert against after the XCTest wait has finished).