Every year, Apple and its engineers attempt to do the impossible by developing the next major releases of macOS, iOS, and the other littler OSes, at the same time that its development environment, Xcode, is changing rapidly through successive beta-releases. Keeping them all in step and working correctly seems an astonishing feat.

Here’s an example of where that feat doesn’t come off – not intended as criticism, but an illustration of what can go wrong, how to work around it, and documentation of a bug to beware of.

This involves Signposts, the first major new log feature which Apple has promoted since it detailed the new unified log at WWDC back in 2016. I have been exploring these in High Sierra and Mojave since Signposts first appeared around macOS 10.13.5 (I think). Mojave adds a great deal to the limited implementation available in 10.13.6, and makes them accessible to third-party developers.

I have two tools which write Signposts in full Mojave style: Blowhole, a command tool for writing to the unified log, and Whither, a test app which writes Signposts (and Pseudo-Signposts in Sierra and High Sierra) as its primary purpose. When built in Xcode 10ß4, both worked fine.

When I built Blowhole using Xcode 10ß5, I discovered that it no longer wrote Signposts properly in Mojave. Instead of seeing a neat static string for each SignpostName and a dynamic string for its eventMessage, the SignpostName contained the formatting string intended for use in the eventMessage, and the evenMessage could contain the error string <compose failure [UUID]>. It looked like someone had screwed up the interface glue between my Swift 4.2 code making the call, and the underlying code executing it.

When I rebuilt Whither using Xcode 10ß5 or 6, it continued to write Signposts perfectly well, so I assumed that it was using the code correctly, and it was all my fault.

Because Blowhole only works with log entries, it calls them in an unusual way, using a custom class. Here’s the start of its code, together with the two functions which, in Mojave, write Signposts.

The commented-out code was used before and since the tool broke, but I have more recently changed it to include a signpostID, in the hope that might fix the bug. It didn’t.

In Whither, the same calls are made from within an NSViewController, but with almost identical parameters, as shown below.

There were a few minor differences, most notably that Blowhole originally made all these calls from an OSLog with the category “general”, whereas Whither did the proper thing in using a category of “Signpost”. Changing that made no difference to Blowhole or its defective Signposts.

The bugs are that when any of
os_signpost(type, log: Blowhole.gen_log, name: "blowhole")
os_signpost(type, log: Blowhole.gen_log, name: "blowhole", signpostID: mySpid)
os_signpost(type, log: Blowhole.gen_log, name: "blowhole", "%{public}@", string)
os_signpost(type, log: Blowhole.gen_log, name: "blowhole", signpostID: mySpid, "%{public}@", string)
are called, the parameters passed don’t work as intended.

In the first two cases, in which no content is supplied to go into the eventMessage field, what is passed for that field fails to compose into a permissible string, generating the error <compose failure [UUID]>. And in all four cases, the SignpostName of “blowhole” which is passed isn’t put into the SignpostName field, but any formatting string supplied, such as “%{public}@”, is put there instead. But these only occur when these calls are made in my command tool, and they appear to work perfectly well when called in a Cocoa app instead.

Despite extensive experimentation, I have been unable to get any sense out of function calls of the first two types, which do not pass a string to go into the eventMessage field in the log. So I now substitute for them a call of the form
os_signpost(type, log: myLog, name: "blowhole", signpostID: mySpid, "blowhole %{public}s", "")
which writes “blowhole” to the SignpostName as a static string, and “blowhole” to the eventMessage field. This avoids the compose failures, even though it clutters up those Signposts with unnecessary data.

To pass a dynamic string to be inserted into the eventMessage field, I now make the call
os_signpost(type, log: myLog, name: "blowhole", signpostID: mySpid, "blowhole %{public}@", string)
which also writes “blowhole” as a static string to the SignpostName, but doesn’t write it to the eventMessage field. Instead, the dynamic string supplied is inserted in place of the formatting string %{public}@, and the first word and space of the resulting string (‘blowhole ‘) are then dropped. As an example:
let string = "message 1"
os_signpost(type, log: myLog, name: "blowhole", signpostID: mySpid, "blowhole %{public}@", string)
first composes the supplied string to form a final parameter of “blowhole message 1”, which it then truncates to “message 1”, and passes as the eventMessage field.

But all of this only applies when these calls are made from my command tool. They behave quite differently – and as advertised – when called from a Cocoa app, Whither. In that case,
os_signpost(.event, log: self.myLog!, name: "scanFolderSP", signpostID: mySpid, "%{public}@ %{public}@", "\(theOldVers.count)", theSourceURL.path)
correctly writes a Signpost of type event to the Signpost category of the subsystem co.eclecticlight.Whither, with the SignpostName of ‘scanFolderSP’, the SignpostID of mySpid, and an eventMessage field composed of a formatted integer (theOldVers.count), a space character, and a file path (a dynamic string).

There are, I am sure, smarter ways of discovering this workaround. I relied on repeated tests to understand exactly what was going wrong, thanks to the Signpost display in RouteMap:

and of course the full log information in Consolation – where you can see one of the dreaded compose failure errors.

I’ll try to put this succinctly in a bug report on Radar in the next few days, although as this affects Signposts, I would imagine that plenty of Apple engineers are already yelling at other Apple engineers. With only a month or so to go before Mojave Golden Master.