Signposts are a special part of the Unified Logging and Activity Tracing system. They allow you to mark point-in-time events that occur in your code, or track the duration of operations by specifying the begin and end for an activity. These can be visualized in Instruments to get a rich, high level view of how these operations are performing, how often they are occurring, and how long they are taking. In this episode we will see how to add signposts to an app and how to view these signposts in Instruments.
Episode Links 3 Key Performance Techniques for iOS 12 Developers - a great blog post covering signposts and more. Lots of great stuff to learn here. Measuring Performance using Logging - WWDC 2018 Session 405. This session talks about using signposts and building custom signpost instruments. Getting Started First, import the modules we'll be using at the top of the file: import os.log import os.signpost The signposts will be added to an OSLog, so we'll need to add one of those. I chose to put this in a separate file so I could use it from anywhere in my app: import os.log struct SignpostLog { static var pointsOfInterest = OSLog(subsystem: "com.ficklebits.SignpostDemo", category: .pointsOfInterest) static var general = OSLog(subsystem: "com.ficklebits.SignpostDemo", category: "general") static var json = OSLog(subsystem: "com.ficklebits.SignpostDemo", category: "json") } The signposts in Instruments are grouped by the log we choose. Additionally, if we want to use point-in-time signposts, we have to use a special .pointsOfInterest category. Measuring Performance of Cell Configuration In our view controller we can add begin/end signposts where we configure our cells, to measure the time this takes for each. If we are doing anything slow within these methods it will be clear to see with these signposts. os_signpost(.begin, log: SignpostLog.general, name: "Configure Cell", "Story %d - %s", story.id, story.title) configure(cell: cell, with: story) os_signpost(.end, log: SignpostLog.general, name: "Configure Cell") Note here that we use the same name, so these calls can get correlated together. The begin signpost has metadata attached to it that we'll be able to see within instruments. Measuring Asynchronous Operations The begin/end calls are not always inline like that, and often we'll have to associate begin and end signposts using something other than the name. For this we can use signpost ids. private func loadStory(with id: Int, indexPath: IndexPath) { let spidForStory = OSSignpostID(log: SignpostLog.general, object: id as AnyObject) os_signpost(.begin, log: SignpostLog.general, name: "loadStory", signpostID: spidForStory, "Load Story %d", id) let task = newsAPI.loadStory(id: id) { result in switch result { case .success(let story): os_signpost(.end, log: SignpostLog.general, name: "loadStory", signpostID: spidForStory, "%s", story.title) // .... case .failed(let error): if self.isCancellationError(error) { os_signpost(.end, log: SignpostLog.general, name: "loadStory", signpostID: spidForStory, "Cancellation") } else { os_signpost(.end, log: SignpostLog.general, name: "loadStory", signpostID: spidForStory, "Error: %@", error as NSError) } } } // .... } For each of these calls we add metadata to the end call to add more information when viewing this in Instruments. Points of Interest Another useful application of signposts is marking events that occur in the app. We can use this to visualize how long the app takes to start up and display the first cell, for instance. We'll add signpost events to app launch, view controller lifecycle events, and the display of the first cell, like this: // AppDelegate.swift func application(_ application: UIApplication, willFinishLaunchingWithOptions launchOptions: [UIApplication.LaunchOptionsKey : Any]? = nil) -> Bool { os_signpost(.event, log: SignpostLog.pointsOfInterest, name: "willFinishLaunching") return true } func application(_ application: UIApplication, didFinishLaunchingWithOptions launchOptions: [UIApplication.LaunchOptionsKey: Any]?) -> Bool { os_signpost(.event, log: SignpostLog.pointsOfInterest, name: "didFinishLaunching") return true } // ViewController.swift override func viewDidLoad() { super.viewDidLoad() os_signpost(.event, log: SignpostLog.pointsOfInterest, name: "ViewController-viewDidLoad") // .... } override func viewWillAppear(_ animated: Bool) { super.viewWillAppear(animated) os_signpost(.event, log: SignpostLog.pointsOfInterest, name: "ViewController-viewWillAppear") } override func viewDidAppear(_ animated: Bool) { super.viewDidAppear(animated) os_signpost(.event, log: SignpostLog.pointsOfInterest, name: "ViewController-viewDidAppear") } And then finally when the first cell is displayed: override func tableView(_ tableView: UITableView, willDisplay cell: UITableViewCell, forRowAt indexPath: IndexPath) { if indexPath.row == 0 { os_signpost(.event, log: SignpostLog.pointsOfInterest, name: "Will Display First Cell") } }