unity-jar-resolver icon indicating copy to clipboard operation
unity-jar-resolver copied to clipboard

[FR] High GC Allocation in Editor - Cache ExecutionEnvironment Cmdlineargs

Open snorrsi opened this issue 3 years ago • 18 comments

[REQUIRED] Please fill in the following fields:

  • Unity editor version: 2020.2.6 and 2021.1.0
  • External Dependency Manager version: 1.2.164
  • Source you installed EDM4U: Unity Package Manager
  • Features in External Dependency Manager in use: Android iOS, iOS Resolver
  • Plugins SDK in use: Firebase (none in 2021.1.0)
  • Platform you are using the Unity editor on: Mac and Windows

[REQUIRED] Please describe the issue here:

During Editor profiling it's clear that same functions in EDM4U are run multiple time which are causing high GC Alloc due to string ToLower function. Due to string conversion the GC Alloc is 10kb or so each frame or at least very often. Can't this data be cached as the UnityEngine.Environment.CommandLine surely does not change often?

source/VersionHandlerImpl/src/ExecutionEnvironment.cs#L32 source/VersionHandlerImpl/src/ExecutionEnvironment.cs 31 | public static bool InBatchMode { 32 | get { return Environment.CommandLine.ToLower().Contains("-batchmode"); } … |   38 | public static bool ExecuteMethodEnabled { 39 | get { return Environment.CommandLine.ToLower().Contains("-executemethod"); } 40 | }

source/VersionHandlerImpl/src/Logger.cs#L52 source/VersionHandlerImpl/src/Logger.cs 50 | internal static bool DebugLoggingEnabled { 51 | get { 52 | return Environment.CommandLine.ToLower().Contains("-gvh_log_debug"); 52 | }

Please answer the following, if applicable:

What's the issue repro rate? 100%

What happened? How can we make the problem occur? During Editor profiling it's clear that same functions in EDM4U are run multiple time which are causing high GC Alloc due to string ToLower function. Run a project in Unity Editor with Call Stacks (GC Alloc) profiling and look at origination of GC Allocation in Editor.

Attached is callstack and image from the Unity Profiling. All of the 5.8kb GC Alloc is related to this issue.

Screenshot 2021-03-24 at 11 45 41

edm4u_gc_alloc_callstack.txt

snorrsi avatar Mar 24 '21 11:03 snorrsi

This issue does not seem to follow the issue template. Make sure you provide all the required information.

google-oss-bot avatar Mar 24 '21 11:03 google-oss-bot

Hi @snorrsi,

In order to ensure that your editor has the latest updates and bug fixes, could you try updating to the latest version (Unity 2021.1.0)? If the issue persists after doing this, I'd like you to provide a minimal, reproducible example of your project so that the cause of your issue can be identified.

Thanks.

paulinon avatar Mar 24 '21 13:03 paulinon

Hi @snorrsi,

In order to ensure that your editor has the latest updates and bug fixes, could you try updating to the latest version (Unity 2021.1.0)? If the issue persists after doing this, I'd like you to provide a minimal, reproducible example of your project so that the cause of your issue can be identified.

Thanks.

Hi @paulinon ,

Thanks for quick reply. I just tested empty project from 3D template in Unity 2021.1.0f1

The same issue is happening with Unity 2021.1.0f1 every frame. Not sure if it's of much help to send an empty project but I include the manifest.json as it is the only thing in the project I changed. I only added EDM4U nothing else.

manifest.json.txt

snorrsi avatar Mar 24 '21 16:03 snorrsi

Hi @snorrsi,

It would be great if you provide the steps you've taken before experiencing this issue along with the minimal repro I asked previously. This way, I can have a better understanding of this behavior

paulinon avatar Mar 25 '21 12:03 paulinon

Hi @snorrsi,

It would be great if you provide the steps you've taken before experiencing this issue along with the minimal repro I asked previously. This way, I can have a better understanding of this behavior

Hi @paulinon ,

No problem. My apologies, didn't really think the project was needed since I basicly didn't change anything except adding EDM4U.

I have now uploaded the project to GitHub. It can be found on https://github.com/snorrsi/edm4u_gc_alloc

I explained the steps taken in the readme file for the project.

snorrsi avatar Mar 25 '21 13:03 snorrsi

Hi @snorrsi,

So far, I have not been able to reproduce the issue you're facing, but I haven't used the same Unity editor version you used. Also, I have not been able to update my editor due to some issue on my end. While I try to fix that, could you try using an LTS version of Unity (such as 2020.3.0) and see if the issue persists? If so, it would be great if you can provide another minimal repro that uses an LTS version.

paulinon avatar Mar 26 '21 09:03 paulinon

Hi @snorrsi,

So far, I have not been able to reproduce the issue you're facing, but I haven't used the same Unity editor version you used. Also, I have not been able to update my editor due to some issue on my end. While I try to fix that, could you try using an LTS version of Unity (such as 2020.3.0) and see if the issue persists? If so, it would be great if you can provide another minimal repro that uses an LTS version.

Hi @paulinon ,

I have updated the repository to Unity 2020.3.1f1 version. The issue still exists. Should be basicly same as 2020.3.0f1. The 2021.1.0f1 is now in a branch called 2021_1_0

2020.3.1f1 example project now at https://github.com/snorrsi/edm4u_gc_alloc

According to the GC Alloc logs it seems that EDM4U most favourite property is ExecuteMethodEnabled in source/ExecutionEnvironment.cs line 39 I wouldn't think there is any way for the CommandLine to change after initial Unity run and therefore it's most likely safe to cache this data. Other usage of the command line can be found by searching for ToLower() (or CommandLine) Newer version of Unity (from 2018.2) have the property Application.isBatchMode (which you could possible use for the isBatchModeEnabled property for those versions)

Possible fix with caching

private static bool? _executeMethodEnabled = null;
public static bool ExecuteMethodEnabled {
 //get { return Environment.CommandLine.ToLower().Contains("-executemethod"); }
  if (!_executeMethodEnabled.HasValue) {
    _executeMethodEnabled = Environment.CommandLine.ToLower().Contains("-executemethod");
  }
  return _executeMethodEnabled.Value;
}

Example GC Alloc log from 2020.3.1

Metadata: Size: 618

Callstack: 0x16C12D865 0x16CD44622 mscorlib.dll!System.Text::StringBuilder.ToString() 0x1821B422B mscorlib.dll!System::Environment.get_CommandLine() 0x1821B3F82 Google.VersionHandlerImpl.dll!Google::ExecutionEnvironment.get_ExecuteMethodEnabled() Z:/tmp/tmp.zHMt0MAu9G/third_party/unity/unity_jar_resolver/source/VersionHandlerImpl/src/ExecutionEnvironment.cs:39 0x1821B57FA Google.VersionHandlerImpl.dll!Google::RunOnMainThread.<ExecuteAllUnnested>m__1() Z:/tmp/tmp.zHMt0MAu9G/third_party/unity/unity_jar_resolver/source/VersionHandlerImpl/src/RunOnMainThread.cs:531 0x1821B56D6 Google.VersionHandlerImpl.dll!Google::RunOnMainThread.RunAction() Z:/tmp/tmp.zHMt0MAu9G/third_party/unity/unity_jar_resolver/source/VersionHandlerImpl/src/RunOnMainThread.cs:341 0x1821B568A Google.VersionHandlerImpl.dll!Google::RunOnMainThread.ExecuteAllUnnested() Z:/tmp/tmp.zHMt0MAu9G/third_party/unity/unity_jar_resolver/source/VersionHandlerImpl/src/RunOnMainThread.cs:521 0x183307192 Google.VersionHandlerImpl.dll!Google::RunOnMainThread.ExecuteAll() Z:/tmp/tmp.zHMt0MAu9G/third_party/unity/unity_jar_resolver/source/VersionHandlerImpl/src/RunOnMainThread.cs:512

snorrsi avatar Mar 26 '21 10:03 snorrsi

Hi @snorrsi,

According to my replication, there's a GC allocation of 3.2kB, none of them show any origin.

Screen Shot 2021-03-29 at 8 53 10 PM

I see that you've indicated that this occurs for both Mac and Windows operating systems. With that, could you provide recent screenshots of the profiler for both operating systems so we can narrow down what's causing this behavior?

paulinon avatar Mar 29 '21 12:03 paulinon

Hi @paulinon ,

you have to make sure to select Call Stacks on the top right side of the Profiler window before you record. Without doing that you don't get the origin of the callstacks. It's enough to select GC Alloc callstack in the dropdown. But you have to press it down so the button becomes light gray. See attached image..

gc_alloc

snorrsi avatar Mar 29 '21 13:03 snorrsi

There are some gains to be made here by caching these command line argument flags as you point out. I'll label this as a feature request and alter this ticket's name to describe more about what the engineering efforts are. Thanks for the report!

DellaBitta avatar Mar 30 '21 13:03 DellaBitta

@DellaBitta @chkuang-g any change this will actually be fixed anytime soon? It's simple to cache these values as they don't change ever during run.

snorrsi avatar Nov 20 '21 02:11 snorrsi

Hey @chkuang-g ,

see that you had the last commit to these files I mentioned 2 years ago. Isn't it time to update them with the fix I mentioned?

It's bit annoying to see upto 19KB of totally uneeded GC Alloc in Editor for every frame.

snorrsi avatar Feb 21 '22 15:02 snorrsi

2 years later I guess it is still not fixed or addressed. After installing SDK, Unity Editor got funky. Checking Profiler shows constant call of RunOnMainThread. See attached file:

image

Edit: screenshot from latest version (1.2.179)

arcv avatar Apr 19 '24 17:04 arcv

@arcv haha, yeah don't understand why they didn't take this seriously.. but hey, I created a simple branch and pull for this issue. Maybe that will wake them up

snorrsi avatar Apr 19 '24 22:04 snorrsi