Migrating to Unified Logging: Console and Instruments

Debugging With Signposts

os_log is a great tool for efficient logging in your app, but the unified logging system has another tool to help with debugging: Signposts. Signposts are another logging mechanism that you can use to better visualize your code as it runs. They also work well for debugging performance.

A signpost is a type of log that can be visualized in Instruments. You can use it to see when a task begins and ends, as well as any other events related to the task.

You’ll use signposts to take a closer look at fetchRecordings(matching:page:onCompletion:). First, you’ll need to create a Signpost ID that will help Instruments identify the signpost. At the top of fetchRecordings(matching:page:onCompletion:), add this line:

let signpostID = OSSignpostID(log: Log.networking)

Next, create your first signpost after the end of the guard block that starts with guard let url = components?.url. Immediately after guard statement, add this code:

os_signpost(.begin, 
  log: Log.networking,
  name: "Fetch recordings", 
  signpostID: signpostID,
  "%@", 
  url.absoluteString)

The Structure of a Signpost

os_signpost takes six parameters:

1. Type: The type of signpost call. This call marks the start of your signpost, so you use .begin.
2. Log: Same as os_log, you pass an OSLog object to help categorize your signposts.
3. Name: The name helps Instruments group together signpost events. As a bonus, it makes things easier for you to read as well. :]
4. Signpost ID: While not necessary if you have unique names for your signposts, the Signpost ID is a cleaner way to identify your signposts.
5. Log Message: Along with the signpost event, you can provide a log message with any other important info.
6. Format Arguments: These provide any arguments for format strings in your log message.

In life, when there’s a beginning, there must be an end. Your signposts are the same, in that sense. :] So, you’ll need to fire os_signpost with a .end event when the app has finished fetching the recordings to fully utilize the power of signposts in this method.

fetchRecordings(matching:page:onCompletion:) fires a completion handler when it has finished. You’ll need to add the signpost event just before firing the onCompletion closure. In the nested fireErrorCompletion(_:) function, find the line that fires the completion handler:
.

onCompletion(RecordingsResult(
  recordings: nil, 
  error: error,
  currentPage: 0, 
  pageCount: 0))

Add a new signpost event immediately before it:

os_signpost(.end, 
  log: Log.networking,
  name: "Fetch recordings", 
  signpostID: signpostID,
  "%@", 
  error?.localizedDescription ?? "No error")

This signpost event is similar to the one you created earlier: It uses the same name and the same signpost ID so Instruments will group them together. It fires if fetchRecordings(matching:page:onCompletion:) finishes with an error. The event type is set to .end to indicate the end of the event and you pass the error into the format string to have it show up in Instruments.

You still need to add a signpost event when the recordings are successfully fetched. Look for this line that passes the results to the completion handler:

onCompletion(recordingsResult)

Immediately before that, add a new signpost event:

os_signpost(.end, 
  log: Log.networking,
  name: "Fetch recordings", 
  signpostID: signpostID,
  "Fetched %d recordings with %d pages remaining.",
  count, 
  result.numPages)

And that’s it! You’re ready to look at the signposts in Instruments.

Viewing Signposts in Instruments

First, from Xcode, open Instruments by pressing Command-I on your keyboard, or go to Product ► Profile. It is important to use this method so Xcode builds the app and launches Instruments with the process already attached to it.

Next, choose the Blank document type.

Then, click + at the top right to add an instrument. Search for the os_signpost instrument and double-click the item to add it:

Now click ◯ at the top left to start recording. Play around in the Chirper app in the Simulator. Perform a search and page through the results.

When you’re finished playing around with the app, click ▢ at the top left of Instruments to stop the recording. You should see something like this:

You can see some information about the performance of the code within your signposts. The min duration, max duration and standard deviation metrics are great indicators that can help you dial in the performance of your code. They describe the time it takes to make it from the start signpost to the end signpost.

Drill down on the signposts you created in the networking category to see the log messages you added:

And that’s all there is to signposts. Hopefully you won’t have too many performance issues to debug, but if you do, the os_signpost instrument could be a big help. Congratulations!

Where to Go From Here?

You can download the completed version of the project using the Download Materials button at the top or bottom of this tutorial. There are still a handful of print statements left in the finished app. Why not convert them to the appropriate os_log and os_signpost statements for practice?

With your newfound knowledge of the unified logging system, you can add as many logs as you need to your apps and rest assured that your users will be well supported. With minimal performance impact and an easy way to organize your log messages, logging is a treat with os_log and os_signpost.

If you’d like to learn more, the official documentation on the unified logging system is a great reference.

If you’re more of a visual learner, check out the Unified Logging and Activity Tracing and Measuring Performance Using Logging WWDC videos.

Do you have anything to share about using unified logging in your own apps? If you have any questions or insights, I’d love to hear from you in the forum discussion below.