# Checking port 54593
# Found port 54593
Name: primary
Data directory: /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_primary_data/pgdata
Backup directory: /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_primary_data/backup
Archive directory: /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_primary_data/archives
Connection string: port=54593 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/cx2f9CcQDX
Log file: /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/log/031_recovery_conflict_primary.log
[08:07:19.049](0.011s) # initializing database system by copying initdb template
# Running: cp -RPp /Users/admin/pgsql/build/tmp_install/initdb-template /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_primary_data/pgdata
# Running: /Users/admin/pgsql/build/src/test/regress/pg_regress --config-auth /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_primary_data/pgdata
### Starting node "primary"
# Running: pg_ctl -w -D /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_primary_data/pgdata -l /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/log/031_recovery_conflict_primary.log -o --cluster-name=primary start
waiting for server to start.... done
server started
# Postmaster PID for node "primary" is 14634
# Taking pg_basebackup my_backup from node "primary"
# Running: pg_basebackup -D /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_primary_data/backup/my_backup -h /var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/cx2f9CcQDX -p 54593 --checkpoint fast --no-sync
# Backup finished
# Checking port 54594
# Found port 54594
Name: standby
Data directory: /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_standby_data/pgdata
Backup directory: /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_standby_data/backup
Archive directory: /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_standby_data/archives
Connection string: port=54594 host=/var/folders/xc/tpssff9959345bnqq4c6tlww0000gn/T/cx2f9CcQDX
Log file: /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/log/031_recovery_conflict_standby.log
# Initializing node "standby" from backup "my_backup" of node "primary"
### Enabling streaming replication for node "standby"
### Starting node "standby"
# Running: pg_ctl -w -D /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_standby_data/pgdata -l /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/log/031_recovery_conflict_standby.log -o --cluster-name=standby start
waiting for server to start.... done
server started
# Postmaster PID for node "standby" is 14802
Waiting for replication conn standby's replay_lsn to pass 0/3437018 on primary
done
Waiting for replication conn standby's replay_lsn to pass 0/34370D8 on primary
done
[08:07:21.137](2.087s) # issuing query via background psql: 
#     BEGIN;
#     DECLARE test_recovery_conflict_cursor CURSOR FOR SELECT b FROM test_recovery_conflict_table1;
#     FETCH FORWARD FROM test_recovery_conflict_cursor;
[08:07:21.138](0.002s) ok 1 - buffer pin conflict: cursor with conflicting pin established
Waiting for replication conn standby's replay_lsn to pass 0/34370D8 on primary
done
[08:07:21.297](0.159s) ok 2 - buffer pin conflict: logfile contains terminated connection due to recovery conflict
[08:07:21.329](0.032s) ok 3 - buffer pin conflict: stats show conflict on standby
Waiting for replication conn standby's replay_lsn to pass 0/343F910 on primary
done
[08:07:21.435](0.106s) # issuing query via background psql: 
#         BEGIN;
#         DECLARE test_recovery_conflict_cursor CURSOR FOR SELECT b FROM test_recovery_conflict_table1;
#         FETCH FORWARD FROM test_recovery_conflict_cursor;
#         
[08:07:21.436](0.001s) ok 4 - snapshot conflict: cursor with conflicting snapshot established
Waiting for replication conn standby's replay_lsn to pass 0/3440000 on primary
done
[08:07:21.825](0.389s) ok 5 - snapshot conflict: logfile contains terminated connection due to recovery conflict
[08:07:21.891](0.066s) ok 6 - snapshot conflict: stats show conflict on standby
[08:07:21.891](0.000s) # issuing query via background psql: 
#         BEGIN;
#         LOCK TABLE test_recovery_conflict_table1 IN ACCESS SHARE MODE;
#         SELECT 1;
#         
[08:07:21.891](0.001s) ok 7 - lock conflict: conflicting lock acquired
Waiting for replication conn standby's replay_lsn to pass 0/34405F0 on primary
done
[08:07:22.068](0.177s) ok 8 - lock conflict: logfile contains terminated connection due to recovery conflict
[08:07:22.114](0.046s) ok 9 - lock conflict: stats show conflict on standby
[08:07:22.114](0.000s) # issuing query via background psql: 
#         BEGIN;
#         SET work_mem = '64kB';
#         DECLARE test_recovery_conflict_cursor CURSOR FOR
#           SELECT count(*) FROM generate_series(1,6000);
#         FETCH FORWARD FROM test_recovery_conflict_cursor;
#         
[08:07:22.116](0.002s) ok 10 - tablespace conflict: cursor with conflicting temp file established
Waiting for replication conn standby's replay_lsn to pass 0/3440690 on primary
done
[08:07:22.274](0.158s) ok 11 - tablespace conflict: logfile contains terminated connection due to recovery conflict
[08:07:22.304](0.030s) not ok 12 - tablespace conflict: stats show conflict on standby
[08:07:22.304](0.000s) #   Failed test 'tablespace conflict: stats show conflict on standby'
#   at /Users/admin/pgsql/src/test/recovery/t/031_recovery_conflict.pl line 332.
[08:07:22.304](0.000s) #          got: '0'
#     expected: '1'
### Restarting node "standby"
# Running: pg_ctl -w -D /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_standby_data/pgdata -l /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/log/031_recovery_conflict_standby.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "standby" is 15296
Waiting for replication conn standby's replay_lsn to pass 0/34433E0 on primary
done
[08:07:22.692](0.388s) ok 13 - startup deadlock: cursor holding conflicting pin, also waiting for lock, established
[08:07:22.708](0.016s) ok 14 - startup deadlock: lock acquisition is waiting
Waiting for replication conn standby's replay_lsn to pass 0/3443408 on primary
done
[08:07:22.863](0.154s) ok 15 - startup deadlock: logfile contains terminated connection due to recovery conflict
[08:07:22.898](0.036s) ok 16 - startup deadlock: stats show conflict on standby
### Restarting node "standby"
# Running: pg_ctl -w -D /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_standby_data/pgdata -l /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/log/031_recovery_conflict_standby.log restart
waiting for server to shut down.... done
server stopped
waiting for server to start.... done
server started
# Postmaster PID for node "standby" is 15372
[08:07:23.883](0.984s) ok 17 - 5 recovery conflicts shown in pg_stat_database
Waiting for replication conn standby's replay_lsn to pass 0/3449B48 on primary
done
[08:07:24.281](0.399s) ok 18 - database conflict: logfile contains terminated connection due to recovery conflict
### Stopping node "standby" using mode fast
# Running: pg_ctl -D /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_standby_data/pgdata -m fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "standby"
### Stopping node "primary" using mode fast
# Running: pg_ctl -D /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/data/t_031_recovery_conflict_primary_data/pgdata -m fast stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "primary"
[08:07:24.511](0.230s) 1..18
[08:07:24.512](0.001s) # Looks like you failed 1 test of 18.