Npgsql.NpgsqlTimeout.Check - The operation has timed out

[devzealot]

Npgsql Team,

I have developed the Web APIs in our project thru C# for .NET Core. I am using the Entity Framework Core (EFCore) with Database-First approach for database access. We use PostgreSQL database as backend for data storage. These Web APIs are called on UI application for data retrieval/save functionality. While testing the UI application, we have observed that couple of Web APIs will not return data when called for first time on UI; when we refresh the UI (pages), then the APIs will return the data for the same calls. I have verified thru Swagger also and could reproduce the issue. I have executed one Web API endpoint thru Swagger by proividing the input parameters, it does not return any data though gives 200 response code, but when I re-execute the same endpoint with same input parameters then it gives the data results. when I have checked the logs (written thru the Web APIs), then I have found the error message below for one of the Web API endpoint executed.

2020-12-24 15:39:37.478 +00:00 [ERR] ProvidersDAL->GetProviderCredentialingSummary()
System.InvalidOperationException: An exception has been raised that is likely due to a transient failure.
---> System.TimeoutException: The operation has timed out.
at Npgsql.NpgsqlTimeout.Check()
at Npgsql.NpgsqlConnector.RawOpen(NpgsqlTimeout timeout, Boolean async, CancellationToken cancellationToken)
at Npgsql.NpgsqlConnector.Open(NpgsqlTimeout timeout, Boolean async, CancellationToken cancellationToken)
at Npgsql.ConnectorPool.AllocateLong(NpgsqlConnection conn, NpgsqlTimeout timeout, Boolean async, CancellationToken cancellationToken)
at Npgsql.NpgsqlConnection.<>c__DisplayClass32_0.<g__OpenLong|0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.OpenDbConnectionAsync(Boolean errorsExpected, CancellationToken cancellationToken)
at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.OpenDbConnectionAsync(Boolean errorsExpected, CancellationToken cancellationToken)
at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.OpenAsync(CancellationToken cancellationToken, Boolean errorsExpected)
at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReaderAsync(RelationalCommandParameterObject parameterObject, CancellationToken cancellationToken)
at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable1.AsyncEnumerator.InitializeReaderAsync(DbContext _, Boolean result, CancellationToken cancellationToken) at Npgsql.EntityFrameworkCore.PostgreSQL.Storage.Internal.NpgsqlExecutionStrategy.ExecuteAsync[TState,TResult](TState state, Func4 operation, Func4 verifySucceeded, CancellationToken cancellationToken) --- End of inner exception stack trace --- at Npgsql.EntityFrameworkCore.PostgreSQL.Storage.Internal.NpgsqlExecutionStrategy.ExecuteAsync[TState,TResult](TState state, Func4 operation, Func4 verifySucceeded, CancellationToken cancellationToken) at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable1.AsyncEnumerator.MoveNextAsync()
at Microsoft.EntityFrameworkCore.EntityFrameworkQueryableExtensions.ToListAsync[TSource](IQueryable1 source, CancellationToken cancellationToken) at Microsoft.EntityFrameworkCore.EntityFrameworkQueryableExtensions.ToListAsync[TSource](IQueryable1 source, CancellationToken cancellationToken)
at CHC.CredentialingManager.WebAPI.DAL.Providers.ProvidersDAL.GetProviderCredentialingSummary(Nullable`1 clientID, Int64 ownerID) in D:\WebApps\CMAPI\chc.credentialingmanager.webapi1\CHC.CredentialingManager.WebAPI.DAL\Providers\ProvidersDAL.cs:line 1442

Below is the function code which is failing for above error scenario.

public async Task<IEnumerable<CredEntity>> GetProviderCredentialingSummary(long? clientID, long ownerID)
{
 using (var ctx = new ProvContext())
 {
   try
   {
     // some business logic based on input parameters

     NpgsqlParameter id = new NpgsqlParameter("_clientid", NpgsqlDbType.Bigint);
     id.Value = (clientID.HasValue) ? clientID : DBNull.Value;

     var data = await ctx.Cred.FromSqlRaw("select * from dbo.sp_getcreddata(@_id)",id).AsNoTracking().ToListAsync();
     return data;
   }
   catch (Exception ex)
   {
     Logger.LogToFile.LogError(ex, String.Format("ProvidersDAL->GetProviderCredentialingSummary()"));
     return null;
   }
}

Here below is the DB connection string specified in appsettings.json file (API project).

"ConnectionString": {
"DBContextPostgreSQL": "host=perfdb.domain.net;port=5432;database=cmdatabase;UserId=user01;Password=pwd01;SslMode=Require;Trust Server Certificate=true;"
}
}

Am I doing anything wrong in the above code that is causing the timeout issue? I have not received this error while the Web APIs development. This is happening in performance environment (PERF) while the regression testing. Please help me to identify the issue and fix it for verification. Thank you in advance.

[RichioProg]

Having the same issue with DbContext.Entity.FromSqlRaw. There is a lot to find about increasing a so called CommandTimeout when executing DbContext.Entity.CreateDbCommand. Unfortunately it looks like FromSqlRaw does not respect this CommandTimeout which is set with UseNpgsql Options. From my current implementation the default value of CommandTimeout is set to 30 seconds which exactly corresponds with the timing of getting the Npgsql.NpgsqlTimeout. I increased the CommandTimeout to 60 and my request keeps failing at 30 seconds.

Can somebody tell us if FromSqlRaw respects the CommandTimeout parameter or should we look somewhere else?

[vikasillumina]

@devzealot we are seeing this too. Were you able to get a resolution for this?

[vikasillumina]

@roji sorry for reaching out to you directly. But we are experiencing the same error as reported in this issue right after Dotnet 6 upgrade from 3.1. We have a connection timeout of 30s that has served us well over the years, but right after the upgrade we started seeing this error. Other than increasing the timeout can't think of any other solution. Any inputs from you or your team will be helpful.

[roji]

@vikasillumina what exactly changeg during the upgrade? Are we talking about a pure netcoreapp3.1 -> net6 TFM change, or did any other component versions changed? In particular, are you sure that the Npgsql version didn't change?

[vikasillumina]

Thank you @roji for your response. Yes this upgrade was a pure NET core upgrade from 3.1 to 6.

If it helps here are before and after version of different libraries for our dataccess project:
*****Before *******

<PackageReference Include="LinqKit.Microsoft.EntityFrameworkCore" Version="3.0.0" />
<PackageReference Include="Microsoft.EntityFrameworkCore" Version="3.1.17" />
<PackageReference Include="Npgsql.EntityFrameworkCore.PostgreSQL" Version="3.1.11" />
<PackageReference Include="Microsoft.EntityFrameworkCore.Proxies" Version="3.1.17" />
 <PackageReference Include="Microsoft.EntityFrameworkCore.Relational" Version="3.1.17" />

Before***

After*******

<PackageReference Include="LinqKit.Microsoft.EntityFrameworkCore" Version="6.1.2" />
<PackageReference Include="Microsoft.EntityFrameworkCore" Version="6.0.4" />
<PackageReference Include="Npgsql.EntityFrameworkCore.PostgreSQL" Version="6.0.4" />
<PackageReference Include="Microsoft.EntityFrameworkCore.Proxies" Version="6.0.4" />
<PackageReference Include="Microsoft.EntityFrameworkCore.Relational" Version="6.0.4" />

After*****

The postgres DB version has not changed. We are still using 10.11 Postgres running in Amazon RDS.

Thanks

[roji]

@vikasillumina you're using EF Core - this is an issue within the old non-core EF6 repo.

You're going to have to open a new issue on https://github.com/npgsql/efcore.pg; unfortunately there's not much I can do with "it worked before and doesn't work any more" - I hope you're able to put together some sort of repro code sample that shows the problem... 30 seconds should indeed be enough in general, and hitting the timeout typically means that there's some deadlock, network issue or similar, which isn't really related to Npgsql or EF Core. But a code sample would be necessary to be know for sure.

[vikasillumina]

Hi @roji thanks for your suggestion and guiding us towards the right repo where we should be raising this. But yes I understand what you mean. We will try to come up with sample code but its going to be hard. We are not even able to reliably repro this issue in DEV environments. But we are trying to mimic load from production to see if we can repro. Thanks once again for your help.