[Asset pipeline v2] Script reimport performance

Hi, I upgraded a project to 2019.3b12 and asset pipeline v2. I'm using a bunch of unity packages like Entities, Jobs and Burst.

Changing one line in a script and going back to unity takes 9 seconds (it was closer to 5-6 seconds in unity 2019.2). Looking at the profiler, I feel like there is a lot of room for optimization. For example ScanAssemblies in EndReloadAssembly spends 375ms scanning all assemblies, of which only 5.5ms is spend on my game assembly, the only one that actually changed. Most of the time is spent scanning UnityEngine and Unity.Entities, and those basically never change in a normal workflow. Couldn't result of the scanning be kept around between reloads somehow?

That exemple aside, is the performance of scripts reloading being worked on, and can we expect improvements? With unity moving more and more of its engine modules over c#, it becomes especially important that the reimport time of c# code is kept low imo.

9 Likes

Here are some screenshot and a link to my profiler save:
5219981--520217--Screenshot 2019-11-26 at 23.22.55.jpg 5219981--520220--Screenshot 2019-11-27 at 17.08.06.png
https://drive.google.com/file/d/1-7I_H5m-WvSWcTi22RI73VGYcRZ-ILPc/view?usp=sharing

Hey, could be worth to submit a bug report with your findings.

Hi @Seb-1814

This is a very valuable capture of the profiler. Thanks for showing it.

Out of curiosity, how many Assets (roughly) have you got in your project?

There are some issues which we're addressing right now with regard to the performance (i.e. batching asset creation regressed severely, and we're working on a fix). It would be helpful to at least know how your Assets are distributed.

I made a Gist which you should just be able to run: https://gist.github.com/Unity-Javier/670752cb02b4c92e451665631fc2ea7d

And it'll output how many of each asset type you have in your project, so we can see if its more Script heavy or not.

Additionally, a Bug report could help us see what setup you have more precisely.

Looking forward to your reply!

2 Likes

Hi Javier,

Sure, happy to help where I can

Our project has quite a lot of heavy textures. I’m curious as to what impact it could have. I’m guessing it shouldn’t matter for script compilation and reloading, but could impact the 1.4 sec spent in AssetDatabase.V2.PostProcessAllAssets?

I’m guessing our project is also rather script heavy, I don’t know what’s a normal amount of script. I’m also not sure what proportions of scripts are from packages like Entities versus our own project.

I saw that unity 2019.3f1 was released over night so I switched to it. It seems to be a little faster (around 8 seconds). Or it could be due to a change my method of testing or environnement, I’m not sure. If you need I can send another profile.

The script you provided ran with an error:
NullReferenceException: Object reference not set to an instance of an object
AssetDistribution.GetAssetDistribution () (at Assets/Editor/AssetsDistribution.cs:18)

By stepping in with the debugger I found that AssetImporter.GetAtPath() returns null for one of the paths: “Packages/com.unity.entities/Unity.Entities.Editor/Mode/default.mode”

So I added a null-check

            var curImporter = AssetImporter.GetAtPath(assetPath);
            if (curImporter == null) {
                Debug.LogWarning($"No importer for asset at path {assetPath}");
                continue;
            }

Here is what the script logged:

UnityEditor.AssetImporter,971
UnityEditor.MonoImporter,2675
UnityEditor.PrefabImporter,85
UnityEditor.TextureImporter,921
UnityEditor.TrueTypeFontImporter,27
UnityEditor.TextScriptImporter,93
UnityEditor.ShaderImporter,102
UnityEditor.ModelImporter,9
Unity.VectorGraphics.Editor.SVGImporter,8
UnityEditorInternal.PackageManifestImporter,56
UnityEditorInternal.AssemblyDefinitionImporter,109
UnityEditor.StyleSheets.StyleSheetImporter,24
UnityEditor.PluginImporter,11
Unity.Build.BuildPipelineScriptedImporter,2
UnityEditor.UIElements.UIElementsViewImporter,11
UnityEditor.AudioImporter,10
UnityEditorInternal.AssemblyDefinitionReferenceImporter,1
Total assets: 5116
UnityEngine.Debug:Log(Object)
AssetDistribution:GetAssetDistribution() (at Assets/Editor/AssetsDistribution.cs:40)

I didn’t make a bug report right away, because I wasn’t sure if this would be treated like a bug, and reporting bug has proven quite time consuming for me in the past. Also our project is pretty big, would it still be useful for you if I made a bug report without attaching all of the project somehow (project might be in a broken state then) ?

2 Likes

(or are you mainly interested in my machine specs, info on the project like package used and profiler saves, in which case I can submit a bug without the project but with this info?)

Hey, thanks for the reply.

I got something similar (in terms of time spent inside a Refresh) by installing 3 packages.

However, would it be possible for you to share a deep profiler capture, so I can reach out to the teams where the time is being spent at?

It looks like its not just the AssetDatabase, but the usage of the APIs that is slowing things down.

Glad you could reproduce a similar refresh time with just unity packages. It seems there is sill a lot of work to do before reaching the 500ms goal mentioned at unite some time ago ;)

Here is a link to a deep profile, reload happens at frame number 658.
https://drive.google.com/file/d/1-Fj7XBLPeMbsgyh_UZTU7cz8sMl4VpEE/view?usp=sharing

Thanks for the support! I really hope it will help, I'm happy to provide more details if needed

2 Likes

Hey, so we tried to open the capture and it didn't work. It looks like the data is incomplete:

The file size we got is 165742256 bytes, but it should be 2-3x larger according to some of the data in it.

Could you try uploading it again, and checking if the download opens on your machine?

Indeed, I can't load the save either. I did another one and couldn't load it either, it seems to me like the profiler has a bug and doesn't save big profiles correctly. I get this error message when loading one of the deep profiles:

5230415--521672--Screenshot 2019-11-30 at 16.37.09.png
So I guess that's another bug to log ¯_(ツ)_/¯
But in the meantime, since you managed to reproduce the high reload times with a project of your own, maybe you can pass it to the relevant teams, and they can do a deep profile by themselves?

1 Like

I just want to add that I got this too and I cannot efficently edit assets because it wants to autosave and reimport everything that is related, which is the exact opposite what you would expect from nested prefabs, should just be links right? Also why does it have to block anyone's mainthread and usage at all? Also would be nice if it was a package so that we can fix stuff for ourselves.

Also the Asset pipeline v2 fucks things up for my special editor windows. It, for some god damn reason uses editor window stuff when it import it during a save which apparently causes one of my lists of script objects top be full of null during one stage which is quite weird. Which triggers some of my editor window sanity checks and set things to false because it is null, even though it isnt actually null.

//Rant

Edit:
Wanted to add my current project size

UnityEditor.AssetImporter,2903
UnityEditor.MonoImporter,3397
UnityEditor.TextureImporter,5984
UnityEditorInternal.AssemblyDefinitionImporter,79
UnityEditor.ModelImporter,125
UnityEditor.PrefabImporter,667
UnityEditor.TrueTypeFontImporter,28
UnityEditor.AudioImporter,203
UnityEditor.PluginImporter,40
UnityEditor.TextScriptImporter,128
UnityEditor.ShaderImporter,229
UnityEditorInternal.PackageManifestImporter,59
UnityEditor.StyleSheets.StyleSheetImporter,117
UnityEditor.UIElements.UIElementsViewImporter,59
UnityEditor.ShaderGraph.ShaderGraphImporter,6
MLAgents.DemonstrationImporter,1
Barracuda.NNModelImporter,8
Total assets: 14033

Edit 2: also I cannot properly debug the save because unity crashes ect, but takes like 24 seconds.

2 Likes

If only Unity tried making just one full AA+ commercial game on their own, they would've catch 90% of annoying issues and regressions like this, without being surprised every time something like this is brought up by users.

11 Likes

A million times this. The more you structure things using nested prefabs, the more abysmal their usability gets due to all the progress bars anytime you change a variable with autosave (or you disable autosave and just have to grit your teeth every time you’re about to save).

1 Like

Okay I managed to save the dump file at home but it turns out to be 3.3 GIGABYTE, so I took some snippets that I hope will aid you Unity_Javier.

The context for this save is a fairly empty scene (where we will generate our procedural level) the scene is only about 740kb large so it is suprising that it takes 12-24seconds to save even though in this case I have not even changed anything at all but just pressed save.

I hope you will solve this, thanks.

5252738--524864--topDuring save.PNG 5252738--524867--topDuring save2.PNG 5252738--524870--topDuring save3.PNG

Hey @spiderspy ,
Thanks for the images. This looks like the Raw Hierarchy view, and that is also very valuable to put the order of operations into perspective.

We have spent the entire week looking at the performance issues (and will continue doing so for the near future) and have reached out to a number of teams across Unity who are investigating how to fix the issues, and how to make sure they get into 2019.3 so that you all don’t have to get hit with these regressions.

Even if the capture is 3.3GB, a .zip of it would be good to have, since the profiler data compresses really well (i.e. a 3.08GB profile compressed down to 148MB for an investigation related to this).

You can DM it to me as well if you prefer, or put it in a bug so we get some infrastructure around it and track the progress.

Either way, thanks for sharing all this info with us! The more info we have the more scenarios we can cover.

9 Likes

Hi @spiderspy ,
I am Vitaly and I work in the same team with Javier. We have made a lot of performance fixes on AssetPipeline side and are still help other teams to improve performance on their side. That said, we looked at your profiler information (you sent to Javier) and noticed 2 seconds in UnityEditor.Rendering.DebugWindow, we reached to the team owning this, but unfortunately they can't really say what is happening there... and asking for more info.
Could you please give more context on the project/scene you recorded profiler info with? or ideally file a bug report and attach project (stripped scene) and post bug number here or DM me - that will help us a lot in identifying and fixing the problem
Thanks in advance :)

6 Likes

Could you explain to me what UnityEditor.Rendering.DebugWindow is? and I will look into it. @Vitaly_Unity

Also concerning context, is that I am saving a small scene that will procedurally generate a larger scene world, but at the point of savig it is a fairly small scene, less than 1mb. We use the nested prefabs a lot, it is a 2D based project.

Unfortunately I cannot really share the project in itself.

Just like to point out that I've noticed these incredibly long script compile and enter play mode times with brand new projects. In 2019.3.0f4, I created a new URP project and without any modifications to the project I'm getting 20+ second play mode entry times. Here's what the profiler produces:

5351013--540486--upload_2020-1-8_22-17-0.png

Just like to add how odd it is that it's using ~1.8GB GC allocation for a project that is ~1GB in size.

4 Likes

I created a new project in 2019.3.0f3, and they also seem to have the exact same issue - this didn’t always happen and has only just started recently. Is there perhaps some corrupted file perhaps in app data that each editor uses globally?

To continue the campaign of weirdness. Today I loaded up the same fresh URP project from my original post which had 20s+ play mode entry time (profiler screenshot in first post), and now get a completely expected ~3s play mode entry time:
5354217--541014--upload_2020-1-9_19-13-33.png