At AppSpector, we often debug client applications with our integrated tools and, naturally, our code, including the core part — mobile SDKs. We have always embraced various tools available for the particular platform to speed up debugging and make the development process more accessible. Thus, when we spotted WWDC 2018 session 410, “Creating custom instruments,” we couldn’t wait to build something with the new APIs.
If all you have is a hammer, everything looks like a nail. A problem worth building a custom Instruments package was short in coming. The core part of AppSpector iOS SDK is a messaging module that, in a few words, is responsible for two-way traffic exchange between iOS and our backend.
SDKs send many events describing host app behavior and various actions and receive requests from the backend. The amount of traffic is significant enough to require compression, so we implemented it initially. Now, all messages are being compressed/decompressed at both SDK and backend sides.
At some point, we decided to change the compression algorithm from LZ4 to zstd, which is dictionary-based and could provide better compression on our data type. As we all know, the ability to measure any changes is crucial to bring them in safely and effectively, so we decided to create a built-in mechanism to track compression rate and performance. Of course, the custom instrument was the best candidate.
Almost the same is easily achieved with simple logging, but what we wanted and what Instruments were suited for was data sampling and visualization. Imagine that a single message in a hundred experiences compression problems. Its compression rate is disturbingly low, and you need to perform specific actions, e.g., establish a Bluetooth connection, to trigger it on an actual device.
Searching the logs for this message can be a real pain. Even if you use a service of some kind to collect and save log messages from a device, and your message has a precalculated compression rate, it’s not quite the thing. However, looking at the interactive graph like that guy at the WWDC session, saving collected data and comparing two runs later, and building custom selection rules to identify and aggregate messages with specific properties looked awesome.
Technically Instruments is a frontend for one of the most powerful debugging platforms out there, DTrace. It came to OSX from Sun Solaris, and describing it in detail could take the whole book (and it does). DTrace operates with unique tracers written in D language and called probes.
Before Apple introduced Instruments packages, you could have built a custom instrument by writing your D script as a data provider and wrapping it in an instrument template. We’ll look at using os_signpost API to provide data to our instrument.
For convenience, we will build a sample project to illustrate a simple Instruments package. Our instrument for compression profiling works the same way except for the randomly generated event values we used in the sample project to simulate compressed and decompressed message size. We recommend cloning the sample project and referring to it while reading.
Xcode provides a new target type called ‘Instruments Package’ available under the ‘MacOS -> ‘Other’ section. The Target template doesn’t do any magic; it just adds one file with the .instrpkg extension, an XML file describing our instrument layout and functionality.
Most of the work on building the package is written in raw XML. We hope to get a task-specific editor like InterfaceBuilder or CoreData model editor soon.
The instrument we’ll build will use os_signpost calls as data providers. This API allows us to define the event's start and end and pass some formatted string along with start and end calls. Getting data for the event on the Instruments side is performed by parsing this string according to its format, just as you do with ‘scanf().’
We will be using os_signpost() for Swift, and if you are writing in Objective-C, you should use os_signpost_interval_begin / os_signpost_interval_end calls. To start using these APIs, we need to instantiate the ‘log’ instance because os_signpost uses the os_logging subsystem for sending messages and a unique signpost identifier:
static let log = OSLog(subsystem: "com.package", category: "Behavior")
static let signpostID = OSSignpostID(log: AppDelegate.log, object: self as AnyObject)
Note that subsystem and category arguments pass to the os_log initializer. These values will later be used in a package description to match our signpost calls. We have to call ‘begin’ before our event of interest starts and ‘end’ after it ends, passing previously created log and signpost_id instances as parameters:
os_signpost(.begin, log: AppDelegate.log, name: "event-tracking", signpostID: AppDelegate.signpostID, "size: %llu", before)
// your action here...
os_signpost(.end, log: AppDelegate.log, name: "event-tracking", signpostID: AppDelegate.signpostID, "size: %llu", after)
That’s all we need in our app code, and we can proceed to the Instruments part.
The instrument package file is a long XML file divided into three parts: package metadata, schema, and implementation. Let’s go from top to bottom, looking through the instrpkg file of our sample project. Writing a massive amount of XML is difficult, but the Xcode team added a bunch of templates for the main sections of the package structure, so when you start typing some tag, you will almost always receive a suggestion for the template with basic subtags.
Right after the ‘package’ tag, you can see the metadata section with ‘id,’ ‘title,’ and ‘owner’ info. The Instruments app will use this info to identify and install your package. ‘owner’ value will be displayed in the package info when you select it for usage. You can also provide ‘version’ and ‘note’ tags here.
The following section is our schema description. This section describes the data our instrument will operate and starts with ‘id’ and ‘title’ tags. ‘Id’ is a unique value we’ll use later to reference our schema from the Instrument UI description, and ‘title’ is a value presented near the graph view in Instruments UI.
Next, we have ‘subsystem,’ ‘category,’ and ‘name’ tags for identifying our signpost calls. They must match the ones we used to create the os_log subsystem handle in our app’s code. The following tags, ‘start-pattern’ and ‘end-pattern,’ define the format for parsing our messages.
This format will be applied to the string parameter we passed to begin/end calls. Strings starting with the question mark, ‘size-before’ and ‘size-after,’ are the names of the variables holding the data we pass from the app side.
This is the first place we meet CLIPS expression. CLIPS is a language Apple uses for data processing in Instruments, and even its brief overview deserves a separate article. If interested, you can navigate the CLIPS reference for more information on the language.
At the end of the schema, we have a bunch of ‘column’ tags describing data columns available for our package. We use four fields for each:
We use the input data we received in the start-pattern / end-pattern section for the first two columns and simple rate calculation for the third one. The last two columns will contain string values, high/low values in the first, and color names in the second. These values will be calculated depending on the rate value, and we’ll use them later while building Instrument UI.
This part describes the UI components of our instrument and how they will be populated with data. We have some metadata here at the beginning, followed by the graph, table, and aggregation sections. Metadata includes package id, which should match the one we used as a subsystem value for creating the os_log instance, ‘title,’ ‘category,’ and ‘purpose’ fields used for reference in Instruments UI, and ‘icon’ to choose an icon for your instrument.
If you have used Instruments, remember almost any Instrument UI is divided into two parts: a graph at the top and table data at the bottom. Tags ‘graph’ and ‘list’ are used to describe these two parts. First, to define a table, we need to create it with the ‘create-table’ tag referencing our schema ID. It will allow us to use data from the columns we described above.
After that, we describe a graph part of the UI, which consists of one lane. At this point, we refer to our table and state which columns should be used for plotting. The list tag describes the bottom part of the UI referencing the table ID just like the previous graph element and listing columns to display. Not that we skipped the ‘rate-color’ column here because we use it only for coloring a graph, and it doesn’t make sense to include it in our table.
This package is already almost complete, but we wanted to have a separate data view displaying messages with a compression rate below 0.15% for our task with compression profiling. Finding them among all the messages would be challenging, so we decided to use an aggregation tag to describe a separate view available at the table part of the Instrument UI.
The aggregation section includes a ‘slice’ tag, which tells Instruments to display only data with a ‘High’ value in the ‘rate-status’ column and a list of columns to display for each entry. We decided to show the size before and after the compression only.
To run a package and test it with an app producing signpost events, you need to build the app itself, then create the package scheme with the ‘My Mac’ target. After the building is done, Xcode will run a unique instance of Instruments for you. This Instance contains your package embedded. Its icon is grey-scaled to distinguish it from ordinary running Instruments.
After starting instruments, you’ll be presented with a template selection window. Select ‘Blank’ and then press the ‘plus’ icon at the top right corner of the new window. You’ll see the list of packages available and your package among them. It will be marked with a debug badge indicating that it was run from the Xcode.
Drag it to the Instruments window or double-click to add, select the device and app in the upper left corner and press the ‘record’ button.
If you want to share your newly built package with your colleagues, all you need is the .instrdst file under the ‘Products’ folder in Xcode. Running it will show you a small window with package info and an ‘install’ button. Install it, and you’ll have it in your Instruments packages list.
Most of the time, debugging is about searching for the root of the problem, not fixing it, as fixing often takes significantly less time than looking through the logs, attempts to reproduce the issue, and all the other activities of exploratory kind. Choosing the proper tool is the most critical part. Sure, you can do it the old way, say detect leaks just by looking at the memory dump or logging an object's lifetime, but with a leaks instrument, this will be much faster and easier.
Instruments allow you to choose a specific point of view to observe your app or its part; sometimes, it’s all you need to identify the problem. This tool was already fantastic, but the Xcode team made it even more powerful by allowing developers to build a custom instrument.
Building a custom Instrument is easy and fun, and you will only need to spend an hour or so to save much more time later. Of course, it would be great to have more docs and some editor for package files, but even in the current state, it could be instrumental, especially for medium-sized and big projects.
to Kacper Harasim, who was extremely kind in answering questions and helped me understand how everything works. ✌️