Repository navigation
Queries that contain multiple statements (";") experiencing random timeouts #5861
Description
Queries that contain multiple statements unexpectedly throw timeout errors in .NET 8.0. By multiple statements, I mean statements separated by a semi-colon that should be run in a single call to Execute/Query. It occurs randomly in both our staging and production environments (in AWS using RDS) but I can also replicate the error locally. If I split these queries into two separate calls to Execute/Query, they work fine and I don't experience the issue.
The exception is as follows:
Npgsql.NpgsqlException (0x80004005): Exception while reading from stream
---> System.TimeoutException: Timeout during reading attempt
and the stack trace that represents these errors typically looks as follows:
Npgsql.NpgsqlException (0x80004005): Exception while reading from stream
---> System.TimeoutException: Timeout during reading attempt
at Npgsql.Internal.NpgsqlReadBuffer.<Ensure>g__EnsureLong|55_0(NpgsqlReadBuffer buffer, Int32 count, Boolean async, Boolean readingNotifications)
at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
at Npgsql.Internal.NpgsqlConnector.ReadMessageLong(Boolean async, DataRowLoadingMode dataRowLoadingMode, Boolean readingNotifications, Boolean isReadingPrependedMessage)
at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
at Npgsql.Internal.NpgsqlConnector.ReadMessageLong(Boolean async, DataRowLoadingMode dataRowLoadingMode, Boolean readingNotifications, Boolean isReadingPrependedMessage)
at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
at Npgsql.NpgsqlDataReader.NextResult(Boolean async, Boolean isConsuming, CancellationToken cancellationToken)
at Npgsql.NpgsqlDataReader.NextResult(Boolean async, Boolean isConsuming, CancellationToken cancellationToken)
at Npgsql.NpgsqlCommand.ExecuteReader(Boolean async, CommandBehavior behavior, CancellationToken cancellationToken)
at Npgsql.NpgsqlCommand.ExecuteReader(Boolean async, CommandBehavior behavior, CancellationToken cancellationToken)
at Npgsql.NpgsqlCommand.ExecuteNonQuery(Boolean async, CancellationToken cancellationToken)
at Dapper.SqlMapper.ExecuteCommand(IDbConnection cnn, CommandDefinition& command, Action`2 paramReader) in /_/Dapper/SqlMapper.cs:line 2965
at Dapper.SqlMapper.ExecuteImpl(IDbConnection cnn, CommandDefinition& command) in /_/Dapper/SqlMapper.cs:line 656
Steps to reproduce
I have attached a tiny console
npgbugrepro.zip
project that demonstrates this issue. I can get it to occur 100% of the time in my local environment. The DDL for the tables is as follows:
CREATE TABLE public.sessions (
session_id text NOT NULL,
user_id int4 NOT NULL,
total int4 DEFAULT 1 NOT NULL,
last_update_date timestamptz DEFAULT now() NOT NULL,
creation_date timestamptz DEFAULT now() NOT NULL,
ip_address text NULL,
CONSTRAINT "PK_sessions" PRIMARY KEY (session_id)
);
CREATE UNIQUE INDEX sess_session_id_user_id_last_update_date_idx ON public.sessions USING btree (user_id, session_id);
CREATE TABLE public.page_views (
session_id text NOT NULL,
user_id int4 NOT NULL,
url text NULL,
full_url text NULL,
creation_date timestamptz DEFAULT now() NOT NULL,
ip_address text NULL
);
CREATE INDEX pv_user_id_idx ON public.page_views USING btree (user_id);
Further technical details
Npgsql version: 8.0.4
PostgreSQL version: 16.3
Operating system: Windows Server 2022 but seen it in RDS on AWS.
Other details about my project setup: Using dapper for queries but no ORM's.
Any ideas on what is happening here? Thank you!
Activity
vonzshik commentedon Oct 3, 2024
There is a good chance this is due to us replacing a dedicated write thread to instead use threadpool in #5196. The problem with batches is that we can't always write them completely in one go, as it could lead to a deadlock (postgres is waiting for us to read results for the first query while we're waiting for postgres to read whatever we've already written). The problem with dedicated write thread is that it doesn't scale whenever there are multiple queries written simultaneously and it doesn't for some of the platforms (like Blazor and webassembly).
In your case, switching to async methods should fix the issue.
gdau commentedon Oct 3, 2024
I appreciate you taking a look at this so quickly as it's becoming a larger issue within my organisation.
If what you are describing is the case, this is very unfortunate and I would urge you to consider it to be a regression in behaviour (we have confirmed that running this same repro with version 7.0.8 of npgsl does not experience this issue). I would say that there will be many companies that will still be running a mostly sync-stack for various reasons - partly because some of these database calls are made deep within a call-stack (where the callers cannot be modified to fully async) and partly because the benefits of async are negligible in many cases.
It would be a great shame if such a major feature was no longer supported. If this cannot be fixed, I would favour some kind of flag that reverts to the previous behaviour for those of us who have no plans to use Blazor or Webassembly. At the very least it deserves a massive disclaimer prominent in the documentation that sync calls are no longer supported for some types of queries (as far as I am aware, async was entirely optional and opt-in - this would no longer be the case).
Thank you!
vonzshik commentedon Oct 3, 2024
They are definitely supported. In your case what happens is that you synchronously block each threadpool thread which makes it so no-one can handle write task. As a workaround for now you can specify
ThreadPool.SetMinThreadsat the start of your app.We're definitely not going to revert this change. As for a flag to revert to the previous behavior, that's something I have to discuss with other team members.
gdau commentedon Oct 3, 2024
I appreciate the response.
Please bear in mind when this is discussed with the wider team that, although the console app I supplied was a contrived example to demonstrate the issue, in reality we are seeing this error in our production web applications where we have a very basic (and probably very typical) setup: an ASP.NET application running on IIS on Windows Server and an MVC controller making a database call using dapper. We are not doing anything atypical in terms of managing thread pools ourselves; if this is indeed what is happening, they are a consequence of the standard interaction between Windows, IIS and ASP.NET.
All of this aside, the developer experience from our point of view is that an application that has previously been working now experiences errors when upgrading to a newer npgsql package. I respectfully don't agree with the position that multiple statements are still "supported" if an inner implementation detail of the library is bringing new considerations to the environment in which the library is used.
Thank you again for taking a look.
NinoFloris commentedon Oct 3, 2024
In our experience it's actually becoming less and less common, especially on .NET Core+ projects. Since our 8.0.0 release we've had about 5 issues opened on this topic, and of those most ended up fixing underlying issues causing starvation or switching to async. ASP.NET Core has an explicit opt-in for sync I/O since .NET Core 3.0 which comes with exactly the same disclaimer: potential threadpool starvation, no mitigations.
Async code is never about *direct* performance benefits, there is always a tiny cost associated to a method being async. Its advantage is that it allows much better thread utilization, which then allows much more work to be done when waiting for I/O. Optimal thread utilization has only become more important after the spectre/meltdown vulnerabilities, as thread context switches have really become quite expensive. So in the ideal scenario - when you are async throughout - you run as many threads as you have cores, and no more.
With 9.0 we've dropped .NET Framework support, and in this spirit we're considering obsoleting the sync apis in 9.0 or 10.0 as well (see #5865).
We're aware this isn't great from a backwards compatibility standpoint (which is why any these changes happen only at major version bumps). However Npgsql is an evolving driver and we have to re-evaluate trade-offs and workarounds over time to stay modern and maintainable. In 8.x we decided to remove one of our workarounds to handle synchronous batch queries at higher loads. The workaround had deep impact on all the async code we needed to maintain, and required Npgsql plugin authors to do the same. Keeping it would have been a burden on new work we wanted to deliver like the support for NativeAOT we landed in 8.0.0. Removing this workaround also solved some long standing issues like enabling Microsoft Orleans compatibility where before it was preventing users from using Npgsql asynchronously together with it at all (#1130).
Over time balances shift to favor one trade-off over another based on maintainability costs, popularity and impact. Async is really here to stay and is our recommended execution mode for anything beyond data exploration or simple single statement queries.
gdau commentedon Oct 3, 2024
I have had another look at the release notes for 8.0 and there is no mention of this but my apologies if there is somewhere else I should rather be looking: https://www.npgsql.org/doc/release-notes/8.0.html.
Even in this thread there seems to be confusion as to whether this scenario is currently officially supported or not.
I can see now from the latest announcements that support for sync - generally speaking - will be dropped in a future version and that is something that can be planned for - but I am still left unsure as to whether anything will be done about this for version 8.0.
If not, I only ask that this breaking change is documented somewhere so that other developers get something useful in their search results and avoid wasting their time on something that is unsupported. This will also give you something formal to point people to if they log similar issues. I'm sure we can all appreciate that the database drivers we use are an integral part of the applications we develop and any known issues should be well-documented as they are generally the last places where developers expect to see backwards-compatibility issues.
Thanks again - I know this has been a long thread.
NinoFloris commentedon Oct 3, 2024
That's fair and I agree we could have done a better job communicating this change.
Absolutely, though just a friendly reminder that Npgsql is an OSS project and we're all doing this in our free time.
My advice would be to assume we won't but if we get more issues we might invest the (I'm assuming fairly substantial) effort to bring back some form of workaround.
I've opened npgsql/doc#368 to supplement the 8.0 release notes. I'll go ahead and close this issue now.
roji commentedon Oct 4, 2024
It's just important to clarify that synchronous batch use is supported - but uses sync-over-async. There are mitigations to make this work without hanging (e.g. setting the minimum thread pool size), and there was definitely an important behavioral change in 8.0 here, but there's nothing "unsupported" here per se (not until we maybe remove sync support at some point in the future).