Profiling Jobs

What’s the best way to find out which calls are taking the most time inside of a Bursted job?

I’m not sure how to use the Unity profiler to do this.

Thank you for any advice. :slight_smile:

Using the profiler, you cant really see “inside” a job and how long individual commands are taking.

Instead, you can cut up a job into multiple different jobs. If you’re using Entities.ForEach or Jobs.WithCode, you can also name the job produced by that lambda function using .WithName(“name”).

Then go to the profiler, turn it on, then scroll down to “Job”.

Click the expand arrow button next to Job to see individual threads and your job durations will be shown.

I didnt name mine so they’re all job0, job1, job2, etc but they’re durations are displayed in parathesis to the right of the name and the (Burst) notification.

You don’t have to split your jobs for this. You can instrument sections of your job using ProfilerMarkers. In 2020.1 you can also add metadata (to provide additional info from within the job to the Profiler) using the ProfilerUnsafeUtility.BeginSampleWithMetadata API.
We’re working on adding a more user friendly and strippable API
layer on top of ProfilerUnsafeUtility but you can already use this API until that is ready. (Note: this API works in jobs, I’m currently not 100% sure that this works with Burst, as I’m not at my computer but I’ll check next week.)

2 Likes

Such great news, thank you!

Would you mind shedding some light on how to use ProfilerUnssafeUtility.BeginSampleWithMetadata in a job? The example on that confluence page stores a pointer to some unknown piece of data that’s passed into the DoWork() function:

metadata[0].Ptr = UnsafeUtility.AddressOf(ref num);

I’m unsure what pointer I should assign in the case of a job.

Ty!

That’s a pointer to the meta data to report with the marker. The type is defined on creation of the Marker where
ProfilerUnsafeUtility.CreateMarker’s last parameter defines the amount of metadata parameters and
ProfilerUnsafeUtility.SetMarkerMetadata defines the first paramerer’s type as ProfilerMarkerDataType.Int32, i.e. int.
So you can pass in any data outlined by the enum ProfilerMarkerDataType, but Blob8 can’t be visualized in the selection tool-tip of timeline view, where you’d see the meta data for all other types. With this you can e.g. report the index or count of the data you’re operating on.

But using the MetaData APIs is just an additional flourish in this. To see which part of the job took how long, the ProfilerMarker.Begin/End or ProfilerUnsafeUtility.BeginSample / EndSample calls should already offer a good starting point.

2 Likes

The example how to use ProfilerMarker with Burst jobs:

class Example
{

    static readonly ProfilerMarker myMarker = new ProfilerMarker("Inner job workload");

    static void ScheduleJob()
    {
        var job = new TestJob
        {
            Marker = myMarker,
        };
        job.Schedule();
    }
   
    public struct TestJob : IJob
    {
        public ProfilerMarker Marker;

        void IJob.Execute()
        {
            Marker.Begin();
            // Workload
            Marker.End();
        }
    }
}
9 Likes

I have 3 questions :

  1. Why do we have to pass the profilerMarker to the job instead of using it directly knowing that it’s a readonly static variable ?

[EDIT]
2) does using the profilerMarker have any performance cost ?
3) if yes (2), is it possible to disable the ProfilerMarker for release builds ?

Answer : Methods Begin and End are marked with ConditionalAttribute. They are conditionally compiled away and thus have zero overhead in non-Developmenet (Release) builds.

Thanks!

1 Like

Burst doesn’t support static init of string literals yet. It is not the best for usability here - we are planning to fix that for profiler markup.

2 Likes

(Necro but right on topic)

Using Profiler markers, can I see the total time for job execution somewhere? If I go to Hierarchy, I can see that I can select specific threads to get to the timing data for the markers:

But I’d be most interested in seeing how much time in total it’s spending on a given marker rather than how much time it does so on each individual worker (which for me is already 23 threads; someone on a ThreadRipper must be looking at a hopeless situation :)).

PS: Hey Alexey :slight_smile: This is Rene.

Timeline view shows this. Just click on a rect and it will show you instance, thread total, and frame total timings. The last one is what you want.

1 Like