Output formatter unexpectedly returns new instance of scoped service

[HaoQian-MS]

Is there an existing issue for this?

• I have searched the existing issues

Describe the bug

We have a middleware and a scoped service "IRequestTelemetryContext " in our service.
Then we initialized the scoped service in the middleware. Simplified code:

public Task InvokeAsync(HttpContext context, IRequestTelemetryContext telemetryContext) 
{
   telemetryContext.StartTimeStamp = DateTime.UtcNow;
}

The "StartTimeStamp" is not updated by any other code. Then, in output formatter, we get its value back. Simplified code:

public override Task WriteResponseBodyAsync(OutputFormatterWriteContext context)
{
   var telemetryContext = context.HttpContext.RequestServices.GetService(typeof(IRequestTelemetryContext)) as IRequestTelemetryContext;
   return Task.Run(() =>
   {
        var startTimeStamp = telemetryContext.StartTimeStamp;
        // Some other code omitted
   }
}

The issue is that occasionally (at low frequency) the "StartTimeStamp" returned is DateTime.MinValue instead of the value we set in middleware. It's unexpected. Scoped service is supposed to be the same instance throughout the request.

Expected Behavior

startTimeStamp should not be the default value of DateTime.

Steps To Reproduce

No response

Exceptions (if any)

No response

.NET Version

No response

Anything else?

Project target framework is net8.0

[martincostello]

My hunch is that the issue is because you're using Task.Run(), and the Task returned from which isn't awaited. That means it's possible that the code receiving the instance still has the default value for the property because the task to set it hasn't run yet in those cases.

The fix would be to set the property directly in the middleware before returning, or to introduce some other mechanism to ensure no code that needs the value runs before the Task to set it has completed.

You can check that you're getting the same instance in the required places by doing something like calling GetHashCode() on the service, which should give you the same value.

[HaoQian-MS]

The "InvokeAsync" of middleware is executed before request handling in controller and the "WriteResponseBodyAsync" of output formatter is executed after request handling in controller. I don't think there's a "get before set".

We also tried to set the value into HttpContext.Items in the middleware and it can successfully got back in output formatter.

public Task InvokeAsync(HttpContext context, IRequestTelemetryContext telemetryContext) 
{
   telemetryContext.StartTimeStamp = DateTime.UtcNow;
   context.Items["StartTimeStamp"] = telemetryContext.StartTimeStamp;
}

public override Task WriteResponseBodyAsync(OutputFormatterWriteContext context)
{
   var telemetryContext = context.HttpContext.RequestServices.GetService(typeof(IRequestTelemetryContext)) as IRequestTelemetryContext;
   return Task.Run(() =>
   {
        var startTimeStamp = telemetryContext.StartTimeStamp;
        var startTimeStamp1 = context.HttpContext.Items["StartTimeStamp"] as DateTime?;
        // Some other code omitted
   }
}

[BrennanConroy]

Can you turn on logging and if possible provide a minimal repro app?

This seems like it'll be a difficult issue to figure out.

Side-note: wondering why you don't use:
context.HttpContext.RequestServices.GetService<IRequestTelemetryContext>()

[HaoQian-MS]

We logged hashcode of objects and found out when issue happens, the hashcode of HttpContext instance is same in middleware and output formatter. However, httpConext.RequestServices shows a different hashcode in middleware and output formatter.

I didn't find any RequestServices reassign code in our repo.

I'm not sure if there's minimal repro. Will try.

[martincostello]

If the service collections are different, that's probably because one is the app's root service collection, and the other is the scoped service collection for an individual HTTP request.

[BrennanConroy]

Try turning on scope validation so if it tries to get a scoped service from the root container it'll fail?
https://learn.microsoft.com/aspnet/core/fundamentals/host/web-host?view=aspnetcore-9.0#scope-validation

Also, since you're logging hashcodes, try logging the hashcode for the ApplicationServices as well?

[HaoQian-MS]

The validation only happens on service startup? It won't help then.
To me, the question is in what cases, httpContext.RequiredServices will change.
Another evidence on there being two scopes for a request is that we observed two dispose calls on two instances of a scoped service.
The services continues to handle following requests normally after issue observed.

[BrennanConroy]

The validation only happens on service startup?

Pretty sure it validates every time a service is created/accessed.

the question is in what cases, httpContext.RequiredServices will change.

It shouldn't change unless app code modifies it
https://source.dot.net/#Microsoft.AspNetCore.Http/Features/RequestServicesFeature.cs,31

We fallback to ApplicationServices in middleware injection here https://source.dot.net/#Microsoft.AspNetCore.Http.Abstractions/Extensions/UseMiddlewareExtensions.cs,145 but that shouldn't be possible in normal app code.