Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SEVERE ASP Api Response Time Problems with 8.0.1 and beyond #1895

Open
CollinHerber opened this issue Mar 18, 2024 · 10 comments
Open

SEVERE ASP Api Response Time Problems with 8.0.1 and beyond #1895

CollinHerber opened this issue Mar 18, 2024 · 10 comments

Comments

@CollinHerber
Copy link

Steps to reproduce

Swap versions around, and note the response time from something like Postman.

The issue

Average response times on my API recently doubled and it took me several days to figure out. Finally was able to confirm the problem was from Pomelo.EntityFrameworkCore.Mysql

I just got done benchmarking the following endpoint

    [AllowAnonymous]
    [HttpGet("Ping")]
    public IActionResult Ping()
    {
        return Ok("Pong");
    }

I ran a test of 5000 requests and the following were observed
8.0.0 = 32ms response time average
8.0.1 = 75ms response time average
8.0.2 = 54ms response time average

The ONLY thing I am changing is my Pomelo.EntityFrameworkCore.MySql and Pomelo.EntityFrameworkCore.MySql.Json.Newtonsoft version

I got into this mess after noticing that my average response times in Application Insights on my API doubled and was causing some weirdness.

Further technical details

MySQL version: N/A
Operating system: Windows 11
Pomelo.EntityFrameworkCore.MySql version: 8.0.0, 8.0.1, 8.0.2
Microsoft.AspNetCore.App version:

Other details about my project setup:

My project is not super large, but there is a lot of moving parts so maybe something else is causing this. Let me know what information you would like and I can try to provide it.
If the maintainer would like I can copy paste my project into a new repo and invite via github just to give a full idea as to whats going on.

@CollinHerber
Copy link
Author

CollinHerber commented Mar 18, 2024

I noticed that upon downgrading the migration I ran with 8.0.2 includes the following

MySqlModelBuilderExtensions.AutoIncrementColumns(modelBuilder);

Is this safe to remove after the downgrade? Anything that should replace it? Comparing diff it seems to be a net new add.

@lauxjpn
Copy link
Collaborator

lauxjpn commented Mar 19, 2024

@CollinHerber Please add the .NET/ASP.NET Core version you are using to the Further technical details section in the OP.

Am I assuming correctly that you mentioned no MySQL/MariaDB version in the Further technical details section because there should be no database connection made in your scenario?

(This would imply, that you are manually specifying the ServerVersion in any UseMySql() call and not using ServerVersion.AutoDetect().)

My project is not super large, but there is a lot of moving parts so maybe something else is causing this. Let me know what information you would like and I can try to provide it.
If the maintainer would like I can copy paste my project into a new repo and invite via github just to give a full idea as to whats going on.

Feel free to do so. Otherwise, we will need some kind of MRE and instructions on how to run it to reproduce the issue.

I noticed that upon downgrading the migration I ran with 8.0.2 includes the following

MySqlModelBuilderExtensions.AutoIncrementColumns(modelBuilder);

Is this safe to remove after the downgrade? Anything that should replace it? Comparing diff it seems to be a net new add.

8.0.1 fixed issues regarding auto increment metadata (see #1852). The snapshot file and ...Design.cs files in 8.0.1 contain this new metadata. Calls in the Up()/Down() methods regarding this should not do anything and can probably be safely removed in this case.

I just got done benchmarking the following endpoint

    [AllowAnonymous]
    [HttpGet("Ping")]
    public IActionResult Ping()
    {
        return Ok("Pong");
    }

Assuming you are only benchmarking the endpoint and not any kind of initialization code or custom middleware, there should be no call to any Pomelo code at all (the endpoint does not use a DbContext and I am assuming that any context setup is done once on startup and not on every request).

This is a typical scenario to analyze with a profiler (e.g. VS or dotTrace).

@CollinHerber
Copy link
Author

CollinHerber commented Mar 19, 2024

Please add the .NET/ASP.NET Core version you are using to the Further technical details section in the OP.

I am using the latest of everything aside from Pomelo at this point, there are no updates to make in Pomelo.
Here is the full list if you'd like

  <ItemGroup>
    <PackageReference Include="AutoMapper" Version="13.0.1" />
    <PackageReference Include="Azure.Messaging.ServiceBus" Version="7.17.4" />
    <PackageReference Include="Discord.Net" Version="3.13.1" />
    <PackageReference Include="FluentValidation.AspNetCore" Version="11.3.0" />
    <PackageReference Include="Microsoft.ApplicationInsights.AspNetCore" Version="2.22.0" />
    <PackageReference Include="Microsoft.AspNetCore.Authentication.JwtBearer" Version="8.0.3" />
    <PackageReference Include="Microsoft.AspNetCore.Http" Version="2.2.2" />
    <PackageReference Include="Microsoft.AspNetCore.Mvc.NewtonsoftJson" Version="8.0.3" />
    <PackageReference Include="Microsoft.EntityFrameworkCore.Proxies" Version="8.0.3" />
    <PackageReference Include="Microsoft.EntityFrameworkCore.Tools" Version="8.0.3">
      <PrivateAssets>all</PrivateAssets>
      <IncludeAssets>runtime; build; native; contentfiles; analyzers; buildtransitive</IncludeAssets>
    </PackageReference>
    <PackageReference Include="Microsoft.Extensions.Configuration.Abstractions" Version="8.0.0" />
    <PackageReference Include="NSec.Cryptography" Version="22.4.0" />
    <PackageReference Include="Pomelo.EntityFrameworkCore.MySql" Version="8.0.0" />
    <PackageReference Include="Pomelo.EntityFrameworkCore.MySql.Json.Newtonsoft" Version="8.0.0" />
    <PackageReference Include="Stripe.net" Version="43.19.0" />
    <PackageReference Include="Swashbuckle.AspNetCore" Version="6.5.0" />
    <PackageReference Include="Swashbuckle.AspNetCore.Newtonsoft" Version="6.5.0" />
	  <PackageReference Include="Microsoft.EntityFrameworkCore.Relational" Version="8.0.3" />
  </ItemGroup>

The only two I am changing in between benchmarking runs are

    <PackageReference Include="Pomelo.EntityFrameworkCore.MySql" Version="8.0.0" />
    <PackageReference Include="Pomelo.EntityFrameworkCore.MySql.Json.Newtonsoft" Version="8.0.0" />

Am I assuming correctly that you mentioned no MySQL/MariaDB version in the Further technical details section because there should be no database connection made in your scenario?

That is correct. However I am using MySQL 8.0.32 locally and 8.0.36 on Digital Ocean Production Cluster

(This would imply, that you are manually specifying the ServerVersion in any UseMySql() call and not using ServerVersion.AutoDetect().)

I am using ServerVersion.AutoDetect()

Here is the exact DI

    public static IServiceCollection AddDatabase(this IServiceCollection services, IConfiguration configuration)
    {
        services.AddDbContext<BetsyDbContext>(options =>
        {
            var connectionString = configuration.DbConnectionString();

            options.UseMySql(connectionString, ServerVersion.AutoDetect(connectionString));
#if DEBUG
            options.EnableSensitiveDataLogging();
#endif
        });
        return services;
    }

Assuming you are only benchmarking the endpoint and not any kind of initialization code or custom middleware, there should be no call to any Pomelo code at all (the endpoint does not use a DbContext and I am assuming that any context setup is done once on startup and not on every request).

This behavior was witnessed with my middleware enabled and disabled. It made no difference. You can check out my middleware if you think it would provide any benefit as well https://pastie.io/cugmkj.cs

8.0.1 fixed issues regarding auto increment metadata (see #1852). The snapshot file and ...Design.cs files in 8.0.1 contain this new metadata. Calls in the Up()/Down() methods regarding this should not do anything and can probably be safely removed in this case.

I can confirm I had no issues removing this and deploying to production after the migrations had already run.

This is a typical scenario to analyze with a profiler (e.g. VS or dotTrace).

I use Rider and was taking a peek at the dotTrace some but honestly it went well over my head. If there is some sort of report I can export and send your way I'd be happy to.

EDIT:
It it worth mentioning that this behavior was witnessed both on my Windows 11 local machine AND my production linux docker image.
Here is my dockerfile if it helps

# Build stage
FROM mcr.microsoft.com/dotnet/sdk:8.0 AS build-env
WORKDIR /App

# Accept the build configuration as an argument.
ARG BUILD_CONFIG=Staging

# Copy the entire source tree
COPY src/ ./

# Restore
RUN dotnet restore ./Api/Api.csproj

# Publish
RUN dotnet publish -c $BUILD_CONFIG -o out ./Api/Api.csproj

# Run stage
FROM mcr.microsoft.com/dotnet/aspnet:8.0
WORKDIR /App
EXPOSE 5000
COPY --from=build-env /App/out .
ENTRYPOINT ["dotnet", "Api.dll"]

@CollinHerber
Copy link
Author

Version 8.0.2 Running in Production 24 Hour Window
Screenshot 2024-03-19 at 9 10 29 AM

Version 8.0.0 Running in Production 12 Hour Window
Screenshot 2024-03-19 at 9 10 51 AM

Here is what application insights has to say about the past 12 hours (I deployed production with the 8.0.2 -> 8.0.0 pomelo update 14 hours ago) vs a 24 hour window the day before.

The endpoint I am observing is the one with the highest call count.

Screenshot 2024-03-19 at 9 13 04 AM

The above is a picture of my pull request with the changes. I know it sounds very improbable, I was dumbfounded when I figured out what was causing this especially when using something simple like that benchmark route.

@lauxjpn
Copy link
Collaborator

lauxjpn commented Mar 20, 2024

@CollinHerber Thank you for the provided information. However, due to the nature of the problem and the fact that the posted Ping endpoint in the OP is not calling any Pomelo method at all:

My project is not super large, but there is a lot of moving parts so maybe something else is causing this. Let me know what information you would like and I can try to provide it.
If the maintainer would like I can copy paste my project into a new repo and invite via github just to give a full idea as to whats going on.

Feel free to do so. Otherwise, we will need some kind of MRE and instructions on how to run it to reproduce the issue.

Thanks!

@lauxjpn
Copy link
Collaborator

lauxjpn commented Apr 16, 2024

@CollinHerber Thank you for the provided information. However, due to the nature of the problem and the fact that the posted Ping endpoint in the OP is not calling any Pomelo method at all:

My project is not super large, but there is a lot of moving parts so maybe something else is causing this. Let me know what information you would like and I can try to provide it.
If the maintainer would like I can copy paste my project into a new repo and invite via github just to give a full idea as to whats going on.

Feel free to do so. Otherwise, we will need some kind of MRE and instructions on how to run it to reproduce the issue.

Thanks!

@CollinHerber Any update on this?

@CollinHerber
Copy link
Author

@CollinHerber Thank you for the provided information. However, due to the nature of the problem and the fact that the posted Ping endpoint in the OP is not calling any Pomelo method at all:

My project is not super large, but there is a lot of moving parts so maybe something else is causing this. Let me know what information you would like and I can try to provide it.
If the maintainer would like I can copy paste my project into a new repo and invite via github just to give a full idea as to whats going on.

Feel free to do so. Otherwise, we will need some kind of MRE and instructions on how to run it to reproduce the issue.

Thanks!

@CollinHerber Any update on this?

Apologies, I have not copied this into a new project yet. Would you be able to communicate via Discord, as it's going to result in a much faster and more streamlined communication.
If yes throw me an add collin.h

Alternatively I can try and get something put together something that takes out all the sensitive bits out of my app soon

@CollinHerber
Copy link
Author

Just an update on this, I have been trying to create an MVP of this issue but it seems as soon as I start removing some of my project layers the problem seems to disappear. I still have not figured out why 8.0.0 works fine but 8.0.1 and 8.0.2 2x-3x my endpoint response times.

The most I say is that I'm fairly certain it has something to do with Dependency Injection, as soon as I remove my DI registrations the problem goes away but the Benchmarking controller I am using is only including a single interface for testing purposes and there is nearly no logic in it

@CollinHerber
Copy link
Author

It's definitely something with the DI and those versions

public class BenchmarkController(IDiscordGuildClient discordGuildClient, IDiscordServerService discordServerService) : ControllerBase
{
    [AllowAnonymous]
    [HttpGet("Ping")]
    public IActionResult Ping()
    {
        return Ok("Pong");
    }
    
    [Authorize]
    [HttpGet("AuthPing")]
    public IActionResult AuthorizePing()
    {
        return Ok("Pong");
    }
}

For example with this I am getting the 2-3x response times, however if I remove IDiscordGuildClient discordGuildClient, IDiscordServerService discordServerService
The endpoint response time is "normal"

This is only a problem after upgrading to 8.0.1 or 8.0.2 and is not a problem with 8.0.0

I don't know if that helps you at all.

@lauxjpn
Copy link
Collaborator

lauxjpn commented Apr 20, 2024

Because the sample code you provided does not use any EF Core or Pomelo call at all, I am assuming that the issue has either not do to anything directly with Pomelo, or that you are running EF Core/Pomelo initialization code on ever request, instead of once per app startup.

This is also the reason, why I am insisting on an MRE.


However, I will through a suspicion out there, which I think is the most likely source of the issue you are experiencing.

Instead of calling ServerVersion.AutoDetect(), please define and call the following custom method using Pomelo 8.0.2:

public static ServerVersion CustomServerVersionAutoDetect(string connectionString)
{
    using var connection = new MySqlConnection(
        new MySqlConnectionStringBuilder(connectionString) {Database = string.Empty}.ConnectionString);
    connection.Open();
    return Parse(connection.ServerVersion);
}

Then check your average response time again and please report back, whether the issue seems to have vanished.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants