Search Unity

Question Synchronizing custom profiling tools with unity editor profiler

Discussion in 'Scripting' started by ChickensAreDinosaurs, Feb 17, 2023.

  1. ChickensAreDinosaurs

    ChickensAreDinosaurs

    Joined:
    May 11, 2021
    Posts:
    17
    Hello,
    I've been stuck for a little while on trying to synchronize one of our own tools for collecting custom profiling information to correlate with profiling captures; often the profiler will start at a different time from our tool, resulting in the profiling capture being off by 1 frame ahead of our tool.

    Here is an overview of how our tool works:

    - We have an EditorWindow tool with start, stop, etc. buttons to begin collecting some custom data per frame. These functions run with GUILayout.Button in OnGui.

    - The start button will enable a code path in a function attached to Canvas.willRenderCanvases to collect data, and opens and starts the profiler in the editor. This means our data is only collected the next time Canvas.willRenderCanvases fires from when the button is pressed.

    The code run when you press the start button looks like this:
    Code (CSharp):
    1. EditorApplication.isPaused = false;
    2.  
    3. EditorApplication.ExecuteMenuItem("Window/Analysis/Profiler");
    4. Profiler.enabled = true;
    5. ProfilerDriver.enabled = true;
    6.  
    7. yield return new WaitForEndOfFrame();
    8. ProfilerDriver.ClearAllFrames();
    9.  
    10. CustomTool.StartTracking();
    - The stop button will disable this code path and stop the profiler. We also trim any data collected that falls on frames after the profiler stops (but this is just compensation for various sync issues and may be removed), this code is also faulty because the profiler does not seem to stop at the same time we stop our tool.

    This code looks like this:
    Code (CSharp):
    1. Profiler.enabled = false;
    2. ProfilerDriver.enabled = false;
    3. CustomTool.StopTracking();
    4. // Code to trim extra frames from CustomTool
    The trouble primarily occurs with starting the profiler at the same time as our custom tool; the profiler appears to start before our tool which offsets the profiler forwards by 1 frame. I suspect this is related to when the start button is pressed during the current frame, but adding WaitForEndOfFrame before starting both does not seem to change anything, which is surprising.

    I have tried various combinations of trying to wait for the start of the next frame, waiting for the end of the frame between starting the profiler and starting our tool, polling on various profiler variables to be sure the profiler has started collecting data, reversing the order of which tool I start first, etc, but I am doing this mostly blind. I seem to be missing something; it does not seem to be a simple lifecycle problem given that waiting until the end of the frame before starting both does not work.

    Any insight appreciated.
     
  2. alexeyzakharov

    alexeyzakharov

    Joined:
    Jul 2, 2014
    Posts:
    507
    Hi @ChickensAreDinosaurs !

    Do you really need `Profiler.enabled = true;` call? That enables profiler immediately and is runtime (player) api.
    ProfilerDriver.enabled api should enable profiler next editor tick regardless of waits - you could also use `yield return null;` to wait.

    Do you have more details on how do you synchronize frames?
    As your tool I believe records Editor data it may be something you have to compensate due to the fact that when playmode starts Unity does 2 game updates, while profiler considers it as a single editor tick and the offset is introduced due to this peculiar behavior.

    Generally it may be beneficial to consider integrating the data into profiler stream itself so that it is always attached to the correct frame and as a benefit you can pass data from players. Please take a look at e.g. blogpost https://blog.unity.com/technology/customizing-performance-metrics-in-the-unity-profiler how to do that.
     
    MartinTilo likes this.
  3. ChickensAreDinosaurs

    ChickensAreDinosaurs

    Joined:
    May 11, 2021
    Posts:
    17
    Hey @alexeyzakharov, thanks for your response.

    To clarify, this tool is activated some time after preview mode / in-editor play mode has started, it's not fully automated. This means the 2 game updates don't sound like they'd affect me. The only thing that matters is starting both so their first frame of recorded data is the same frame between both. As a user, you would open our tool, enable a Sync Profiler button, and press Start, which would open the profiler and start recording frames with both tools at the same time so you can compare them.

    Unfortunately we cannot use the new tech for the profiler yet as we are on 2020.3 and upgrading that far is not an option at this time.

    To update however, I have landed on something that seems to work after a lot of blind fumbling. Occasionally the first frame in the profiler doesn't match to our tool, but all of the other ones do. Interested to hear if there's a way to reduce this code to only what is necessary. I will try messing with the Profiler.enabled and ProfilerDriver.enabled as soon as I am able; waiting on an import/recompile at the moment.

    Our tool updates on Canvas.willRenderCanvases.
    Called on button press from OnGui (with EditorCoroutineUtility.StartCoroutineOwnerless):
    Code (CSharp):
    1.     private IEnumerator StartTracking()
    2.     {
    3.         EditorApplication.isPaused = false; // WaitForEndOfFrame(?) will cause a deadlock here if the editor is paused.
    4.  
    5.         if (m_syncWithProfiler)
    6.         {
    7.             //Open profiler window (or focus it, if it is already open).
    8.             EditorApplication.ExecuteMenuItem("Window/Analysis/Profiler");
    9.  
    10.             //Prepare the profiler to start.
    11.             ProfilerDriver.ClearAllFrames();
    12.             Profiler.enabled = true;
    13.             ProfilerDriver.enabled = true;
    14.         }
    15.  
    16.         if (!CustomTool.TrackingActive)
    17.         {
    18.             CustomTool.StartTracking();
    19.         }
    20.  
    21.         if (m_syncWithProfiler)
    22.         {
    23.             yield return new WaitForSeconds(1);
    24.             yield return new WaitForEndOfFrame();
    25.  
    26.             CustomTool.Clear();
    27.             ProfilerDriver.ClearAllFrames(); // Now running in sync.
    28.  
    29.             yield return new WaitForEndOfFrame();
    30.             ProfilerDriver.ClearAllFrames(); // Kill the first profiler frame so they are aligned; the profiler is always(?) ahead one frame for some reason.
    31.         }
    32.         yield break;
    33.     }
     
  4. ChickensAreDinosaurs

    ChickensAreDinosaurs

    Joined:
    May 11, 2021
    Posts:
    17
    To update, unfortunately without more blind fumbling simply using ProfilerDriver only does not seem to help with any of the off-by-1 issues on its own. It also stops a frame late interestingly. Using Profiler.enabled = false in the stop method is probably the reason why it stops immediately judging from the information you've provided.
     
  5. alexeyzakharov

    alexeyzakharov

    Joined:
    Jul 2, 2014
    Posts:
    507
    the blog post covers the module extensibility API which is available in 2022.2, but the data api is available in 2020 as well - https://docs.unity3d.com/2020.3/Doc...Profiling.FrameDataView.GetFrameMetaData.html
    you can serialize your data to the profiler frame and then read it back in the tool

    I still see the potential desync in you code, did you try something like

    Code (CSharp):
    1. // Profiler.enabled = true; <-- don't do this
    2. ProfilerDriver.enabled = true;
    3. yield return null;
    4. // profiler is now enabled in the editor
    5.  
    6. CustomTool.StartTracking();
    7.  
    This is the pattern we use in tests to sync on events from scripts
     
    ChickensAreDinosaurs likes this.
  6. ChickensAreDinosaurs

    ChickensAreDinosaurs

    Joined:
    May 11, 2021
    Posts:
    17
    Thanks for your help @alexeyzakharov. Removing the Profiler.enabled previously caused desync in a different place and I didn't want to spend more time moving things around and retrying blindly, but I will try your code pattern when I get some time and see what happens.
     
    alexeyzakharov likes this.