Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

ASP.NET Core MVC app request never finish

I am trying to host a ASP.NET Core MVC project on a single core Windows Server 2012 host. I am using ASP.NET Core MVC 1.0.0 and running on IIS 8 with .NET Framework 4.6.1 The app works fine at first ~10 minutes, and then suddenly the server stops responding.

At first I thought it was deadlock on database side so I added logging in the DbContext class:

private static long ActiveContextCount = 0;
private ILogger _log;
private Stopwatch _timer = new Stopwatch();
private Guid _contextId = Guid.NewGuid();
public BlogContext(string nameOrConnectionString, ILoggerFactory logger)
        :base(nameOrConnectionString)
{
    _log  = logger.CreateLogger<BlogContext>();
    Database.Log = l =>
    {
        _log.LogInformation(l);
    };
    ActiveContextCount++;
    _timer.Start();
    _log.LogInformation("BlogContext created. GUID:{0}, Active count {1}", _contextId, ActiveContextCount);
}

protected override void Dispose(bool disposing)
{
    ActiveContextCount--;
    _timer.Stop();
    _log?.LogInformation("BlogContext Disposed. GUID:{0}, Live time: {1}ms, Active count {2}", _contextId, _timer.ElapsedMilliseconds, ActiveContextCount);
    base.Dispose(disposing);
}

I am using Entity Framework 6 and I have setup the DbContext to be scoped:

services.AddScoped(p => new BlogContext(_dataDbConnectionString, p.GetRequiredService<ILoggerFactory>()));

It turned out that the DB operations all works fine. I traced requests in logs and noticed that some request has the last log as:

[Information] Executing ViewResult, running view at path "/Views/Blog/Details.cshtml".

And never finish (i.e. cannot find dispose in the log). From that point the ActiveContextCount just piles up to a few hundreds and the entire application hangs and stops responding.

(EDIT 08/29) Another example, no query was even executed:

[Information] Request starting HTTP/1.1 GET http://myapp/  
[Information] UsersContext created. GUID:bb7743b9-7999-4a01-819f-3d239d34d4d9, Active count 7
[Information] HttpContext.User merged via AutomaticAuthentication from authenticationScheme: "Identity.Application".
[Information] BlogContext created. GUID:8c7505d4-5c87-428e-ad56-12f35f54aadc, Active count 6
[Information] Executing action method "MyApp.Controllers.HomeController.Index (MyApp)" with arguments (["1"]) - ModelState is Valid
[Information] Executing ViewResult, running view at path "/Views/Home/Index.cshtml".

I am stuck at this point. Why does the view result never finish? Is this a bug in the framework or my app? Even if there is a bug, why doesn't the request just be aborted and abandoned after some timeout? I tried to specify a timeout in web.config but doesn't help:

<aspNetCore processPath=".\MyApp.exe" arguments="" forwardWindowsAuthToken="false" stdoutLogEnabled="false" stdoutLogFile=".\logs\stdout" requestTimeout="00:00:40" />

How can I further debug this issue?

like image 496
Duo Avatar asked Aug 28 '16 19:08

Duo


1 Answers

So I've finally figured out the problem after a few weeks of debugging. The problem was indeed in the view. I went through the asp.net core doc and noticed this line:

The PartialAsync method is available for partial views containing asynchronous code (although code in views is generally discouraged).

Then I went over to look at the actual implementation of Html.Partial on github.

var result = htmlHelper.RenderPartialAsync(partialViewName, htmlHelper.ViewData.Model, viewData);
result.GetAwaiter().GetResult();

So the synchronous partial was actually just a blocking wrapper over the async version! And this is the classic async await deadlock (1), since I am calling @await Component.InvokeAysnc in the partial view (as there is no synchronous version for invoking View Components). I have replaced all Html.Partial reference to await Html.PartialAsync and problem solved. I really hope they could have a better warning on this... :(

P.S. I don't have the reputation to post more than 2 links, but why...

(1): blog.stephencleary.com/2012/07/dont-block-on-async-code.html

like image 68
Duo Avatar answered Sep 28 '22 03:09

Duo