3

I'm struggling to determine the cause of an exception when the code is run in parallel, but works fine when run one at a time.

As background information, I'm running a set of unit tests, where each test picks up a database from a pool of databases and clears the data from it. The pool is created just in time, one database at a time as needed. (I acquire a pg_advisory_lock around creation of the database to prevent threading issues seemingly inside of postgres). The postgres server is hosted inside of a Vagrant machine running ubuntu/xenial64 and postgres 9.6

When calculating the tables to clear data from, I run the following SQL:

SELECT target_table.table_schema || '.' || target_table.table_name AS TargetTable,
       source_table.table_schema || '.' || source_table.table_name AS SourceTable,
       source_column.column_name AS SourceColumn,
       source_column.is_nullable::boolean AS SourceColumnIsOptional
FROM information_schema.table_constraints AS source_table
JOIN information_schema.key_column_usage AS kcu ON source_table.constraint_name = kcu.constraint_name
JOIN information_schema.constraint_column_usage AS target_table ON target_table.constraint_name = source_table.constraint_name
JOIN information_schema.columns AS source_column ON kcu.table_name = source_column.table_name AND kcu.table_schema = source_column.table_schema AND kcu.column_name = source_column.column_name
WHERE constraint_type = 'FOREIGN KEY';

When run one test at a time, it works fine. When run inside of DataGrip console, it takes about 750ms to execute (which is surprisingly slow, but good enough). However when I run several unit tests concurrently (e.g. 3 or more) then the following exception is thrown pretty reliably:

Npgsql.NpgsqlException
  HResult=0x80004005
  Message=Exception while reading from stream
  Source=<Cannot evaluate the exception source>
  StackTrace:
   at Npgsql.ReadBuffer.<Ensure>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.<DoReadMessage>d__157.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.<ReadMessage>d__156.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.<ReadExpecting>d__163`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.<NextResult>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.<Execute>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.<ExecuteDbDataReader>d__92.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.ExecuteDbDataReader(CommandBehavior behavior)
   at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader(CommandBehavior behavior)
   at PeregrineDb.Databases.Mapper.SqlMapper.<QueryImpl>d__10`1.MoveNext()
   at System.Collections.Generic.List`1..ctor(IEnumerable`1 collection)
   at System.Linq.Enumerable.ToList[TSource](IEnumerable`1 source)
   at PeregrineDb.Databases.DefaultSqlConnection.Query[T](SqlCommand& command, Nullable`1 commandTimeout)
   at PeregrineDb.Databases.DefaultDatabase`1.PeregrineDb.ISqlConnection.Query[T](SqlCommand& command, Nullable`1 commandTimeout)
   at InteractiveReports.Infrastructure.Postgres.PgDatabaseWiper.GenerateCommands(String connectionString, String lockKey) in C:\Dev\Git\IReports\src\InteractiveReports.Infrastructure\Postgres\PgDatabaseWiper.cs:line 40

Inner Exception 1:
IOException: Unable to read data from the transport connection: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond.

Inner Exception 2:
SocketException: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond

I use the connection string Server=10.10.3.202; Port=5432; User Id=postgres; Password=postgres123; Pooling=false; and automatically insert a database name with a GUID in it. I've disabled pooling so that the database can be dropped reliably after disposing of all NpgsqlConnections.

I'm not sure where to start looking in diagnosing why I get a timeout when run in parallel.


Update

When I skip this particular query, everything works fine, so I'm pretty sure it's something about that query. I've added a pg_advisory_lock around it to try make it serial, but it still errors!

The only thing I can think of is it's querying the information_schema "too soon" after creating the database (which is made from scratch and ~70 tables created). But I don't know why it only errors when done in parallel. Does querying the information_schema of one database get blocked by the creation of another database?

1
  • "Does querying the information_schema of one database get blocked by the creation of another database?" As far as I understood information_schema is just some representation of the catalog to comply with the standard. The actual catalog is available via pg_catalog. And it is not limited to a database. So there could be something to it. I wouldn't expect the described behavior though.
    – sticky bit
    May 3, 2018 at 0:29

0

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.