Search code examples
asp.net-corerazor-pages

Significant delay between RuntimeViewCompiler and PageActionInvoker / PageResult

In a asp.net razor pages application, there is significant delay between request and response. The app queries a database and displays text in cshtml razor page. Database query is fast, completes under 5ms. App runs in Visual Studio debug mode without any issue. But when published to production server, there is delay of around 10 seconds on each request. The application is published on 5 different domains on the same server but the delay is happening only on one of them. All the configuration, IIS settings, web.config, appsettings.json are same for all domains. The only difference is domain name and database.

Investigating using MiniProfiler I got following result snapshot. There is a visible delay on Result: PageResult in MiniProfiler.

MiniProfiler result snapshot

After enabling and examining trace log, I concluded following extracts. There is always a gap of around 10 seconds between category entries Microsoft.AspNetCore.Mvc.Razor.RuntimeCompilation.RuntimeViewCompiler (Located compiled view...) and Microsoft.AspNetCore.Mvc.RazorPages.Infrastructure.PageActionInvoker (After executing action ... PageResult) There are no log entries between these two events. All other entries for a request, before and after these two events, complete within a few ms.

{
    "Timestamp": "11:29:25",
    "EventId": 5,
    "Category": "Microsoft.AspNetCore.Mvc.Razor.RuntimeCompilation.RuntimeViewCompiler",
    "Message": "Located compiled view for view at path \u0027/Pages/Shared/_References.cshtml\u0027.",
    "Path": "/Pages/Shared/_References.cshtml",
    "RequestPath": "/"
    "ActionName": "/Index"
}
{
    "Timestamp": "11:29:34",
    "EventId": 6,
    "Category": "Microsoft.AspNetCore.Mvc.RazorPages.Infrastructure.PageActionInvoker",
    "Message": "After executing action result Microsoft.AspNetCore.Mvc.RazorPages.PageResult.",
    "ActionResult": "Microsoft.AspNetCore.Mvc.RazorPages.PageResult",
    "RequestPath": "/"
    "ActionName": "/Index"
}

I tried using following trace logs in appsetting.json:

"Default": "Trace",
"Microsoft.AspNetCore": "Trace",
"Microsoft": "Trace",
"Microsoft.Hosting.Lifetime": "Trace",
"Microsoft.AspNetCore.Mvc.Razor.Internal": "Trace",
"Microsoft.AspNetCore.Mvc.Razor.Razor": "Trace",
"Microsoft.AspNetCore.Mvc.Razor": "Trace",
"Microsoft.AspNetCore.Mvc": "Trace",
"Microsoft.AspNetCore.Routing": "Trace",
"Microsoft.AspNetCore.Server": "Trace",
"Microsoft.AspNetCore.StaticFiles": "Trace",
"Microsoft.AspNetCore.HostFiltering": "Trace",
"Microsoft.AspNetCore.Hosting": "Trace"

Another thing I noticed is that if I add images to the page (all under 100kb, hosted on the same server under wwwroot), the delay increases approx. by 10 seconds for each image i.e. for 3 images total delay is around 40 seconds (10+(3*10)). My Program.cs initialization is as under:

var builder = WebApplication.CreateBuilder(args);
builder.Services
    .AddRazorPages()
    .AddRazorRuntimeCompilation();
builder.Services.AddDistributedMemoryCache();
builder.Services.AddSession(options =>
{
    options.Cookie.HttpOnly = true;
    options.Cookie.IsEssential = true;
});
builder.Services.AddMiniProfiler(options =>
{
    ...
});
builder.Services.AddControllers();

var app = builder.Build();
app.UseStaticFiles();
app.UseMiniProfiler();
app.UseRouting();
app.UseAuthorization();
app.UseSession();
app.MapRazorPages();
app.MapControllers();
app.Run();

Earlier the application TargetFramework was net7.0. I updated it to net8.0 but the problem persists. All packages are up to date. Application runs on Windows Server 2019 (1809) under IIS 10.

I do not know how and where to further investigate to figure out the reason of this delay.

Solution

  • After trying a lot of different things with asp.net app and logging from within the app and MiniProfiler, I tried to shift my focus outside the app. I enabled Website Failed Request Tracing in IIS and analyzing the logs found that the issue was not related to asp.net code / app or configuration.

    I have installed ModSecurity (Web Application Firewall) on the production server. Searching the web for causes of ModSecurity slowing down the site pointed out to the large ip.pag file used by it for logging. For this particular domain this file had grown to around 1 GB which was causing all the delays. To resolve the issue I had to:

    • Temporarily turn off ModSecurity
    • Take a backup of ip.pag file in ModSecurity logs
    • Delete the ip.pag file
    • Turn ModSecurity on again

    And the site was up again without any issue and responding under a few ms.

    I hope this will be helpful to anyone other facing similar issue.