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

System.NullReferenceException at Npgsql.NpgsqlConnector.Cleanup() #1667

Closed
t0pd3v1c3 opened this Issue Sep 1, 2017 · 11 comments

Comments

Projects
None yet
3 participants
@t0pd3v1c3

t0pd3v1c3 commented Sep 1, 2017

Npgsql 3.2.5.

System.NullReferenceException: Object reference not set to an instance of an object.
at Npgsql.NpgsqlConnector.Cleanup()
at Npgsql.NpgsqlConnector.Break()
at Npgsql.ReadBuffer.d__27.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Npgsql.NpgsqlConnector.d__148.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
at Npgsql.NpgsqlConnector.d__147.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
at Npgsql.NpgsqlConnector.d__154`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
at Npgsql.NpgsqlDataReader.d__32.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Npgsql.NpgsqlDataReader.NextResult()
at Npgsql.NpgsqlCommand.d__71.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
at Npgsql.NpgsqlCommand.d__87.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
at Npgsql.NpgsqlCommand.ExecuteScalar()
@roji

This comment has been minimized.

Show comment
Hide comment
@roji

roji Sep 10, 2017

Member

Can you reproduce this exception in a reliable way, and submit a code sample which reproduces it?

If not, I've seen this before when the same connection is used concurrently from multiple threads, which isn't allowed. Can you please confirm that this isn't the case here?

Member

roji commented Sep 10, 2017

Can you reproduce this exception in a reliable way, and submit a code sample which reproduces it?

If not, I've seen this before when the same connection is used concurrently from multiple threads, which isn't allowed. Can you please confirm that this isn't the case here?

@monty241

This comment has been minimized.

Show comment
Hide comment
@monty241

monty241 Nov 29, 2017

Found same problem on 3.2.5:

Exception: System.NullReferenceException
   at Npgsql.NpgsqlConnector.Cleanup()
   at Npgsql.NpgsqlConnector.Break()
   at Npgsql.ReadBuffer.<Ensure>d__27.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Npgsql.NpgsqlConnector.<DoReadMessage>d__148.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
   at Npgsql.NpgsqlConnector.<ReadMessage>d__147.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
   at Npgsql.NpgsqlConnector.<ReadExpecting>d__154`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
   at Npgsql.NpgsqlDataReader.<NextResult>d__32.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Npgsql.NpgsqlDataReader.NextResult()
   at Npgsql.NpgsqlCommand.<Execute>d__71.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
   at Npgsql.NpgsqlCommand.<ExecuteScalar>d__87.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
   at Npgsql.NpgsqlCommand.ExecuteScalar()
   at Invantive.Data.AnsiSqlProviderBase.RetrieveSimpleScalar(IConnection connection, String actionSql, ParameterList parameters, String callSafeNameOverrule)
   at Invantive.Data.Providers.PostgreSql.PostgreSqlProvider.GetDatabaseVersion(Connection connection)
   at Invantive.Data.AnsiSqlProviderBase.OnOpen(SerializableDatabase database, DataContainer dataContainer, OAuthToken token)
   at Invantive.Data.GenericConnectionDataProvider.Open(SerializableDatabase database, DataContainer dataContainer, OAuthToken token)
   at Invantive.Data.ConnectionManager.JB(IConnectionDataProvider , SerializableDatabase , DataContainer , OAuthToken )
   at Invantive.Data.ConnectionManager.OB(SerializableDatabase , DataContainer , OAuthToken )
   at Invantive.Data.ConnectionManager.QB(OAuthToken )
   at Invantive.Data.ConnectionManager.Open(OAuthToken token)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Invantive.Data.ConnectionManager.Open(OAuthToken token)
   at Invantive.Producer.WebhookReceiver.Controllers.RocketChatController..ctor() in C:\ws\Invantive.Customer.Service\src\Invantive.Producer.WebhookReceiver\Controllers\RocketChatController.cs:line 34

monty241 commented Nov 29, 2017

Found same problem on 3.2.5:

Exception: System.NullReferenceException
   at Npgsql.NpgsqlConnector.Cleanup()
   at Npgsql.NpgsqlConnector.Break()
   at Npgsql.ReadBuffer.<Ensure>d__27.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Npgsql.NpgsqlConnector.<DoReadMessage>d__148.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
   at Npgsql.NpgsqlConnector.<ReadMessage>d__147.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
   at Npgsql.NpgsqlConnector.<ReadExpecting>d__154`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
   at Npgsql.NpgsqlDataReader.<NextResult>d__32.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Npgsql.NpgsqlDataReader.NextResult()
   at Npgsql.NpgsqlCommand.<Execute>d__71.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
   at Npgsql.NpgsqlCommand.<ExecuteScalar>d__87.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
   at Npgsql.NpgsqlCommand.ExecuteScalar()
   at Invantive.Data.AnsiSqlProviderBase.RetrieveSimpleScalar(IConnection connection, String actionSql, ParameterList parameters, String callSafeNameOverrule)
   at Invantive.Data.Providers.PostgreSql.PostgreSqlProvider.GetDatabaseVersion(Connection connection)
   at Invantive.Data.AnsiSqlProviderBase.OnOpen(SerializableDatabase database, DataContainer dataContainer, OAuthToken token)
   at Invantive.Data.GenericConnectionDataProvider.Open(SerializableDatabase database, DataContainer dataContainer, OAuthToken token)
   at Invantive.Data.ConnectionManager.JB(IConnectionDataProvider , SerializableDatabase , DataContainer , OAuthToken )
   at Invantive.Data.ConnectionManager.OB(SerializableDatabase , DataContainer , OAuthToken )
   at Invantive.Data.ConnectionManager.QB(OAuthToken )
   at Invantive.Data.ConnectionManager.Open(OAuthToken token)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Invantive.Data.ConnectionManager.Open(OAuthToken token)
   at Invantive.Producer.WebhookReceiver.Controllers.RocketChatController..ctor() in C:\ws\Invantive.Customer.Service\src\Invantive.Producer.WebhookReceiver\Controllers\RocketChatController.cs:line 34

@monty241

This comment has been minimized.

Show comment
Hide comment
@monty241

monty241 Nov 29, 2017

This call stack was taken from a single session IIS application. It has a connection pool shared by all sessions with a maximum size of 1:

Released connection. Currently 0 connections in use. Preferred number is 1, maximum is 1.

It occurs with milliseconds after logging on, when requesting the views.

So it is multi-thread application with at most one SQL statement active and/or open.

monty241 commented Nov 29, 2017

This call stack was taken from a single session IIS application. It has a connection pool shared by all sessions with a maximum size of 1:

Released connection. Currently 0 connections in use. Preferred number is 1, maximum is 1.

It occurs with milliseconds after logging on, when requesting the views.

So it is multi-thread application with at most one SQL statement active and/or open.

@monty241

This comment has been minimized.

Show comment
Hide comment
@monty241

monty241 Nov 29, 2017

Occurs consistently 50 times per day out of approximately 250 tries. Postgresql 9.6.

monty241 commented Nov 29, 2017

Occurs consistently 50 times per day out of approximately 250 tries. Postgresql 9.6.

@roji

This comment has been minimized.

Show comment
Hide comment
@roji

roji Nov 29, 2017

Member

@monty241, any chance you're trying to close a connection that's currently executing a command, due to a race condition? If so, this is a known issue and not currently supported.

Member

roji commented Nov 29, 2017

@monty241, any chance you're trying to close a connection that's currently executing a command, due to a race condition? If so, this is a known issue and not currently supported.

@monty241

This comment has been minimized.

Show comment
Hide comment
@monty241

monty241 Nov 29, 2017

Hi @roji , thanks for fast addition. No, during initialization of the connection we do the following steps:

  • open connection
  • get metadata (including view names etc)
  • then start doing the real work

The first steps are executed sequentially and protected by a lock. It nonetheless tries to close a previous connection to PostgreSQL through NPGSQL 25 ms earlier, but that call succeeds.

Just to be sure: what is issue# of that issue? Maybe I can analyze the code to completely rule that possible cause out.

monty241 commented Nov 29, 2017

Hi @roji , thanks for fast addition. No, during initialization of the connection we do the following steps:

  • open connection
  • get metadata (including view names etc)
  • then start doing the real work

The first steps are executed sequentially and protected by a lock. It nonetheless tries to close a previous connection to PostgreSQL through NPGSQL 25 ms earlier, but that call succeeds.

Just to be sure: what is issue# of that issue? Maybe I can analyze the code to completely rule that possible cause out.

@monty241

This comment has been minimized.

Show comment
Hide comment
@monty241

monty241 Nov 29, 2017

Added some measurements in code to be able to better analyze cause and will plugin npgsql logger in our logging framework.

Might it be that with CurrentReader.Command.State the CurrentReader.Command == null ?

monty241 commented Nov 29, 2017

Added some measurements in code to be able to better analyze cause and will plugin npgsql logger in our logging framework.

Might it be that with CurrentReader.Command.State the CurrentReader.Command == null ?

@roji

This comment has been minimized.

Show comment
Hide comment
@roji

roji Nov 30, 2017

Member

@monty241 from your stack trace it seems that the error occurs while attempting to "break" a connection - this happens when an unrecoverable error occurs (e.g. broken network connection).

I can try to look, but the best way forward is if you can produce a code sample which reproduces this? I don't need a 100% repro, but something which runs in a loop and does 50% would be more than enough. However, please try to avoid IIS/ASP.NET/other heavy APIs or libraries.

Member

roji commented Nov 30, 2017

@monty241 from your stack trace it seems that the error occurs while attempting to "break" a connection - this happens when an unrecoverable error occurs (e.g. broken network connection).

I can try to look, but the best way forward is if you can produce a code sample which reproduces this? I don't need a 100% repro, but something which runs in a loop and does 50% would be more than enough. However, please try to avoid IIS/ASP.NET/other heavy APIs or libraries.

@monty241

This comment has been minimized.

Show comment
Hide comment
@monty241

monty241 Dec 1, 2017

After adding npgsql logging problem and upgrading infrastructuer problem not yet seen.

monty241 commented Dec 1, 2017

After adding npgsql logging problem and upgrading infrastructuer problem not yet seen.

@roji roji removed the waiting for answer label Jun 8, 2018

@roji

This comment has been minimized.

Show comment
Hide comment
@roji

roji Jun 9, 2018

Member

Closing for age, since no repro has been submitted and in any case the issue may be gone.

Member

roji commented Jun 9, 2018

Closing for age, since no repro has been submitted and in any case the issue may be gone.

@roji roji closed this Jun 9, 2018

@roji roji added the invalid label Jun 9, 2018

@monty241

This comment has been minimized.

Show comment
Hide comment
@monty241

monty241 Jun 9, 2018

Correct, problem never seen again after adding npgsql logging. Apologies for not updating this issue.

monty241 commented Jun 9, 2018

Correct, problem never seen again after adding npgsql logging. Apologies for not updating this issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment