# Checking port 50358 # Found port 50358 Name: publisher Data directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_publisher_data/pgdata Backup directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_publisher_data/backup Archive directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_publisher_data/archives Connection string: port=50358 host=/var/folders/n8/pp_chp6x3jlfy1n94r6hdjv40000gn/T/bnrD19abq0 Log file: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/log/040_standby_failover_slots_sync_publisher.log [07:06:46.972](0.120s) # initializing database system by copying initdb template # Running: cp -RPp /Users/admin/pgsql/build/tmp_install/initdb-template /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_publisher_data/pgdata # Running: /Users/admin/pgsql/build/src/test/regress/pg_regress --config-auth /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_publisher_data/pgdata ### Starting node "publisher" # Running: pg_ctl -w -D /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_publisher_data/pgdata -l /Users/admin/pgsql/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 17327 # Checking port 50359 # Found port 50359 Name: subscriber1 Data directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_subscriber1_data/pgdata Backup directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_subscriber1_data/backup Archive directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_subscriber1_data/archives Connection string: port=50359 host=/var/folders/n8/pp_chp6x3jlfy1n94r6hdjv40000gn/T/bnrD19abq0 Log file: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/log/040_standby_failover_slots_sync_subscriber1.log [07:06:47.487](0.515s) # initializing database system by copying initdb template # Running: cp -RPp /Users/admin/pgsql/build/tmp_install/initdb-template /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_subscriber1_data/pgdata # Running: /Users/admin/pgsql/build/src/test/regress/pg_regress --config-auth /Users/admin/pgsql/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 /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_subscriber1_data/pgdata -l /Users/admin/pgsql/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 17411 [07:06:47.967](0.480s) ok 1 - logical slot has failover false on the publisher [07:06:48.026](0.059s) ok 2 - logical slot has failover true on the publisher [07:06:48.069](0.043s) ok 3 - logical slot has failover false on the publisher [07:06:48.105](0.036s) ok 4 - logical slot has failover true on the publisher [07:06:48.141](0.035s) ok 5 - altering failover is not allowed for enabled subscription [07:06:48.177](0.037s) ok 6 - cannot sync slots on a non-standby server (sb1_slot,) (sb2_slot,) # Taking pg_basebackup backup from node "publisher" # Running: pg_basebackup -D /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_publisher_data/backup/backup -h /var/folders/n8/pp_chp6x3jlfy1n94r6hdjv40000gn/T/bnrD19abq0 -p 50358 --checkpoint fast --no-sync # Backup finished # Checking port 50360 # Found port 50360 Name: standby1 Data directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_standby1_data/pgdata Backup directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_standby1_data/backup Archive directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_standby1_data/archives Connection string: port=50360 host=/var/folders/n8/pp_chp6x3jlfy1n94r6hdjv40000gn/T/bnrD19abq0 Log file: /Users/admin/pgsql/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" ### Starting node "standby1" # Running: pg_ctl -w -D /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_standby1_data/pgdata -l /Users/admin/pgsql/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 17611 Waiting for replication conn standby1's replay_lsn to pass 0/3000000 on publisher done (save_xmin,0/3000060) # Checking port 50361 # Found port 50361 Name: standby2 Data directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_standby2_data/pgdata Backup directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_standby2_data/backup Archive directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_standby2_data/archives Connection string: port=50361 host=/var/folders/n8/pp_chp6x3jlfy1n94r6hdjv40000gn/T/bnrD19abq0 Log file: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/log/040_standby_failover_slots_sync_standby2.log # Initializing node "standby2" from backup "backup" of node "publisher" ### Enabling streaming replication for node "standby2" ### Enabling WAL restore for node "standby2" ### Starting node "standby2" # Running: pg_ctl -w -D /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_standby2_data/pgdata -l /Users/admin/pgsql/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 17703 Waiting for replication conn standby2's replay_lsn to pass 0/3000060 on publisher done ### Reloading node "publisher" # Running: pg_ctl -D /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_publisher_data/pgdata reload server signaled # Checking port 50362 # Found port 50362 Name: subscriber2 Data directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_subscriber2_data/pgdata Backup directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_subscriber2_data/backup Archive directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_subscriber2_data/archives Connection string: port=50362 host=/var/folders/n8/pp_chp6x3jlfy1n94r6hdjv40000gn/T/bnrD19abq0 Log file: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/log/040_standby_failover_slots_sync_subscriber2.log [07:06:50.864](2.686s) # initializing database system by copying initdb template # Running: cp -RPp /Users/admin/pgsql/build/tmp_install/initdb-template /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_subscriber2_data/pgdata # Running: /Users/admin/pgsql/build/src/test/regress/pg_regress --config-auth /Users/admin/pgsql/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 /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_subscriber2_data/pgdata -l /Users/admin/pgsql/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 17767 #### Begin standard error psql::3: NOTICE: created replication slot "lsub2_slot" on publisher #### End standard error ### Stopping node "standby1" using mode fast # Running: pg_ctl -D /Users/admin/pgsql/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/3025520 on publisher done [07:06:51.377](0.513s) ok 7 - standby2 gets data from primary Waiting for replication conn regress_mysub2's replay_lsn to pass 0/3025520 on publisher done [07:06:51.427](0.050s) ok 8 - subscriber2 gets data from primary [07:06:51.440](0.013s) ok 9 - subscriber1 doesn't get data from primary until standby1 acknowledges changes ### Starting node "standby1" # Running: pg_ctl -w -D /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_standby1_data/pgdata -l /Users/admin/pgsql/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 17895 Waiting for replication conn standby1's replay_lsn to pass 0/3025520 on publisher done [07:06:51.922](0.482s) ok 10 - standby1 gets data from primary Waiting for replication conn regress_mysub1's replay_lsn to pass 0/3025520 on publisher done [07:06:52.015](0.093s) ok 11 - subscriber1 gets data from primary after standby1 acknowledges changes Waiting for replication conn regress_mysub1's replay_lsn to pass 0/3025BC8 on publisher done ### Stopping node "standby1" using mode fast # Running: pg_ctl -D /Users/admin/pgsql/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" [07:06:52.268](0.252s) # issuing query via background psql: SELECT pg_backend_pid() [07:06:52.391](0.123s) ok 12 - cancelling pg_logical_slot_get_changes command [07:06:52.461](0.070s) ok 13 - subscriber1 doesn't get data as the sb1_slot doesn't catch up ### Reloading node "publisher" # Running: pg_ctl -D /Users/admin/pgsql/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/30261A8 on publisher done [07:06:52.650](0.188s) ok 14 - subscriber1 gets data from primary after standby1 is removed from the standby_slot_names list ### Reloading node "publisher" # Running: pg_ctl -D /Users/admin/pgsql/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 /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_publisher_data/pgdata reload server signaled (lsub3_slot,0/30261E0) ### Starting node "standby1" # Running: pg_ctl -w -D /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_standby1_data/pgdata -l /Users/admin/pgsql/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 18250 Waiting for replication conn standby1's replay_lsn to pass 0/30261E0 on publisher done [07:06:52.944](0.295s) ok 15 - logical slots have synced as true on standby [07:06:53.064](0.120s) ok 16 - synchronized slot has been dropped ### Reloading node "standby1" # Running: pg_ctl -D /Users/admin/pgsql/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 [07:06:53.520](0.455s) ok 17 - synchronized slot has been invalidated ### Reloading node "standby1" # Running: pg_ctl -D /Users/admin/pgsql/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 Waiting for replication conn standby1's replay_lsn to pass 0/4000130 on publisher done [07:06:54.221](0.701s) not ok 18 - logical slot is re-synced [07:06:54.222](0.001s) # Failed test 'logical slot is re-synced' # at /Users/admin/pgsql/src/test/recovery/t/040_standby_failover_slots_sync.pl line 459. [07:06:54.222](0.000s) # got: '' # expected: 't' ### Reloading node "publisher" # Running: pg_ctl -D /Users/admin/pgsql/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 /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_standby1_data/pgdata reload server signaled [07:06:54.259](0.037s) not ok 19 - logical decoding is not allowed on synced slot [07:06:54.259](0.000s) # Failed test 'logical decoding is not allowed on synced slot' # at /Users/admin/pgsql/src/test/recovery/t/040_standby_failover_slots_sync.pl line 481. [07:06:54.271](0.012s) not ok 20 - synced slot on standby cannot be altered [07:06:54.271](0.000s) # Failed test 'synced slot on standby cannot be altered' # at /Users/admin/pgsql/src/test/recovery/t/040_standby_failover_slots_sync.pl line 490. [07:06:54.282](0.011s) not ok 21 - synced slot on standby cannot be dropped [07:06:54.282](0.000s) # Failed test 'synced slot on standby cannot be dropped' # at /Users/admin/pgsql/src/test/recovery/t/040_standby_failover_slots_sync.pl line 496. ### Reloading node "standby1" # Running: pg_ctl -D /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_standby1_data/pgdata reload server signaled [07:06:54.311](0.029s) ok 22 - cannot sync slots if dbname is not specified in primary_conninfo ### Reloading node "standby1" # Running: pg_ctl -D /Users/admin/pgsql/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 /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_standby1_data/backup/backup2 -h /var/folders/n8/pp_chp6x3jlfy1n94r6hdjv40000gn/T/bnrD19abq0 -p 50360 --checkpoint fast --no-sync # Backup finished # Checking port 50363 # Found port 50363 Name: cascading_standby Data directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_cascading_standby_data/pgdata Backup directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_cascading_standby_data/backup Archive directory: /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_cascading_standby_data/archives Connection string: port=50363 host=/var/folders/n8/pp_chp6x3jlfy1n94r6hdjv40000gn/T/bnrD19abq0 Log file: /Users/admin/pgsql/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 /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_cascading_standby_data/pgdata -l /Users/admin/pgsql/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 18783 [07:06:55.301](0.989s) ok 23 - cannot sync slots to a cascading standby server ### Stopping node "cascading_standby" using mode fast # Running: pg_ctl -D /Users/admin/pgsql/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" ### Reloading node "standby1" # Running: pg_ctl -D /Users/admin/pgsql/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 /Users/admin/pgsql/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 /Users/admin/pgsql/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 regress_mysub1's replay_lsn to pass 0/4004978 on publisher done [07:11:09.000](253.700s) # poll_query_until timed out executing this query: # SELECT '0/40000F8' = restart_lsn AND '0/4004978' = confirmed_flush_lsn from pg_replication_slots WHERE slot_name = 'lsub1_slot'; # expecting this output: # t # last actual query output: # # with stderr: [07:11:09.003](0.003s) not ok 24 - restart_lsn and confirmed_flush_lsn of slot lsub1_slot synced to standby [07:11:09.004](0.001s) # Failed test 'restart_lsn and confirmed_flush_lsn of slot lsub1_slot synced to standby' # at /Users/admin/pgsql/src/test/recovery/t/040_standby_failover_slots_sync.pl line 626. ### Promoting node "standby1" # Running: pg_ctl -D /Users/admin/pgsql/build/testrun/recovery/040_standby_failover_slots_sync/data/t_040_standby_failover_slots_sync_standby1_data/pgdata -l /Users/admin/pgsql/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 [07:11:09.152](0.149s) not ok 25 - synced slot retained on the new primary [07:11:09.152](0.000s) # Failed test 'synced slot retained on the new primary' # at /Users/admin/pgsql/src/test/recovery/t/040_standby_failover_slots_sync.pl line 645. [07:11:09.153](0.000s) # got: '' # expected: 'lsub1_slot' Waiting for replication conn regress_mysub1's replay_lsn to pass 0/40093B0 on standby1 [07:15:24.485](255.333s) # poll_query_until timed out executing this query: # SELECT '0/40093B0' <= replay_lsn AND state = 'streaming' # FROM pg_catalog.pg_stat_replication # WHERE application_name IN ('regress_mysub1', 'walreceiver') # expecting this output: # t # last actual query output: # # with stderr: timed out waiting for catchup at /Users/admin/pgsql/src/test/recovery/t/040_standby_failover_slots_sync.pl line 653. # Postmaster PID for node "publisher" is 17327 ### Stopping node "publisher" using mode immediate # Running: pg_ctl -D /Users/admin/pgsql/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" # Postmaster PID for node "subscriber1" is 17411 ### Stopping node "subscriber1" using mode immediate # Running: pg_ctl -D /Users/admin/pgsql/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" # Postmaster PID for node "standby1" is 18250 ### Stopping node "standby1" using mode immediate # Running: pg_ctl -D /Users/admin/pgsql/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" # Postmaster PID for node "standby2" is 17703 ### Stopping node "standby2" using mode immediate # Running: pg_ctl -D /Users/admin/pgsql/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" # Postmaster PID for node "subscriber2" is 17767 ### Stopping node "subscriber2" using mode immediate # Running: pg_ctl -D /Users/admin/pgsql/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" # No postmaster PID for node "cascading_standby" [07:15:25.147](0.661s) # Tests were run but no plan was declared and done_testing() was not seen. [07:15:25.147](0.000s) # Looks like your test exited with 60 just after 25.