View Bridge Logging

One of the bits of magic associated with app extensions is that when for example a Share extension’s UI is presented in the context of host application, it behaves as though it were hooked into the UI of the app itself. Standard menu item command such as Cut, Copy, Paste, etc., are all mapped through to the extension’s UI so that standard editing commands work as expected.

But the app extension itself is actually hosted in a separate process. How does all this magic work? On the Mac at least, when the extension’s user interface is displayed, a private framework from the system called ViewBridge.framework seems to be in charge of displaying the view and coordinating communication between it and the host app.

I was trying to figure out why some specific keystrokes did not seem to be making it to my app extension, and while poking around in the debugger I noticed that the ViewBridge framework is riddled with logging messages that are, by default, largely disabled. With a little detective work I was able to figure out how to turn them on.

The long and short of it is that, Apple’s ViewBridge framework looks for an undocumented NSUserDefaults key, “ViewBridgeLogging”. The key can be used to activate, by name, any of a slew of different logging “domains,” which compel the framework to dump copious information about topics ranging from accessibility, to events, to window animations.

Two of these domains, “communications_failure” and “exceptions” are always on, so you will see console logging from these categories should the need arise. The easiest way to coax ViewBridge to dump a massive amount of information for all the other domains is to simply set the NSUserDefaults key globally from the command line:

defaults write -g ViewBridgeLogging -bool YES

Now, when you invoke and interact with your own app extension UI, you’ll see a bunch of logging messages like this:

12/2/14 11:00:30.798 AM MarsEdit Shuttle[83129]:
	<NSViewServiceMarshal: 0x7fc43af09070>
	sending key event to <NSWindow: 0x6000001ecc00>:
	NSEvent: type=FlagsChanged loc=(135,-19) time=226109.1
	flags=0x100 win=0x0 winNum=13244 ctxt=0x0 keyCode=55

This could be handy if you’re trying to work out the particulars of why or if a particular event is even reaching your extension. In fact the vast number of logging messages have often been carefully crafted to provide specific information that could be useful if you’re confused about an edge case. Here’s a more verbose one:

12/2/14 3:11:30.709 PM MarsEdit Shuttle[87440]: 
	<NSViewServiceMarshal: 0x7febfad00b30>
	choosing not to make <NSWindow: 0x6180001eea00> resign
	key because it already believes itself to lack keyness

Yet more examples of pithy prose you’ll find among the console log messages:

"activated TSM because service window became key while remote view is first responder"
"incremented TSM activation count to 1"
"told app it acquired key focus"

Even some particularly juicy language like “discarded toxic NSEvent.” Intriguing. Tell me more!

It’s worth mentioning that the ViewBridge seems to be responsible for managing more than just the UI for app extensions. For example if you leave this console logging enabled while you bring up a standard save panel from TextEdit, you’ll see a massive number of messages relating to the sandboxed file chooser’s behaviors.

It could all become pretty overwhelming, so if you want to limit the kinds of logs that make it to the system console, you can change the NSUserDefaults value from a blunt “YES” to a dictionary representation of the subset of domains you want to activate. As I said before, I believe the “exceptions” and “communications_failure” domains are always on, but to get a feel for the other domains you can selectively enable, run this from the command line:

strings - /System/Library/PrivateFrameworks/ViewBridge.framework/ViewBridge | grep kLogDomain | sort -u

These are the symbolic constant names for the strings, but the actual string values seem to be easily inferred. For example kLogDomain_Events becomes “events”. But to make things even more bullet-proof, just look closely at the messages that appear in the console in “firehose mode,” with all logging messages enabled as above. Each of the logs ends with a hashtag-style marker indicating the domain of the incident. For example, if the types of logging messages you’re interested in all end with #events or #miscellany, just change the global logging default to show only those varieties by adjusting the default like this:

default write -g ViewBridgeLogging -dict events 1 miscellany 1

Now you know a whole lot about how to learn a whole lot about what goes on when Apple’s ViewBridge framework is in charge of managing a view. Here’s hoping this makes the task of debugging particular behaviors of your app extension’s UI more palatable.