4.1.0 Unhandled Exception: System.NullReferenceException: Object reference not set to an instance of an object. #205

Havunen · 2020-01-08T10:08:20Z

DryIoc 4.1.0 is throwing exception for load test.

See updated pull request to reproduce the problem:
#165

Unhandled Exception: System.NullReferenceException: Object reference not set to an instance of an object.

DryIoc.dll!DryIoc.Interpreter.InterpretGetScopedViaFactoryDelegateNoDisposalIndex(DryIoc.IResolverContext resolver, FastExpressionCompiler.LightExpression.MethodCallExpression callExpr, object paramExprs, object paramValues, DryIoc.Interpreter.ParentLambdaArgs parentArgs, bool useFec) Line 3284
	at C:\git\DryIoc\src\DryIoc\Container.cs(3284)
DryIoc.dll!DryIoc.Interpreter.TryInterpretMethodCall(DryIoc.IResolverContext r, FastExpressionCompiler.LightExpression.Expression expr, object paramExprs, object paramValues, DryIoc.Interpreter.ParentLambdaArgs parentArgs, bool useFec, ref object result) Line 2996
	at C:\git\DryIoc\src\DryIoc\Container.cs(2996)
DryIoc.dll!DryIoc.Interpreter.TryInterpret(DryIoc.IResolverContext r, FastExpressionCompiler.LightExpression.Expression expr, object paramExprs, object paramValues, DryIoc.Interpreter.ParentLambdaArgs parentArgs, bool useFec, out object result) Line 2653
	at C:\git\DryIoc\src\DryIoc\Container.cs(2653)
DryIoc.dll!DryIoc.Interpreter.TryInterpret(DryIoc.IResolverContext r, FastExpressionCompiler.LightExpression.Expression expr, object paramExprs, object paramValues, DryIoc.Interpreter.ParentLambdaArgs parentArgs, bool useFec, out object result) Line 2658
	at C:\git\DryIoc\src\DryIoc\Container.cs(2658)
DryIoc.dll!DryIoc.Interpreter.TryInterpret(DryIoc.IResolverContext r, FastExpressionCompiler.LightExpression.Expression expr, object paramExprs, object paramValues, DryIoc.Interpreter.ParentLambdaArgs parentArgs, bool useFec, out object result) Line 2614
	at C:\git\DryIoc\src\DryIoc\Container.cs(2614)
DryIoc.dll!DryIoc.Interpreter.InterpretGetNameScopedViaFactoryDelegate(DryIoc.IResolverContext r, FastExpressionCompiler.LightExpression.MethodCallExpression callExpr, object paramExprs, object paramValues, DryIoc.Interpreter.ParentLambdaArgs parentArgs, bool useFec) Line 3447
	at C:\git\DryIoc\src\DryIoc\Container.cs(3447)
DryIoc.dll!DryIoc.Interpreter.TryInterpretMethodCall(DryIoc.IResolverContext r, FastExpressionCompiler.LightExpression.Expression expr, object paramExprs, object paramValues, DryIoc.Interpreter.ParentLambdaArgs parentArgs, bool useFec, ref object result) Line 3008
	at C:\git\DryIoc\src\DryIoc\Container.cs(3008)
DryIoc.dll!DryIoc.Interpreter.TryInterpret(DryIoc.IResolverContext r, FastExpressionCompiler.LightExpression.Expression expr, object paramExprs, object paramValues, DryIoc.Interpreter.ParentLambdaArgs parentArgs, bool useFec, out object result) Line 2653
	at C:\git\DryIoc\src\DryIoc\Container.cs(2653)
DryIoc.dll!DryIoc.Interpreter.TryInterpret(DryIoc.IResolverContext r, FastExpressionCompiler.LightExpression.Expression expr, object paramExprs, object paramValues, DryIoc.Interpreter.ParentLambdaArgs parentArgs, bool useFec, out object result) Line 2658
	at C:\git\DryIoc\src\DryIoc\Container.cs(2658)
DryIoc.dll!DryIoc.Interpreter.TryInterpret(DryIoc.IResolverContext r, FastExpressionCompiler.LightExpression.Expression expr, object paramExprs, object paramValues, DryIoc.Interpreter.ParentLambdaArgs parentArgs, bool useFec, out object result) Line 2645
	at C:\git\DryIoc\src\DryIoc\Container.cs(2645)
DryIoc.dll!DryIoc.Interpreter.TryInterpretAndUnwrapContainerException(DryIoc.IResolverContext r, FastExpressionCompiler.LightExpression.Expression expr, bool useFec, out object result) Line 2510
	at C:\git\DryIoc\src\DryIoc\Container.cs(2510)
DryIoc.dll!DryIoc.Container.ResolveAndCacheKeyed(System.Type serviceType, object serviceKey, DryIoc.IfUnresolved ifUnresolved, object scopeName, System.Type requiredServiceType, DryIoc.Request preResolveParent, object[] args) Line 433
	at C:\git\DryIoc\src\DryIoc\Container.cs(433)
DryIoc.dll!DryIoc.Container.ResolveAndCache(System.Type serviceType, DryIoc.IfUnresolved ifUnresolved) Line 284
	at C:\git\DryIoc\src\DryIoc\Container.cs(284)
DryIoc.dll!DryIoc.Container.DryIoc.IResolver.Resolve(System.Type serviceType, DryIoc.IfUnresolved ifUnresolved) Line 267
	at C:\git\DryIoc\src\DryIoc\Container.cs(267)
DryIoc.dll!DryIoc.Resolver.Resolve(DryIoc.IResolver resolver, System.Type serviceType) Line 6996
	at C:\git\DryIoc\src\DryIoc\Container.cs(6996)
LoadTest.exe!LoadTest.Program.IterateInOrder.AnonymousMethod__0() Line 142
	at C:\git\DryIoc\playground\LoadTest\Program.cs(142)
[External Code]

The text was updated successfully, but these errors were encountered:

dadhi · 2020-01-08T11:19:25Z

Hi @Havunen

You are just in time, thanks for finding.
Do you have maybe a line numbers for the exception stack?

Havunen · 2020-01-08T11:37:31Z

@dadhi
Sure. I updated the issue. You can also reproduce the issue with changes done to LoadTest:
#165

Havunen · 2020-01-08T11:40:11Z

@dadhi
When debugging the edited load test I am also seeing following alert to popup.

dadhi · 2020-01-08T11:45:41Z

When debugging the edited load test I am also seeing following alert to popup.

Thanks, this is valuable - some of my assumtions were surely wrong. Will check.

Havunen · 2020-01-09T19:54:42Z

Awesome, I'm waiting for next release! :)

dadhi · 2020-01-09T20:19:39Z

@Havunen Did you see the results I've added in comment in LoadTest Program.cs?
Interesting, is it OK to have 15 and 16 min of test time? I have also saw 155 threads in output. Sorry I did not have much time to fully grasp what the test is doing, just concentrated on the fixes.

Havunen · 2020-01-09T20:45:49Z

Yes I noticed it. The test takes for a while because it creates lots of parallel load to verify there is no dead-lock / locking issues. I will run the tests now and compare it to previous DryIoc version to see if there is performance change.

Havunen · 2020-01-09T21:06:59Z

@dadhi Did you notice that when running LoadTest using "WithoutFastExpressionCompiler" -option its now crashing to new exception:

Unhandled Exception:
Unhandled Exception:

Unhandled Exception:Unhandled Exception: Unhandled Exception:
Unhandled Exception: Unhandled Exception: Unhandled Exception: Unhandled Exception: Unhandled Exception:Unhandled Exception:
 Unhandled Exception: Unhandled Exception:   Unhandled Exception:
Unhandled Exception:


Unhandled Exception: Unhandled Exception: Unhandled Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
   at DryIoc.Container.Registry.TryCacheKeyedFactory(Type type, Object key, Object factory)
   at DryIoc.Container.ResolveAndCacheKeyed(Type serviceType, Object serviceKey, IfUnresolved ifUnresolved, Object scopeName, Type requiredServiceType, Request preResolveParent, Object[] args)    at DryIoc.Container.ResolveAndCache(Type serviceType, IfUnresolved ifUnresolved)
   at DryIoc.Container.DryIoc.IResolver.Resolve(Type serviceType, IfUnresolved ifUnresolved)
   at LoadTest.Program.<>c__DisplayClass3_0.<IterateInOrder>b__0()
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Threading.ThreadHelper.ThreadStart()
System.IndexOutOfRangeException: Index was outside the bounds of the array.
   at DryIoc.Container.Registry.TryCacheKeyedFactory(Type type, Object key, Object factory)
   at DryIoc.Container.ResolveAndCacheKeyed(Type serviceType, Object serviceKey, IfUnresolved ifUnresolved, Object scopeName, Type requiredServiceType, Request preResolveParent, Object[] args)    at DryIoc.Container.ResolveAndCache(Type serviceType, IfUnresolved ifUnresolved)
   at DryIoc.Container.DryIoc.IResolver.Resolve(Type serviceType, IfUnresolved ifUnresolved)
   at LoadTest.Program.<>c__DisplayClass3_0.<IterateInOrder>b__0()
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Threading.ThreadHelper.ThreadStart()

dadhi · 2020-01-09T21:15:11Z

I did not test it without FEC, but now will do. thanks again. I have a clue regarding this exception.

dadhi · 2020-01-10T20:15:43Z

@Havunen ,
I have fixed the keyed resolution cache which was not working at all - that means controllers were not cached and not compiled either.
After the fix it is became clear that compilation slows down the whole thing 100x times - so to emulate the previous results I need to add WithUseInterpreation() rule.

The problem with compilation is not only compilation time but multiple threads attempting to compile the same expression wasting the resources and moreover competing over resources slowing everythijg even further (cpu was 100% loaded).

Havunen · 2020-01-10T20:36:03Z

@dadhi

I think its real-world problem in web applications, multiple threads can start resolving same controller same time? It would be good to get it fixed.

In the load test I tried to compile and cache everything before the actual parallel work starts.
See these code lines:
https://github.com/dadhi/DryIoc/blob/master/playground/LoadTest/Program.cs#L108-L110

I thought DryIoc works so that first time it resolves controller it interprets the result and then next time it caches it. Doesn't it work like that anymore?

dadhi · 2020-01-11T06:54:10Z

The lines you've mentioned should work as expected , I will add stopwatch to track how much time it takes.
I've added the issue #208 to address compilation.

dadhi · 2020-01-11T07:42:11Z

I have documented the exact pipeline here #199 (comment)

dadhi · 2020-01-11T08:19:09Z

I think, here is the way to go for now #208 (comment)

dadhi · 2020-01-11T17:31:52Z

Feeling dumb, I've fixed another issue with the keyed service and it started to work.

Havunen · 2020-01-14T10:19:29Z

I think ideally it would be nice to run LoadTest using all possible Configurations, but then it would take even longer to finish...

dadhi · 2020-01-14T11:17:19Z

I have run it locally with and without FEC and the times are both faster (~ 7 and 10 minutes). I have added the results to the source and will push it later.
It would be also interesting to check WithUseInterpretation.. will see.

dadhi · 2020-01-15T19:42:08Z

Here the results:

/*
* The results after fixes on my 8750h machine:
*
* - Validation finished       - 00:00:27.39
*
* - ResolveAllControllersOnce of 156 controllers
* -- Default               - 1st time: 0.2001231 seconds, 2nd time (cache entry compilation):    4.8156956  seconds (!!! - FEC is 4 times faster)
* -- WithoutFEC            - 1st time: 0.2052857 seconds, 2nd time (cache entry compilation):    16.4215528 seconds
* -- WithUseInterpretation - 1st time: 0.20758   seconds, 2nd time (cache entry interpretation): 0.1651708  seconds
*
* - Starting compiled + cached tests:
* -- Load Test Finished       - 00:00:37.35; WithoutFEC: 00:00:33.65; WithUseInterpretation: 00:00:58.54; 
* -- Randomized Load Finished - 00:07:42.93; WithoutFEC: 00:07:49.95; WithUseInterpretation: 00:08:07.61; 
*
* - Starting cold run tests
* -- Load Test Finished       - 00:00:41.93; WithoutFEC: 00:00:50.20; WithUseInterpretation: 00:00:59.72; 
* -- Randomized Load Finished - 00:07:53.44; WithoutFEC: 00:08:18.08; WithUseInterpretation: 00:08:20.03; 
*/

Havunen · 2020-01-15T20:10:18Z

hmm, in the second section

Starting compiled + cached tests:

-- Load Test Finished - 00:00:37.35; WithoutFEC: 00:00:33.65; WithUseInterpretation: 00:00:58.54;

Does that mean FEC compiled code executes slower than FEC (linq) compiled code?
Randomized tests we can pretty much ignore because there is random involved, one run might resolve heavy constructor more times than next run.

dadhi · 2020-01-15T21:13:36Z

I am not sure, may be I did something on my machine while testing or just exchanged the results by mistake. I run each test only once.

Havunen · 2020-01-15T23:01:38Z

I tested it on my machine too and linq compiled code execute about 25% faster, no idea why :( IL code seems very simple... maybe there is a catch somewhere

dadhi · 2020-01-16T05:46:49Z

Thanks for the testing
Obviously there is a catch - I will open a separate issue for this.

* fixing keyed cache #205 results and fixed #208 * first compiling draft for the #101 * fixed spelling in DIZero readme * added ResolveGenerated to Resolve * ResolveGenerated for the keyed service fixing CI - removing System.Diagnostics.CodeAnalysis.ExcludeFromCodeCoverageAttribute * added ResolveMany and the passing test for the Example * rc * moar * renaming and package related stuff * tests WithoutFEC * fix source package * add smarter initial factory id * fix net40 target * WIP adding to the ASP .NET Core sample the CompileTimeDI * added troubleshooting tip * moving the DIZero stuff to CompileTimeDI folder including example updating release notes * added Asp NET Core 3.1 Mvc example - WIP * cleanup

dadhi added the bug Something isn't working label Jan 8, 2020

dadhi added this to the v4.1.0 milestone Jan 8, 2020

dadhi added a commit that referenced this issue Jan 9, 2020

fixed : #205

89ec947

dadhi closed this as completed in 1f47aed Jan 9, 2020

dadhi mentioned this issue Jan 9, 2020

Pool slot array for ImMap and ImHashMap in caches and scope #204

Closed

dadhi reopened this Jan 9, 2020

dadhi mentioned this issue Jan 10, 2020

Avoid wasteful compilation of the same cached expression by multiple threads #208

Closed

dadhi added a commit that referenced this issue Jan 15, 2020

fixing keyed cache #205 results and fixed #208

5176248

dadhi added a commit that referenced this issue Jan 15, 2020

fixing keyed cache #205 results and fixed #208 (#209)

4da18a3

dadhi closed this as completed Jan 15, 2020

dadhi mentioned this issue Jan 16, 2020

Observing FEC compiled code is 25 percent slower in some cases #211

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

4.1.0 Unhandled Exception: System.NullReferenceException: Object reference not set to an instance of an object. #205

4.1.0 Unhandled Exception: System.NullReferenceException: Object reference not set to an instance of an object. #205

Havunen commented Jan 8, 2020 •

edited

Loading

dadhi commented Jan 8, 2020

Havunen commented Jan 8, 2020

Havunen commented Jan 8, 2020 •

edited

Loading

dadhi commented Jan 8, 2020

Havunen commented Jan 9, 2020

dadhi commented Jan 9, 2020

Havunen commented Jan 9, 2020

Havunen commented Jan 9, 2020

dadhi commented Jan 9, 2020

dadhi commented Jan 10, 2020

Havunen commented Jan 10, 2020

dadhi commented Jan 11, 2020

dadhi commented Jan 11, 2020

dadhi commented Jan 11, 2020

dadhi commented Jan 11, 2020

Havunen commented Jan 14, 2020

dadhi commented Jan 14, 2020

dadhi commented Jan 15, 2020

Havunen commented Jan 15, 2020 •

edited

Loading

dadhi commented Jan 15, 2020

Havunen commented Jan 15, 2020

dadhi commented Jan 16, 2020

4.1.0 Unhandled Exception: System.NullReferenceException: Object reference not set to an instance of an object. #205

4.1.0 Unhandled Exception: System.NullReferenceException: Object reference not set to an instance of an object. #205

Comments

Havunen commented Jan 8, 2020 • edited Loading

dadhi commented Jan 8, 2020

Havunen commented Jan 8, 2020

Havunen commented Jan 8, 2020 • edited Loading

dadhi commented Jan 8, 2020

Havunen commented Jan 9, 2020

dadhi commented Jan 9, 2020

Havunen commented Jan 9, 2020

Havunen commented Jan 9, 2020

dadhi commented Jan 9, 2020

dadhi commented Jan 10, 2020

Havunen commented Jan 10, 2020

dadhi commented Jan 11, 2020

dadhi commented Jan 11, 2020

dadhi commented Jan 11, 2020

dadhi commented Jan 11, 2020

Havunen commented Jan 14, 2020

dadhi commented Jan 14, 2020

dadhi commented Jan 15, 2020

Havunen commented Jan 15, 2020 • edited Loading

dadhi commented Jan 15, 2020

Havunen commented Jan 15, 2020

dadhi commented Jan 16, 2020

Havunen commented Jan 8, 2020 •

edited

Loading

Havunen commented Jan 8, 2020 •

edited

Loading

Havunen commented Jan 15, 2020 •

edited

Loading