MiniProfiler / dotnet

A simple but effective mini-profiler for ASP.NET (and Core) websites
https://miniprofiler.com/dotnet/
MIT License
2.9k stars 598 forks source link

MiniPorfiler Keep repeating the requests #659

Open Abanoub98 opened 1 year ago

Abanoub98 commented 1 year ago

I'm using a mini profiler to examine my project performance however, I have a problem where the requests in profiler/results-index is repeated as I am using an infinite loop

My solution consists of Asp.net core web API for the back end and Blazor for the view

here is the profiler code in program.cs inside the Api project

builder.Services.AddMiniProfiler(
  options =>
  {
      options.RouteBasePath = "/profiler";
      (options.Storage as MemoryCacheStorage)!.CacheDuration = TimeSpan.FromMinutes(60);
      options.SqlFormatter = new StackExchange.Profiling.SqlFormatters.InlineFormatter();
      options.ColorScheme = StackExchange.Profiling.ColorScheme.Auto;
  }).AddEntityFramework();

Screenshot 2023-09-05 043434

NickCraver commented 1 year ago

I'm not sure I'm clear on the report/ask - it looks like you indeed have those requests all distinct with times, etc. MiniProfiler is only reporting what it sees here.

Abanoub98 commented 1 year ago

@NickCraver No, it keeps repeating the requests while they come only one time in the network tab and I debugged it many times and tested it in the logger. All the requests is repeated every 2 seconds

NickCraver commented 1 year ago

@Abanoub98 I agree that seems to be happening, but what does that have to do with MiniProfiler? It's only recording the requests it sees.

Abanoub98 commented 1 year ago

@NickCraver are there any alternatives to it? or any other options I can add? maybe the order of lines in the program.cs?

NickCraver commented 1 year ago

@Abanoub98 Again, I think you're chasing the wrong thing here. You're asking "why are there duplicate requests?", which is absolutely the question you should be asking - but you seem to be focused on MiniProfiler causing them, rather than what it's almost certainly doing: reporting they exist. I cannot say why you're fetching every 2 seconds, my assumption would be errant JavaScript somewhere along the way causing reloads.

VitaliySmolyakov commented 1 year ago

That must be same problem as https://github.com/MiniProfiler/dotnet/issues/653. I faced it too :(

klyakh commented 10 months ago

I'm experiencing the same problem.

Here I opened Posts/Index, which calls API Categories/Index. As a result Categories/Index is duplicated with exactly the same Started time. image

Details:

axylophon commented 8 months ago

We have the same problem. I think #550 is the cause.

juanchavezlive commented 7 months ago

Same error here.

Brads3290 commented 7 months ago

@NickCraver Could you please lend a hand here? The other commenters might not have explained it quite right, but this is an actual issue with MiniProfiler - I've found what's causing it.

Although it wasn't shown correctly in the screenshot above, here's what's happening on the results-index page:


The client script calls results-list to fetch the profiled requests. Sometimes (especially on first load) there are multiple requests returned from this call.

The results will be something like this. They will be sorted in descending order, by Started.

image

The client script then appends them to the HTML table. Then it takes the bottom guid (which is the first request to have occurred, because descending order), and uses that for the ?last-id=... parameter in the next call.

So last-id for the next call is set to the guid of the first request. As a result, the next call includes the remaining two requests. They are appended to the HTML.

Then the process repeats, until it reaches the actual last request.

So the calls we get are as follows: First, results-list?last-id=undefined responds with:

image

Then, results-list?last-id=c7b26ca7-6a2b-4422-9127-2a6650384991 responds with:

image

Then, results-list?last-id=95e56e80-ff2b-4d09-8ba8-6d7bcdd0fa2b responds with:

image

Finally, results-list?last-id=08997c28-b49a-4887-8399-2ea7b1f0d522 responds with nothing

Obviously this process goes on for longer, the more requests you start with in the first request.

For completeness, this is what the table ends up looking like. Note the "Started" column in the table is in the wrong order too.

image

Also, the times/guids are different in the final screenshot vs. the others because I restarted the server in between - sorry.


I suspect the issue is here, in MiniProfilerMiddleware.cs. I added some comments explaining:

private async Task<string> ResultsListAsync(HttpContext context)
{
    if (!await AuthorizeRequestAsync(context, isList: true))
    {
        return "Unauthorized";
    }

    // `guids` is returned in Descending order. This is required for the `last-id` logic
    var guids = await Options.Storage.ListAsync(100).ConfigureAwait(false);

    // Requires guids in descending order
    if (context.Request.Query.TryGetValue("last-id", out var lastId) && Guid.TryParse(lastId, out var lastGuid))
    {
        guids = guids.TakeWhile(g => g != lastGuid);
    }

    // Here the guids are returned, still in descending order.
    return guids
            .Select(g => Options.Storage.Load(g))
            .Where(p => p != null)
            .Select(p => new
            {
                p!.Id,
                p.Name,
                p.ClientTimings,
                p.Started,
                p.HasUserViewed,
                p.MachineName,
                p.User,
                p.DurationMilliseconds
            }).ToJson();
}

I can see here that the guids used to be reversed, but that was removed for some reason. I suspect this has been broken ever since.

So the question is where the fix is best implemented:

If it's the .Reverse() option, I can submit a PR. I probably wouldn't feel that comfortable submitting a PR for the client script. It'll probably be a little more involved and I don't have a whole lot of time to test it properly... which is how we got here to start with.

P.S. You mention here that "The most recent being at the top ... is the intended behavior", but that might be broken too because now the records are added to the bottom of the HTML table.

LEIRONGHUA commented 1 month ago

Is there the latest progress? I also encounter the trouble brought by this situation.