Signposts for performance: 1 introduction

Apple made it clear that the theme for macOS Mojave is improving performance. This is good for users, and even better for developers, as Apple is at last starting to make better use of the unified log to help all of us get better performance from our Macs.

Although this article and its successors are aimed primarily at developers, they should also be of value to anyone who scripts (in AppleScript, in command scripts, or in any other scripting system), and to any user who performs demanding tasks with their Mac(s).

For most of us, the unified log introduced with macOS Sierra has been quite disastrous. Even if you have spent time using Apple’s Console, the log command, or my tools Consolation and Woodpile, the new log is full of thousands of entries which are only meaningful to Apple. Finding anything useful to us has been exceedingly difficult, and most have given up trying to do so. Life is too short to waste all that time negotiating your way around those countless messages, only to discover that what you needed doesn’t seem to get logged any more.

Mojave changes this with the introduction of Signposts. Although these can be browsed as part of the main log, you can fairly readily view just Signposts – suddenly, the incessant noise of every other process chattering away has gone. It’s like walking out of a crowded party into the fresh air and quiet of the night.

Writing Signposts is straightforward too: they’re easy to access in Xcode with either Swift (see below) or Objective-C, and using my free command tool Blowhole (from Downloads above), you can write Signpost entries into the unified log from any app, tool, or language which lets you execute a shell command like
blowhole -V "Loop started"
which writes a Signpost of the Event type with the message “Loop started”.

There are two snags with Signposts, though. First, although Apple has been using them through its private APIs in High Sierra, they’re only available to us in Mojave. If you try to write Signposts in earlier versions of macOS using Blowhole, it converts those into regular log entries. But the macOS interface to Signposts is only accessible when running in Mojave.

The second problem is retrieving and analysing your Signposts. Xcode 10 supports Instruments which can do some stunning things with Signposts, as demonstrated at WWDC. But you have to be running your app within Xcode, and writing a suitable Instrument is a non-trivial task, requiring dozens or more lines of XML, apparently. For smaller developers, there just isn’t the time to learn to do this, I fear.

Consolation 3 does support Signpost harvesting and analysis: you can capture a log excerpt containing only your Signposts and export it in CSV. But Consolation itself can’t do anything more than export those Signposts, and is not specifically tailored to work with Signposts. It’s a general log browser, not a performance analysis tool.

I have now started work on developing a tool to enable you to harvest and analyse Signposts from Mojave: RouteMap. The first step was, naturally, to write a tester app to provide an inexhaustible supply of Signposts of different types, which I have called Whither. I am making that app and its complete source code available for download here: Whither
and from Downloads above.

Whither and RouteMap go a bit beyond plain Signposts too. Although Signposts are a valuable improvement on regular log entries, because they are so readily viewed in isolation, the source code of Whither and the powers of RouteMap can use normal log entries as Signposts when run in Sierra or High Sierra.

As shown at WWDC, using Signposts in Mojave requires very little code. Whither first creates an OSLog variable using
let myLog = OSLog(subsystem: "co.eclecticlight.Whither", category: "Signpost")
then it obtains a unique SignpostID (essentially a UInt64) using
let mySpid = OSSignpostID(log: self.myLog!)
Writing a plain begin Signpost is then performed with
os_signpost(.begin, log: myLog!, name: "scanFolderSP", signpostID: mySpid)
which produces something like
scanFolderSP begin process 1
in the relevant fields in the unified log.

Writing a full event Signpost, with a couple of variables included, might then be
os_signpost(.event, log: self.myLog!, name: "scanFolderSP", signpostID: mySpid, "%{public}@ %{public}@", "\(theOldVers.count)", theSourceURL.path)
to see the log output
17 /Users/hoakley/OtherDocuments/Xcode/blowhole/blowhole/main.swift scanFolderSP event process 1
for example.

Viewed in Consolation 3, this becomes:

routemap01

In the Whither sourcecode, you’ll see that pre-Mojave plain log equivalents might be
doOSLog(signType: "begin", theLog: self.myLog!, name: "scanFolder", signpostID: mySpid)
to write an eventMessage of
Signpost begin scanFolder 1
and
doOSLog(signType: "event", theLog: self.myLog!, name: "scanFolder", signpostID: mySpid, theStr: ("\(theOldVers.count) " + theSourceURL.path))
to write eventMessages like
Signpost event scanFolder 1 17 /Users/hoakley/OtherDocuments/Xcode/blowhole/blowhole/main.swift

Viewed in Consolation 3 (in Sierra), this becomes:

routemap02

Unfortunately, combining those in conditional code gets quite messy, as Signposts rely on OSSignpostIDs, which don’t exist prior to Mojave, so in Whither I have written two separate functions to cope with this. I’m sure the more adept will work out a clean way of rolling them into a single function using conditional code.

Unlike Apple’s solution of Signposts which only work in Mojave, RouteMap will therefore be able to harvest and analyse pseudo-Signposts written to the regular unified log in Sierra and High Sierra. And it will work outside of Xcode, and with any app or language which can write to the log using Blowhole – opening Signposts up to Automator, AppleScript, other scripting systems, and many apps which can run simple shell commands.

There’s more too. Apple has been using Signposts already in High Sierra, and I expect when Mojave is released in the autumn/fall, there will still be macOS subsystems which write Signposts. RouteMap will also be able to harvest and analyse those, enabling its use for looking at aspects of macOS performance too. So even if you don’t code yourself, RouteMap should still prove a valuable tool.