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?
information_schema
is just some representation of the catalog to comply with the standard. The actual catalog is available viapg_catalog
. And it is not limited to a database. So there could be something to it. I wouldn't expect the described behavior though.