Resolved ECS Job causes frame rate drop in VR: 90 down to 60

Ok, so this is ODD, and I while I want to delete this post out of embarrassment (maybe)

While attempting to find the issue I was turn things on/off, deleting objects from the Hierarchy, commenting code, etc. When I removed my System from the project I got a 10 to 30 fps boost. I was able to reproduce this over and over, on multiple days. So that SEEMED likely.

Then yesterday, while taking a break from attempting to figure out how to research various items within the Profiler, I started going through some basic measures. I went through and updated about 20 materials from HDRP/Lit, to Unlit. I also update the Quality from High to Medium.

Now I am getting 90 fps compiled in VR.

YAY!

So... you might ask, I know I am, why did removing that System affect the performance?

I DON'T KNOW! F!

I still need to learn more about the Profiler, and thanks to those who were helpful here. Profiler is IMPRESSIVE, which also means it's a Deep Well. So I have a lot to learn <sigh>

So at this time I'm gonna mark this as 'answered', but if I learn more I promise to update this post or this thread.


-----------------------------------
Hello gang,

I am upgrading a project from ECS 0.17 to 1.0 and while running a VERY basic job (code below) I am losing 20 to 30 frames per second while in VR.

I have run some basic tests to find this and after I post this I am going to dig into the Profiler to see if I can find more, but I wanted to post this in case there is something simple I am missing:

Notice that within the job, the .Move() function is commented out, as it was with all tests.

Tests done with the menu enabled AND disabled: JOBS > BURST > ENABLE COMPILATION

The number of entities this is affecting is 70.

As I dig in with the profiler I will report back with any details I find

Thanks for ANY feedback.

Code (CSharp):

1.  
2. using Unity.Burst;
3. using Unity.Collections.LowLevel.Unsafe; //This is because of a second job, but not show in this POST.  That job is commented out, so it's not relevant.
4. using Unity.Entities;
5. using Unity.Jobs;
6.  
7. [BurstCompile]
8. public partial struct BattleBotMovementSystem : ISystem
9. {
10.     [BurstCompile]
11.     public void OnCreate(ref SystemState state)
12.     {
13.         state.RequireForUpdate<RandomComponent>();
14.     }
15.  
16.     [BurstCompile]
17.     public void OnUpdate(ref SystemState state)
18.     {
19.         float deltaTime0 = SystemAPI.Time.DeltaTime;
20.  
21.         //60 FPS
22.         //JobHandle jobHandle = new BattleBotMoveJob
23.         //{
24.         //    deltaTime = deltaTime0
25.         //}
26.         //.ScheduleParallel(state.Dependency);
27.         //jobHandle.Complete();
28.  
29.  
30.         //70 fps
31.         new BattleBotMoveJob
32.         {
33.             deltaTime = deltaTime0
34.         }
35.         .Schedule();
36.  
37.  
38.         //75 to 80 fps
39.         //new BattleBotMoveJob
40.         //{
41.         //    deltaTime = deltaTime0
42.         //}
43.         //.Run();
44.  
45.     }
46. }
47.  
48. [BurstCompile]
49. public partial struct BattleBotMoveJob : IJobEntity
50. {
51.     public float deltaTime;
52.  
53.     [BurstCompile]
54.     public void Execute(BattleBotMoveAspect battleBotMoveAspect)
55.     {
56.         //battleBotMoveAspect.Move(deltaTime);
57.     }
58. }

 

This is with BURST enabled AND disabled. No difference. Thanks though.

 

Now, the reason I "KNOW" this is an issue with the job is that if I remove that file, "BattleBotMovementSystem.cs" from the project and compile, I get 90 FPS. I spent yesterday removing everything else (all buildings, etc) and still the issue remained. That said, I can be VERY wrong. (often am)


Follows is the BattleBotMoveAspect as requested. Note that within the Job the Move function is commented out, so I am unsure why you want to see this, but hey, WHATEVER helps. (heck, if you want I'll post the entire project to my site for you to download, if YOU want. Please don't think Unity OWES me their time, you don't. I'm posting this in case there is an issue)

I have been running these tests on a compiled version showing FPS within the game. I am just starting to look at the profiler while in editor. So if you want me to look at something specific, just let me know.

Jobs Menu settings: https://imgur.com/a/4znnZt8

Unity 2022.3.0
Entities: 1.0.11
Burst: 1.8.7
Collections: 2.1.4
OpenXR
Quest 2 via Link Cable or Air Link (makes no difference in the FPS)

Code (CSharp):

1.  
2. using Unity.Mathematics;
3. using Unity.Entities;
4. using Unity.Transforms;
5. using UnityEngine;
6.  
7. public readonly partial struct BattleBotMoveAspect : IAspect
8. {
9.     private readonly RefRW<LocalTransform> localTransform;
10.     private readonly RefRO<Speed> speed;
11.     private readonly RefRW<TargetPosition> targetPosition;
12.     private const float reachedDistance = 0.4f;
13.     private const float minX = -1872f;  //The points that outline the play-field
14.     private const float maxX = -1591f;
15.     private const float minZ = -1509f;
16.     private const float maxZ = -1394f;
17.     private const float yOffset = -6.5f;
18.     private const float speedOffset = 0.124f;
19.  
20.     public void Move(float deltaTime)
21.     {
22.         float3 direction = math.normalize(targetPosition.ValueRO.value - localTransform.ValueRO.Position);
23.  
24.         localTransform.ValueRW.Position += direction * deltaTime * speed.ValueRO.value;
25.  
26.         Quaternion lookOnLook = Quaternion.LookRotation(targetPosition.ValueRO.value - localTransform.ValueRO.Position);
27.         localTransform.ValueRW.Rotation = Quaternion.Slerp(localTransform.ValueRO.Rotation, lookOnLook, deltaTime * (speed.ValueRO.value * speedOffset));
28.     }
29.  
30.     public void ReachedTargetPosition(RefRW<RandomComponent> randomComponent)
31.     {
32.         //if (math.distancesq(localTransform.ValueRO.value, targetPosition.ValueRO.value) < reachedDistance)
33.         if (math.distance(localTransform.ValueRO.Position, targetPosition.ValueRO.value) < reachedDistance)
34.         {
35.             targetPosition.ValueRW.value = NextPosition(randomComponent);
36.         }
37.     }
38.  
39.     private float3 NextPosition(RefRW<RandomComponent> randomComponent)
40.     {
41.         return new float3
42.         {
43.             x = randomComponent.ValueRW.random.NextFloat(minX, maxX),
44.             y = yOffset,
45.             z = randomComponent.ValueRW.random.NextFloat(minZ, maxZ)
46.         };
47.     }
48. }

 

I agree. Sadly my knowledge of the Profiler is very limited, but I am looking through it right now.

I am sure that it is something stupid I am doing, so thank you kindly for your time. Whenever I find a solution I will post back.

 

Even if you don't do anything within the BattleBotMoveJob you are introducing dependencies in the complete system chain. Your job accesses three components: Speed (readonly), LocalTransform (write) and TargetPosition (write). When you schedule the job via the 70 fps code above, the job has to wait for other jobs accessing Speed (writeonly), LocalTransform (read or write) or TargetPosition (read or write) running before in the player loop. So you may introduce some waiting time until your job gets started. When you simply don't start the BattleBotMoveJob this won't happen. But how this affects performance depends on the other systems and their usage of the three components. Also LocalTransform is a ECS built-in component used by ECS built-in systems. Many things changed in ECS since 0.17. Profiling may give you some insights.

 

WOW have things changed! Thanks for the clarification on data usage, good points. However this is currently the only System running (there is one more system at startup that spawns the BattleBots, but that is disabled after finishing)

So yea, I am ATTEMPTING to look at the Profiler, but again WOW. I am in over my head with this... so gonna take a minute or two. Though I promise to report back, whenever I find something.

Thanks again

 

Ok gang,

An ignorant update: Since my knowledge of Profiler is limited I thought it important to post this IN CASE it's of value

If anyone has a way for me to research a given item within the profiler and it's value. ie: some of these items are valid in the time they take, and other items within the hierarchy should be resolved. How do I know which is which?

I updated my code so I could find this one item.

Code (CSharp):

1.  
2.         Profiler.BeginSample("BattleBotMoveJob Sample");
3.         JobHandle jobHandle = new BattleBotMoveJob
4.         {
5.             deltaTime = dt
6.         }
7.         .ScheduleParallel(state.Dependency);
8.         jobHandle.Complete();
9.         Profiler.EndSample();
10.  

Here you can see that that one item is taking ONE PERCENT of the PlayerLoop (which on this frame is 79% of the entire process)
https://imgur.com/a/FHAGj3z

So yea, there are obviously some limits on my knowledge, so what I would really like is a hint on where to go for info. (I don't expect anyone to answer ever "what is this percent", "what is this function" "is it important")

Thanks kindly.

 

I am not sure if I can answer your question, but you can get a bit more info. As mentioned in my post above there are two profiling relevant things happening: One thing is waiting for dependencies and the other thing thereafter is executing the job in separate job worker threads. Both may take their time. You can measure how many time it is waiting for dependencies and how many time for the execution itself is spent. I updated your code a bit:

Code (CSharp):

1. Profiler.BeginSample("BattleBotMoveJob Wait");
2. state.Dependency.Complete();
3. Profiler.EndSample();
4.  
5. Profiler.BeginSample("BattleBotMoveJob Sample");
6. JobHandle jobHandle = new BattleBotMoveJob
7. {
8.     deltaTime = dt
9. }
10. .ScheduleParallel(state.Dependency);
11. jobHandle.Complete();
12. Profiler.EndSample();

 

Thanks @FaithlessOne I will look into that.

Have a wonderful evening

 

Since you mentioned VR, note that the compositor will try to keep a consistent frame rate, so if you can't render at 120Hz it will drop to 60Hz and use reprojection for the missing frame. But looking at the FPS you are reporting this is not what is happening. Profiling without VR and with Vsync disabled could give you a better view of what your FPS is doing.

With OpenXR I get a XRBeginFrame in the profiler timeline, that stretches out the frame to fit in the refresh rate. Maybe without the job this is very small, and with the job you are missing the required frame rate triggering some big FPS drop combined with XRBeginFrame taking a big part of this new Frame.

 

Thanks. That's enlightening.

Have a wonderful weekend