Unity Script Compilation - IO analyis - Editor.log does two IO calls per byte written

I spent some time looking at our script compile / reload performance and trying to understand where the time is going. Lets look at the original state of things from the moment we click on unity and it starts a script recompile.

> baseline benchmark

a) recompiling scripts (9s, spinner icon spinning)
b) doing something (6s, spinner icon frozen, editor frozen)

This is too slow, so I tried using the incremental compiler from here:

https://github.com/SaladLab/Unity3D.IncrementalCompiler

> incremental compiler added

a) recompiling scripts (3s, spinner icon spinning)
b) doing something (6s, frozen)

This is amazing, and much much better, but what is the halt after we finish compiling? I ran procmon and did some rough analysis of what is happening during the whole compilation process. You can see the full notes here: http://pastebin.com/n7FbycVH

There are five major time consuming things going on:

a) actual compilation work
b) devenv spamming git reads/writes/packs
c) unity log writes
d) NotifyChangeDirectory()
e) SearchIndexer.exe

Lets look at each of these:

a) actual compilation work: this is normal and expected

b) devenv spamming git

Tools->Options->Source Control->Plug-in Selection: choose None, restart Visual Studio

c) unity log writes

Ok, now we're going to dig deeper here because the log writes are taking up a huge amount of time. Looking at the procmon calls it seems that each log write issues two windows API calls for EACH CHARACTER that it writes to log.



Needless to say, this is slow. For my test compilation that is 600,000~ IO calls, for writing 5000~ lines of text. I don't know if unity log code is expecting clib to buffer or write differently, but this is not good. I don't know how well windows IO or SSD drivers will be handling this in terms of buffering.

Looking at the general time taken, this is somewhere close to half the freeze time after compilation (2-3s). I would consider this is a massive massive bug in Unity that should be extremely high priority.

Attempting to make the Editor.log read-only will crash Unity, I'm looking at alternative (maybe mount the editor log folder directly in memory, instead of on disk).

d) NotifyChangeDirectory()

I don't really know much about this API, or what to do about it. Suggestions welcome!

e) SearchIndexer.exe

Start->Run, services.msc, Windows Search, right-click -> Properties, Startup: Disabled.


Summary:

Unity editor logging is the worst possible performance implementation possible, as far as I understand. Visual Studio default settings for source control are slow. Windows SearchIndexer is slow. Incremental compiler is great.

Actual post-compilation freeze time should be able to be reduced from 6s to about 1-2s if the Unity logging is fixed. This should bring total edit/run cycle from about 15s to about 5s.

 

Regarding NotifyChangeDirectory(), this is called a few times swapping from c:\project to c:\project\Unity\project folder, and then back again, it seems like it could be replaced with better path handling to prevent the whole stall during build.

 

Minor optimization: -logFile NUL

This will prevent log files actually doing IO writes, but it's still probably a lot of overhead just calling IO API.

 

In the meantime, an SSD (for those that don't have them) and lots of RAM, plus something like PrimoCache might help.

 

What did you mean by "Minor optimization: -logFile NUL"? How do I use that? Have you learned of any new ways to speed up compilation? Thanks for all your work!

 

@Speedrun-Labs It means starting Unity with that parameter, like so

"C:\Program Files\Unity\Editor\Unity.exe" -logFile NUL

This will prevent Unity from actually writing anything, but I'm not sure how much is there to gain from that.
That command is telling Unity to use NUL as a log file. Using NUL as a filename is similar to piping to /dev/null in linux.

 

The bug with writing logs so badly was fixed; it shouldn't be a problem as much now. You can just use '-nolog' parameter on the editor anyway, which should be better than the method above. It's all still kind of slow anyway, just gotta enjoy the suffering.

 

In the original thread about the incremental C# compiler, I posted a note about the error I'm seeing in 2017.1: https://forum.unity.com/threads/incremental-c-compiler-for-faster-compilation.379613/#post-3292772

Not sure if anyone here has any insight on it; there wasn't anything I saw that made that work easily, and their project has had no commits for 7 months at this point.

Using -nolog does seem to help with the compile time being a bit lower, but it's hard to say for sure. Turning off windows search makes sense, but that is then more widespread-annoying elsewhere on windows. Is that still a needed thing if the logging is off?

I have 32GB of RAM and a top-end SSD, but the compile times on large projects are still killer, even with a lot of things moved into Standard Assets to prevent continual recompilation. It's a bit baffling. Compiling the code directly from visual studio takes under two seconds, if that. In unity it's sometimes a 31-second turnaround time if you include a lengthy period before and after the script compilation process that happens in the middle.

I'm using TortoiseSVN locally for an svn repository, and then using visual studio 2015 with VisualSVN installed as a plugin there. Turning that off seems to maybe slightly increase the speed of the "waiting on something" period, but it wound up turning itself back on and I don't think it was really that big a help. Maybe I should switch to VS 2017 and see how that does.

I'm surprised more people aren't up in arms about this, frankly.

 

If I were to guess, the unity QA team will test this on a very small project (if even, maybe they just add a single .cs file to a new project). So they'll need something bigger to actually confirm slow performance.

I noticed extremely long (20s+) delays when changing code and switching back to unity as well.

(Windows 7, high-end SSD)

 

Blah. And there's no real way to benchmark what is taking so long here, that I'm aware of at least. I mean, we can use educated guesses and point to excessive file accesses, but we can't know quite why this is happening or what is being processed simply in memory in a strange way.

 

Well -- moving to Unity 2017.3 beta and converting everything into separate dlls via the new script compilation assembly definitions seems to have fixed it for me.

The documentation, if you haven't seen it: https://docs.unity3d.com/2017.3/Documentation/Manual/ScriptCompilationAssemblyDefinitionFiles.html

I've turned back on the windows search indexer and that seems not to make a difference anymore. The "hang after compile" time has pretty much disappeared, and that's with logging still on. The actual import and compilation times are, side-by-side, almost twice as fast as Unity 2017.1 even for things that aren't scripts.

They've made a lot of strides, for sure. The compilation time itself is still pretty bad, but at least now we can split that apart and have less compiling all at once. The downside is increased project complexity, regarding dependencies and so forth.

I'm down from a 31+ second turnaround time from code changes to being able to hit play in the editor, to closer to 9, and that's with a lot of background stuff hitting my disk during that particular test, so it wasn't really a fair fight. Really it's more like 5 or 7 seconds if I didn't have an svn commit and some audio transcoding going on in separate processes in the background.

So... definitely worth an upgrade. For what it's worth, stability has been good so far with beta 9. I think it's supposed to leave beta by the end of this month.

 

@kalineh did you continue with your benchmarks/tests? I'm also investigating how to improve the "freeze" time after compilation. It seems just useless waste of time.

At least having a specific way to diagnose what causes the problem is extremely useful. Thanks btw!

 

I'm interested in this too. On my work machine with tons of stuff open compile times are damn near instant, at the house with only Unity and VS on slightly slower hardware, it's frustratingly slow.

Work:
Intel I7-9700K base 3.6Ghz, 32GB DDR4 1600Mhz with EVO 860 M.2 SSD

Home:
AMD Ryzen ? base 3.7GHZ, 16GB DDR4 1600Mhz with EVO 860 SATA III SSD

(It's possible I need to upgrade from a SATA III to an M.2 SSD)

 

That's a 10x slower hard drive, I'd say at a glance.

 

Yeah I have an 890 PRO NVMe M2 PCIe x4 in the mail now, bought it not long after posting. I did a quick google on them and was so shocked at how cheap the drives were, that I just bought one on the spot; $150 for 1TB! of the 3rd fastest SSD).

Next up is my home pc CPU, it's slower than I thought, the work CPU is 36% faster according to cpu.userbenchmark.com. I'll catalog the results when the gear comes in so we can see it's effects for future googlers.

 

Slow hard drive on your home machine + slower cpu. Unity loves a fast singecore. So: intel