-
Notifications
You must be signed in to change notification settings - Fork 819
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
Npgsql.NpgsqlException (0x80004005): Exception while reading from stream - 8.0.0 #5430
Comments
Could you make this a runnable sample? Adding the (if possible, simplified) definitions of querySql, summarySql, ItemModel and SummaryModel would help me investigate. |
Ok, Give me some time. |
I have a feeling that this problem is actually caused by another issue. When the SQL query returns a lot of content, the first thing I encounter is a timeout before Hopefully this will help in investing the problem Npgsql.NpgsqlException (0x80004005): Exception while reading from stream
---> System.TimeoutException: Timeout during reading attempt
at async ValueTask Npgsql.Internal.NpgsqlReadBuffer.Ensure(int count, bool async)+EnsureLong(?)
at async Task Npgsql.Internal.NpgsqlReadBuffer.Skip(int len, bool async)
at async Task Npgsql.NpgsqlDataReader.ConsumeRow(bool async)+ConsumeRowSequential(?)
at async bool Npgsql.NpgsqlDataReader.NextResult()+ConsumeResultSet(?)
at async Task<bool> Npgsql.NpgsqlDataReader.NextResult(bool async, bool isConsuming, CancellationToken cancellationToken) x 2
at async Task Dapper.SqlMapper+GridReader.OnAfterGridAsync(int index) in /_/Dapper/SqlMapper.GridReader.Async.cs:line 148 I continued to try to write a runnable sample.
|
It does help, it confirms my suspicion we're going off the rails somewhere, likely losing protocol sync.
Thanks. In the meantime could you try to rerun your code with Let us know what the results are, even if nothing changed! |
This is the exception after set Npgsql.NpgsqlException (0x80004005): Exception while reading from stream
---> System.TimeoutException: Timeout during reading attempt
at Npgsql.Internal.NpgsqlReadBuffer.<Ensure>g__EnsureLong|54_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.NpgsqlReadBuffer.Skip(Int32 len, Boolean async)
at Npgsql.Internal.PgReader.Consume(Boolean async, Nullable`1 count, CancellationToken cancellationToken)
at Npgsql.Internal.PgReader.<CommitAsync>g__CommitSlow|99_0()
at Npgsql.NpgsqlDataReader.<ConsumeRow>g__ConsumeRowSequential|129_0(Boolean async)
at Npgsql.NpgsqlDataReader.<NextResult>g__ConsumeResultSet|52_0(Boolean async)
at Npgsql.NpgsqlDataReader.NextResult(Boolean async, Boolean isConsuming, CancellationToken cancellationToken)
at Npgsql.NpgsqlDataReader.NextResult(Boolean async, Boolean isConsuming, CancellationToken cancellationToken)
at Dapper.SqlMapper.GridReader.OnAfterGridAsync(Int32 index) in /_/Dapper/SqlMapper.GridReader.Async.cs:line 148
at Dapper.SqlMapper.GridReader.ReadBufferedAsync[T](Int32 index, Func`2 deserializer) in /_/Dapper/SqlMapper.GridReader.Async.cs:line 246 |
@yunfandev I think #5440 will solve your issue as well. To confirm could you run your code on our daily build? https://www.myget.org/feed/npgsql-vnext/package/nuget/Npgsql/9.0.0-preview.1-ci.20231128T234421+sha.b21c41c58 |
Thanks! @NinoFloris |
@NinoFloris I tested the latest Nuget package and the problem is solved! Thx! |
@NinoFloris After upgrade to 8.0.1 we still receive this error: Npgsql.NpgsqlException (0x80004005): Exception while reading from stream
---> System.TimeoutException: Timeout during reading attempt
at async ValueTask Npgsql.Internal.NpgsqlReadBuffer.Ensure(int count, bool async)+EnsureLong(?)
at async Task Npgsql.Internal.NpgsqlReadBuffer.Skip(int len, bool async)
at async Task Npgsql.NpgsqlDataReader.ConsumeRow(bool async)+ConsumeRowSequential(?)
at async bool Npgsql.NpgsqlDataReader.NextResult()+ConsumeResultSet(?)
at async Task<bool> Npgsql.NpgsqlDataReader.NextResult(bool async, bool isConsuming, CancellationToken cancellationToken) x 2
at async Task Dapper.SqlMapper+GridReader.OnAfterGridAsync(int index) in /_/Dapper/SqlMapper.GridReader.Async.cs:line 148
at async Task<IEnumerable<T>> Dapper.SqlMapper+GridReader.ReadBufferedAsync<T>(int index, Func<DbDataReader, object> deserializer) in /_/Dapper/SqlMapper.GridReader.Async.cs:line 246 |
And you're sure it was fixed with #5430 (comment) ? Regardless, for me to do anything here I really need a runnable repro of your issue. |
And could you also confirm that the issue doesn't happen with npgsql 7.0? |
@vonzshik This problem doesn't occur in 7.0 @NinoFloris I'll reconfirm the issue tomorrow, as we're all docker builds without a nuget package cache, so it's unlikely to be a problem with me not upgrading to version 8.0.1 I will make a working repo as soon as I can. |
Was resolved for repro code. with errors "Internal Npgsql bug: unexpected value 0 of enum BackendMessageCode. Please file a bug." tried to repro it with simplest case and had reproducible error with code using System;
using System.Threading.Tasks;
namespace pgTest;
public class Program {
private const string ConnStr = "Server=pg;Port=5432;Database=temp;User id=admin;Password=admin";
private static readonly Npgsql.NpgsqlDataSource ds = new Npgsql.NpgsqlDataSourceBuilder(ConnStr).Build();
public static async Task Main() {
AppContext.SetSwitch("Npgsql.EnableAssertions", true);
try {
Console.WriteLine($"Started");
using var conn = await ds.OpenConnectionAsync();
Console.WriteLine($"Connected");
using var tx = await conn.BeginTransactionAsync();
using var cmd = conn.CreateCommand();
cmd.CommandTimeout = 1;
cmd.Transaction = tx;
cmd.CommandText = """select v.i, repeat('1', 10), repeat('2', 10), repeat('3', 10), repeat('4', 10), 1, 2 from generate_series(1, 1000) as v(i)""";
var rdr = await cmd.ExecuteReaderAsync(System.Data.CommandBehavior.SingleResult | System.Data.CommandBehavior.SequentialAccess);
while (await rdr.ReadAsync()) {
_ = rdr[0];
_ = rdr[1];
//_ = rdr[2];
//_ = rdr[3];
//_ = rdr[4];
//_ = rdr[5]; // uncomment lines for successful execution
_ = rdr[6];
}
await rdr.DisposeAsync();
await cmd.DisposeAsync();
await tx.CommitAsync();
await conn.DisposeAsync();
}
catch (Exception e) {
Console.WriteLine(e);
}
}
} But with error
Not sure it's tightly linked, but maybe it has same reason. |
@kae thanks for the repro, that's unfortunate... I've tested it against #5476 which does away with the complicated buffered sequential fast path entirely. It passes there but I'm not sure it's something we want to backport to 8.0.2. Because of that I've also created a targeted fix in #5486. I'm sorry for the issue persisting into the 8.0.1 release. |
I guess i have the same issue in package Npgsql.EntityFrameworkCore.PostgreSQL version 8.0.0
Stacktrace
|
@Skayloo you might want to open another issue with a minimal repro. EF doesn't use CommandBehavior.Sequential so it should not be affected by this particular issue. |
Unless I'm mistaken, QueryMultipleAsync is Dapper (which I think does use CommandBehavior.Sequential) - in any case there's no such thing in EF. |
Heyho 👋
The Stacktrace looks pretty simiular to this issue so i decided to post this here. Some information about our system:
|
Hi, i run in a similiar problem. I use npgsl 8.0.1 and it works fine except one case where i have a huge load of executed queries. The queries are inside a for loop and get multiple times repeated with different parameters. After a few executions it will throw a timeout execution The problem occurs also with the quoted preview release. It works normal with 7.0.6. |
Hello, FYI same problem here with very simple query on a table with 100k rows, sometimes it works, sometimes it fails (but apparently always on the same WHERE xxx = value) with the following stack TFM: net8.0 System.Data.DataException: Exception while reading from stream
---> Npgsql.NpgsqlException (0x80004005): Exception while reading from stream
---> System.TimeoutException: Timeout during reading attempt
at Npgsql.Internal.NpgsqlReadBuffer.<Ensure>g__EnsureLong|54_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.NpgsqlReadBuffer.Skip(Int32 len, Boolean async)
at Npgsql.NpgsqlDataReader.<>c__DisplayClass128_0.<<SeekToColumnSequential>g__Core|0>d.MoveNext()
--- End of stack trace from previous location ---
at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
at Npgsql.NpgsqlDataReader.GetValue(Int32 ordinal)
at Npgsql.NpgsqlDataReader.get_Item(Int32 ordinal)
at Deserializeb0d63090-174b-4788-9742-033a6792fc73(DbDataReader)
--- End of inner exception stack trace ---
at Dapper.SqlMapper.ThrowDataException(Exception ex, Int32 index, IDataReader reader, Object value) in /_/Dapper/SqlMapper.cs:line 3928
at Deserializeb0d63090-174b-4788-9742-033a6792fc73(DbDataReader)
at Dapper.SqlMapper.QueryAsync[T](IDbConnection cnn, Type effectiveType, CommandDefinition command) |
@NinoFloris should we move this to the 8.0.2 milestone? |
Moved! |
I want to make sure we can put this issue to bed properly with 8.0.2. @kae would you mind running the latest ci build from myget to see if things are working correctly for you? (https://www.myget.org/feed/npgsql-vnext/package/nuget/Npgsql/9.0.0-preview.1-ci.20240131T215454+sha.882265627) Anybody else is free to try as well of course. |
Hello, To test this bug we have added integration test. The error is consistently reproduced under fairly high load (hundreds of parallel requests or more). We have now run this test for build with the specified package version (9.0.0-preview.1-ci.20240131T215454). Unfortunately, the error is being reproduced. Message: "Timeout during reading attempt". at Npgsql.Internal.NpgsqlReadBuffer.<<Ensure>g__EnsureLong|54_0>d.MoveNext()
at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
at Npgsql.Internal.NpgsqlConnector.<ReadMessageLong>d__233.MoveNext()
at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
at Npgsql.Internal.NpgsqlConnector.<ReadMessageLong>d__233.MoveNext()
at System.Runtime.CompilerServices.PoolingAsyncValueTaskMethodBuilder`1.StateMachineBox`1.System.Threading.Tasks.Sources.IValueTaskSource<TResult>.GetResult(Int16 token)
at Npgsql.NpgsqlDataReader.<NextResult>d__52.MoveNext()
at Npgsql.NpgsqlDataReader.<NextResult>d__52.MoveNext()
at Npgsql.NpgsqlDataReader.NextResult()
at Npgsql.NpgsqlCommand.<ExecuteReader>d__119.MoveNext()
at Npgsql.NpgsqlCommand.<ExecuteReader>d__119.MoveNext()
at System.Threading.Tasks.ValueTask`1.get_Result()
at Npgsql.NpgsqlCommand.<ExecuteNonQuery>d__107.MoveNext()
at Npgsql.NpgsqlCommand.ExecuteNonQuery()
at Npgsql.NpgsqlBatch.ExecuteNonQuery()
at Red.WorkPoint.Data.TmConnectionInterceptor.ConnectionOpened(DbConnection connection, ConnectionEndEventData eventData) in D:\repos\backend\Red.WorkPoint.Data\Data\TmConnectionInterceptor.cs:line 22
at Microsoft.EntityFrameworkCore.Diagnostics.Internal.RelationalConnectionDiagnosticsLogger.ConnectionOpened(IRelationalConnection connection, DateTimeOffset startTime, TimeSpan duration)
at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.OpenInternal(Boolean errorsExpected)
at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.Open(Boolean errorsExpected)
at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteReader(RelationalCommandParameterObject parameterObject)
at Microsoft.EntityFrameworkCore.Query.Internal.SingleQueryingEnumerable`1.Enumerator.InitializeReader(Enumerator enumerator)
at Microsoft.EntityFrameworkCore.Query.Internal.SingleQueryingEnumerable`1.Enumerator.<>c.<MoveNext>b__21_0(DbContext _, Enumerator enumerator)
at Npgsql.EntityFrameworkCore.PostgreSQL.Storage.Internal.NpgsqlExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded) |
@zolotovvv It does makes sense that you can repro something like that under high load because the database itself will also be under high load and in turn that makes it so queries take longer to complete. |
@zolotovvv that is not the same issue, please create a new issue with its own runnable repro. EF does not use CommandBehavior.Sequential, which Dapper does and where our fixes have been targeted. |
Checked with repro |
I ran some tests. It looks good, the problem seems to be gone. Thanks. |
The issue
After upgrading to 8.0, the third line of code runs with the following error:
Further technical details
Npgsql version: 8.0
PostgreSQL version: 15.3
Operating system: Debian 12 in Docker
The text was updated successfully, but these errors were encountered: