{{ message }}
Repository navigation
Received backend message CommandComplete while expecting BindCompleteMessage. Please file a bug. #4906
Description
Steps to reproduce
There's no obvious steps. We have a reasonably high level of traffic on this DB instance and we see a message like this every few weeks. It's not having an impact on us, but it says please file a bug 😄
Let me know if there's any other information I can provide!
The issue
A couple of times now we've seen error messages along these lines:
On 26/1/23:
Exception message: Received backend message CommandComplete while expecting BindCompleteMessage. Please file a bug.
Stack trace:
async Task<bool> NpgsqlDataReader.NextResult(bool async, bool isConsuming, CancellationToken cancellationToken)
async ValueTask<NpgsqlDataReader> NpgsqlCommand.ExecuteReader(CommandBehavior behavior, bool async, CancellationToken cancellationToken) x 2
async Task<TResult> TaskContinuationGenerator<TIntegration, TTarget, TReturn, TResult>.ContinuationAction(Task<TResult> previousTask, TTarget target, CallTargetState state)
On 5/1/23:
Exception message: Received backend message CommandComplete while expecting ParseCompleteMessage. Please file a bug.
Stack trace:
async Task<bool> NpgsqlDataReader.NextResult(bool async, bool isConsuming, CancellationToken cancellationToken)
async ValueTask<NpgsqlDataReader> NpgsqlCommand.ExecuteReader(CommandBehavior behavior, bool async, CancellationToken cancellationToken) x 2
async Task<TResult> TaskContinuationGenerator<TIntegration, TTarget, TReturn, TResult>.ContinuationAction(Task<TResult> previousTask, TTarget target, CallTargetState state)
For the one that happened today, these are the potentially relevant log lines from our postgres error logs:
2023-01-26 02:36:15 UTC:10.11.1.205(49184):<user>@<database>:[30821]:ERROR: canceling statement due to user request
2023-01-26 02:36:15 UTC:10.11.1.205(49184):<user>@<database>:[30821]:STATEMENT: SET SESSION AUTHORIZATION DEFAULT;RESET ALL;CLOSE ALL;UNLISTEN *;SELECT pg_advisory_unlock_all();DISCARD SEQUENCES;DISCARD TEMP
2023-01-26 02:36:15 UTC:10.11.1.205(49184):<user>@<database>:[30821]:LOG: could not receive data from client: Connection reset by peer
Further technical details
Npgsql version: 6.0.7
PostgreSQL version: 14.4 and 11.16 (we upgraded between occurrences)
Operating system: Alpine linux
Other details about my project setup:
Activity
vonzshik commentedon Jan 26, 2023
Hello!
Yeah, I can confirm that there is indeed a bug with the cancellation of prepended queries (they're used to discard temporary tables, locks and other things when a connection is closed).
These queries should be very fast, but it seems like under heavy load it's possible to cancel them, and Npgsql doesn't handle that very well.
I'm going to submit a pr fixing this.
Fix cancellation being able to cancel prepended queries (#4907)
Fix cancellation being able to cancel prepended queries (#4907)
Fix cancellation being able to cancel prepended queries (#4907)
Fix cancellation being able to cancel prepended queries (#4907)