You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
I created a sample postgres cluster with backup into a S3 bucket. When trying to bootstrap another cluster in recovery mode with a target time using the backup in the s3 bucket, I get the following error logs.
{"level":"info","ts":"2023-11-05T19:52:35Z","msg":"barman-cloud-check-wal-archive checking the first wal","logging_pod":"cluster-example-pitr-1-full-recovery"}
{"level":"info","ts":"2023-11-05T19:52:36Z","msg":"Recovering from external cluster","logging_pod":"cluster-example-pitr-1-full-recovery","sourceName":"cluster-example"}
{"level":"info","ts":"2023-11-05T19:52:36Z","msg":"Target backup found","logging_pod":"cluster-example-pitr-1-full-recovery","backup":{"backup_name":"backup-20231105182000","backup_label":"'START WAL LOCATION: 0/3000028 (file 000000010000000000000003)\\nCHECKPOINT LOCATION: 0/3000F00\\nBACKUP METHOD: streamed\\nBACKUP FROM: standby\\nSTART TIME: 2023-11-05 18:20:00 UTC\\nLABEL: Barman backup cloud 20231105T182000\\nSTART TIMELINE: 1\\n'","begin_time":"Sun Nov 5 18:20:00 2023","end_time":"Sun Nov 5 18:20:04 2023","BeginTime":"2023-11-05T18:20:00Z","EndTime":"2023-11-05T18:20:04Z","begin_wal":"000000010000000000000003","end_wal":"000000010000000000000004","begin_xlog":"0/3000028","end_xlog":"0/4097950","systemid":"7298043307299090456","backup_id":"20231105T182000","error":"","timeline":1}}
{"level":"info","ts":"2023-11-05T19:52:37Z","msg":"Starting barman-cloud-restore","logging_pod":"cluster-example-pitr-1-full-recovery","options":["--endpoint-url","http://minio:9000","s3://db-backup/dev","cluster-example","20231105T182000","--cloud-provider","aws-s3","/var/lib/postgresql/data/pgdata"]}
{"level":"info","ts":"2023-11-05T19:52:37Z","msg":"Restore completed","logging_pod":"cluster-example-pitr-1-full-recovery"}
{"level":"info","ts":"2023-11-05T19:52:37Z","msg":"Creating new data directory","logging_pod":"cluster-example-pitr-1-full-recovery","pgdata":"/controller/recovery/datadir_3712382910","initDbOptions":["--username","postgres","-D","/controller/recovery/datadir_3712382910","--no-sync"]}
{"level":"info","ts":"2023-11-05T19:52:38Z","logger":"initdb","msg":"The files belonging to this database system will be owned by user \"postgres\".\nThis user must also own the server process.\n\nThe database cluster will be initialized with locale \"en_US.utf8\".\nThe default database encoding has accordingly been set to \"UTF8\".\nThe default text search configuration will be set to \"english\".\n\nData page checksums are disabled.\n\nfixing permissions on existing directory /controller/recovery/datadir_3712382910 ... ok\ncreating subdirectories ... ok\nselecting dynamic shared memory implementation ... posix\nselecting default max_connections ... 100\nselecting default shared_buffers ... 128MB\nselecting default time zone ... Etc/UTC\ncreating configuration files ... ok\nrunning bootstrap script ... ok\nperforming post-bootstrap initialization ... ok\n\nSync to disk skipped.\nThe data directory might become corrupt if the operating system crashes.\n\n\nSuccess. You can now start the database server using:\n\n pg_ctl -D /controller/recovery/datadir_3712382910 -l logfile start\n\n","pipe":"stdout","logging_pod":"cluster-example-pitr-1-full-recovery"}
{"level":"info","ts":"2023-11-05T19:52:38Z","logger":"initdb","msg":"initdb: warning: enabling \"trust\" authentication for local connections\ninitdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.\n","pipe":"stderr","logging_pod":"cluster-example-pitr-1-full-recovery"}
{"level":"info","ts":"2023-11-05T19:52:38Z","msg":"Installed configuration file","logging_pod":"cluster-example-pitr-1-full-recovery","pgdata":"/controller/recovery/datadir_3712382910","filename":"pg_hba.conf"}
{"level":"info","ts":"2023-11-05T19:52:38Z","msg":"Ignore minSyncReplicas to enforce self-healing","logging_pod":"cluster-example-pitr-1-full-recovery","syncReplicas":-1,"minSyncReplicas":0,"maxSyncReplicas":0}
{"level":"info","ts":"2023-11-05T19:52:38Z","msg":"Installed configuration file","logging_pod":"cluster-example-pitr-1-full-recovery","pgdata":"/controller/recovery/datadir_3712382910","filename":"custom.conf"}
{"level":"info","ts":"2023-11-05T19:52:38Z","msg":"Generated recovery configuration","logging_pod":"cluster-example-pitr-1-full-recovery","configuration":"recovery_target_action = promote\nrestore_command = 'barman-cloud-wal-restore --endpoint-url http://minio:9000 s3://db-backup/dev cluster-example --cloud-provider aws-s3 %f %p'\nrecovery_target_time = '2023-11-05 19:21:00.00000+01'\nrecovery_target_inclusive = true\n"}
{"level":"info","ts":"2023-11-05T19:52:38Z","msg":"enforcing parameters found in pg_controldata","logging_pod":"cluster-example-pitr-1-full-recovery","parameters":{"max_connections":"100","max_locks_per_transaction":"64","max_prepared_transactions":"0","max_wal_senders":"10","max_worker_processes":"32"}}
{"level":"info","ts":"2023-11-05T19:52:38Z","msg":"Starting up instance","logging_pod":"cluster-example-pitr-1-full-recovery","pgdata":"/var/lib/postgresql/data/pgdata","options":["start","-w","-D","/var/lib/postgresql/data/pgdata","-o","-c port=5432 -c unix_socket_directories=/controller/run","-t 40000000","-o","-c listen_addresses='127.0.0.1'"]}
{"level":"info","ts":"2023-11-05T19:52:38Z","logger":"pg_ctl","msg":"waiting for server to start....2023-11-05 19:52:38.577 UTC [37] LOG: redirecting log output to logging collector process","pipe":"stdout","logging_pod":"cluster-example-pitr-1-full-recovery"}
{"level":"info","ts":"2023-11-05T19:52:38Z","logger":"pg_ctl","msg":"2023-11-05 19:52:38.577 UTC [37] HINT: Future log output will appear in directory \"/controller/log\".","pipe":"stdout","logging_pod":"cluster-example-pitr-1-full-recovery"}
{"level":"info","ts":"2023-11-05T19:52:38Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:38.577 UTC","process_id":"37","session_id":"6547f286.25","session_line_num":"1","session_start_time":"2023-11-05 19:52:38 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"ending log output to stderr","hint":"Future log output will go to log destination \"csvlog\".","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:38Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:38.577 UTC","process_id":"37","session_id":"6547f286.25","session_line_num":"2","session_start_time":"2023-11-05 19:52:38 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"starting PostgreSQL 16.0 (Debian 16.0-1.pgdg110+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:38Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:38.577 UTC","process_id":"37","session_id":"6547f286.25","session_line_num":"3","session_start_time":"2023-11-05 19:52:38 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"listening on IPv4 address \"127.0.0.1\", port 5432","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:38Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:38.580 UTC","process_id":"37","session_id":"6547f286.25","session_line_num":"4","session_start_time":"2023-11-05 19:52:38 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"listening on Unix socket \"/controller/run/.s.PGSQL.5432\"","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:38Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:38.584 UTC","process_id":"41","session_id":"6547f286.29","session_line_num":"1","session_start_time":"2023-11-05 19:52:38 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"database system was interrupted while in recovery at log time 2023-11-05 18:15:38 UTC","hint":"If this has occurred more than once some data might be corrupted and you might need to choose an earlier recovery target.","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:38Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:38.584 UTC","process_id":"41","session_id":"6547f286.29","session_line_num":"2","session_start_time":"2023-11-05 19:52:38 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"creating missing WAL directory \"pg_wal/archive_status\"","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:39Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:39.084 UTC","process_id":"41","session_id":"6547f286.29","session_line_num":"3","session_start_time":"2023-11-05 19:52:38 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"starting point-in-time recovery to 2023-11-05 18:21:00+00","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:39Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:39.467 UTC","process_id":"41","session_id":"6547f286.29","session_line_num":"4","session_start_time":"2023-11-05 19:52:38 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"000000010000000000000003\" from archive","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:39Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:39.496 UTC","process_id":"41","session_id":"6547f286.29","session_line_num":"5","session_start_time":"2023-11-05 19:52:38 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"redo starts at 0/3000028","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:39Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:39.935 UTC","process_id":"41","session_id":"6547f286.29","session_line_num":"6","session_start_time":"2023-11-05 19:52:38 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"000000010000000000000004\" from archive","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:40Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:40.313 UTC","process_id":"41","session_id":"6547f286.29","session_line_num":"7","session_start_time":"2023-11-05 19:52:38 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"consistent recovery state reached at 0/4097950","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:40Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:40.313 UTC","process_id":"37","session_id":"6547f286.25","session_line_num":"5","session_start_time":"2023-11-05 19:52:38 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"database system is ready to accept read-only connections","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:40Z","logger":"pg_ctl","msg":". done","pipe":"stdout","logging_pod":"cluster-example-pitr-1-full-recovery"}
{"level":"info","ts":"2023-11-05T19:52:40Z","logger":"pg_ctl","msg":"server started","pipe":"stdout","logging_pod":"cluster-example-pitr-1-full-recovery"}
{"level":"info","ts":"2023-11-05T19:52:40Z","msg":"Checking if the server is still in recovery","logging_pod":"cluster-example-pitr-1-full-recovery","recovery":true}
{"level":"info","ts":"2023-11-05T19:52:40Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:40.636 UTC","process_id":"41","session_id":"6547f286.29","session_line_num":"8","session_start_time":"2023-11-05 19:52:38 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"redo done at 0/4097A38 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 1.13 s","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:40Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:40.636 UTC","process_id":"41","session_id":"6547f286.29","session_line_num":"9","session_start_time":"2023-11-05 19:52:38 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"last completed transaction was at log time 2023-11-05 18:16:16.014052+00","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:40Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:40.636 UTC","process_id":"41","session_id":"6547f286.29","session_line_num":"10","session_start_time":"2023-11-05 19:52:38 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"FATAL","sql_state_code":"XX000","message":"recovery ended before configured recovery target was reached","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:40Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:40.637 UTC","process_id":"37","session_id":"6547f286.25","session_line_num":"6","session_start_time":"2023-11-05 19:52:38 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"startup process (PID 41) exited with exit code 1","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:40Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:40.637 UTC","process_id":"37","session_id":"6547f286.25","session_line_num":"7","session_start_time":"2023-11-05 19:52:38 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"terminating any other active server processes","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:40Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:40.638 UTC","process_id":"37","session_id":"6547f286.25","session_line_num":"8","session_start_time":"2023-11-05 19:52:38 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"shutting down due to startup process failure","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:40Z","logger":"postgres","msg":"record","logging_pod":"cluster-example-pitr-1-full-recovery","record":{"log_time":"2023-11-05 19:52:40.642 UTC","process_id":"37","session_id":"6547f286.25","session_line_num":"9","session_start_time":"2023-11-05 19:52:38 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"database system is shut down","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2023-11-05T19:52:45Z","logger":"pg_ctl","msg":"pg_ctl: no server running\n","pipe":"stdout","logging_pod":"cluster-example-pitr-1-full-recovery"}
{"level":"info","ts":"2023-11-05T19:52:45Z","msg":"Error while deactivating instance","logging_pod":"cluster-example-pitr-1-full-recovery","err":"instance is not running"}
{"level":"info","ts":"2023-11-05T19:52:45Z","msg":"Exited log pipe","fileName":"/controller/log/postgres.csv","logging_pod":"cluster-example-pitr-1-full-recovery"}
{"level":"error","ts":"2023-11-05T19:52:45Z","msg":"Error while restoring a backup","logging_pod":"cluster-example-pitr-1-full-recovery","error":"while waiting for PostgreSQL to stop recovery mode: error while reading results of pg_is_in_recovery: failed to connect to `host=/controller/run user=postgres database=postgres`: dial error (dial unix /controller/run/.s.PGSQL.5432: connect: no such file or directory)","stacktrace":"github.com/cloudnative-pg/cloudnative-pg/pkg/management/log.(*logger).Error\n\tpkg/management/log/log.go:128\ngithub.com/cloudnative-pg/cloudnative-pg/pkg/management/log.Error\n\tpkg/management/log/log.go:166\ngithub.com/cloudnative-pg/cloudnative-pg/internal/cmd/manager/instance/restore.restoreSubCommand\n\tinternal/cmd/manager/instance/restore/cmd.go:89\ngithub.com/cloudnative-pg/cloudnative-pg/internal/cmd/manager/instance/restore.NewCmd.func2\n\tinternal/cmd/manager/instance/restore/cmd.go:60\ngithub.com/spf13/cobra.(*Command).execute\n\tpkg/mod/github.com/spf13/cobra@v1.7.0/command.go:940\ngithub.com/spf13/cobra.(*Command).ExecuteC\n\tpkg/mod/github.com/spf13/cobra@v1.7.0/command.go:1068\ngithub.com/spf13/cobra.(*Command).Execute\n\tpkg/mod/github.com/spf13/cobra@v1.7.0/command.go:992\nmain.main\n\tcmd/manager/main.go:64\nruntime.main\n\t/opt/hostedtoolcache/go/1.21.1/x64/src/runtime/proc.go:267"}
reacted with thumbs up emoji reacted with thumbs down emoji reacted with laugh emoji reacted with hooray emoji reacted with confused emoji reacted with heart emoji reacted with rocket emoji reacted with eyes emoji
-
Hello,
I created a sample postgres cluster with backup into a S3 bucket. When trying to bootstrap another cluster in recovery mode with a target time using the backup in the s3 bucket, I get the following error logs.
Here my cluster manifests:
Original cluster: cluster-example
And here the backup cluster: cluster-example-pitr
My wals
![image](https://private-user-images.githubusercontent.com/29024526/280552068-b679699b-67d3-4058-b40c-d13d429157fa.png?jwt=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJnaXRodWIuY29tIiwiYXVkIjoicmF3LmdpdGh1YnVzZXJjb250ZW50LmNvbSIsImtleSI6ImtleTUiLCJleHAiOjE3MjE0OTQ2ODgsIm5iZiI6MTcyMTQ5NDM4OCwicGF0aCI6Ii8yOTAyNDUyNi8yODA1NTIwNjgtYjY3OTY5OWItNjdkMy00MDU4LWI0MGMtZDEzZDQyOTE1N2ZhLnBuZz9YLUFtei1BbGdvcml0aG09QVdTNC1ITUFDLVNIQTI1NiZYLUFtei1DcmVkZW50aWFsPUFLSUFWQ09EWUxTQTUzUFFLNFpBJTJGMjAyNDA3MjAlMkZ1cy1lYXN0LTElMkZzMyUyRmF3czRfcmVxdWVzdCZYLUFtei1EYXRlPTIwMjQwNzIwVDE2NTMwOFomWC1BbXotRXhwaXJlcz0zMDAmWC1BbXotU2lnbmF0dXJlPWRkZmQ4M2I2OGIwOGYzZjkxMDM0NWQ4MDc5YzM2NGY1MGIzNDJkNzgwM2E0Yzc3ODVlMzEyZmZkNjljZDYxNTMmWC1BbXotU2lnbmVkSGVhZGVycz1ob3N0JmFjdG9yX2lkPTAma2V5X2lkPTAmcmVwb19pZD0wIn0.-TChviO1zXtH5aj_2j0T63PZhpjaEEd00s1U85JZqwA)
My base data
![image](https://private-user-images.githubusercontent.com/29024526/280552101-d392fc54-90e7-4e73-a0a8-3e7d547619d9.png?jwt=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJpc3MiOiJnaXRodWIuY29tIiwiYXVkIjoicmF3LmdpdGh1YnVzZXJjb250ZW50LmNvbSIsImtleSI6ImtleTUiLCJleHAiOjE3MjE0OTQ2ODgsIm5iZiI6MTcyMTQ5NDM4OCwicGF0aCI6Ii8yOTAyNDUyNi8yODA1NTIxMDEtZDM5MmZjNTQtOTBlNy00ZTczLWEwYTgtM2U3ZDU0NzYxOWQ5LnBuZz9YLUFtei1BbGdvcml0aG09QVdTNC1ITUFDLVNIQTI1NiZYLUFtei1DcmVkZW50aWFsPUFLSUFWQ09EWUxTQTUzUFFLNFpBJTJGMjAyNDA3MjAlMkZ1cy1lYXN0LTElMkZzMyUyRmF3czRfcmVxdWVzdCZYLUFtei1EYXRlPTIwMjQwNzIwVDE2NTMwOFomWC1BbXotRXhwaXJlcz0zMDAmWC1BbXotU2lnbmF0dXJlPTliODQwZGM4NWIwYzFlN2FjZDgwODkwMTkyNjc4NmNiMWEzZjNkYTIyY2I4ZDI1YjI0NjA2NzllYzg3ODA1MzUmWC1BbXotU2lnbmVkSGVhZGVycz1ob3N0JmFjdG9yX2lkPTAma2V5X2lkPTAmcmVwb19pZD0wIn0.QnKoYX0jPs7UCkzB3puPTxp-sZ76QD4KzQGXAiXl6ZQ)
Any idea?
Beta Was this translation helpful? Give feedback.
All reactions