Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ArrayPool logging initialization is 70% of startup for empty program #9579

Closed
jkotas opened this issue Jan 21, 2018 · 9 comments
Closed

ArrayPool logging initialization is 70% of startup for empty program #9579

jkotas opened this issue Jan 21, 2018 · 9 comments
Labels
tenet-performance Performance related issue
Milestone

Comments

@jkotas
Copy link
Member

jkotas commented Jan 21, 2018

Empty program executes about 320 managed methods today (in release build). Initialization of ArrayPool logging (ArrayPoolEventSource) is responsible for 220 of them. When the ArrayPool initialization is commented out, I am back to about 100 where we used to to be historically.

Is the ArrayPool logging valueable enough to contribute this much to startup cost of empty program? Can we make it cheaper or not have it?

@jkotas
Copy link
Member Author

jkotas commented Jan 21, 2018

cc @vancem

@stephentoub
Copy link
Member

Just curious, what in an empty program uses ArrayPool?

@jkotas
Copy link
Member Author

jkotas commented Jan 21, 2018

The first call comes from Path APIs:

System_Private_CoreLib!System.Runtime.InteropServices.StringBuffer..ctor(Int32)+0x5b
System_Private_CoreLib!System.IO.PathHelper.Normalize(System.String, Boolean, Boolean)+0x57
System_Private_CoreLib!System.IO.Path.GetFullPath(System.String)+0x3b1
System_Private_CoreLib!System.AppDomain.NormalizePath(System.String, Boolean)+0x2e
System_Private_CoreLib!System.AppDomain.NormalizeAppPaths(System.String)+0x1d4
System_Private_CoreLib!System.AppDomain.Setup(System.Object)+0x651

@benaadams
Copy link
Member

benaadams commented Jan 21, 2018

Its all to run log.IsEnabled() and get false back.

I had a look at this before and but couldn't work out how to address it, is 100% EventSource .ctor.
Looks like Guid generation/Sha1, CultureInfo and Reflection

image

@benaadams
Copy link
Member

With Prestub/Unknown contributing:
image

@benaadams
Copy link
Member

Time wise 87% is EventSource.GetGuid

@Alois-xx
Copy link
Contributor

@benaadams : Then using the internal EventSource ctor with the guid would be way to go. Reading the Guid via reflection is costly after all. FrameworkEventSource() uses this trick.

@benaadams
Copy link
Member

Then using the internal EventSource ctor with the guid would be way to go.

Seems to do the trick, goes straight to Initialize dotnet/coreclr#16054

Post
image

@Alois-xx
Copy link
Contributor

That was a fast change. The numbers look great.

@msftgits msftgits transferred this issue from dotnet/coreclr Jan 31, 2020
@msftgits msftgits added this to the 2.1.0 milestone Jan 31, 2020
@ghost ghost locked as resolved and limited conversation to collaborators Dec 18, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
tenet-performance Performance related issue
Projects
None yet
Development

No branches or pull requests

5 participants