DryIoc cold start performance

[Fruchuxs]

After one week of investigations we found out, that DryIoc 3.0.2 is rather slow in comparison to 2.12.8 at the first execution time (cold start). In most cases the first call of a C# application doesn't count. But we measured a time increase of ca. six seconds for greater object graphs in our application. So for example our asp.net core 2.1 application starts, DryIoc resolves some small Services, than the applications tries to resolve a controller and .. we can make a cup of coffee. For a web applications this is just uncomfortable (because after the JIT compiling it's fast), but for one of our console applications this is really painful.

We looked at the expression trees which dryioc generates in version 3.0.2 and 2.12.8 for one of our object graphs. Too much to post here and to analyze in depth, but we can say, that the dryioc 3.0.2 expression tree is roundabout 90% bigger and seems even more complex.

We didn't changed the service registrations much. We just replaced Reuse.InWebrequest through Reuse.Scoped and two RegisterDelegates through RegisterMany as you mentioned out here.

Maybe you can say more about this? In most of the cases we use simple service registrations like Register<IA, A>, or factories, or made: Parameters.Of.Type ... We also use the IEnumerable-resolve Feature.

[dadhi]

Hi @Fruchuxs ,

v3 does not reuse expressions across the object graph, so if you have A in multiple places in the object graph, you will have new expressions each time. Basically, the expression cache was removed, because it was really hard to figure out the invalidation pattern.

In upcoming v3.1 the expression reuse (cache) is back. But it has a different transient nature, which is simple to manage. It should improve cold-start performance.

For the other use-cases, I am not sure. Could you provide some notable parts of the object graphs, where you see an increase comparing to v2?

[dadhi]

You can use container.Resolve<LambdaExpression>(serviceType) to get an actual expression. Just don't forget to OpenScope if you are resolving a scoped service.

[Fruchuxs]

Hello again, thanks for your quick responses. I think I will await v3.1. With your explanations it makes sense, why the graphs seems more complex, because of the nested graphs. So no problems here I think. Can you give a time span you think you are ready with v3.1? Just to examinate if we need to downgrade.

[dadhi]

Next week, hopefully.

[dadhi]

Another idea, I can release a preview of 3.1 now.

Would you be able to check performance using it?

[Fruchuxs]

Sounds nice. I can test it, maybe till monday.

[dadhi]

The late update..

While working in 3.1 preview release, I have found (remembered) other problem with .net core targeting. That .net core won't use FEC, oops :(

That was done close to v3 because of complexity (new projects needed) to support .netstandard 1.3 and 2.0 versions.

But the main obstacle is that I have used old csproj system.

I went ahead, and started to bring everything under new csprojs with multi-targeting. At the moment I am almost complete to release the preview. Hopefully, tomorrow.

[dadhi]

Preview is out: https://www.nuget.org/packages/DryIoc.dll/3.1.0-preview-01

[Fruchuxs]

Thank you for the prerelease. But we got an exception in our main project we can't explain. I assume a problem with DryIoc.Microsoft.DependencyInjection. A Testproject with only DryIoc works fine.

System.IO.FileLoadException: 'Could not load file or assembly 'DryIoc, Version=3.0.2.0, Culture=neutral, PublicKeyToken=null'. The located assembly's manifest definition does not match the assembly reference. (Exception from HRESULT: 0x80131040)'

I checked all our projects and can't find a reference to 3.0.2.0, but VS generates 3.0.2.0 references in .assembly.cache and .deps.json files. Looks strange to me.

[dadhi]

This is strange, the problem either with assembly versions in preview, or with Di.Ms.Di deps. Will check.

[dadhi]

Try the new DI.MS.DI preview: https://www.nuget.org/packages/DryIoc.Microsoft.DependencyInjection/2.2.0-preview-01

[Fruchuxs]

Got the same exception with different assembly version number (3.1.0.0). We looked into the .net standard 2.0 assembly with ILSpy and it seems, that the assembly version is not set ("0.0.0.0"). Dunno how this happened, your cproj Files seems to be correct.

[dadhi]

But now I know a possible reason. Thank you. I will release new DryIoc preview 2 with fix.

[dadhi]

https://www.nuget.org/packages/DryIoc.dll/3.1.0-preview-02

[Fruchuxs]

Not so fast as 2.12.8, but a greatly increase to 3.0 in our cases (~0,5 seconds difference). Over all it looks great. Thank you.

[dadhi]

Interesting, I would like to look at your object graph. Maybe it something simple to fix or optimize.

[Fruchuxs]

Here it is. tree.txt

[dadhi]

Thank you very much. It is a deep tree indeed.

Could you try to add the rule to the container:

new Container(rules => rules.WithoutDependencyDepthToSplitObjectGraph());

or via:

container.With(rules => rules.WithoutDependencyDepthToSplitObjectGraph());

or with DependencyDepth set to a bigger than 8 (a default value):

container.With(rules => rules.WithDependencyDepthToSplitObjectGraph(20));

and check the results.

The reason is the default Rules.DefaultDependencyDepthToSplitObjectGraph is set to 8. Maybe, it is not a good default value. It would be good to find out.

The number is used to split an object sub-graph deeper than the 8th level to the separate Resolve call, But this nested call requires a context from the upper graph (for instance, if you need a condition based injection, or find a mismatching lifestyle), so there goes call-stack recreation with Request.Empty.Push(..).Push(..).Push(..),.., etc. So, here is the tradeoff.

BTW, The mechanizm in v2 for splitting the large object graph was different, based on whole amount of dependencies rather than on the depth.

[Fruchuxs]

Thank you for the information and explanation. But with WithoutDependencyDepthToSplitObjectGraph the container resolves slower and the graph seems bigger (a little bit). In conclusion it doesn't matter.

[Fruchuxs]

Okay, I tested with another graph (but with a similar depth). Here the results:

WithDependencyDepthToSplitObjectGraph(20) 00:00:00.1715299

WithDependencyDepthToSplitObjectGraph(2) // just for the science 00:00:00.1683051

WithDependencyDepthToSplitObjectGraph(8) 00:00:00.1934737

With Default Constructor 00:00:00.1531935

WithoutDependencyDepthToSplitObjectGraph 00:00:00.1361311

[Fruchuxs]

But the measurements fluctating .. As I said, I don't think it matters in our cases.

[dadhi]

Thank you for measuring!

Seems like using the depth split does not add any value in your case.

Need to go deeper..

[dadhi]

Could you use a ExpressionToCodeLib nuget package and dump the expression without depth argument?

[Fruchuxs]

Here the Tree To Code output from the tree I used for measuring.

treetocode.txt

[dadhi]

That's what I need! Thank you.

[dadhi]

Shame on me, the FastExpressionCompiler was not included yet because of different compile constant :-( Now fixed in DryIoc v3.1.0-preview-03. Please, check.

[Fruchuxs]

Btw. (I don't tested pv03 yet) we investigated with pv02, that we got an lifespan exception in our web project:

ContainerException: Dependency AuthStateManager as parameter "aAuthStateManager" reuse Scoped {Lifespan=100} lifespan shorter than its parent's: scoped AuthenticationEvents #284 from Container with Scope {no name} with Rules with {TrackingDisposableTransients, SelectLastRegisteredFactory} and without {ThrowOnRegisteringDisposableTransient} with FactorySelector= with Made.Of= To turn Off this error, specify the rule with new Container(rules => rules.WithoutThrowIfDependencyHasShorterReuseLifespan()).

The problem is, that AuthStateManager is added via dryIoc as reuse: Reuse.Scoped and AuthenticationEvents via .net DI with AddScoped. We replaced the .net DI registration with a dryIoc equivalent and we don't got the exception anymore. We checked the Code in Di.Ms.Di and discovered that AddScoped is registred in dryIoc as Reuse.ScopedOrSingleton. So we changed our replaced service registration with Reuse.Scoped to Reuse.ScopedOrSingletone and the exception occured again. We tested out if our services was added as singleton by dryioc, because maybe no scope was open and the new version is just more restrictive, but we had to recognize that the object is created at every request and not just first. In conclusion it seems, that dryioc means that ScopedOrSingleton is more healthy as Scoped which seems strange.

[dadhi]

Mm, ok. Another thing to check.

Have an idea, though...

[Fruchuxs]

Don't know why, but prev02 seems faster. I started a loop with 50 iterations. with the creation of the container and measured the resolving of the object from the graph I posted before ... The median as well as the average says, that prev02 is faster for this graph.

prev02	prev03	type
0,0178340	0,0214996	median
0,0224712	0,0261303	average

Maybe my test is nonsense, because I have no idea how your cache works. I just hope you cache is an instance not shared cache and no static shared cache. I think this values are negligible. Sadly I can't test the performance of the more complex tree of our web controllers good because of asp.net core dependencies and contexts.

[dadhi]

ok, thanks for that. And I am lost a bit. Let it sink in over weekend :)

[Fruchuxs]

Okay, we found out that there is some JIT magic .. If we resolve an object, the dryioc tree doesn't seems to be compiled by the JIT compiler. I assume JIT means, that it doesn't need to instatiate the object because it isn't used yet. First we access a method on the resolved object, the JIT compiler instantiates the object completly (but just with the dependencies he needs to execute the method). Then the JIT Compiler starts to compile the dryIoc tree in the need to instantiate the object ... I'm not sure this is true.

But this means, that my tests are just nonesense. In the Test-Loop I just resolve the service, but never used it. I will try to find a better test.

EDIT: Tryed to simplify my explanations. :p

[dadhi]

Hi again,

Just realeased a Preview 4: https://www.nuget.org/packages/DryIoc.dll/3.1.0-preview-04

I have fixed (hopefully) bug with wrong reuse mismatch for Scoped and ScopedOrSingleton.

I have also condensed a Request stack passed to Resove to a single Constant, it should decrease size of graph with default depth split value (8).

Will be happy to hear your feeadback. Thanks!

[Fruchuxs]

Hey,

New performance numbers for you:

3.0	pv2	pv4
5,0888453	1,5168796	2,1876228
5,5643245	1,8527184	0,9721876
5,9362024	1,9551376	1,1744556
7,013724	2,0682004	1,3053725
7,4730085	2,1848985	2,2390254
6,21522094	1,9155669	1,57573278

We tested it with the whole console application which uses the dependency graph above, but the app doesn't do much. So the performance lost through other code should be marginal. The other bug doesn't occur anymore since prev 04. :)

EDIT: Value measurements in seconds.

[dadhi]

@Fruchuxs Thanks, What about V2 for comparison?

[Fruchuxs]

Here the results incuding DryIoc 2.12.

3.0	pv2	pv4	2.12
5,0888453	1,5168796	2,1876228	1,6066698
5,5643245	1,8527184	0,9721876	1,4519457
5,9362024	1,9551376	1,1744556	1,4118938
7,013724	2,0682004	1,3053725	1,4485652
7,4730085	2,1848985	2,2390254	1,2885061
6,21522094	1,9155669	1,57573278	1,44151612

It's hard to measure, there are hight flucatuations between the probes. I assume this is a problem with the CPU boost / throttling.

[dadhi]

Ok, now I can see the scale.

I think, the major problem is addresed :)

So, I am planning to close the issue when v3.1 rtm is released.

The expression dump you provided gave me a ton of info, and hopefully I will find some time later to dig it more thoroughly.

If you have an idea, what other optimizations may be done, let's discuss.

[Fruchuxs]

Nice to hear! If I find other Problems or suggestion I will open another ticket like here. I'm looking forward to 3.1 Release. :)

[ahydrax]

Env: .NET 4.6.2; DryIoc.dll 3.0.2; selfhost owin/IIS Express

Faced the same problem: I have a complex object graph (with deep nesting services and decorators). Cold start for some on my controllers takes about 1 minute (!) and memory footprint raises up to 13Gb. Profiling showed that 99% memory allocations and CPU are consumed by JIT.

I'm also getting StackOverflowException when running my app over IIS Express but stack trace shows that there are only ~30-40 stack frames. The most interesting thing is that my app works in selfhost mode. It seems like something inside DryIoC/JIT allocates a lot on stack and when I'm using IIS Express I'm hitting the stack size.

Gonna test 3.1.0-preview.

[dadhi]

@ahydrax Thanks for reporting. Let me know what are results with v3.1

[ahydrax]

Hi @dadhi Cold start became faster but I'm still getting StackOverflowException under IIS Express. Tried to use .WithoutDependencyDepthToSplitObjectGraph() - got the same results. Application still works under selfhost mode (same code, same test, same container configuration Rules.Default.WithoutDependencyDepthToSplitObjectGraph()). Gist with call stack: https://gist.github.com/ahydrax/bfb1f2132f478af6465ad577f2157bd5

Another thing is the huge memory footprint more than 4gb for just started application. Used latest preview: 3.1.0-preview-05

[dadhi]

Strange, not so much stack to choke in.

Mmm, what is the size of graph? How many layers deep and how many arguments in constructors on each layer. What are the reuses, Scoped?

[dadhi]

@ahydrax , Also, did you use any Func<X> dependencies?

[ahydrax]

@dadhi, no, I don't use any Func<X> or Action<X> dependencies. The most big controller (whom resolution causes StackOverflowException) uses 14 dependencies. Each dependency can have from 0 to 7 layers deep, from 1 to 15 constructor arguments, approximately ~200 resolutions have to be done in total. Most registrations are Transient. Controllers registered as Scoped.

[ahydrax]

@dadhi, Found interesting thing, tried with both 3.0.2 and 3.1.0-preview5

• Created container with default config
• Generated resolution expression using container.GenerateResolutionExpressions(x => x.ServiceType.Name.EndsWith("MyControllerWithLotOfDependencies"));
• Generated code using ExpressionToCodeLib and saved it to a file 3.0.2 resulted a 5mb text file whereas 3.1.0-preview5 resulted 18mb file.

Anything else I can do to help you with diagnosting this?

[dadhi]

3.0.2 resulted a 5mb text file whereas 3.1.0-preview5 resulted 18mb file.

Omg, I suppose the latter result uses .WithoutDependencyDepthToSplitObjectGraph() or no?

I would love to peek into that dump as well, any chance?

[dadhi]

Linking #39 and #40 here.

[ahydrax]

3.0.2 resulted a 5mb text file whereas 3.1.0-preview5 resulted 18mb file.

Omg, I suppose the latter result using .WithoutDependencyDepthToSplitObjectGraph() or not?

Yes, using .WithoutDependencyDepthToSplitObjectGraph() on 3.1.0-preview gives bigger output than stable version.

[dadhi]

What is the default output size in v3.1 without .WithoutDependencyDepthToSplitObjectGraph()

[ahydrax]

Same, I even tried to diff both files: exactly the same. ~17346kB

[dadhi]

Ok, could you try a different value for .WithDependencyDepthToSplitObjectGraph(5) like 5 or something?