EF Core 3.1.14 Recurring Cold Start

Question

We have deployed a very simple .NET CORE 3 Web API application to Azure Cloud. The application is a web api and talks to a very simple SQL server database hosted in Azure as well. There are two main performance problems we are noticing

All API calls go to DB for either read or write operations. The tables only contain 4 and 5 rows and the queries are just basic select and insert queries with no joins.

1. The first call to the API is very slow (30 seconds to query 1 record in a table of size 10) and we added the timer and noticed it is the DB call that is taking 99.99% of the time. So I used the Azure Data Studio Profiler and realized that the query reached SQL Server after like 29.90 seconds. So the issue is not the query itself. Also, the second, third query etc. are super fast and return within < 30 milli-seconds. So the issue is not the internet connectivity between the Web App and the Azure SQL Database.

2. The bigger problem is that, if you stop calling the API for say 2-3 minutes and then do another call, then again the first query takes 30 seconds. But the subsequent queries are faster.

If this was only happening when w3wp.exe starts then I wouldn't be concerned but if the requests to the API stop coming for 2-3 minutes then again it is down. This is of concern.

We have Always ON set to Yes.

I tried collecting .NET Trace in Azure for the web app but this is giving me this weird error.

Here are the Nuget package versions installed in the VS solution related to EF.

Here is the SQL Server pricing tier.

Is there any other way to collect trace for Azure Web APP. I really need to see the call stack of the code for those 30 seconds to move forward. I have access to KUDU etc.

Thanks.

UPDATE 3 - 8th May 2021

I have posted the answer to my own question. This may not be root cause for other people who face similar problem but at least 1 area to look into.

UPDATE 2 - 7th May 2021

After adding EF Core logging as suggested by Ivan, he is right that the opening of connection is taking too long? Why is that? And how to stop that from happening?

UPDATE 1 - 7th May 2021

Jason Pan - We are using App Service Plan and this is the only application hosted there. The plan is P1V2 (https://azure.microsoft.com/en-us/pricing/details/app-service/windows/).

Ivan Stoev - Yes since the .NET Trace is not working for some reason as explained in my question, we captured the App Insights Profiler Trace to capture the call stack and as per call stack it appears that the connection to the SQL server was opened after 30 seconds. So I made two changes in my code:

a. Removed IDisposable from our Repository class that was having our context inject through DI. Before inside the Dispose method, I was calling Dispose on our context class.

b. I replaced services.AddDbContext with services.AddDbContextPool

I then wrote a test program to call the API method randomly once every 2 to 4 mins for 1 hour and only 1 call took 30 seconds and the remaining 21 took few milli-seconds.

But my next step is to run a 24 hours test (1 call every 2-7 mins for example) to see if this was just fluke or actually the solution.

Answer 1

Ok so posting an answer to my question. It turned out that there was no issue with web application, app service plan, sql server or entity framework. I took a network trace of my application and 1 other application which doesn't have any issue and opened it with network monitor. We noted that they are taking different paths. After looking into the IP address we realized that the other application had a virtual network setup. You can see that by going to your app service plan and then click on Networking option in the left menu bar. And then choose the first one for vNet. Once we configured vNet, then all responses were within < 1 second.

There was one another oversight by me. The Auth0 calls were also taking 14 seconds sometimes. And when I tried running tcpping google.com from KUDU that timed out sometimes as well. But was working fine for other web applications.