Points of Interest — Profiling Unity with Xcode Instruments

TL;DR

Xcode Instruments allows custom markers (Signposts) being inserted by the application, while profiling. By using this feature wisely you can quickly identify marked code blocks in Xcode Instruments and easily determine performance characteristics. This article describes how to combine this feature with Unity by developing a module for Signposts.

Xcode Instruments with Signposts

When you are interested in one of these points, Signposts are the way to go:

  • When do certain events happen?
  • How often do they happen?
  • How much time is spent in those events?
  • Where in the source code was the event started/stopped?
  • Is there a correlation to other performance metrics (e.g. CPU, Allocations, etc.)?
  • Compare multiple Xcode runs and check by looking at the events if there are performance improvements

Introduction

Unity is nowadays one of the most widespread game engines in use. Its ease of use and the huge amount of features makes it so popular, especially for mobile games. When developing mobile games you have to be very careful on how to use the limited resources you have available. If your app suffers of a low frame rate because of wasted CPU/GPU or if your app gets terminated by iOS because you use too much memory your users won’t have a good time playing your game and most likely delete your app immediately. As a mobile developer you always have to take a close look on how your app utilises the existing resources. You also need a way to easily correlate the profiling data with what is happening in your game. Regularly profiling is a must.

In this blog post you will learn on how to get more details out of the profiling data on iOS. We introduce a solution that lets you insert markers into Xcode Instruments timeline and also show how to use this with your Unity app.

Unity Profiler

Unity already ships with a great Profiler. With the integrated Profiler, you can easily check your game for performance issues without actually deploying it on a physical device. You can even connect the Unity profiler to your app running on a device. That is a tremendous help and you gain valuable information from this functionality that helps you make your game even better. But sometimes you even have to dig a bit further (or just perhaps you are curious what is going on under the hood). Maybe because you want to check the exact memory allocations on iOS level or check how much CPU your app consumes. Then you need a native Profiling tool like Apple’s Xcode Instruments that tells you the iOS point of view regarding your app’s performance metrics. Xcode Instruments Profiler comes with Xcode and it is free to use. You can download it either from the Mac AppStore or from Apple’s developer site: https://developer.apple.com.

Xcode Instruments is a very powerful tool that lets you decide what kind of performance metric categories you want to collect (e.g. CPU usage, memory allocations, system calls, etc). Each category is called Instrument and can be added or removed from your trace setup.

Xcode Instruments collects a huge amount of data when profiling your app and this enables you to inspect your app behavior in much more great detail. For example, you can get the native call stack for every allocation (and the corresponding de-allocation) that happens in your app. You can let Xcode Instruments track every system call and from where in your code it was triggered.

Xcode Instruments Profiler

Even though with Unity your game gets converted from C# to C++ via Unity’s IL2CPP tool the symbol names are still preserved and even when you are not that familiar with C++ you will not get lost with the C++ callstacks provided.

Points of Interest and Signposts

As you can imagine you can easily be overwhelmed by the sheer amount of data Xcode Instruments provides. And because it takes a lot of time to find the bit of data you are looking for you probably will profile your app less often and your app’s performance and quality will be affected by this in a negative way.

But there’s help! At WWDC 2016 (Session 411 — System Trace in Depth), Apple mentioned some tiny little functions in their API that will help you a lot navigating through the performance data maze of your app like a wizard (requires iOS 10+ and Xcode 8+)! As you might already know some Instruments insert markers (Signposts) in the timeline view in order to annotate the metrics.

Signpost markers in Xcode Instruments

Wouldn’t it be great if your app could do this, too? For the examples in the article, we make use of the Unity Example Project Endless Runner that can be downloaded from the Unity Asset-Store for free. In this little game, you control a cat running down the street, collecting items and trying to avoid obstacles like trash-bins, dogs, etc.

Sample Project Endless Runner

In the first example, we implement Signpost markers every time you collide with a coin (fishbone) or an obstacle. In the screenshot below you see an Instruments run with Instruments for CPU, Allocations, and Points of Interest. The Points of Interest Instrument is the container that will show all your custom Signposts while your app is running. Right now it shows Signpost events for Coin collisions and Obstacle collisions.

Signpost events

Implementing Signposts with Unity

The following three C functions found in sys/kdebug_signpost.h will help us with adding Signposts to your app:

int kdebug_signpost(uint32_t code, 
uintptr_t arg1,
uintptr_t arg2,
uintptr_t arg3,
uintptr_t arg4);
int kdebug_signpost_start(uint32_t code, 
uintptr_t arg1,
uintptr_t arg2,
uintptr_t arg3,
uintptr_t arg4);
int kdebug_signpost_end(uint32_t code, 
uintptr_t arg1,
uintptr_t arg2,
uintptr_t arg3,
uintptr_t arg4);

For the first example, we use kdebug_signpost which inserts a simple event (Point) to the Points of Interest timeline. This method accepts a code parameter and four additional argument parameters (arg1, arg2, arg3,arg4). The code parameter can be used by your app to distinguish different events, each event using a different code. In our example Coin collision uses a value of 0 and Obstacle collision a value of 1.

Recording options

In order to enable Xcode Instruments to show a corresponding string description for every code, you can map the codes to string descriptions by selecting File -> Recording Options and then select Points of Interest in the Options for drop-down (see screenshot on the left). By adding string descriptions in the Signpost Code Names list, Xcode Instruments will show string descriptions instead of the plain code values.

We also check the setting Color using last argument so that we can apply different colors to Signposts. This means that Xcode Instruments expects that the value of arg4 will contain the color to be used for the event.

Signpost Events

For being able to use the kdebug_signpost method in Unity we need to create a little iOS plugin.

Therefore we add SignPost.mm with the code below:

#import <sys/kdebug_signpost.h>
extern "C"
{
int SignPostEvent(unsigned int _code,
unsigned int _arg1,
unsigned int _arg2,
unsigned int _arg3,
unsigned int _arg4)
{
return kdebug_signpost(_code, _arg1, _arg2, _arg3, _arg4);
}
}

Both files should be located inside a Plugins/iOS folder so that they get only included in the iOS build.

For being able to use this native C function in C# we create a wrapper for it:

using System.Runtime.InteropServices;
namespace SignPosts
{
public class SignPost
{
#if UNITY_IOS && !UNITY_EDITOR
        [DllImport("__Internal")]
public static extern int SignPostEvent(uint _code,
uint _arg1,
uint _arg2,
uint _arg3,
uint _arg4);
#else
        public static int SignPostEvent(uint _code, 
uint _arg1,
uint _arg2,
uint _arg3,
uint _arg4)
{
return -1;
}
#endif
}
}

The class SignPost offers the C# version of the function SignPostEvent which can from now on be used from within your C# project. We also added a stub version of SignPostEvent. This way we do not need to wrap all usages of SignPosts.SignPostEvent inside an #if UNITY_IOS && !UNITY_EDITOR block. In case the app is running on a different platform SignPosts.SignPostEvent just does nothing and might be even stripped by the compiler during the optimization phase.

To make the implementation more comfortable to use we create an enum that defines the codes (called categories) we pass as the first parameter to SignPosts.SignPostEvent.

namespace SignPosts
{
public enum SignPostCategory
{
CoinCollision = 0,
ObstacleCollision = 1
}
}

The same we do for the color values. By using enum types and not a bunch of hardcoded values the usage of the API becomes much more clear.

namespace SignPosts
{
public enum Color: uint
{
Blue = 0,
Green = 1,
Purple = 2,
Orange = 3,
Red = 4
}
}

We now combine all this in a class called SignPostManager. This class is the main entry point for the user. Later we will see that this class does even more.

namespace SignPosts
{
public static class SignPostManager
{
#if UNITY_IOS && !UNITY_EDITOR
        public static void SignPostEvent(SignPostCategory _category,
Color _color,
uint _arg1 = 0,
uint _arg2 = 0,
uint _arg3 = 0)
{
SignPost.SignPostEvent((uint)_category,
_arg1,
_arg2,
_arg3,
(uint)_color);
}
#else
        public static void SignPostEvent(SignPostCategory _category,
Color _color,
uint _arg1 = 0,
uint _arg2 = 0,
uint _arg3 = 0)
{
}
#endif
}
}

By putting all this together adding Signposts in the game is pretty easy. Adding a Signposts to the example project whenever the cat hits a collider now looks like this:

protected void OnTriggerEnter(Collider c)
{
if (c.gameObject.layer == k_CoinsLayerIndex)
{
SignPostManager.SignPostEvent(SignPostCategory.CoinCollision,
SignPostManager.Color.Blue);

}
else if(c.gameObject.layer == k_ObstacleLayerIndex)
{
SignPostManager.SignPostEvent(
SignPostCategory.ObstacleCollision,
SignPostManager.Color.Orange);

}
}

That’s easy, isn’t it? But we are not done, yet.

Signpost Intervals

Beside the Signpost events, you can also insert Signpost intervals. The additional value of Signpost intervals is that they contain a start and end event which implicitly delivers a duration. This comes in handy when you want to track how long a specific operation in your app takes and where it started and ended (including call stacks).

Signpost intervals

In the example project, we will add an interval Signpost for loading assets asynchronously. In the screenshot above you can see the output. All async load operations are shown as green Signpost interval markers. In the lower pane you see a list of all async loads that happened and some more details like duration, start thread and call-stack (right panel).

You might have already noticed the two functions kdebug_signpost_start and kdebug_signpost_end mentioned at the beginning of the article. These two functions actually start and stop a specific Signpost. Let’s add the missing code.

First we add the two methods to our iOS plugin in SignPost.mm:

#import <Foundation/Foundation.h>
#import <sys/kdebug_signpost.h>
extern "C"
{
    int SignPostStart(unsigned int _code, 
unsigned int _arg1,
unsigned int _arg2,
unsigned int _arg3,
unsigned int _arg4)
{
return kdebug_signpost_start(_code,
_arg1,
_arg2,
_arg3,
_arg4);
}
    int SignPostEnd(unsigned int _code, 
unsigned int _arg1,
unsigned int _arg2,
unsigned int _arg3,
unsigned int _arg4)
{
return kdebug_signpost_end(_code,
_arg1,
_arg2,
_arg3,
_arg4);
}
}

Now, we have to import these methods to be able to use them in C# code:

using System.Runtime.InteropServices;
namespace SignPosts
{
public class SignPost
{
#if UNITY_IOS && !UNITY_EDITOR
        ...
        [DllImport(“__Internal")]
public static extern int SignPostStart(uint _code,
uint _arg1,
uint _arg2,
uint _arg3,
uint _arg4);
        [DllImport(“__Internal")]
public static extern int SignPostEnd(uint _code,
uint _arg1,
uint _arg2,
uint _arg3,
uint _arg4);
#else
        ...
        public static int SignPostStart(uint _code, 
uint _arg1,
uint _arg2,
uint _arg3,
uint _arg4)
{
return -1;
}
        public static int SignPostEnd(uint _code, 
uint _arg1,
uint _arg2,
uint _arg3,
uint _arg4)
{
return -1;
}
#endif
}
}

The last step now is to integrate the new methods into the SignPostManager class.

using System.Collections.Generic;
namespace SignPosts
{
public static class SignPostManager
{
private static readonly uint s_invalidEventId = uint.MaxValue;
#if UNITY_IOS && !UNITY_EDITOR
        private static uint s_categoryCounter = 0;
private static Dictionary<uint, SignPostCategory> s_eventId2SignPostCategory = new Dictionary<uint, SignPostCategory>(32);
private static Dictionary<uint, Color> s_eventId2SignPostColor = new Dictionary<uint, Color>(32);
        public static uint SignPostStart(SignPostCategory _category,
Color _color,
uint _arg1 = 0,
uint _arg2 = 0)
{
var eventId = s_categoryCounter++;
s_eventId2SignPostCategory[eventId] = _category;
s_eventId2SignPostColor[eventId] = _color;
            SignPost.SignPostStart((uint)_category, 
eventId,
_arg1,
_arg2,
(uint)_color);
            return eventId;
}
        public static void SignPostEnd(uint _eventId, 
uint _arg1 = 0,
uint _arg2 = 0)
{
var category = (uint)s_eventId2SignPostCategory[_eventId];
var color = (uint)s_eventId2SignPostColor[_eventId];

SignPost.SignPostEnd(category,
_eventId,
_arg1,
_arg2,
(uint)color);
            s_eventId2SignPostCategory.Remove(_eventId);
s_eventId2SignPostColor.Remove(_eventId);
}
#else
        public static uint SignPostStart(SignPostCategory _category,
Color _color,
uint _arg1 = 0,
uint _arg2 = 0)
{
return s_invalidEventId;
}
        public static void SignPostEnd(uint _eventId, 
uint _arg1 = 0,
uint _arg2 = 0)
{
}
#endif
}
}

We now have everything in place to also add Signpost intervals to our game. But lets first go through the code a bit more detailed. As with Signpost events you also need to specify a category and color for each interval you start when calling SignPostManager.SignPostStart. You then need to store the return value because this value is the id of the just started Signpost which you will need later when you want to stop the interval via SignPostManager.SignPostEnd. But how does Xcode Instruments know about which Signpost interval we want to stop? When configuring Xcode Instruments as described above, you also need to check the option Code and first argument for the setting Match signpost intervals by. This tells Xcode Instruments that the arg1 parameter, for Signpost intervals, always contains a unique identifier, provided by the application which identifies a specific Signpost interval. So whenever you start a new Signpost interval via SignPostManager.SignPostStart, a unique identifier is created internally and returned. This way you can use multiple Signpost intervals of the same category in parallel and even on multiple threads. But be aware that the current implementation of the SignPostManager class is not thread-safe which would be an easy feature to add.

Let’s see how to integrate this in the example app:

public class AssetBundleLoadAssetOperationFull
{
    protected uint m_signPostId = 0;
    public AssetBundleLoadAssetOperationFull(string bundleName,  
string assetName,
System.Type type)
{
        m_signPostId = SignPostManager.SignPostStart(               
SignPostCategory.LoadAssetAsync,
SignPostManager.Color.Green);
}
    public override bool IsDone ()
{
        if(m_Request != null && m_Request.isDone)
SignPostManager.SignPostEnd(m_signPostId);
        return m_Request != null && m_Request.isDone;
}
}

We inserted the Signpost handling code in AssetBundleLoadOperationFull which is the central point for asynchronous asset loading in the example project. In its constructor, we call SignPostManager.SignPostStart and remember the return value which we will use later to finish the Signpost interval. Once the asset was loaded, which is checked in AssetBundleLoadAssetOperationFull.IsDone we call SignPostManager.SignPostEnd and pass the value we stored in m_signPostId.

So what?

By adding Signposts (events and intervals) wisely and continuously to your game you will benefit from the following:

  • When do certain events happen?
  • How often do they happen?
  • How much time is spent in those events?
  • Where in the source code was the event started/stopped?
  • Is there a correlation to other performance metrics (e.g. CPU, Allocations, etc.)?
  • Compare multiple Xcode runs and check by looking at the events if there are performance improvements

It would be great if Unity would also add support for Signposts and trigger them at central points in their engine. This would make Unity’s engine behavior more transparent and the users could even better optimize their app for Unity.

Software used

  • Xcode 9.1
  • Unity 2017.2.0f3

References

One clap, two clap, three clap, forty?

By clapping more or less, you can signal to us which stories really stand out.