I expect no connection to stay open after ConnectionPool.dispose() exits.
However idle connections remains in pg_stat_activity and never released.
ConnectionPool.dispose() unexpected behaviour
Steps to reproduce
Input Code
```java
final LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
context.getLogger(Logger.ROOT_LOGGER_NAME).setLevel(Level.INFO);
context.getLogger("io.r2dbc.postgresql.QUERY").setLevel(Level.DEBUG);
context.getLogger(ConnectionPool.class).setLevel(Level.DEBUG);
// create pooled connection to postgres
final ConnectionFactory connectionFactory = ConnectionFactories.get("r2dbc:pool:postgresql://test:test@localhost:5432/postgres");
// run query
for(int i = 0; i < 10; i++) {
DatabaseClient.create(connectionFactory)
.sql("SELECT 1")
.then()
.block();
}
// dispose pool
if (connectionFactory instanceof Disposable) {
((Disposable) connectionFactory).dispose();
System.out.println("POOL DISPOSED");
}
// check number of connections in db.
final ConnectionFactory noPoolCf = ConnectionFactories.get("r2dbc:postgresql://test:test@localhost:5432/postgres");
DatabaseClient.create(noPoolCf).sql("select application_name, state, query " +
"from postgres.pg_catalog.pg_stat_activity " +
"where application_name=$1")
.bind(0, "r2dbc-postgresql")
.fetch()
.all()
.collectList()
.doOnNext(connections -> {
System.out.printf("CONNECTIONS (%d):\n", connections.size());
connections.forEach(System.out::println);
})
.block();
```
Console Output (0.9.0-M2)
```bash
18:30:45.667 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:30:45.829 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.835 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.843 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:30:45.853 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:30:45.863 [reactor-tcp-epoll-2] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.863 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.863 [reactor-tcp-epoll-2] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.864 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.864 [reactor-tcp-epoll-2] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:30:45.865 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.865 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:30:45.866 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.867 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.868 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.869 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.870 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.871 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.871 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.872 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.873 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.873 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.873 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.874 [reactor-tcp-epoll-3] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.874 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.874 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.874 [reactor-tcp-epoll-3] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.875 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.875 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.875 [reactor-tcp-epoll-3] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:30:45.876 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:30:45.891 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.892 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.892 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:30:45.895 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:30:45.902 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.902 [reactor-tcp-epoll-5] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.902 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.902 [reactor-tcp-epoll-5] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.903 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.903 [reactor-tcp-epoll-5] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:30:45.903 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.904 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:30:45.904 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.905 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.905 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.906 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.906 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.907 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.907 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.908 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.908 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.908 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.909 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.909 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.909 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.910 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.911 [reactor-tcp-epoll-6] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.911 [reactor-tcp-epoll-6] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.912 [reactor-tcp-epoll-6] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:30:45.912 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:30:45.921 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.922 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.923 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:30:45.925 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:30:45.930 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.931 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.931 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.931 [reactor-tcp-epoll-8] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.931 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.932 [reactor-tcp-epoll-8] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.932 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.932 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.932 [reactor-tcp-epoll-8] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:30:45.933 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.933 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:30:45.933 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.934 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.934 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.934 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.935 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.935 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.935 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.935 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.936 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.936 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.936 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.939 [reactor-tcp-epoll-9] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.939 [reactor-tcp-epoll-9] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.940 [reactor-tcp-epoll-9] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:30:45.940 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:30:45.950 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.950 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.951 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
POOL DISPOSED
18:30:45.959 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.960 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.960 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.961 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.961 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.962 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.962 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.963 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.963 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.963 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.964 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.964 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.964 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.965 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.965 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.965 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.965 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.966 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.966 [reactor-tcp-epoll-11] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:30:45.967 [reactor-tcp-epoll-11] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:30:45.977 [reactor-tcp-epoll-11] DEBUG io.r2dbc.postgresql.QUERY - Executing query: select application_name, state, query from postgres.pg_catalog.pg_stat_activity where application_name=$1
CONNECTIONS (10):
{application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')}
{application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')}
{application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')}
{application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')}
{application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')}
{application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')}
{application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')}
{application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')}
{application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')}
{application_name=r2dbc-postgresql, state=active, query=select application_name, state, query from postgres.pg_catalog.pg_stat_activity where application_name=$1}
Process finished with exit code 0
```
Console Output (0.8.7-RELEASE)
```bash
18:36:29.499 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:36:29.661 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:36:29.666 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:36:29.675 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:36:29.681 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:36:29.683 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:36:29.691 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:36:29.692 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:36:29.693 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:36:29.693 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:36:29.694 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:36:29.695 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:36:29.696 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:36:29.696 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:36:29.696 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:36:29.697 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:36:29.698 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:36:29.698 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:36:29.699 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:36:29.699 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:36:29.699 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:36:29.700 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:36:29.700 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:36:29.701 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:36:29.701 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:36:29.701 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:36:29.702 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:36:29.702 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:36:29.704 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:36:29.704 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:36:29.706 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:36:29.706 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:36:29.707 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:36:29.707 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:36:29.708 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:36:29.708 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:36:29.708 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:36:29.709 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
18:36:29.709 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver
18:36:29.710 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1
POOL DISPOSED
18:36:29.728 [reactor-tcp-epoll-2] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL
18:36:29.728 [reactor-tcp-epoll-2] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')
18:36:29.739 [reactor-tcp-epoll-2] DEBUG io.r2dbc.postgresql.QUERY - Executing query: select application_name, state, query from postgres.pg_catalog.pg_stat_activity where application_name=$1
CONNECTIONS (1):
{application_name=r2dbc-postgresql, state=active, query=select application_name, state, query from postgres.pg_catalog.pg_stat_activity where application_name=$1}
```
Comments
The problem is that after pool.dispose(), new connections are still acquired, probably on another reactor sequence. Also it looks suspicious that 0.9.0-M2 version acquires new connection on each "select 1" query and all 10 pool connections are created every time for every query.
It also looks like dispose may also fail on 0.8.7-RELEASE, but not every time.
I didn't manage to fix this issue. I suspect there are actually two issues:
1) new pool connections created for every query (this only happens in 0.9.9-M2)
2) and pool.dispose does not wait for all pool connection to be created in case it is called at the moment new pool connections are created, neither it cancels new connections creation (this might be correct for both 0.8.7 and 0.9.0).
mp911de
commented
2 years ago
Bug Report
Versions
Current Behavior
I expect no connection to stay open after ConnectionPool.dispose() exits. However idle connections remains in pg_stat_activity and never released.
ConnectionPool.dispose() unexpected behaviour
Steps to reproduce
Input Code
```java final LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory(); context.getLogger(Logger.ROOT_LOGGER_NAME).setLevel(Level.INFO); context.getLogger("io.r2dbc.postgresql.QUERY").setLevel(Level.DEBUG); context.getLogger(ConnectionPool.class).setLevel(Level.DEBUG); // create pooled connection to postgres final ConnectionFactory connectionFactory = ConnectionFactories.get("r2dbc:pool:postgresql://test:test@localhost:5432/postgres"); // run query for(int i = 0; i < 10; i++) { DatabaseClient.create(connectionFactory) .sql("SELECT 1") .then() .block(); } // dispose pool if (connectionFactory instanceof Disposable) { ((Disposable) connectionFactory).dispose(); System.out.println("POOL DISPOSED"); } // check number of connections in db. final ConnectionFactory noPoolCf = ConnectionFactories.get("r2dbc:postgresql://test:test@localhost:5432/postgres"); DatabaseClient.create(noPoolCf).sql("select application_name, state, query " + "from postgres.pg_catalog.pg_stat_activity " + "where application_name=$1") .bind(0, "r2dbc-postgresql") .fetch() .all() .collectList() .doOnNext(connections -> { System.out.printf("CONNECTIONS (%d):\n", connections.size()); connections.forEach(System.out::println); }) .block(); ```Console Output (0.9.0-M2)
```bash 18:30:45.667 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:30:45.829 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.835 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.843 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:30:45.853 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:30:45.863 [reactor-tcp-epoll-2] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.863 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.863 [reactor-tcp-epoll-2] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.864 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.864 [reactor-tcp-epoll-2] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:30:45.865 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.865 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:30:45.866 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.867 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.868 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.869 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.870 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.871 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.871 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.872 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.873 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.873 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.873 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.874 [reactor-tcp-epoll-3] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.874 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.874 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.874 [reactor-tcp-epoll-3] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.875 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.875 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.875 [reactor-tcp-epoll-3] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:30:45.876 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:30:45.891 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.892 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.892 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:30:45.895 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:30:45.902 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.902 [reactor-tcp-epoll-5] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.902 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.902 [reactor-tcp-epoll-5] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.903 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.903 [reactor-tcp-epoll-5] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:30:45.903 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.904 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:30:45.904 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.905 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.905 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.906 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.906 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.907 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.907 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.908 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.908 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.908 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.909 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.909 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.909 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.910 [reactor-tcp-epoll-4] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.911 [reactor-tcp-epoll-6] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.911 [reactor-tcp-epoll-6] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.912 [reactor-tcp-epoll-6] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:30:45.912 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:30:45.921 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.922 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.923 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:30:45.925 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:30:45.930 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.931 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.931 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.931 [reactor-tcp-epoll-8] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.931 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.932 [reactor-tcp-epoll-8] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.932 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.932 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.932 [reactor-tcp-epoll-8] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:30:45.933 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.933 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:30:45.933 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.934 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.934 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.934 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.935 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.935 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.935 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.935 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.936 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.936 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.936 [reactor-tcp-epoll-7] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.939 [reactor-tcp-epoll-9] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.939 [reactor-tcp-epoll-9] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.940 [reactor-tcp-epoll-9] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:30:45.940 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:30:45.950 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.950 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.951 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 POOL DISPOSED 18:30:45.959 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.960 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.960 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.961 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.961 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.962 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.962 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.963 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.963 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.963 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.964 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.964 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.964 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.965 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.965 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.965 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.965 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.966 [reactor-tcp-epoll-10] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.966 [reactor-tcp-epoll-11] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:30:45.967 [reactor-tcp-epoll-11] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:30:45.977 [reactor-tcp-epoll-11] DEBUG io.r2dbc.postgresql.QUERY - Executing query: select application_name, state, query from postgres.pg_catalog.pg_stat_activity where application_name=$1 CONNECTIONS (10): {application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')} {application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')} {application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')} {application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')} {application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')} {application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')} {application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')} {application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')} {application_name=r2dbc-postgresql, state=idle, query=SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore')} {application_name=r2dbc-postgresql, state=active, query=select application_name, state, query from postgres.pg_catalog.pg_stat_activity where application_name=$1} Process finished with exit code 0 ```Console Output (0.8.7-RELEASE)
```bash 18:36:29.499 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:36:29.661 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:36:29.666 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:36:29.675 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:36:29.681 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:36:29.683 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:36:29.691 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:36:29.692 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:36:29.693 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:36:29.693 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:36:29.694 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:36:29.695 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:36:29.696 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:36:29.696 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:36:29.696 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:36:29.697 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:36:29.698 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:36:29.698 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:36:29.699 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:36:29.699 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:36:29.699 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:36:29.700 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:36:29.700 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:36:29.701 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:36:29.701 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:36:29.701 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:36:29.702 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:36:29.702 [reactor-tcp-epoll-1] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:36:29.704 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:36:29.704 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:36:29.706 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:36:29.706 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:36:29.707 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:36:29.707 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:36:29.708 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:36:29.708 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:36:29.708 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:36:29.709 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 18:36:29.709 [main] DEBUG io.r2dbc.pool.ConnectionPool - Obtaining new connection from the driver 18:36:29.710 [main] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT 1 POOL DISPOSED 18:36:29.728 [reactor-tcp-epoll-2] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SHOW TRANSACTION ISOLATION LEVEL 18:36:29.728 [reactor-tcp-epoll-2] DEBUG io.r2dbc.postgresql.QUERY - Executing query: SELECT oid, typname FROM pg_catalog.pg_type WHERE typname IN ('hstore') 18:36:29.739 [reactor-tcp-epoll-2] DEBUG io.r2dbc.postgresql.QUERY - Executing query: select application_name, state, query from postgres.pg_catalog.pg_stat_activity where application_name=$1 CONNECTIONS (1): {application_name=r2dbc-postgresql, state=active, query=select application_name, state, query from postgres.pg_catalog.pg_stat_activity where application_name=$1} ```Comments
The problem is that after pool.dispose(), new connections are still acquired, probably on another reactor sequence. Also it looks suspicious that 0.9.0-M2 version acquires new connection on each "select 1" query and all 10 pool connections are created every time for every query.
It also looks like dispose may also fail on 0.8.7-RELEASE, but not every time.
I didn't manage to fix this issue. I suspect there are actually two issues:
1) new pool connections created for every query (this only happens in 0.9.9-M2) 2) and pool.dispose does not wait for all pool connection to be created in case it is called at the moment new pool connections are created, neither it cancels new connections creation (this might be correct for both 0.8.7 and 0.9.0).