The Mysterious Case Of The Unit Tests That Ran At The Speed Of Light

elegant chaos

January 22, 2013

Once or twice I’ve had the situation where I ran some unit tests in Xcode, and they seem to run incredibly fast. Too fast.

Spoiler: they didn’t Instead of Xcode’s Log Navigator looking something like this:

unit tests that ran ok

it instead shows this:

unit tests saying that it succeeded, but where nothing ran

The observant amongst you will have already spotted the flaw in this otherwise nice, friendly, green display of unit testing happiness.

There are no issues because no unit tests ran.

What’s Going On?

Unless you know where to look, just beginning to discover why this might be is a little challenging.

You might think to yourself: “silly me, I must have turned them all off”. A quick look at the Tests settings in the Scheme will verify this:

test settings in the scheme

Nope, they’re on, but Xcode isn’t running them for some reason.

Console Yourself

Normally when something goes wrong with unit tests my first port of call is the console output, and the way I get to it is via the little button that appears on the right hand side of a test when you hover over it:

But with no tests apparently running, there is no little button, so we need to actually go and look in the separate console area.

If you’re the kind of person who leaves everything visible all the time in Xcode, you’ll probably be wondering why I’m even mentioning this, but if (like me), you have behaviors that hide things at various times, then it’s quite possible to not even remember that the console output is still there once the run has finished.

You can get to it like this:

Activate Console menu item

When you do, you’ll discover that something very odd is going on. The normally copious unit test console output has been reduced to:

Console Output

Luckily, Xcode tells us what’s happening (I’ve shortened the paths):

    The test bundle at CURLHandleTests.octest could not be loaded because its
    Objective-C runtime information does not match the runtime 
    information required by the test rig.

and why:

    This is likely because the test rig is being run with
    Objective-C garbage collection disabled, but the test
    bundle requires Objective-C garbage collection.
    To enable Objective-C garbage collection for the test rig,
    run it in an environment without the OBJC_DISABLE_GC 
    environment variable.

Thank you Mr Xcode, you are so good to me.

So, I got my build settings wrong and forgot to disable garbage collection right? I’ll just go and fix it and… oh, hang on… no I didn’t. No garbage collection here.

So, what the hell is going on?

Back to the console. It looks like otest is having trouble:

    2013-01-22 18:25:46.057 otest[5433:203] *** NSTask: Task
    create for path 'CURLHandleTests.octest/Contents/MacOS/CURLHandleTests'
    failed: 22, "Invalid argument".  Terminating temporary process.

For those who are wondering, otest is the command line tool that loads and runs your unit tests.

So it seems to be having trouble. It’s failed, with error code 22. Which is an invalid argument.

Well, that clears things up then.

Long Story Short

Ok, so let’s cut to (somewhat nearer) the chase.

What’s actually happening here, in the cases that I’ve encountered at least, is that otest is failing to load CURLHandleTests.octest - which is the bundle that contains your compiled tests.

There are probably a few reasons why it could fail. Clearly Xcode thinks that garbage collection incompatibility is right up there. However, also high up on the list is that the dynamic loader is failing to load it because it can’t find a shared library or framework that your test code depends on.

If you are using the default Xcode setup, the octest bundle is built into the Products directory, along with any other dependent targets. If your tests need to link at runtime to any custom libraries or frameworks, you need to make sure that they end up here (or somewhere else that the dyld loader can find them).

This is fairly obvious in most cases - for example if you are unit testing a framework that you’re building, it kind of makes sense that you’ll need the framework. In these cases Xcode generally does the right thing anyway - your unit test target will probably depend on the framework target, and they’ll both end up in the Products directory.

So most of the time you’ll be ok, and perhaps even blissfully unaware of how your tests are loaded and run.

However, things can get tricky when the library dependencies are a bit more complex. For example if you’re testing a framework and the framework itself relies on some other shared libraries that are custom built, and not just pre-installed in some convent location like /Library/Frameworks/.

It’s possible in this case for the framework to embed these libraries as part of it’s own build process, which makes life a lot simpler for people who use it - and will probably not cause the sort of issues I’m talking about. That doesn’t always happen though, for good reasons such as not wanting to end up with multiple copies of a library embedded in more than one framework.

In this situation, where your framework is looking for a shared library that it can’t find, what will happen is a runtime failure to load your framework. This in turn will cause your unit test bundle to fail to load, which in turn will cause otest to bomb out with the useful error 22, which in turn will cause Xcode to LIE TO YOU BY PUTTING UP A BIG GREEN THING SAYING ALL YOUR TESTS RAN.

Sorry. Deep breaths.

## The Fix

So once you’ve figured out what library you’re missing, the fix is quite simple. Just add a build phase to your unit test target which copies the relevant things into the Products Directory:

Copy Files Phase

(yes, in this case we’re linking against our own builds of libssh2, libssl and libcrypto - they aren’t the normal builds, so if they are missing, everything goes pear-shaped).

Happily, if you’ve got the right libraries, all will now be well and the unit tests will run.

What To Link

Of course, working out what library you’re missing isn’t always trivial, especially if it’s a big codebase and/or you aren’t in control of it all.

How to work out which libraries depend on which is a blog post all of its own, but here are a few handy hints.

otool

You can use otool (not to be confused with otest, which I mentioned earlier), to work out what something links to.

You have to run it on the actual binary inside your octest bundle

otool -l /Caches/DerivedData/CURLHandle-flfotwdrtmazzmdpxjznosnizjlm/Build/Products/Debug/CURLHandleTests.octest/Contents/MacOS/CURLHandleTests 

This will produce a big load of output, including things like this:

          cmd LC_LOAD_DYLIB
      cmdsize 104
         name /System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation (offset 24)
   time stamp 2 Thu Jan  1 01:00:02 1970
      current version 744.1.0
compatibility version 150.0.0

Which tells you that you’re linking against CoreFoundation - which you could probably have guessed.

All the system ones are probably fairly expected and aren’t likely to be the problem. However, if something shows up in this dump that you weren’t expecting, it’s a good clue where to look.

Update: otool -L actually gives you a much more compact output here, just listing the libraries that are linked to:

    @rpath/Connection.framework/Versions/A/Connection (compatibility version 1.0.0, current version 1.0.0)
    @rpath/SenTestingKit.framework/Versions/A/SenTestingKit (compatibility version 1.0.0, current version 4053.0.0)
    @rpath/DAVKit.framework/Versions/A/DAVKit (compatibility version 1.0.0, current version 1.0.0)
/System/Library/Frameworks/Foundation.framework/Versions/C/Foundation (compatibility version 300.0.0, current version 945.11.0)
    /usr/lib/libobjc.A.dylib (compatibility version 1.0.0, current version 228.0.0)
    /usr/lib/libSystem.B.dylib (compatibility version 1.0.0, current version 169.3.0)
    /System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation (compatibility version 150.0.0, current version 744.1.0)

DYLD_ variables

Another thing that may help is to enable a few DYLD_ environment variables and then run otest manually. Knock up a little script like this:

export DYLD_PRINT_LIBRARIES=YES
export DYLD_PREBIND_DEBUG=YES
export DYLD_PRINT_ENV=YES
export DYLD_PRINT_APIS=YES

export OBJC_DISABLE_GC=YES

xcrun otest /Caches/DerivedData/CURLHandle-flfotwdrtmazzmdpxjznosnizjlm/Build/Products/Debug/CURLHandleTests.octest 

What you’ll see when you run this is a whole load of debug output from the DYLD loader itself.

...
dlopen(/Caches/DerivedData/CURLHandle-flfotwdrtmazzmdpxjznosnizjlm/Build/Products/Debug/CURLHandleTests.octest/Contents/MacOS/CURLHandleTests, 0x00000115)
dlopen(/Caches/DerivedData/CURLHandle-flfotwdrtmazzmdpxjznosnizjlm/Build/Products/Debug/CURLHandleTests.octest/Contents/MacOS/CURLHandleTests, 0x00000109)
dyld: loaded: /Caches/DerivedData/CURLHandle-flfotwdrtmazzmdpxjznosnizjlm/Build/Products/Debug/CURLHandleTests.octest/Contents/MacOS/CURLHandleTests
dyld: loaded: /Volumes/titan/Users/Shared/Applications/Xcode/Xcode46-DP4.app/Contents/Developer/Tools/../Library/Frameworks//SenTest
....

This may give you a clue about which library or framework is failing.

Other References

The topic of libraries, frameworks and dynamic linking is a fairly complicated one in its own right.

If you encounter the problem that I’ve described above, the chances are that you’re working with a fairly large and/or complex project with multiple libraries, and you’ll already know a bit about dynamic linking.

If not, these links may help.

Run-Path Dependent Libraries: This article explains how the system finds out where your libraries are at runtime, and how you can set up any frameworks or libraries that you build so that they can be hosted in the the /Library/Frameworks folder, or inside your app, or embedded in another framework, in a way which still allows them to be found.
Mac OS X Debugging Magic: This tech note gives a lot of helpful advice on debugging.
Friday Q&A 2009-11-06: Linking and Install Names: Mike Ash has also covered this topic.
You can also use man dyld in the terminal to get a full list of the DYLD_ variables.

In Conclusion

This problem can be really tricky to solve.

Just knowing what the problem is would be a good start, but Xcode does it’s best not to tell you.

Of course, I have filed a radar. Feel free to dupe it.

Hopefully, if you’ve stumbled across this blog post whilst tracking it down, I’ll have pointed you in the right direction!