# Checking port 56403
# Found port 56403
Name: primary
Data directory: /home/vagrant/postgresql/src/test/recovery_6/tmp_check/t_031_recovery_conflict_primary_data/pgdata
Backup directory: /home/vagrant/postgresql/src/test/recovery_6/tmp_check/t_031_recovery_conflict_primary_data/backup
Archive directory: /home/vagrant/postgresql/src/test/recovery_6/tmp_check/t_031_recovery_conflict_primary_data/archives
Connection string: port=56403 host=/tmp/uvBRDP3fhY
Log file: /home/vagrant/postgresql/src/test/recovery_6/tmp_check/log/031_recovery_conflict_primary.log
[13:25:35.168](0.096s) # initializing database system by copying initdb template
# Running: cp -RPp /home/vagrant/postgresql/tmp_install/initdb-template /home/vagrant/postgresql/src/test/recovery_6/tmp_check/t_031_recovery_conflict_primary_data/pgdata
# Running: /home/vagrant/postgresql/src/test/recovery_6/../../../src/test/regress/pg_regress --config-auth /home/vagrant/postgresql/src/test/recovery_6/tmp_check/t_031_recovery_conflict_primary_data/pgdata
### Starting node "primary"
# Running: pg_ctl -w -D /home/vagrant/postgresql/src/test/recovery_6/tmp_check/t_031_recovery_conflict_primary_data/pgdata -l /home/vagrant/postgresql/src/test/recovery_6/tmp_check/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 1523036
# Taking pg_basebackup my_backup from node "primary"
# Running: pg_basebackup -D /home/vagrant/postgresql/src/test/recovery_6/tmp_check/t_031_recovery_conflict_primary_data/backup/my_backup -h /tmp/uvBRDP3fhY -p 56403 --checkpoint fast --no-sync
# Backup finished
# Checking port 56404
# Found port 56404
Name: standby
Data directory: /home/vagrant/postgresql/src/test/recovery_6/tmp_check/t_031_recovery_conflict_standby_data/pgdata
Backup directory: /home/vagrant/postgresql/src/test/recovery_6/tmp_check/t_031_recovery_conflict_standby_data/backup
Archive directory: /home/vagrant/postgresql/src/test/recovery_6/tmp_check/t_031_recovery_conflict_standby_data/archives
Connection string: port=56404 host=/tmp/uvBRDP3fhY
Log file: /home/vagrant/postgresql/src/test/recovery_6/tmp_check/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 /home/vagrant/postgresql/src/test/recovery_6/tmp_check/t_031_recovery_conflict_standby_data/pgdata -l /home/vagrant/postgresql/src/test/recovery_6/tmp_check/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 1523183
Waiting for replication conn standby's replay_lsn to pass 0/342BEE0 on primary
done
Waiting for replication conn standby's replay_lsn to pass 0/342BFA0 on primary
done
[13:27:00.694](85.526s) # 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;
[13:27:00.697](0.003s) ok 1 - buffer pin conflict: cursor with conflicting pin established
Waiting for replication conn standby's replay_lsn to pass 0/342BFA0 on primary
done
[13:27:01.584](0.887s) ok 2 - buffer pin conflict: logfile contains terminated connection due to recovery conflict
[13:27:01.999](0.414s) ok 3 - buffer pin conflict: stats show conflict on standby
Waiting for replication conn standby's replay_lsn to pass 0/3434828 on primary
done
[13:27:02.993](0.994s) # 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;
#         
[13:27:02.996](0.003s) ok 4 - snapshot conflict: cursor with conflicting snapshot established
Waiting for replication conn standby's replay_lsn to pass 0/3434D98 on primary
done
[13:27:05.850](2.854s) ok 5 - snapshot conflict: logfile contains terminated connection due to recovery conflict
[13:27:05.873](0.023s) ok 6 - snapshot conflict: stats show conflict on standby
[13:27:05.874](0.000s) # issuing query via background psql: 
#         BEGIN;
#         LOCK TABLE test_recovery_conflict_table1 IN ACCESS SHARE MODE;
#         SELECT 1;
#         
[13:27:05.875](0.001s) ok 7 - lock conflict: conflicting lock acquired
Waiting for replication conn standby's replay_lsn to pass 0/3435558 on primary
done
[13:27:08.199](2.324s) ok 8 - lock conflict: logfile contains terminated connection due to recovery conflict
[13:27:08.242](0.043s) ok 9 - lock conflict: stats show conflict on standby
[13:27:08.243](0.001s) # 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;
#         
[13:27:08.252](0.009s) ok 10 - tablespace conflict: cursor with conflicting temp file established
Waiting for replication conn standby's replay_lsn to pass 0/34355F8 on primary
done
[13:27:12.062](3.810s) ok 11 - tablespace conflict: logfile contains terminated connection due to recovery conflict
[13:27:12.085](0.023s) ok 12 - tablespace conflict: stats show conflict on standby
### Restarting node "standby"
# Running: pg_ctl -w -D /home/vagrant/postgresql/src/test/recovery_6/tmp_check/t_031_recovery_conflict_standby_data/pgdata -l /home/vagrant/postgresql/src/test/recovery_6/tmp_check/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 1524100
Waiting for replication conn standby's replay_lsn to pass 0/3438398 on primary
done
[13:27:36.717](24.632s) ok 13 - startup deadlock: cursor holding conflicting pin, also waiting for lock, established
[13:27:39.034](2.317s) ok 14 - startup deadlock: lock acquisition is waiting
Waiting for replication conn standby's replay_lsn to pass 0/343E6D0 on primary
done
timed out waiting for match: (?^:User transaction caused buffer deadlock with recovery.) at t/031_recovery_conflict.pl line 318.
# Postmaster PID for node "primary" is 1523036
### Stopping node "primary" using mode immediate
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_6/tmp_check/t_031_recovery_conflict_primary_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "primary"
# Postmaster PID for node "standby" is 1524100
### Stopping node "standby" using mode immediate
# Running: pg_ctl -D /home/vagrant/postgresql/src/test/recovery_6/tmp_check/t_031_recovery_conflict_standby_data/pgdata -m immediate stop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "standby"
[13:30:44.545](185.511s) # Tests were run but no plan was declared and done_testing() was not seen.
[13:30:44.545](0.001s) # Looks like your test exited with 255 just after 14.
