Profiling Durations in SwiftUI App with OSSignposter

I watch old WWDC sessions nowadays. Recently I watched the sessions about Signpost. So I decided to apply it to my new project.

Duration

I tracked durations with debugPrint like this.

debugPrint("begin something. id \(newItemId)")
...
debugPrint("end something. id \(newItemId)")

This case are ordered. However if tasks are a lot and they are asynchronous?

OSLog

WWDC 2018 session mentioned WWDC 2016, but I couldn’t find anything.

So I googled about OSLog and found the document.

It’s just container, itself is not a log.

According to the official article, it seemed like to possible to print logs with os_log. To use os_log, import os or OSLog.

import OSLog

And call with message.

private func addItem() {
    os_log("Begin addItem")
    ...
}

Something is different… what about print?

As you noticed, there is no line, and narrow between logs.

os_log also can receive format parameters like print.

os_log("Begin addItem. Count %d", state.count)

Logger

There is also example using Logger instead of os_log.

logger.debug("Begin addItem. Count %d", state.count)

However logger cannot receive string format.

It only can receive a string.

logger.debug("Begin addItem. Count \(state.count)")

Output is same to os_log’s.

os_signpost

WWDC 2018 introduced os_signpost , but it is deprecated now.

beginInterval

Signposter

They introduced new methods since iOS 15. To call beginInterval, we should create a instance of OSSignposter first.

let signposter = OSSignposter()

Signpost ID

Then create Signpost ID with the Signposter. The id is for each begin/end event fair.

private func addItem() {
    let signpostID = signposter.makeSignpostID()

Lastly call beginInterval with the ID and message.

signposter.beginInterval("addItem", id: signpostID)

endInterval

This is beginInterval, of course there is also endInterval. So I called endInterval end of process.

withAnimation {
    let newItem = Item(timestamp: Date())
    modelContext.insert(newItem)
    
    state.send(.countIncreaseButtonTapped)
    
    signposter.endInterval("addItem", id: signpostID)
}

But something was wrong.

endInterval usage is different to begin.

Ah… endInterval requires state. How can we make this state? beginInterval will return state. Therefore we have to hold it.

let signpostBeginState = signposter.beginInterval("addItem", id: signpostID)
        
withAnimation {
    let newItem = Item(timestamp: Date())
    modelContext.insert(newItem)
    
    state.send(.countIncreaseButtonTapped)
    
    signposter.endInterval("addItem", signpostBeginState)
}

Now building is success, let’s run the app!

I couldn’t see anything. What’s wrong?

According to document for OSSignposter,

Instruments displays signpost data visually in a timeline

So it seemed like to possible to see the logs through Instruments

Instruments

Intstruments are official debugging tool provided by Apple. I followed another article.

Profile

Launch Product > Profile Menu or press Command + I (i is instruments?)

After building… failed

Except Test from Profile and re run Profile.

There are so many tools.

But, this time, I just chose Blank Template.

To see Signposts, add os_signpost instrument by double clicking it.

Now I we see os_signpost in instrument list.

Press Record Button.

Use features in the app to log signposts and stop.

Expand os_signpost

And search Signpost event with name.

I could see Signpost events. However too narrow.

Pinch out, so we can the events widely.

Or drag and drop the range with Option key.

Press the item in Track.

Instruments will provide also duration statistics.

Hover on item of list and press the arrow.

Then I could see details of selected item in the track.

If you select item in list, track will scroll to the related item automatically.

With this feature we can track which task took long time and what happened. 😀

beginAnimationInterval

There is another interval only to measure animation. But there is no endAnimationInterval. It just share endInterval.

let signpostBeginState = signposter.beginAnimationInterval("addItem", id: signpostID)

Result is something different. I don’t know detail yet.

If you found this post helpful, please give it a round of applause 👏. Explore more iOS-related content in my other posts.

For additional insights and updates, check out my LinkedIn profile. Thank you for your support!

Now I’m currently looking for iOS Development Job here in Seoul. If you interested, contact me on Linked-In. But I cannot speak English :)

Troubleshooting

Module … was not compiled for testing

Uncheck Test Target from Profile

References

Measuring Performance Using Logging - WWDC18 - Videos - Apple Developer

OSLog | Apple Developer Documentation

Generating Log Messages from Your Code | Apple Developer Documentation

os_signpost(_:dso:log:name:signpostID:) | Apple Developer Documentation

beginInterval(_:id:) | Apple Developer Documentation