Search Unity

  1. Unity Asset Manager is now available in public beta. Try it out now and join the conversation here in the forums.
    Dismiss Notice

Profile Analyzer: feedback on case 1156539

Discussion in 'Profiler Previews' started by roberto_sc, Jun 4, 2019.

  1. roberto_sc

    roberto_sc

    Joined:
    Dec 13, 2010
    Posts:
    144
    This is a message to Lyndon Homewood, he answered my case 1156539 but I had further questions. Fogbugz says to "send email to accounts@unity3d.com mentioning 'Case 1156539' in the subject" but that only created a new Customer Case ¯\_(ツ)_/¯ how do I follow up on a case??

    Lyndon,
    Thank you so much for the explanation.
    It took me a while to notice the "Top markers from median frame" label in the Top 10 but even then I couldn't figure out why it was different.


    The information on Top 10 doesn't seem much important to me anymore: it is still probably useful to know the size of the medium frame, but knowing how a particular method ran in the median frame seems pointless; it doesn't tell me anything about how that method is performing, and if you want to look at a method in a single frame, the median frame is as good as any. Does my thought make sense?

    What's the best way to find a culprit that's making my frame summary mean/medium higher? At first I thought of simply checking the methods with highest mean or medium but I actually have to look the occurrences counter and/or the occurrences in the graph. Difference between mean and medium may help indicate spikes, but there's nothing that tells me how much impact a method has over the total set, is there?

    Thanks again.
     
    roberto_sc, Jun 4, 2019
    #1
    tigerleapgorge likes this.

  2. lyndon_unity

    lyndon_unity

    Unity Technologies

    Joined:
    Nov 2, 2017
    Posts:
    66
    Hi, I'll break down your post and try and offer some advice for each part:

    Top 10 markers section
    Regarding the Top 10 markers section.
    This shows the frame with the median overall frame time.
    The median frame is assumed to be the 'average' or 'most representative' frame.
    It is often a good indication of the main contributors to the frame time.

    In the comparison view this offers some insights into what has got slower.
    By default it shows a percentage of the longest frame time so you can compare if the ratio of time in the frame changes. You can change the display to use the longest time as the bar length, which means you can compare the absolute marker time more easily.

    (In your example only the FixedUpdate.PhysicsFixedUpdate shows up as a new entry in the second scan. Some others change length which shows there is a different balance of activity in the frame)


    Marker timings / Upcoming features
    Before answering the query for the 'best way to find a culprit that's making my frame summary mean/medium higher' I should highlight the following:

    The markers in the list view include the times of the children.
    In the compare view we default to sorting by the absolute difference in time so you can see what marker times changed the most.

    Some features that are coming in the next iteration that may help tracking down the main contributor are:
    • Adding a column to show the total time of a marker over all frames
    • Option to show the 'self time' excluding children (as an alternative to the time including children)

    Best way to find a culprit that's making my frame summary mean/medium higher
    Start by looking at the marker at the top of the comparison list as the main contributor.
    Work down until you find the one which is slower in your second scan.
    (The Right Median value is higher than the Left Median value and the Diff is positive, or 'the orange bar is longer')

    View the median frame in the Unity Profiler's timeline or hierarchy views to see what children that marker has. (Below I'll give you a specific example for the scans you sent to us.)
    Return to the profile analyser to see where this markers children appear in the list.
    This should give you a good idea what level of the callstack the slowdown is most noticeable at.


    Your specific example:
    Based on the captures you previously sent (with the first loaded into the left slow and 2nd in the right slot)
    We see FixedUpdate.PhysicsFixedUpdate at the top as the marker that has slowed down the most (on the main thread).
    Then looking at the Profiler timeline view we can see what markers are a child of this. The hierarchy is as follows:
    • FixedUpdate.PhysicsFixedUpdate
    • Physics.ProcessReports
    • Physics.TriggerStays
    • LinkModel.OnTriggerStay
    Back in the compare view we can see that all of these are showing performance drops. Remember the parent includes the child time here so look out for a large difference between the markers to see where the time is spent.

    You can also see that LinkModel.OnTriggerStay has a high call count.
    Overall the number of FixedUpdate.PhysicsFixedUpdate calls is slightly higher, but the number of calls to OnTriggerStay is much higher.
    It would appear the number of updates is similar but there are more collisions / intersections with the trigger region are occurring in the second scan.
    Hopefully your knowledge of the changes between scans and scene setup will help identify how you can resolve this particular slow down.


    Summary
    The profile analyzer is a handy tool for dissecting the performance issues, and it will get easier to drill down to the key areas in the next update.
     
    lyndon_unity, Jun 12, 2019
    #2
    tigerleapgorge, Cromfeli, MartinTilo and 1 other person like this.

  3. roberto_sc

    roberto_sc

    Joined:
    Dec 13, 2010
    Posts:
    144
    Thank you so much for your help.

    The total time over all frames feature would be appreciated. But I want to add that at a later point I found out about the ability to right-click at the time line and Order by Frame Time.


    upload_2019-6-21_9-47-32.png



    This helps a lot to find who is adding time to the game as a whole: go to the part where frames got lengthier and try to find the common denominator.
     
    roberto_sc, Jun 21, 2019
    #3
    tigerleapgorge, Cromfeli, MartinTilo and 1 other person like this.

  4. Cromfeli

    Cromfeli

    Joined:
    Oct 30, 2014
    Posts:
    202
    This is now included?
     
    Cromfeli, Dec 4, 2019
    #4

  5. lyndon_unity

    lyndon_unity

    Unity Technologies

    Joined:
    Nov 2, 2017
    Posts:
    66
    Yes it's included in 0.5.0
    • You can turn if on by right clicking the column headers and selecting "Total" (and/or "Total Bar")
    • There is also a "Marker Columns" drop down for quick selection of commonly used column combinations in the marker table. "Time With Totals" and "Totals" both include this new column.
    It filters the times to the current frame selection. So by default it will be all frames and you can select a sub region if required.
     
    lyndon_unity, Dec 4, 2019
    #5
    Cromfeli likes this.