Why is my Coroutine Continuing to allocate GC from the "MoveNext()" After it completes?

Unity Engine
1

I try to be straightforward in my titles… it’s exactly what it sounds like.

I simply call a single Coroutine, which does not call any other coroutines, at any time… I call this single coroutine via the “StartCoroutine(Coroutine())” method at the Start() method… (this also occurs when I call it from Awake or anywhere really.)

Shouldn’t it only be getting called once???

Nevertheless, I am getting MAJOR Lag Spikes from GC Alloc according to the profiler, from this coroutine being repeatedly called… this issue persists in numerous scripts I’ve written. I’m completely confused rn; I’m about ready to never use Coroutines again…

Also, I am NOT calling it from ANYWHERE else, even though it says it’s getting called from the Update method, I have triple and quadruple checked with our 'ol friend Ctrl+F… it’s ONLY in Start().

Any input is appreciated.

UPDATE:

So I’ve FINALLY found out what is causing it to continue calling the Coroutine… though it doesn’t make sense… here’s my test:

        private IEnumerator Test()
        {
            while (brainStarted != BrainStarted.True)
            {
                debugLog = "WAITNG....";
                yield return null;
            }

            debugLog += " - EXITED";
        }

and of course it DOES meet the exit condition after a short time… and surely enough, I DO get the " - EXITED" logged. (debuglog is just a reference to a static UI text Component) although the conditions are met, it continues to call the Coroutine… I’m continuing investigation - still input is welcome from anyone.
The issue is pertaining to while loops inside of Coroutines… this is very strange.

UPDATE:

So only a minor update, but I also noticed this:

And again, this coroutine (Test()) is merely called one time in the Monobehaviour.Start() method. Via StartCoroutine(Test());

I changed the exit condition from my enum to a bool to verify the issue is not related to the enum… the issue persists.

UPDATE:

Here’s an isolated Class I’ve built for proper testing (still occurring):

using BrainConnect;
using System.Collections;
using UnityEngine;

public class Test : MonoBehaviour {

    private bool brainReady = false;

    void Start ()
    {
        ConnectBrain.BrainReady += BrainReadyEvent;
        StartCoroutine(TestEnumerator());
    }

    private void BrainReadyEvent(object s, System.EventArgs e)
    {
        brainReady = true;
    }

    private IEnumerator TestEnumerator()
    {
        while (!brainReady)
        {
            ConnectBrain.debugLog = "WATING....";
            yield return null;
        }

        ConnectBrain.debugLog += " - EXITED";
    }
}

This new isolated script is simply attached to a new Empty GameObject Parented under nothing.
I get the same results.

1 Like
2

A big problem with profiling Coroutines is that they tend to show all the cost under MoveNext, which is obviously not what’s costing time. Try profiling this in the editor, with deep profiling turned on - it might reveal the actual culprit.

What is ConnectBrain.debugLog actually? Is it just a public string that gets written to, or is it a property that does like getting a component and setting text and such?

2 Likes
3

Hey, thank you for the reply, I have tried deep profiling via the editor as you suggested, and it certainly gives more info… but it’s info that doesn’t make any sense.
Here’s a screen capture of such:

I should also note that the lag spikes begin, ironically, after the brain has been “started” in other words - it starts lagging down, after the coroutines should be finished. In that image, the whole first section of activity is the brain generating.
Here’s what I mean:

Obviously I do expect a decrease in performance during the brain computations, but the profiler says the GC Alloc is due to Coroutines that shouldn’t even still be running… This is where I’m confused.

The other thing is that the “DrawAttach” script never calls “Test” because Test is its own completely isolated script attached to a completely isolated GameObject (Even though the profiler says it is) - it’s only connection is in (as you can see in the code) Test subscribes to the static “BrainStarted” event, and the event handler flips the bool, allowing “Test” to exit the “TestEnumerator()” … and what’s more is “Test” never calls, “Private Update”(Even though the profiler says it is) and so I’m very confused why they are all stacked as though they are connected to one another.

As for the debugLog:

debugLog is of type “string” and in the appropriate Script, under the Monobehaviour.Update() Method, it checks if a bool is flipped “updateUI” and… well:

void Update()
{
    if (updateUI && standardUI != null)
    {
        if (brainStarted == BrainStarted.True)
        {
            standardUI.text = "Debug Log:" + debugLog;
        }
    }
}

and standardUI is:

standardUI = gameObject.GetComponent<Text>();

Also, here’s the other “DelayedUpdate” section that all the coroutines are supposed to be under… test is still in there, doing strange things that also make no sense.

As you can see from the script I shared originally, all “TestEnumerator()” does is wait while the brain is starting, then exits… I logically should not see anything from the “test” script after the brain is started… even though I do.

4

Update:
___________________________________________________________________________
Okay… so to take out all potential variables, I’ve created a new project entirely, and I am still able to reproduce the issue:

  • Create a new project
  • Create a Text Object (so you can see what’s going on easier)
  • Create an empty GameObject
  • Create a new C# Script Titled “Test” and paste in the following:
using System.Collections;
using UnityEngine;
using UnityEngine.UI;

public class Test : MonoBehaviour {

    private bool exit = false;
    [SerializeField] [Range(1001, 100001)] private readonly int runTime = 1001;
    [SerializeField] private Text text;

    void Start ()
    {
        StartCoroutine(TestEnumerator());
        StartCoroutine(Count());
    }

    private IEnumerator Count()
    {
        for (int i = 0; i < runTime; i++)
        {
            text.text = i.ToString() + "\nExit: " + exit.ToString();
            if (i == runTime / 2)
            {
                exit = true;
            }
            yield return null;
        }
    }

    private IEnumerator TestEnumerator()
    {
        while (!exit)
        {
            print("WAITING....");
            yield return null;
        }

        print(" - EXITED");
    }
}

  • Attach the Script to the Empty GameObject

  • Under the Canvas (Created automatically with the Text Object) choose Canvas>RenderMode>Screen Space - Camera

  • Drag the MainCamera to the open spot on the Canvas Component called “Render Camera”

  • Set the Text font to 36+, enable “Best Fit”, center the text on the Screen and Canvas, and set both “Vertical Overflow” and “Horizontal Overflow” to “Overflow” Under the Text Component>Paragraph

  • Under the Empty “Test” GameObject Drag the “Text” GameObject (Under Canvas) to set the Text GameObject as the referenced Text Component within the Script I’ve shared

  • Open the Profiler, and Enable Deep Profiling

You’ll notice, the issue somehow lays in when the condition of the while loop within the “TestEnumerator” is set based on another condition elsewhere that is still going.
So, I have the “Exit” bool set to flip to true after the counter hit’s half way to the for loop’s end point (Under the Count() Coroutine)

When you run this, you’ll notice that, as long as the “Count() Coroutine” is still “counting” - even though the boolean has been flipped and the “TestEnumerator() Coroutine” is complete and exited. For some reason, the “TestEnumerator() Coroutine” continues to produce GC Allocations until the “Count() Coroutine” is also complete and exited…

Once both Coroutines are complete, then and only then do the Coroutines stop producing GC Allocatio

5

Hm… I was able to see what you’re talking about. I mean the test only showed 32bytes, but ya. :slight_smile:

I cannot tell you what inspired my silliness to test the following, but if I swap the order of the 2 calls to StartCoroutine, then when the one finishes it doesn’t stay in the profiler’s list. :slight_smile:

2 Likes
6

So I ran your example.

Here is my profiler after ‘exit’ has flipped and ‘TestEnumerator’ has exited:

3509407--280132--GC_Coroutine.png
3509407--280132--GC_Coroutine.png1584×209 25.6 KB

Now I’m noticing something here. It says we’re in TestEnumerator…

But beneath that is says we’re in c__Iterator0.MoveNext, and the garbage is being created by an Int32.ToString. And the only thing that does that is Count.

I also notice that zTest01.Count section only has a call to ‘Current’.

This says to me some sort of optimization occurred by the compiler. Probably because you access a boolean that is touched in both iterator functions.

Note that iterator functions (coroutines) get compiled into their own anonymous class by the C# compiler. And the compiler will take a lot of its own liberties in doing so.

So I compiled this, and looked at the IL with DotPeek… but nope, no optimizations.

So then I rewrote the class like follows:

using System.Collections;
using UnityEngine;
using UnityEngine.UI;

public class zTest01 : MonoBehaviour {

    private bool exit = false;
    [SerializeField]
    [Range(1001, 100001)]
    int runTime = 1001;
    [SerializeField]
    private Text text;

    void Start()
    {
        StartCoroutine(Count());
        StartCoroutine(TestEnumerator());
    }

    private IEnumerator Count()
    {
        for (int i = 0; i < runTime; i++)
        {
            text.text = i.ToString();
            if (i == runTime / 2)
            {
                exit = true;
            }
            yield return null;
        }
    }

    private IEnumerator TestEnumerator()
    {
        while (!exit)
        {
            print("WATING....");
            yield return null;
        }

        print(" - EXITED");
    }

}

(yes, it’s called zTest01 in mine… that’s inconsiquential)

And I got:

3509407--280133--GC_Coroutine2.png
3509407--280133--GC_Coroutine2.png1583×172 20.7 KB

This time everything is listed under ‘Count’.

So what this says to me is that it’s not a C# optimization. But instead appears that Unity’s container for the coroutines is being split/shared or something. And it just takes on the name of the first coroutine called.

Regardless, the garbage is being created from the appropriate place.

The weirdness comes from the fact the debugger is just laid out weird. You can see that ‘TestEnumerator’ isn’t called anymore because here it is before ‘exit’ is toggled and you can clearly see entries for TestEnumerator.MoveNext and get_Current:

3509407--280134--GC_Coroutine3.png
3509407--280134--GC_Coroutine3.png1585×228 25.6 KB

(it’s darker because I have my editor set to go dark when the game is playing)

So yeah, my best theory is that Unity is optimizing the creation of whatever handle they use to operate Coroutines by sharing said operator. Only throwing it out after all concurrent coroutines are finished. And that operator just happens to take on the name of the first coroutine passed to it.

Which results in just that the debugger has this weird display quark and you have to instead dig a couple more layers down to see what exactly is creating the garbage.

In theory you could say this is a bug in the way the debugger works. But I doubt Unity will do it. The only other options is to have unique coroutine operators for each coroutine (which is less efficient), or check when a coroutine completes and rename the container accordingly… which why? So that the debugger is slightly more accurate without having to dig another layer down? Anyways, it’ll still be named the first when both are running concurrent.

There’s really no perfect approach, they honestly have the best operation practice IMO.

3 Likes
7

Right, because 'tis the test, as per the original post, the amount in my project is much higher due to this issue, thus my posting about it. But I appreciate the input - and thank you for also looking into it

Very interesting points of discovery… I’ve also flipped both calls to “StartCoroutine” and see what you mean… Very strange… This does - with respect to my actual project - give me a bit better point to go from… At least I know the Coroutine that should be stopping, is in fact stopping… I believe I’ve a clue where it is truly coming from:
With consideration of the result of the test example we had going, I would assume the culprit of GC in my scenario is, (not surprisingly) my “SendVisualData” Coroutine (As it takes up the most computational time next to my brain passing signals around)

Lesson learned: “When using Unity’s Profiler on Coroutines, assume the call to the ‘get_current’ is the actual call target, not the ‘MoveNext’”

Thank you guys for takin’ a look also.

8

And Bingo:

The Lag is the time spent removing objects from a list (for some reason)
The Allocation is from some string Concatenation - Which I can optimize of course, but time to look into better options over list.RemoveAt() :eyes::sunglasses:

Probably re-write it with a Queue FIFO - That’s all RemoveAt is doing anyhow… lol silly nooby Dante.

Yee boiiii, surely enough, problem solved!

9

Did you ever figure out why your coroutines are continuing to be called? I’m getting the same issue when I profile, a coroutine that should be finished very quickly continues to show up with GC in the profiler.

1 Like
10

Did you read the thread in full?

They weren’t being continuely called. It’s just to do with the profiler reporting the wrong name because it creates on Coroutine container for 2 routines. One finished, but the other was still running, but the optimization reported a single name. So really it’s just a ‘display’ issue of the profiler (see my full post for full details).

With that knowledge in hand DDeathlonger was able to locate where the allocations were coming from since they were looking in the wrong method because the profiler reported the wrong method.

2 Likes
11

i have the exactly same problem :frowning:

you understand how to get the correct name of the corutine?

1 Like
12

Come across the same issue.
After narrowing the issue, in my case, to one coroutine I did simple test.
Disabled coroutine and call the same function in Update base on interval.

private void Update()
    {
        intervalTime += Time.deltaTime;
     
        if (intervalTime > 1) // every second
      {
            intervalTime = 0;
            Method.Call(); // of course you need to change a little the IEnumerator method you call here to return void etc.
        }
    }

Should behave the same way.

But … no more GC allocations.
I call exactly the same method as coroutine, at the same interval (plus/minus TIme.deltaTime) and GC disappears.
The moment I enable coroutine it comes back.

I am not saying it is something on Unity part, need some extra time to do more tests.
Probably it is still on my part just really hard to find exact problem.

In the end I am not sure if having coroutines is always the best idea.
It is much harder to debug but you don’t make Update heavier etc.
Probably will try later to get rid of as many coroutines as possible.

13

Note that a running coroutine does not allocate any memory by itself once started. The coroutine itself is not a method but a statemachine object. So each time you start a new coroutine you will allocate memory. Further common errors are using “yield return 0;” instead of “yield return null;”. The IEnumerator interface “enumerates” things of type object (System.Object). That are the values you pass to the yield return statement. When you yield a value type (like an int such as the value 0) the value type will get boxed on the heap and allocates memory.

The same thing happens when you create a “WaitForSeconds” instance. WaitForSeconds is just a class instance. Luckily in the case of WaitForSeconds we can actually reuse the same instance when you always use the same wait value. You can do

public static WaitForSeconds wait1Sec = new WaitForSeconds(1);

Now inside a coroutine you can just do

yield return wait1Sec;

inside your coroutine and you won’t allocate any memory.

8 Likes