# Checking port 54599
# Found port 54599
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=54599 host=/var/folders/n8/pp_chp6x3jlfy1n94r6hdjv40000gn/T/7L_ElBfSJw
Log file: /Users/admin/pgsql/build/testrun/recovery/031_recovery_conflict/log/031_recovery_conflict_primary.log
[20:21:32.689](0.013s) # 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 13302
# 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/n8/pp_chp6x3jlfy1n94r6hdjv40000gn/T/7L_ElBfSJw -p 54599 --checkpoint fast --no-sync
# Backup finished
# Checking port 54600
# Found port 54600
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=54600 host=/var/folders/n8/pp_chp6x3jlfy1n94r6hdjv40000gn/T/7L_ElBfSJw
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 13423
Waiting for replication conn standby's replay_lsn to pass 0/343F248 on primary
done
Waiting for replication conn standby's replay_lsn to pass 0/343F308 on primary
done
[20:21:35.822](3.133s) # 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;
[20:21:35.823](0.001s) ok 1 - buffer pin conflict: cursor with conflicting pin established
Waiting for replication conn standby's replay_lsn to pass 0/3440000 on primary
done
[20:21:36.390](0.567s) ok 2 - buffer pin conflict: logfile contains terminated connection due to recovery conflict
[20:21:36.421](0.031s) ok 3 - buffer pin conflict: stats show conflict on standby
Waiting for replication conn standby's replay_lsn to pass 0/3447B48 on primary
done
[20:21:36.454](0.033s) # 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;
#         
[20:21:36.455](0.001s) ok 4 - snapshot conflict: cursor with conflicting snapshot established
Waiting for replication conn standby's replay_lsn to pass 0/3448098 on primary
done
[20:21:36.604](0.149s) ok 5 - snapshot conflict: logfile contains terminated connection due to recovery conflict
[20:21:36.645](0.041s) ok 6 - snapshot conflict: stats show conflict on standby
[20:21:36.645](0.000s) # issuing query via background psql: 
#         BEGIN;
#         LOCK TABLE test_recovery_conflict_table1 IN ACCESS SHARE MODE;
#         SELECT 1;
#         
[20:21:36.646](0.001s) ok 7 - lock conflict: conflicting lock acquired
Waiting for replication conn standby's replay_lsn to pass 0/3448828 on primary
done
[20:21:37.339](0.693s) ok 8 - lock conflict: logfile contains terminated connection due to recovery conflict
[20:21:37.375](0.036s) ok 9 - lock conflict: stats show conflict on standby
[20:21:37.375](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;
#         
[20:21:37.608](0.233s) ok 10 - tablespace conflict: cursor with conflicting temp file established
Waiting for replication conn standby's replay_lsn to pass 0/34488C8 on primary
done
[20:21:37.779](0.171s) ok 11 - tablespace conflict: logfile contains terminated connection due to recovery conflict
[20:21:37.809](0.029s) not ok 12 - tablespace conflict: stats show conflict on standby
[20:21:37.809](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.
[20:21:37.809](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 13617
Waiting for replication conn standby's replay_lsn to pass 0/344B618 on primary
done
[20:21:38.372](0.563s) ok 13 - startup deadlock: cursor holding conflicting pin, also waiting for lock, established
[20:21:38.385](0.012s) ok 14 - startup deadlock: lock acquisition is waiting
Waiting for replication conn standby's replay_lsn to pass 0/344B640 on primary
done
[20:21:38.529](0.145s) ok 15 - startup deadlock: logfile contains terminated connection due to recovery conflict
[20:21:38.561](0.031s) 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 13718
[20:21:39.010](0.449s) ok 17 - 5 recovery conflicts shown in pg_stat_database
Waiting for replication conn standby's replay_lsn to pass 0/3451D80 on primary
done
[20:21:39.935](0.925s) 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"
[20:21:40.395](0.460s) 1..18
[20:21:40.396](0.001s) # Looks like you failed 1 test of 18.