Npgsql: NpgsqlException - Exception while reading from stream

[moxplod]

I am getting random error messages in my application log with the following stack trace. Most of the time everything is working well. I get about 10 errors and log messages like this a day in the production system. How do I figure out what is going on?

The issue

ERROR [18] 
 Npgsql.NpgsqlException (0x80004005): Exception while reading from stream ---> System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
    at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
    --- End of inner exception stack trace ---
    at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
    at Npgsql.NpgsqlReadBuffer.<>c__DisplayClass31_0.<<Ensure>g__EnsureLong|0>d.MoveNext()
    at Npgsql.NpgsqlReadBuffer.<>c__DisplayClass31_0.<<Ensure>g__EnsureLong|0>d.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
    at Npgsql.NpgsqlConnector.<>c__DisplayClass161_0.<<ReadMessage>g__ReadMessageLong|0>d.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
    at Npgsql.NpgsqlConnector.<>c__DisplayClass161_0.<<ReadMessage>g__ReadMessageLong|0>d.MoveNext()
 --- End of stack trace from previous location where exception was thrown ---
    at Npgsql.NpgsqlDataReader.NextResult(Boolean async, Boolean isConsuming)
    at Npgsql.NpgsqlDataReader.NextResult()
    at Npgsql.NpgsqlCommand.ExecuteDbDataReader(CommandBehavior behavior, Boolean async, CancellationToken cancellationToken)
    at Npgsql.NpgsqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
    at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader(CommandBehavior behavior)
    at Dapper.SqlMapper.ExecuteReaderWithFlagsFallback(IDbCommand cmd, Boolean wasClosed, CommandBehavior behavior) in C:\projects\dapper\Dapper\SqlMapper.cs:line 1051
    at Dapper.SqlMapper.QueryImpl[T](IDbConnection cnn, CommandDefinition command, Type effectiveType)+MoveNext() in C:\projects\dapper\Dapper\SqlMapper.cs:line 1079
    at System.Collections.Generic.List`1.AddEnumerable(IEnumerable`1 enumerable)
    at System.Linq.Enumerable.ToList[TSource](IEnumerable`1 source)
    at Dapper.SqlMapper.Query[T](IDbConnection cnn, String sql, Object param, IDbTransaction transaction, Boolean buffered, Nullable`1 commandTimeout, Nullable`1 commandType) in C:\projects\dapper\Dapper\SqlMapper.cs:line 721
    at Dapper.FastCrud.SqlStatements.GenericSqlStatements`1.BatchSelect(IDbConnection connection, AggregatedSqlStatementOptions`1 statementOptions) in D:\a\1\s\Dapper.FastCrud\SqlStatements\GenericSqlStatements.cs:line 297
    at XXX.Core.Data.SqlRepository`1.FirstOrDefault(String where, Object param, String order)
    at XXXXX.App.Worker.Tasks.XXX.Process() in C:\Dropbox\dev\Src\shop\XXX\Tasks\ShopifyWebhookTask.cs:line 13
    at XXX.App.Worker.TaskBase`1.ProcessMessage(String message) in C:\Dropbox\dev\Src\shop\XXX\TaskBase.cs:line 30
    at Shop.Core.Common.Queue.BaseTaskProcessor`1.Process(QueueMessage message) in C:\Dropbox\dev\Src\shop\XXX\Queue\BaseTaskProcessor.cs:line 38

Exception message:
Stack trace:

Npgsql version: 4.0.10
PostgreSQL version: 10.10
Operating system: Azure Windows Function + Azure Managed PostgresSql.

[uberlei]

I had the same problem I went back to version 4.0.9 and the problem didn't happen anymore.

[stvoidmain]

I had a lot of these messages, ended up disabling pooling but is not a good solution... I'll try to debug the root cause of this.
@moxplod just out of curiosity (i just moved my postgre from azure managed postgresql to self managed VM) you have good latency times? I was getting from 2 ms to 900+ms, was terrible and Azure Postgresql team couldn't find a solution, even when my apps and VM that accessed the Postgre instance were on the same datacenter and the same virtual network, horrible experience...

[roji]

Guys, the error message is saying that PostgreSQL closed the connection for some reason. In these cases, the PostgreSQL log almost always contains a message that provides insight into why that happened - please post those messages here and we can investigate further, otherwise there's no enough information.

[stvoidmain]

I wish, Roji, the logs in Postgre says nothing more than "connection closed unexpectedly" (or something among that lines, believe me, i spent 3 days debugging this), is something related to Npgsql and pooling but haven't had the chance to get the code and debug it properly , when I was looking at that it looked clearly like a race condition on the check and the returning of the connection from the pool but i didn't tested it properly so... now i'm using PgPool and it's all good but having pooling client side also would be a good benefit (it should be at least a couple ms faster than obtaining a connection from pgpool) but I will debug it if I have the chance on next month.

[NinoFloris]

@stvoidmain Do you know what version of npgsql you were running at the time?

I merged this change for 4.1.2, it would really help if you can test it again
https://github.com/npgsql/npgsql/pull/2719

[stvoidmain]

Yes, I was using 4.1.1
Hmm, that seems promising, i'll test again soon!!!

[grandsilence]

I'm using v4.1.2 and got the same issue. I'll try v4.0.9 😞 .

[grandsilence]

I'm using v4.1.2 and got the same issue. I'll try v4.0.9 😞 .

it didn't help. Still have timeout and no any errors in pgsql service.

[stvoidmain]

I'm using 4.1.2 now and still getting the same behaviour, gonna try to reproduce it locally and debug.

[pdhung]

We are getting this problem with version 4.0.10 and Excel O365 using ADO.NET and OLE DB. This only happens if after a NativeQuery we use a Power Query function, like Date.Month() for example.
Excel fetch the first chunk of data, process them with the function, then resume fetching and got this error

[roji]

I'm going to need a code sample to be able to work on this... @stvoidmain have you made any progress with that?

[Borja-Guiles]

Hi, we are also having problems with it, version 4.1.3. Is this being looked into?
Not configuring pooling fixed the issue.

[roji]

@Borja-Guiles I have yet to receive any sort of code sample reproducing this, which would indicate an issue in Npgsql. In all the cases I've seen where this error occurs, the cause is an environmental networking problem or something similar, and outside of Npgsql's domain.

I'm going to close this as there's nothing actionable at the moment. If someone can provide a repro, I can reopen and investigate.

[ijasmp18]

@roji I have similar issue... How can I solve this. https://github.com/npgsql/npgsql/issues/2969

[Borja-Guiles]

@ijasmp18 Not really solve it but either increase the pooling in the connection string or dont cofigure it to start with. If you could post an example it might help us all. Cause i dont really have the time to make a replica of our situation

[ijasmp18]

@Borja-Guiles
string connectionString = "Server=127.0.0.1;Port=6000;User Id=postgres; Password=123; Database=postgres; CommandTimeout=120;"; var connection = new Npgsql.NpgsqlConnection(connectionString); connection.Open();
this is my code it works fine in all my test devices except one. Inside that machine

Exception while reading from stream ---> System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)...
exception occures

[Borja-Guiles]

@ijasmp18 If it still fails it might not be the same reason as when it happened to us however you can check a few things and maybe find something that way:

1. You have enough connections available in the postgres server
2. Your program takes too long between uses of the connection and when you are trying to make a call it already close the connection serverside (This has happened to us before, by default a connection is left idle only for 3 seconds or something like that i believe).
3. You might have enough connections but the server cant handle them, this happened to use on a testing machine which had hardly any resources available and it couldnt deal with the integration tests, plus a demo site plus peoples testing databases. Here it was different errors everytime but who knows

[ijasmp18]

@Borja-Guiles thanks for the hep