# Checking port 57591 # Found port 57591 Name: publisher Data directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/pgdata Backup directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/backup Archive directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/archives Connection string: port=57591 host=C:/Windows/TEMP/J5IoYew9wY Log file: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_publisher.log [03:11:33.206](0.122s) # initializing database system by copying initdb template # Running: robocopy /E /NJS /NJH /NFL /NDL /NP C:/cirrus/build/tmp_install/initdb-template C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/pgdata # Running: C:\cirrus\build\src/test\regress\pg_regress.exe --config-auth C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/pgdata --create-role repl_role ### Starting node "publisher" # Running: pg_ctl -w -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/pgdata -l C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_publisher.log -o --cluster-name=publisher start waiting for server to start.... done server started # Postmaster PID for node "publisher" is 5756 # Checking port 57592 # Found port 57592 Name: subscriber1 Data directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_subscriber1_data/pgdata Backup directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_subscriber1_data/backup Archive directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_subscriber1_data/archives Connection string: port=57592 host=C:/Windows/TEMP/J5IoYew9wY Log file: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_subscriber1.log [03:11:34.930](1.725s) # initializing database system by copying initdb template # Running: robocopy /E /NJS /NJH /NFL /NDL /NP C:/cirrus/build/tmp_install/initdb-template C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_subscriber1_data/pgdata # Running: C:\cirrus\build\src/test\regress\pg_regress.exe --config-auth C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_subscriber1_data/pgdata ### Starting node "subscriber1" # Running: pg_ctl -w -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_subscriber1_data/pgdata -l C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_subscriber1.log -o --cluster-name=subscriber1 start waiting for server to start.... done server started # Postmaster PID for node "subscriber1" is 5752 [03:11:37.166](2.235s) ok 1 - logical slot has failover false on the publisher [03:11:38.134](0.969s) ok 2 - logical slot has failover true on the publisher [03:11:39.044](0.909s) ok 3 - logical slot has failover false on the publisher [03:11:39.998](0.954s) ok 4 - logical slot has failover true on the publisher [03:11:40.361](0.363s) ok 5 - altering failover is not allowed for enabled subscription [03:11:40.593](0.232s) ok 6 - cannot sync slots on a non-standby server # Taking pg_basebackup backup from node "publisher" # Running: pg_basebackup -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/backup/backup -h C:/Windows/TEMP/J5IoYew9wY -p 57591 --checkpoint fast --no-sync # Backup finished # Checking port 57593 # Found port 57593 Name: standby1 Data directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata Backup directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/backup Archive directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/archives Connection string: port=57593 host=C:/Windows/TEMP/J5IoYew9wY Log file: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_standby1.log # Initializing node "standby1" from backup "backup" of node "publisher" ### Enabling streaming replication for node "standby1" ### Enabling WAL restore for node "standby1" ### Reloading node "publisher" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/pgdata reload server signaled (lsub2_slot,0/3000060) (sb1_slot,) ### Starting node "standby1" # Running: pg_ctl -w -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata -l C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_standby1.log -o --cluster-name=standby1 start waiting for server to start.... done server started # Postmaster PID for node "standby1" is 6884 Waiting for replication conn regress_mysub1's replay_lsn to pass 0/3000060 on publisher done [03:11:46.034](5.441s) ok 7 - last inactive time for slot lsub1_slot is valid on node publisher Waiting for replication conn standby1's replay_lsn to pass 0/3000060 on publisher done [03:11:46.644](0.610s) ok 8 - logical slots have synced as true on standby [03:11:46.920](0.276s) ok 9 - last inactive time for slot lsub1_slot is valid on node standby1 [03:11:47.040](0.120s) ok 10 - synchronized slot has got its own inactive_since [03:11:47.519](0.479s) ok 11 - synchronized slot has been dropped ### Reloading node "standby1" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata reload server signaled Waiting for replication conn standby1's replay_lsn to pass 0/40000F8 on publisher done [03:11:48.520](1.001s) ok 12 - synchronized slot has been invalidated ### Reloading node "standby1" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata reload server signaled #### Begin standard error psql::2: NOTICE: dropped replication slot "lsub1_slot" on publisher psql::3: NOTICE: created replication slot "lsub1_slot" on publisher #### End standard error Waiting for replication conn regress_mysub1's replay_lsn to pass 0/4000130 on publisher done [03:11:51.305](2.785s) ok 13 - last inactive time for slot lsub1_slot is valid on node publisher Waiting for replication conn standby1's replay_lsn to pass 0/4000168 on publisher done [03:11:52.384](1.079s) not ok 14 - logical slot is re-synced [03:11:52.385](0.000s) # Failed test 'logical slot is re-synced' # at C:/cirrus/src/test/recovery/t/040_standby_failover_slots_sync.pl line 311. [03:11:52.385](0.000s) # got: '' # expected: 't' ### Reloading node "publisher" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/pgdata reload server signaled ### Reloading node "standby1" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata reload server signaled [03:11:52.688](0.303s) not ok 15 - logical decoding is not allowed on synced slot [03:11:52.688](0.000s) # Failed test 'logical decoding is not allowed on synced slot' # at C:/cirrus/src/test/recovery/t/040_standby_failover_slots_sync.pl line 333. [03:11:52.876](0.188s) not ok 16 - synced slot on standby cannot be altered [03:11:52.876](0.001s) # Failed test 'synced slot on standby cannot be altered' # at C:/cirrus/src/test/recovery/t/040_standby_failover_slots_sync.pl line 342. [03:11:53.075](0.198s) not ok 17 - synced slot on standby cannot be dropped [03:11:53.075](0.000s) # Failed test 'synced slot on standby cannot be dropped' # at C:/cirrus/src/test/recovery/t/040_standby_failover_slots_sync.pl line 348. ### Reloading node "standby1" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata reload server signaled [03:11:53.301](0.226s) ok 18 - cannot sync slots if dbname is not specified in primary_conninfo ### Reloading node "standby1" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata reload server signaled # Taking pg_basebackup backup2 from node "standby1" # Running: pg_basebackup -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/backup/backup2 -h C:/Windows/TEMP/J5IoYew9wY -p 57593 --checkpoint fast --no-sync # Backup finished # Checking port 57594 # Found port 57594 Name: cascading_standby Data directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_cascading_standby_data/pgdata Backup directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_cascading_standby_data/backup Archive directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_cascading_standby_data/archives Connection string: port=57594 host=C:/Windows/TEMP/J5IoYew9wY Log file: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_cascading_standby.log # Initializing node "cascading_standby" from backup "backup2" of node "standby1" ### Enabling streaming replication for node "cascading_standby" ### Enabling WAL restore for node "cascading_standby" (cascading_sb_slot,) ### Starting node "cascading_standby" # Running: pg_ctl -w -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_cascading_standby_data/pgdata -l C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_cascading_standby.log -o --cluster-name=cascading_standby start waiting for server to start.... done server started # Postmaster PID for node "cascading_standby" is 4704 [03:12:06.030](12.730s) ok 19 - cannot sync slots to a cascading standby server ### Stopping node "cascading_standby" using mode fast # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_cascading_standby_data/pgdata -m fast stop waiting for server to shut down.... done server stopped # No postmaster PID for node "cascading_standby" Waiting for replication conn standby1's replay_lsn to pass 0/40002A8 on publisher done [03:12:10.254](4.224s) ok 20 - confirmed_flush_lsn of slot snap_test_slot synced to standby Waiting for replication conn standby1's replay_lsn to pass 0/4432538 on publisher done ### Stopping node "standby1" using mode fast # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata -m fast stop waiting for server to shut down.... done server stopped # No postmaster PID for node "standby1" ### Starting node "standby1" # Running: pg_ctl -w -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata -l C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_standby1.log -o --cluster-name=standby1 start waiting for server to start.... done server started # Postmaster PID for node "standby1" is 4552 ### Reloading node "standby1" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata reload server signaled ### Reloading node "standby1" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata reload server signaled ### Reloading node "standby1" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata reload server signaled ### Reloading node "standby1" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata reload server signaled Waiting for all subscriptions in "subscriber1" to synchronize data done [03:12:15.603](5.349s) ok 21 - confirmed_flush_lsn of slot lsub1_slot synced to standby (sb2_slot,) # Taking pg_basebackup backup3 from node "publisher" # Running: pg_basebackup -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/backup/backup3 -h C:/Windows/TEMP/J5IoYew9wY -p 57591 --checkpoint fast --no-sync # Backup finished # Checking port 57595 # Found port 57595 Name: standby2 Data directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby2_data/pgdata Backup directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby2_data/backup Archive directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby2_data/archives Connection string: port=57595 host=C:/Windows/TEMP/J5IoYew9wY Log file: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_standby2.log # Initializing node "standby2" from backup "backup3" of node "publisher" ### Enabling streaming replication for node "standby2" ### Enabling WAL restore for node "standby2" ### Starting node "standby2" # Running: pg_ctl -w -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby2_data/pgdata -l C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_standby2.log -o --cluster-name=standby2 start waiting for server to start.... done server started # Postmaster PID for node "standby2" is 6100 Waiting for replication conn standby2's replay_lsn to pass 0/6000060 on publisher done ### Reloading node "publisher" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/pgdata reload server signaled # Checking port 57596 # Found port 57596 Name: subscriber2 Data directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_subscriber2_data/pgdata Backup directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_subscriber2_data/backup Archive directory: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_subscriber2_data/archives Connection string: port=57596 host=C:/Windows/TEMP/J5IoYew9wY Log file: C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_subscriber2.log [03:12:28.428](12.825s) # initializing database system by copying initdb template # Running: robocopy /E /NJS /NJH /NFL /NDL /NP C:/cirrus/build/tmp_install/initdb-template C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_subscriber2_data/pgdata # Running: C:\cirrus\build\src/test\regress\pg_regress.exe --config-auth C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_subscriber2_data/pgdata ### Starting node "subscriber2" # Running: pg_ctl -w -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_subscriber2_data/pgdata -l C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_subscriber2.log -o --cluster-name=subscriber2 start waiting for server to start.... done server started # Postmaster PID for node "subscriber2" is 2684 #### Begin standard error psql::3: NOTICE: created replication slot "lsub2_slot" on publisher #### End standard error Waiting for all subscriptions in "subscriber2" to synchronize data done ### Stopping node "standby1" using mode fast # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata -m fast stop waiting for server to shut down.... done server stopped # No postmaster PID for node "standby1" Waiting for replication conn standby2's replay_lsn to pass 0/60008A8 on publisher done [03:12:32.934](4.506s) ok 22 - standby2 gets data from primary Waiting for replication conn regress_mysub2's replay_lsn to pass 0/60008A8 on publisher done [03:12:33.747](0.813s) ok 23 - subscriber2 gets data from primary [03:12:33.889](0.142s) ok 24 - subscriber1 doesn't get data from primary until standby1 acknowledges changes ### Starting node "standby1" # Running: pg_ctl -w -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata -l C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_standby1.log -o --cluster-name=standby1 start waiting for server to start.... done server started # Postmaster PID for node "standby1" is 6452 Waiting for replication conn standby1's replay_lsn to pass 0/60008A8 on publisher done [03:12:34.938](1.049s) ok 25 - standby1 gets data from primary Waiting for replication conn regress_mysub1's replay_lsn to pass 0/60008A8 on publisher done [03:12:36.548](1.610s) ok 26 - subscriber1 gets data from primary after standby1 acknowledges changes Waiting for replication conn regress_mysub1's replay_lsn to pass 0/6004968 on publisher done ### Stopping node "standby1" using mode fast # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata -m fast stop waiting for server to shut down.... done server stopped # No postmaster PID for node "standby1" ### Reloading node "publisher" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/pgdata reload server signaled ### Reloading node "publisher" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/pgdata reload server signaled [03:12:40.105](3.556s) ok 27 - subscriber1 doesn't get data as the sb1_slot doesn't catch up ### Reloading node "publisher" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/pgdata reload server signaled Waiting for replication conn regress_mysub1's replay_lsn to pass 0/6004F30 on publisher done [03:12:42.091](1.986s) ok 28 - subscriber1 gets data from primary after standby1 is removed from the standby_slot_names list ### Reloading node "publisher" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/pgdata reload server signaled ### Starting node "standby1" # Running: pg_ctl -w -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata -l C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_standby1.log -o --cluster-name=standby1 start waiting for server to start.... done server started # Postmaster PID for node "standby1" is 5320 Waiting for replication conn standby1's replay_lsn to pass 0/6004F68 on publisher done ### Promoting node "standby1" # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata -l C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\log/040_standby_failover_slots_sync_standby1.log promote waiting for server to promote.... done server promoted [03:12:44.313](2.222s) ok 29 - last inactive time for slot lsub1_slot is valid on node standby1 [03:12:44.429](0.116s) ok 30 - synchronized slot has got its own inactive_since on the new primary after promotion [03:12:44.763](0.334s) ok 31 - synced slot retained on the new primary Waiting for replication conn regress_mysub1's replay_lsn to pass 0/6007398 on standby1 done [03:12:45.933](1.169s) ok 32 - data replicated from the new primary [03:12:46.143](0.211s) ok 33 - data can be consumed using snap_test_slot [03:12:46.144](0.000s) 1..33 ### Stopping node "publisher" using mode immediate # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_publisher_data/pgdata -m immediate stop waiting for server to shut down.... done server stopped # No postmaster PID for node "publisher" ### Stopping node "subscriber1" using mode immediate # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_subscriber1_data/pgdata -m immediate stop waiting for server to shut down.... done server stopped # No postmaster PID for node "subscriber1" ### Stopping node "standby1" using mode immediate # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby1_data/pgdata -m immediate stop waiting for server to shut down.... done server stopped # No postmaster PID for node "standby1" ### Stopping node "standby2" using mode immediate # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_standby2_data/pgdata -m immediate stop waiting for server to shut down.... done server stopped # No postmaster PID for node "standby2" ### Stopping node "subscriber2" using mode immediate # Running: pg_ctl -D C:\cirrus\build/testrun/recovery/040_standby_failover_slots_sync\data/t_040_standby_failover_slots_sync_subscriber2_data/pgdata -m immediate stop waiting for server to shut down.... done server stopped # No postmaster PID for node "subscriber2" [03:12:46.943](0.800s) # Looks like you failed 4 tests of 33.