Race condition in ControllerActionInvoker causes NullRef #5807

oofpez · 2017-02-15T09:49:43Z

An unhandled exception occurs very rarely in this WebApp hosted in Kestrel.
I have attached a section of the stacktrace - anything in between is just rethrowing of the exception.

Please let me know if this is an issue inside Mvc or if I should be handling it elsewhere.

 Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware
	An unhandled exception has occurred: Object reference not set to an instance of an object.
	System.NullReferenceException: Object reference not set to an instance of an object.
    at lambda_method(Closure , Object , Object[] )    
	at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeActionMethodAsync>d__27.MoveNext() 
	--- End of stack trace from previous location where exception was thrown ---
    at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)    
	at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)    
	at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeNextActionFilterAsync>d__25.MoveNext() 
	--- End of stack trace from previous location where exception was thrown ---    
	at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Rethrow(ActionExecutedContext context)    
	at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)    
	at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeNextResourceFilter>d__22.MoveNext() 
	--- End of stack trace from previous location where exception was thrown ---    
	at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Rethrow(ResourceExecutedContext context)    
	at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)    
	at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeAsync>d__20.MoveNext() 
	--- End of stack trace from previous location where exception was thrown ---    
	at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)    
	at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)    
	at Microsoft.AspNetCore.Builder.RouterMiddleware.<Invoke>d__4.MoveNext() 
	--- End of stack trace from previous location where exception was thrown ---

...more stuff...

 --- End of stack trace from previous location where exception was thrown ---    
	at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)    
	at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)    
	at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.<Invoke>d__6.MoveNext()Null'

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

Eilon · 2017-02-17T21:31:00Z

@oofpez do you have anymore info on how to reproduce this?

@rynowak any idea what this could be?

rynowak · 2017-02-17T21:36:51Z

That's this code https://github.com/aspnet/Mvc/blob/rel/1.1.2/src/Microsoft.AspNetCore.Mvc.Core/Internal/ControllerActionInvoker.cs#L1233

What comes to mind is if there is some kind of crazy unanticipated method signature.

Sporadic says that either there's one rarely used method that's causing issues or it's a race condition

rynowak · 2017-02-18T00:51:59Z

Actually, I spaced on this part lambda_method(Closure , Object , Object[] ) - that's the generated expression thunk we use to call the controller method.

oofpez · 2017-02-24T08:15:49Z

I can't reproduce it, I only got this error occasionally when running parallel integration tests on some compression middleware. It might be some kind of race condition?

The error is rethrown at await _next(context) where _next is the RequestDelegate.

            using (var buffer = new MemoryStream())
            {
                var body = context.Response.Body;
                context.Response.Body = buffer;

                try
                {
                    await _next(context);

                    using (var compressed = new MemoryStream())
                    {
                        using (var gzip = new GZipStream(compressed, CompressionLevel.Optimal, leaveOpen: true))
                        {
                            buffer.Seek(0, SeekOrigin.Begin);
                            await buffer.CopyToAsync(gzip);
                        }

                        context.Response.Headers.Add(ContentEncodingName, new[] { GzipEncodingType });

                        if (context.Response.Headers[ContentLengthName].Count > 0)
                        {
                            context.Response.Headers[ContentLengthName] = compressed.Length.ToString();
                        }

                        compressed.Seek(0, SeekOrigin.Begin);
                        await compressed.CopyToAsync(body);
                    }
                }
                finally
                {
                    context.Response.Body = body;
                }
            }

twirpx · 2017-02-28T12:56:12Z

Getting same exception:

66.249.64.154  GET /file/163423/ - An unhandled exception has occurred: Object reference not set to an instance of an object. System.NullReferenceException: Object reference not set to an instance of an object.
   at lambda_method(Closure , Object , Object[] )
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeActionMethodAsync>d__27.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(Task task)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeNextActionFilterAsync>d__25.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Rethrow(ActionExecutedContext context)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeNextResourceFilter>d__22.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Rethrow(ResourceExecutedContext context)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeAsync>d__20.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(Task task)
   at Microsoft.AspNetCore.Builder.RouterMiddleware.<Invoke>d__4.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(Task task)
   at Site.Web.Security.CookieAuthenticationMiddleware.<Invoke>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(Task task)
   at Site.Web.Security.ApiKeyAuthenticationMiddleware.<Invoke>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(Task task)
   at Microsoft.AspNetCore.Diagnostics.StatusCodePagesMiddleware.<Invoke>d__3.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.ValidateEnd(Task task)
   at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.<Invoke>d__6.MoveNext()

Occurs randomly when executing random action. One of such actions looks like this:

[ HttpGet ]
[ Route("file/{file_id:int:required}") ]
public async Task<IActionResult> Default(int file_id, int snapshot_id = 0, string note = null) {
    ...
    return View("Default", model);
}

Maybe at ControllerActionInvoker.InvokeActionMethodAsync controller is null or became null somehow before calling

result = _executor.Execute(controller, orderedArguments);

or

result = await _executor.ExecuteAsync(controller, orderedArguments);

BTW using autofac as IServiceProvider but is seems no matter because controller is being created by DefaultControllerActivator

rynowak · 2017-03-04T01:33:35Z

I suspect that the issue here is a race condition in https://github.com/aspnet/Mvc/blob/rel/1.1.2/src/Microsoft.AspNetCore.Mvc.Core/Internal/ObjectMethodExecutor.cs#L219

It's possible to observe partially-initialized data when a thread has initialized _parameterDefaultValues to a non-null value.

rynowak · 2017-03-04T01:52:14Z

Keeping this bug to track the 2.0.0 issue, will add separate issues to port the fix to 1.0.X and 1.1.X

This change addressed a race condition in the ObjectMethodExecutor where the default argument values array can become visible before it is initialized. If a second observer accesses the array while it is being initialized, it can observe a null value for a reference type parameter, leading to a nullref. The fix here is to make everything immutable and initialize it all up front. There's no reason to create an OME without eventually running it, so there's no downside to doing the initialization up front.

elangelo · 2017-03-16T12:21:28Z

Can we expect a release in the 1.1.x cycle with this fix very soon?

Eilon · 2017-03-16T16:29:16Z

@elangelo we are working to get this into our next patch release; no ETA on that right now unfortunately. But we're hoping for next month (there are several bug fixes we want to get in).

This change addressed a race condition in the ObjectMethodExecutor where the default argument values array can become visible before it is initialized. If a second observer accesses the array while it is being initialized, it can observe a null value for a reference type parameter, leading to a nullref. The fix here is to make everything immutable and initialize it all up front. There's no reason to create an OME without eventually running it, so there's no downside to doing the initialization up front. (cherry picked from commit 8f4ca32)

Eilon added the investigate label Feb 24, 2017

Eilon assigned rynowak Feb 24, 2017

rynowak removed the investigate label Mar 4, 2017

rynowak removed their assignment Mar 4, 2017

rynowak added this to the 2.0.0-preview1 milestone Mar 4, 2017

This was referenced Mar 4, 2017

Port fix from #5807 to 1.0.X - Race condition in ControllerActionInvoker causes NullRef #5898

Closed

Port fix from #5807 to 1.1.X - Race condition in ControllerActionInvoker causes NullRef #5899

Closed

Eilon assigned rynowak Mar 4, 2017

Eilon added 1 - Ready bug labels Mar 4, 2017

Eilon changed the title ~~Null Reference Exception from ControllerActionInvoker Middleware~~ Race condition in ControllerActionInvoker causes NullRef Mar 4, 2017

rynowak added 2 - Working and removed 1 - Ready labels Mar 9, 2017

rynowak closed this as completed in 8f4ca32 Mar 16, 2017

Eilon added 3 - Done and removed 2 - Working labels Apr 2, 2017

rynowak mentioned this issue Apr 12, 2017

ObjectDisposedException when using WebListener and IP address #6067

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Race condition in ControllerActionInvoker causes NullRef #5807

Race condition in ControllerActionInvoker causes NullRef #5807

oofpez commented Feb 15, 2017 •

edited by Eilon

Loading

Eilon commented Feb 17, 2017

rynowak commented Feb 17, 2017

rynowak commented Feb 18, 2017

oofpez commented Feb 24, 2017

twirpx commented Feb 28, 2017

rynowak commented Mar 4, 2017 •

edited

Loading

rynowak commented Mar 4, 2017

elangelo commented Mar 16, 2017

Eilon commented Mar 16, 2017

Race condition in ControllerActionInvoker causes NullRef #5807

Race condition in ControllerActionInvoker causes NullRef #5807

Comments

oofpez commented Feb 15, 2017 • edited by Eilon Loading

Eilon commented Feb 17, 2017

rynowak commented Feb 17, 2017

rynowak commented Feb 18, 2017

oofpez commented Feb 24, 2017

twirpx commented Feb 28, 2017

rynowak commented Mar 4, 2017 • edited Loading

rynowak commented Mar 4, 2017

elangelo commented Mar 16, 2017

Eilon commented Mar 16, 2017

oofpez commented Feb 15, 2017 •

edited by Eilon

Loading

rynowak commented Mar 4, 2017 •

edited

Loading