Performance related issue with C#

Hello all,

Recently I have been spending a lot of time on improving my skills on theory of programming so I can better structure my code. During this research on the theory of programming I came across Clean Code (I'm a self-thought developer, so it took a little bit time to get there..) Anyway, the refactoring the code and extracting the methods until they get to a point about max.10-20 lines part is really surprised me since my previous knowledge on this matter is how much you rely on method calls will affect your performance since the process on cpu will make more calls to the address points related to these actions.

To test this argument by myself, I wrote a JavaScript application and run it on node.js,

Code (JavaScript):

1. const ITERATION_COUNT = 5000;
2. const SHOW_NUMBER_VERIFICATION = false;
3.  
4. class TestCallToClassMethod
5. {
6.     constructor(num1, num2)
7.   {
8.       this.num = this.multiply(num1, num2);
9.   }
10.  
11.   multiply(num1, num2)
12.   {
13.       return num1 * num2;
14.   }
15. }
16.  
17. function _TestCallToClassMethod()
18. {
19.   var start = Date.now();
20.   var num = 0;
21.   for (var i = 0; i < ITERATION_COUNT; i++)
22.   {
23.     for (var j = 0; j < ITERATION_COUNT; j++)
24.     {
25.       var test = new TestCallToClassMethod(i, j);
26.       num += test.num;
27.     }
28.   }
29.   var end = Date.now();
30.   var time = end-start;
31.  
32.   if (SHOW_NUMBER_VERIFICATION)
33.     console.log("Test Call To Class Method Number: " + num);
34.   console.log("Test Call To Class Method Time: " + time);
35. }
36. _TestCallToClassMethod();
37.  
38. class TestCallToStaticClassMethod
39. {
40.     constructor(num1, num2)
41.   {
42.       this.num = Math.Multiply(num1, num2);
43.   }
44. }
45.  
46. class Math
47. {
48.   static Multiply(num1, num2)
49.   {
50.     return num1 * num2;
51.   }
52. }
53.  
54. function _TestCallToStaticClassMethod()
55. {
56.   var start = Date.now();
57.   var num = 0;
58.   for (var i = 0; i < ITERATION_COUNT; i++)
59.   {
60.     for (var j = 0; j < ITERATION_COUNT; j++)
61.     {
62.       var test = new TestCallToStaticClassMethod(i, j);
63.       num += test.num;
64.     }
65.   }
66.   var end = Date.now();
67.   var time = end-start;
68.  
69.   if (SHOW_NUMBER_VERIFICATION)
70.     console.log("Test Call To Static Class Method Number: " + num);
71.   console.log("Test Call To Static Class Method Time: " + time);
72. }
73. _TestCallToStaticClassMethod();
74.  
75. class TestCallToConcreteClass
76. {
77.     constructor(num1, num2)
78.   {
79.       var multiply = new Multiply(num1, num2);
80.       this.num = multiply.num;
81.   }
82. }
83.  
84. class Multiply
85. {
86.     constructor(num1, num2)
87.   {
88.       this.num = num1 * num2;
89.   }
90. }
91.  
92. function _TestCallToConcreteClass()
93. {
94.   var start = Date.now();
95.   var num = 0;
96.   for (var i = 0; i < ITERATION_COUNT; i++)
97.   {
98.     for (var j = 0; j < ITERATION_COUNT; j++)
99.     {
100.       var test = new TestCallToConcreteClass(i, j);
101.       num += test.num;
102.     }
103.   }
104.   var end = Date.now();
105.   var time = end-start;
106.  
107.   if (SHOW_NUMBER_VERIFICATION)
108.     console.log("Tell Call To Concrete Number: " + num);
109.   console.log("Tell Call To Concrete Class: " + time);
110. }
111. _TestCallToConcreteClass();
112.  
113. function _TestInlineAction()
114. {
115.   var start = Date.now();
116.   var num = 0;
117.   for (var i = 0; i < ITERATION_COUNT; i++)
118.   {
119.     for (var j = 0; j < ITERATION_COUNT; j++)
120.     {
121.       num += i * j;
122.     }
123.   }
124.   var end = Date.now();
125.   var time = end-start;
126.  
127.   if (SHOW_NUMBER_VERIFICATION)
128.     console.log("Test Inline Action Number: " + num);
129.   console.log("Test Inline Action Time: " + time);
130. }
131. _TestInlineAction();

This script gave me the following results on my PC;

Code (JavaScript):

1. Test Call To Class Method Time: 42
2. Test Call To Static Class Method Time: 42
3. Tell Call To Concrete Class: 42
4. Test Inline Action Time: 37

And it really impressed me that calling other classes, instantiating objects and etc. didn't affect the performance too much. But just to be sure I wanted to conduct a similar test on Unity with C# too. So I wrote the following script and attached it on a GameObject in a fresh scene that is also in a fresh Unity project.

Code (CSharp):

1. using System;
2. using UnityEngine;
3. using UnityEngine.UI;
4.  
5. namespace PerformanceTest
6. {
7.     public class TestingBehaviours : MonoBehaviour
8.     {
9.         [SerializeField] private Text _text;
10.  
11.         private readonly int ITERATION_COUNT = 5000;
12.         private readonly bool SHOW_NUMBER_VERIFICATION = false;
13.  
14.         private bool _isTestInitiated = false;
15.         private string _logText;
16.  
17.         private void Update()
18.         {
19.             if (Input.GetKeyDown(KeyCode.Space) && !_isTestInitiated)
20.             {
21.                 _isTestInitiated = true;
22.                 EvaluateTests();
23.             }
24.         }
25.  
26.         private void EvaluateTests()
27.         {
28.             TestMethod(
29.                 "Test Call To Class Method",
30.                 (i, j) =>
31.                 {
32.                     return _TestCallToClassMethod(i, j);
33.                 });
34.  
35.             TestMethod(
36.                 "Test Call To Concrete Class",
37.                 (i, j) =>
38.                 {
39.                     return _TestCallToConcreteClass(i, j);
40.                 });
41.  
42.             TestMethod(
43.                 "Test Call To Static Class",
44.                 (i, j) =>
45.                 {
46.                     return _TestCallToStaticClass(i, j);
47.                 });
48.  
49.             TestMethod(
50.                 "Test Inline Class",
51.                 (i, j) =>
52.                 {
53.                     return _TestInlineClass(i, j);
54.                 });
55.  
56.  
57.             _MethodAction();
58.  
59.  
60.             // ----- Start of Inline Action -----
61.  
62.             long startTime = GetSystemTime();
63.             ulong num = 0;
64.             for (int i = 0; i < ITERATION_COUNT; i++)
65.             {
66.                 for (int j = 0; j < ITERATION_COUNT; j++)
67.                 {
68.                     num += (ulong)(i * j);
69.                 }
70.             }
71.  
72.             long endTime = GetSystemTime();
73.             long processTime = endTime - startTime;
74.  
75.             WriteNumber("Inline Action Process Number", num);
76.             WriteTime("Inline Action Process Time", processTime);
77.  
78.             // ----- End of Inline Action -----
79.  
80.             _text.text = _logText;
81.         }
82.  
83.         private void TestMethod(string logHeader, Func<int, int, ulong> testAction)
84.         {
85.             long startTime = GetSystemTime();
86.  
87.             ulong num = 0;
88.             for (int i = 0; i < ITERATION_COUNT; i++)
89.             {
90.                 for (int j = 0; j < ITERATION_COUNT; j++)
91.                 {
92.                     num += testAction(i, j);
93.                 }
94.             }
95.  
96.             long endTime = GetSystemTime();
97.             long processTime = endTime - startTime;
98.  
99.             WriteNumber(logHeader + " Number", num);
100.             WriteTime(logHeader + " Time", processTime);
101.         }
102.  
103.         private void _MethodAction()
104.         {
105.             long startTime = GetSystemTime();
106.  
107.             ulong num = 0;
108.             for (int i = 0; i < ITERATION_COUNT; i++)
109.             {
110.                 for (int j = 0; j < ITERATION_COUNT; j++)
111.                 {
112.                     num += (ulong)(i * j);
113.                 }
114.             }
115.  
116.             long endTime = GetSystemTime();
117.             long processTime = endTime - startTime;
118.  
119.             WriteNumber("Method Action Process Number", num);
120.             WriteTime("Method Action Process Time", processTime);
121.         }
122.  
123.         private ulong _TestCallToClassMethod(int i, int j)
124.         {
125.             var test = new TestCallToClassMethod(i, j);
126.             return test.num;
127.         }
128.  
129.         private ulong _TestCallToConcreteClass(int i, int j)
130.         {
131.             var test = new TestCallToConcreteClass(i, j);
132.             return test.num;
133.         }
134.  
135.         private ulong _TestCallToStaticClass(int i, int j)
136.         {
137.             var test = new TestCallToStaticClass(i, j);
138.             return test.num;
139.         }
140.  
141.         private ulong _TestInlineClass(int i, int j)
142.         {
143.             var test = new TestInlineClass(i, j);
144.             return test.num;
145.         }
146.  
147.         private void WriteNumber(string header, ulong num)
148.         {
149.             if (SHOW_NUMBER_VERIFICATION)
150.                 _logText += $"{header}: {num}\n";
151.         }
152.  
153.         private void WriteTime(string header, long time)
154.         {
155.             _logText += $"{header}: {time}\n";
156.         }
157.  
158.         private long GetSystemTime()
159.         {
160.             return DateTimeOffset.Now.ToUnixTimeMilliseconds();
161.         }
162.     }
163.  
164.     public class TestCallToClassMethod
165.     {
166.         public ulong num;
167.         public TestCallToClassMethod(int num1, int num2)
168.         {
169.             num = Multiply(num1, num2);
170.         }
171.  
172.         private ulong Multiply(int num1, int num2)
173.         {
174.             return (ulong)(num1 * num2);
175.         }
176.     }
177.  
178.     public class TestCallToConcreteClass
179.     {
180.         public ulong num;
181.         public TestCallToConcreteClass(int num1, int num2)
182.         {
183.             Multiply multiply = new Multiply(num1, num2);
184.             num = multiply.num;
185.         }
186.     }
187.  
188.     public class Multiply
189.     {
190.         public ulong num;
191.         public Multiply(int num1, int num2)
192.         {
193.             num = (ulong)(num1 * num2);
194.         }
195.     }
196.  
197.     public class TestCallToStaticClass
198.     {
199.         public ulong num;
200.         public TestCallToStaticClass(int num1, int num2)
201.         {
202.             num = Math.Multiply(num1, num2);
203.         }
204.     }
205.  
206.     public static class Math
207.     {
208.         public static ulong Multiply(int num1, int num2)
209.         {
210.             return (ulong)(num1 * num2);
211.         }
212.     }
213.  
214.     public class TestInlineClass
215.     {
216.         public ulong num;
217.         public TestInlineClass(int num1, int num2)
218.         {
219.             num = (ulong)(num1 * num2);
220.         }
221.     }
222. }

And the results were really shocked me as you can check below

Code (JavaScript):

1. Test Call To Class Method Time: 2366
2. Test Call To Concrete Class Time: 4468
3. Test Call To Static Class Time: 2327
4. Test Inline Class Time: 2269
5. Method Action Process Time: 15
6. Inline Action Process Time: 15

I tested the code on two different Unity versions and also by building the project and testing on a standalone build, outcome of these different environments didn't alter the results too much. While on JavaScript, instantiating new objects and making calls to static class methods weren't making too much performance difference, on C# with Unity the performance affected by almost 150 to 300 times.

Do I oversight something in here with these tests? Or this interpreted JavaScript runtime beats the compiled (IL2CPP btw) C# code for real?

 

Okay, I have made another test. Because I thought the problem could be related to creating a lot of objects during the iteration phase.

Code (CSharp):

1. using System.Collections.Generic;
2. using UnityEngine;
3.  
4. namespace PerformanceTests
5. {
6.     public class TestingBehaviours2 : MonoBehaviour
7.     {
8.         private const int ITERATOR = 5000;
9.  
10.         private NumberHolder _numberHolder = new NumberHolder(0);
11.         List<Operators> _operators;
12.  
13.         // Start is called before the first frame update
14.         private void Start()
15.         {
16.             _operators = new List<Operators>()
17.             {
18.                 new Divider(_numberHolder),
19.                 new Adder(_numberHolder),
20.                 new Multiplier(_numberHolder),
21.                 new Subtractor(_numberHolder)
22.             };
23.  
24.             OperatorBased();
25.  
26.             PlainMethod();
27.         }
28.  
29.         private void OperatorBased()
30.         {
31.             long startTime = System.DateTimeOffset.Now.ToUnixTimeMilliseconds();
32.             for (int i = 0; i < ITERATOR; i++)
33.             {
34.                 for (int j = 0; j < ITERATOR; j++)
35.                 {
36.                     _operators[j % 4].Operate(j);
37.                 }
38.             }
39.             long endTime = System.DateTimeOffset.Now.ToUnixTimeMilliseconds();
40.             long processTime = endTime - startTime;
41.  
42.             Debug.Log($"Operator Based Calculation: {_numberHolder.Number}");
43.             Debug.Log($"Process Time of Operator Based: {processTime}");
44.         }
45.  
46.         private void PlainMethod()
47.         {
48.             long startTime = System.DateTimeOffset.Now.ToUnixTimeMilliseconds();
49.  
50.             int num = 0;
51.             for (int i = 0; i < ITERATOR; i++)
52.             {
53.                 for (int j = 0; j < ITERATOR; j++)
54.                 {
55.                     int operation = j % 4;
56.  
57.                     if (operation == 0)
58.                     {
59.                         if (j == 0)
60.                             j = 1;
61.                         num /= j;
62.                     }
63.                     else if (operation == 1)
64.                     {
65.                         num += j;
66.                     }
67.                     else if (operation == 2)
68.                     {
69.                         num *= j;
70.                     }
71.                     else if (operation == 3)
72.                     {
73.                         num -= j;
74.                     }
75.                 }
76.             }
77.             long endTime = System.DateTimeOffset.Now.ToUnixTimeMilliseconds();
78.             long processTime = endTime - startTime;
79.  
80.             Debug.Log($"Plain Method Calculation: {num}");
81.             Debug.Log($"Process Time of Plain Method: {processTime}");
82.         }
83.     }
84.  
85.     public class NumberHolder
86.     {
87.         private int _number;
88.  
89.         public int Number { get { return _number;} }
90.  
91.         public NumberHolder(int number)
92.         {
93.             _number = number;
94.         }
95.  
96.         public void SetNumber(int number)
97.         {
98.             _number = number;
99.         }
100.     }
101.  
102.     public abstract class Operators
103.     {
104.         protected NumberHolder _numberHolder;
105.  
106.         public Operators(NumberHolder numberHolder)
107.         {
108.             _numberHolder = numberHolder;
109.         }
110.  
111.         public abstract void Operate(int n);
112.     }
113.  
114.     public class Multiplier : Operators
115.     {
116.         public Multiplier(NumberHolder numberHolder) : base(numberHolder)
117.         {
118.  
119.         }
120.  
121.         public override void Operate(int n)
122.         {
123.             int number = MathOperations.Multiply(_numberHolder.Number, n);
124.             _numberHolder.SetNumber(number);
125.         }
126.     }
127.  
128.     public class Divider : Operators
129.     {
130.         public Divider(NumberHolder numberHolder) : base(numberHolder)
131.         {
132.  
133.         }
134.  
135.         public override void Operate(int n)
136.         {
137.             int number = MathOperations.Divide(_numberHolder.Number, n);
138.             _numberHolder.SetNumber(number);
139.         }
140.     }
141.  
142.     public class Adder : Operators
143.     {
144.         public Adder(NumberHolder numberHolder) : base(numberHolder)
145.         {
146.  
147.         }
148.  
149.         public override void Operate(int n)
150.         {
151.             int number = MathOperations.Add(_numberHolder.Number, n);
152.             _numberHolder.SetNumber(number);
153.         }
154.     }
155.  
156.     public class Subtractor : Operators
157.     {
158.         public Subtractor(NumberHolder numberHolder) : base(numberHolder)
159.         {
160.  
161.         }
162.  
163.         public override void Operate(int n)
164.         {
165.             int number = MathOperations.Subtract(_numberHolder.Number, n);
166.             _numberHolder.SetNumber(number);
167.         }
168.     }
169.  
170.     public static class MathOperations
171.     {
172.         public static int Multiply(int n1, int n2)
173.         {
174.             return n1 * n2;
175.         }
176.  
177.         public static int Divide(int n1, int n2)
178.         {
179.             if (n2 == 0)
180.                 return n1;
181.             return n1 / n2;
182.         }
183.  
184.         public static int Add(int n1, int n2)
185.         {
186.             return n1 + n2;
187.         }
188.  
189.         public static int Subtract(int n1, int n2)
190.         {
191.             return n1 - n2;
192.         }
193.     }
194. }

Code (JavaScript):

1. Process Time of Operator Based: 109
2. Process Time of Plain Method: 61

Which decreased the process time difference significantly, even though there is still almost about 2x more process time difference between two techniques. However, I hardly think there will be situations that would require these kind of heavy loads (2.5m iterations with class/methods calls) on a single frame basis. Still it really surprised me that JavaScript surpassed C#

I would love to hear some technical explanation for this (if there is any) from someone who is more profound on this topic than me.

 

Albeit I feel not "profound" (and I have never used JavaScript) maybe I can give some possible causes for your test results:
1) Unity is a game engine and there are running several more things under the hood than just straight calculations of your code, for example rendering, "timing", input, sound and other organizational stuff. And since Unity is still mainly single threaded these things take performance/time away from your calculations.
2) Unity itself is written in C++ and the communication between the C# runtime with the C++ "backend" has some overhead too.
3) I'm not sure System.Now is appropriate for benchmarks. Better try Systems.Diagnostics.Stopwatch or the built in Profiler features.

I always find such "academic" benchmarks a bit misleading since they don't represent the typical usecase the engine is used (and optimized) for. For straight batch calculations a game engine is overkill.

For your information. UnityTech is working on a "performance by default" initiative. DOTS with jobs (multithreading) and Burst compiler already allow better performance when done right. They are also working on an ECS implementation for utilizing advantages of data oriented design but it's very quiet around that lately so I would not "risk" to use it right now. But this has been able to handle hundreds of thousands of independent entities in real time (look for megacity demo). But it requires a completely new thinking and writing of code and thus is not easy to use right now.

 

The "clean code" stuff isn't about speed. In fact, it pretty much says "stop worrying about speed -- for too long we're been cr*pping up our code for a 1% speed increase that no one will ever notice. Worse, this makes it so every new feature takes forever to add and causes new bugs. So let's stop that -- let's focus on easy-to-upgrade, easy-to-debug code and in return, oh no! our code will be 1% slower".

Your tests are confusing me -- javascript in one environment appears to run faster than Unity/C# in another. OK. But Clean Code is telling you to compare "ugly" Unity code to "clean" code also in Unity. Clean may be a tiny bit slower, but not enough to notice while playing the game.

 

I am aware of DOTS workflow, which brings the multithreading support to Unity, but since Noda.JS is also singlethreaded. That's why I thought it would be a proper competitor for Unity's singlethreaded operations. It means the calculations in this C# test should be processed sequentially, as in JavaScript with Node.js.

And Unity is also converting C# source code into intermediate C++ language before compiling it to proper assembly. So I'm not sure if there is a communication overhead between C# and C++ backend, or anything like that. If there is, I still doubt there will be that much of difference.

And finally, I didn't know about Stopwatch, I will give it a try later. Date.Now may not be the best solution to calculate the time but, since a same kind of logic has been used in javascript also, it would be equivalent enough I think. Additionally, I must say that again, ofcourse I'm not an expert on conducting performance tests such as these, however the initial difference, which was about 150-300x performance loss, was so horribly harsh which made me doubt about the general performance in Unity.

 

I totally agree with, as you mentioned, it would be totally acceptable (and actually more than acceptable, it should be the only way) that if "clean code" rules will make your code much more maintable, you would (again should) ignore %1 of performance loss, and maybe even much more. The results in the second test are definitely acceptable, my problem was about the performance loss on the first test.

It still makes me wonder that how the heck JavaScript outperformed C# in this matter, however then I thought it could be related to some environment specific optimization stuff (first thing came to my mind is maybe node.js' engine behaving class objects a kind of a struct object as in C# which make them much more manageable in the matter of allocating/creating/disposing terms)

Again, to clearify, I tottally agree with everything you say.

 

It's tough for anyone here to actually read and think about someone else's performance tests since the one's posted here are almost always fatally bad -- like not testing the same amount of loop nesting, or confusing milli and microseconds. Sure, you actually know to test on a stand-alone build, even so, I briefly thought about writing "wait, isn't the node.js playground run on their server?" but 2 seconds later realized "wait, this is Unity Forums. If it's not that, it will be something else head-slappingly wrong. Do not get sucked in".