Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Clone attempt failed, extractOne: Interpret failed: Interpret: copy failed #2617

Open
jonathon2nd opened this issue Apr 22, 2024 · 4 comments
Labels
question spilo Issue more related to Spilo

Comments

@jonathon2nd
Copy link

  • Which image of the operator are you using? registry.opensource.zalan.do/acid/postgres-operator:v1.11.0
  • Where do you run it - cloud or metal? Kubernetes or OpenShift? OVH K8s v1.27.8
  • Are you running Postgres Operator in production? yes
  • Type of issue? Bug report

Clone fails when attempting to use s3.

Commented on this issue too: #773

pod logs

2024-04-22 20:19:56,908 - bootstrapping - INFO - Figuring out my environment (Google? AWS? Openstack? Local?)
2024-04-22T20:19:58.267611130Z 2024-04-22 20:19:58,267 - bootstrapping - INFO - Looks like you are running openstack
2024-04-22T20:19:58.285019639Z 2024-04-22 20:19:58,284 - bootstrapping - INFO - Configuring certificate
2024-04-22T20:19:58.285033907Z 2024-04-22 20:19:58,284 - bootstrapping - INFO - Generating ssl self-signed certificate
2024-04-22T20:19:58.377530363Z 2024-04-22 20:19:58,377 - bootstrapping - INFO - Configuring patroni
2024-04-22T20:19:58.384358614Z 2024-04-22 20:19:58,384 - bootstrapping - INFO - Writing to file /run/postgres.yml
2024-04-22T20:19:58.384599392Z 2024-04-22 20:19:58,384 - bootstrapping - INFO - Configuring bootstrap
2024-04-22T20:19:58.385063043Z 2024-04-22 20:19:58,384 - bootstrapping - WARNING - Invalid WALE_S3_ENDPOINT, the format is protocol+convention://hostname:port, but got https://s3.ca-central-1.wasabisys.com
2024-04-22T20:19:58.385112619Z 2024-04-22 20:19:58,385 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-test2/WALE_S3_PREFIX
2024-04-22 20:19:58,385 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-test2/WALG_S3_PREFIX
2024-04-22T20:19:58.385344610Z 2024-04-22 20:19:58,385 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-test2/AWS_ACCESS_KEY_ID
2024-04-22T20:19:58.385447751Z 2024-04-22 20:19:58,385 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-test2/AWS_SECRET_ACCESS_KEY
2024-04-22T20:19:58.385556331Z 2024-04-22 20:19:58,385 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-test2/WALE_S3_ENDPOINT
2024-04-22T20:19:58.385652137Z 2024-04-22 20:19:58,385 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-test2/AWS_ENDPOINT
2024-04-22T20:19:58.385757301Z 2024-04-22 20:19:58,385 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-test2/WALE_DISABLE_S3_SSE
2024-04-22T20:19:58.385864439Z 2024-04-22 20:19:58,385 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-test2/WALG_DISABLE_S3_SSE
2024-04-22T20:19:58.385971467Z 2024-04-22 20:19:58,385 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-test2/AWS_S3_FORCE_PATH_STYLE
2024-04-22T20:19:58.386073215Z 2024-04-22 20:19:58,386 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-test2/USE_WALG_BACKUP
2024-04-22T20:19:58.386172347Z 2024-04-22 20:19:58,386 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-test2/USE_WALG_RESTORE
2024-04-22T20:19:58.386273153Z 2024-04-22 20:19:58,386 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-test2/WALE_LOG_DESTINATION
2024-04-22T20:19:58.386451038Z 2024-04-22 20:19:58,386 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env-clone-acid-test2/TMPDIR
2024-04-22T20:19:58.386487910Z 2024-04-22 20:19:58,386 - bootstrapping - INFO - Configuring log
2024-04-22T20:19:58.386511957Z 2024-04-22 20:19:58,386 - bootstrapping - INFO - Configuring pgbouncer
2024-04-22T20:19:58.386547086Z 2
024-04-22 20:19:58,386 - bootstrapping - INFO - No PGBOUNCER_CONFIGURATION was specified, skipping
2024-04-22T20:19:58.386564339Z 2024-04-22 20:19:58,386 - bootstrapping - INFO - Configuring pgqd
2024-04-22T20:19:58.386656668Z 2024-04-22 20:19:58,386 - bootstrapping - INFO - Configuring crontab
2024-04-22T20:19:58.386767413Z 2024-04-22 20:19:58,386 - bootstrapping - INFO - Skipping creation of renice cron job due to lack of SYS_NICE capability
2024-04-22T20:19:58.390828670Z 2024-04-22 20:19:58,390 - bootstrapping - INFO - Configuring pam-oauth2
2024-04-22T20:19:58.390979533Z 2024-04-22 20:19:58,390 - bootstrapping - INFO - Writing to file /etc/pam.d/postgresql
2024-04-22T20:19:58.391017327Z 2024-04-22 20:19:58,390 - bootstrapping - INFO - Configuring standby-cluster
2024-04-22T20:19:58.391037686Z 2024-04-22 20:19:58,391 - bootstrapping - INFO - Configuring wal-e
2024-04-22T20:19:58.391209661Z 2024-04-22 20:19:58,391 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALE_S3_PREFIX
2024-04-22T20:19:58.391319323Z 2024-04-22 20:19:58,391 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALG_S3_PREFIX
2024-04-22T20:19:58.391433505Z 2024-04-22 20:19:58,391 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_ACCESS_KEY_ID
2024-04-22T20:19:58.391535312Z 2024-04-22 20:19:58,391 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_SECRET_ACCESS_KEY
2024-04-22T20:19:58.391636679Z 2024-04-22 20:19:58,391 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALE_S3_ENDPOINT
2024-04-22T20:19:58.391740721Z 2024-04-22 20:19:58,391 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_ENDPOINT
2024-04-22T20:19:58.391841747Z 2024-04-22 20:19:58,391 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_REGION
2024-04-22T20:19:58.391942333Z 2024-04-22 20:19:58,391 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALE_DISABLE_S3_SSE
2024-04-22T20:19:58.392039532Z 2024-04-22 20:19:58,391 - bootstrapping - INFO - Writing to file /run/etc/w
al-e.d/env/WALG_DISABLE_S3_SSE
2024-04-22T20:19:58.392139426Z 2024-04-22 20:19:58,392 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/AWS_S3_FORCE_PATH_STYLE
2024-04-22T20:19:58.392240652Z 2024-04-22 20:19:58,392 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALG_DOWNLOAD_CONCURRENCY
2024-04-22T20:19:58.392339083Z 2024-04-22 20:19:58,392 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALG_UPLOAD_CONCURRENCY
2024-04-22T20:19:58.392466461Z 2024-04-22 20:19:58,392 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/USE_WALG_BACKUP
2024-04-22T20:19:58.392566154Z 2024-04-22 20:19:58,392 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/USE_WALG_RESTORE
2024-04-22T20:19:58.392717468Z 2024-04-22 20:19:58,392 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/WALE_LOG_DESTINATION
2024-04-22T20:19:58.392790089Z 2024-04-22 20:19:58,392 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/PGPORT
2024-04-22T20:19:58.392892729Z 2024-04-22 20:19:58,392 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/BACKUP_NUM_TO_RETAIN
2024-04-22T20:19:58.392990720Z 2024-04-22 20:19:58,392 - bootstrapping - INFO - Writing to file /run/etc/wal-e.d/env/TMPDIR
2024-04-22T20:19:59.718264187Z 2024-04-22 20:19:59,718 WARNING: Kubernetes RBAC doesn't allow GET access to the 'kubernetes' endpoint in the 'default' namespace. Disabling 'bypass_api_service'.
2024-04-22T20:19:59.773803810Z 2024-04-22 20:19:59,773 INFO: No PostgreSQL configuration items changed, nothing to reload.
2024-04-22T20:19:59.866170746Z 2024-04-22 20:19:59,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:19:59.866179433Z 2024-04-22 20:19:59,865 INFO: trying to bootstrap a new cluster
2024-04-22T20:19:59.866181727Z 2024-04-22 20:19:59,865 INFO: Running custom bootstrap script: envdir "/run/etc/wal-e.d/env-clone-acid-test2" python3 /scripts/clone_with_wale.py --recovery-target-time="2024-04-22T18:04:39+00:00"
2024-04-22T20:19:59.901592128Z 2024-04-22 20:19:59,901 INFO: Try
ing s3://test-postgres-operator-k8s/spilo/test-postgres2-acid-test2/wal/14/ for clone
2024-04-22T20:20:00.651738290Z 2024-04-22 20:20:00,651 INFO: cloning cluster acid-test-test using wal-g backup-fetch /home/postgres/pgdata/pgroot/data base_00000034000000AB00000052
2024-04-22T20:20:00.669425299Z INFO: 2024/04/22 20:20:00.669350 Selecting the backup with name base_00000034000000AB00000052...
2024-04-22 20:20:09,797 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:20:09.818711572Z 2024-04-22 20:20:09,797 INFO: not healthy enough for leader race
2024-04-22 20:20:09,916 INFO: bootstrap in progress
2024-04-22 20:20:19,796 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:20:19.797648303Z 2024-04-22 20:20:19,797 INFO: not healthy enough for leader race
2024-04-22T20:20:19.797654816Z 2024-04-22 20:20:19,797 INFO: bootstrap in progress
2024-04-22 20:20:29,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:20:29.775906396Z 2024-04-22 20:20:29,775 INFO: not healthy enough for leader race
2024-04-22T20:20:29.775911888Z 2024-04-22 20:20:29,775 INFO: bootstrap in progress
2024-04-22 20:20:39,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:20:39.777952796Z 2024-04-22 20:20:39,775 INFO: not healthy enough for leader race
2024-04-22T20:20:39.777978906Z 2024-04-22 20:20:39,775 INFO: bootstrap in progress
INFO: 2024/04/22 20:20:41.471766 Finished extraction of part_005.tar.lz4
INFO: 2024/04/22 20:20:43.796580 Finished extraction of part_002.tar.lz4
INFO: 2024/04/22 20:20:44.226825 Finished extraction of part_009.tar.lz4
2024-04-22 20:20:49,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:20:49.775943626Z 2024-04-22 20:20:49,775 INFO: not healthy enough for leader race
2024-04-22T20:20:49.775950410Z 2024-04-22 20:20:49,775 INFO: bootstrap in progress
2024-04-22 20:20:59,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:20:59.775873147Z 2024-04-22 20:20:59,775 INFO: not healthy enough for leader race
2024-04-22T20:20:59.775881222Z 2024-04-22 20:20:59,775 INFO: bootstrap in progress
INFO: 2024/04/22 20:21:05.689755 Finished extraction of part_010.tar.lz4
2024-04-22 20:21:09,802 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:21:09.802996995Z 2024-04-22 20:21:09,802 INFO: not healthy enough for leader race
2024-04-22T20:21:09.803006514Z 2024-04-22 20:21:09,802 INFO: bootstrap in progress
INFO: 2024/04/22 20:21:11.718804 Finished extraction of part_003.tar.lz4
INFO: 2024/04/22 20:21:13.108772 Finished extraction of part_007.tar.lz4
INFO: 2024/04/22 20:21:13.805118 Finished extraction of part_015.tar.lz4
2024-04-22T20:21:13.805775503Z ERROR: 2024/04/22 20:21:13.805136 Extraction error in part_015.tar.lz4: extractOne: Interpret failed: Interpret: copy failed: read tcp 10.2.7.11:57246->38.143.146.101:443: read: connection reset by peer
INFO: 2024/04/22 20:21:17.720611 Finished extraction of part_006.tar.lz4
INFO: 2024/04/22 20:21:18.464991 Finished extraction of part_008.tar.lz4
INFO: 2024/04/22 20:21:18.933158 Finished extraction of part_001.tar.lz4
2024-04-22 20:21:19,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:21:19.776176663Z 2024-04-22 20:21:19,775 INFO: not healthy enough for leader race
2024-04-22T20:21:19.776293430Z 2024-04-22 20:21:19,775 INFO: bootstrap in progress
INFO: 2024/04/22 20:21:20.658577 Finished extraction of part_004.tar.lz4
INFO: 2024/04/22 20:21:22.311766 Finished extraction of part_014.tar.lz4
2024-04-22T20:21:22.314047154Z ERROR: 2024/04/22 20:21:22.311841 Extraction error in part_014.tar.lz4: extractOne: Interpret failed: Interpret: copy failed: read tcp 10.2.7.11:56168->38.143.146.100:443: read: connection reset by peer
2024-04-22 20:21:29,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:21:29.799736903Z 2024-04-22 20:21:29,796 INFO: not healthy enough for leader race
2024-04-22T20:21:29.799742003Z 2024-04-22 20:21:29,796 INFO: bootstrap in progress
INFO: 2024/04/22 20:21:33.825231 Finished extraction of part_020.tar.lz4
2024-04-22T20:21:33.825483865Z ERROR: 2024/04/22 20:21:33.825261 Extraction error in part_020.tar.lz4: extractOne: Interpret failed: Interpret: copy failed: read tcp 10.2.7.11:57284->38.143.146.101:443: read: connection reset by peer
INFO: 2024/04/22 20:21:39.430684 Finished extraction of part_011.tar.lz4
INFO: 2024/04/22 20:21:39.496587 Finished extraction of part_013.tar.lz4
INFO: 2024/04/22 20:21:39.696570 Finished extraction of part_012.tar.lz4
2024-04-22 20:21:39,797 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:21:39.800570936Z 2024-04-22 20:21:39,797 INFO: not healthy enough for leader race
2024-04-22T20:21:39.800576205Z 2024-04-22 20:21:39,797 INFO: bootstrap in progress
2024-04-22 20:21:49,797 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:21:49.797662244Z 2024-04-22 20:21:49,797 INFO: not healthy enough for leader race
2024-04-22T20:21:49.797668065Z 2024-04-22 20:21:49,797 INFO: bootstrap in progress
2024-04-22 20:21:59,797 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:21:59.799820086Z 2024-04-22 20:21:59,797 INFO: not healthy enough for leader race
2024-04-22T20:21:59.799826299Z 2024-04-22 20:21:59,797 INFO: bootstrap in progress
2024-04-22 20:22:09,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:22:09.775821323Z 2024-04-22 20:22:09,775 INFO: not healthy enough for leader race
2024-04-22T20:22:09.775831533Z 2024-04-22 20:22:09,775 INFO: bootstrap in progress
INFO: 2024/04/22 20:22:19.352564 Finished extraction of part_017.tar.lz4
2024-04-22 20:22:19,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:22:19.776126143Z 2024-04-22 20:22:19,775 INFO: not healthy enough for leader race
2024-04-22T20:22:19.776133346Z 2024-04-22 20:22:19,775 INFO: bootstrap in progress
INFO: 2024/04/22 20:22:23.447544 Finished extraction of part_016.tar.lz4
2024-04-22 20:22:29,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:22:29.775748123Z 2024-04-22 20:22:29,775 INFO: not healthy enough for leader race
2024-04-22T20:22:29.775753784Z 2024-04-22 20:22:29,775 INFO: bootstrap in progress
INFO: 2024/04/22 20:22:33.501678 Finished extraction of part_019.tar.lz4
INFO: 2024/04/22 20:22:35.634801 Finished extraction of part_022.tar.lz4
INFO: 2024/04/22 20:22:37.558647 Finished extraction of part_021.tar.lz4
2024-04-22 20:22:39,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:22:39.775830041Z 2024-04-22 20:22:39,775 INFO: not healthy enough for leader race
2024-04-22T20:22:39.776161625Z 2024-04-22 20:22:39,775 INFO: bootstrap in progress
INFO: 2024/04/22 20:22:44.077020 Finished extraction of part_023.tar.lz4
2024-04-22 20:22:49,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:22:49.791034864Z 2024-04-22 20:22:49,775 INFO: not healthy enough for leader race
2024-04-22T20:22:49.791048561Z 2024-04-22 20:22:49,775 INFO: bootstrap in progress
INFO: 2024/04/22 20:22:54.526297 Finished extraction of part_025.tar.lz4
INFO: 2024/04/22 20:22:55.309007 Finished extraction of part_024.tar.lz4
INFO: 2024/04/22 20:22:59.708530 Finished extraction of part_027.tar.lz4
2024-04-22 20:22:59,797 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:22:59.820549210Z 2024-04-22 20:22:59,797 INFO: not healthy enough for leader race
2024-04-22T20:22:59.820572605Z 2024-04-22 20:22:59,797 INFO: bootstrap in progress
INFO: 2024/04/22 20:23:03.196790 Finished extraction of part_028.tar.lz4
2024-04-22 20:23:09,798 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:23:09.809044705Z 2024-04-22 20:23:09,799 INFO: not healthy enough for leader race
2024-04-22T20:23:09.809171701Z 2024-04-22 20:23:09,799 INFO: bootstrap in progress
2024-04-22 20:23:19,797 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:23:19.808553149Z 2024-04-22 20:23:19,797 INFO: not healthy enough for leader race
2024-04-22T20:23:19.808560362Z 2024-04-22 20:23:19,797 INFO: bootstrap in progress
2024-04-22T20:23:19.808566524Z INFO: 2024/04/22 20:23:19.805135 Finished extraction of part_034.tar.lz4
2024-04-22T20:23:19.808572636Z ERROR: 2024/04/22 20:23:19.805151 Extraction error in part_034.tar.lz4: extractOne: Interpret failed: Interpret: copy failed: read tcp 10.2.7.11:57206->38.143.146.101:443: read: connection reset by peer
2024-04-22 20:23:29,797 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22 20:23:29,797 INFO: not healthy enough for leader race
2024-04-22 20:23:29,797 INFO: bootstrap in progress
2024-04-22 20:23:39,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:23:39.775882663Z 2024-04-22 20:23:39,775 INFO: not healthy enough for leader race
2024-04-22T20:23:39.775888754Z 2024-04-22 20:23:39,775 INFO: bootstrap in progress
INFO: 2024/04/22 20:23:46.765268 Finished extraction of part_026.tar.lz4
2024-04-22 20:23:49,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:23:49.776373651Z 2024-04-22 20:23:49,775 INFO: not healthy enough for leader race
2024-04-22T20:23:49.776381867Z 2024-04-22 20:23:49,775 INFO: bootstrap in progress
INFO: 2024/04/22 20:23:49.850223 Finished extraction of part_029.tar.lz4
INFO: 2024/04/22 20:23:50.657967 Finished extraction of part_030.tar.lz4
INFO: 2024/04/22 20:23:56.808199 Finished extraction of part_031.tar.lz4
2024-04-22T20:23:56.808371446Z INFO: 2024/04/22 20:23:56.808222 Finished extraction of part_018.tar.lz4
2024-04-22 20:23:59,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:23:59.776099591Z 2024-04-22 20:23:59,775 INFO: not healthy enough for leader race
2024-04-22T20:23:59.776105893Z 2024-04-22 20:23:59,775 INFO: bootstrap in progress
INFO: 2024/04/22 20:23:59.918955 Finished extraction of part_032.tar.lz4
INFO: 2024/04/22 20:24:09.477291 Finished extraction of part_033.tar.lz4
2024-04-22 20:24:09,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22 20:24:09,775 INFO: not healthy enough for leader race
2024-04-22T20:24:09.776212184Z 2024-04-22 20:24:09,775 INFO: bootstrap in progress
INFO: 2024/04/22 20:24:12.198343 Finished extraction of part_035.tar.lz4
2024-04-22 20:24:19,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:24:19.775988125Z 2024-04-22 20:24:19,775 INFO: not healthy enough for leader race
2024-04-22T20:24:19.775994967Z 2024-04-22 20:24:19,775 INFO: bootstrap in progress
2024-04-22 20:24:29,775 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:24:29.775945946Z 2024-04-22 20:24:29,775 INFO: not healthy enough for leader race
2024-04-22T20:24:29.775953622Z 2024-04-22 20:24:29,775 INFO: bootstrap in progress
2024-04-22 20:24:39,658 ERROR: Clone failed
2024-04-22T20:24:39.659405951Z Traceback (most recent call last):
2024-04-22T20:24:39.659411491Z   File "/scripts/clone_with_wale.py", line 184, in main
2024-04-22T20:24:39.659415290Z     run_clone_from_s3(options)
2024-04-22T20:24:39.659420168Z   File "/scripts/clone_with_wale.py", line 172, in run_clone_from_s3
2024-04-22T20:24:39.659423244Z     raise Exception("wal-e backup-fetch exited with exit code {0}".format(ret))
2024-04-22T20:24:39.659425969Z Exception: wal-e backup-fetch exited with exit code -9
2024-04-22 20:24:39,666 INFO: removing initialize key after failed attempt to bootstrap the cluster
2024-04-22 20:24:39,715 INFO: renaming data directory to /home/postgres/pgdata/pgroot/data.failed
Traceback (most recent call last):
2024-04-22T20:24:40.092523766Z   File "/usr/local/bin/patroni", line 8, in <module>
2024-04-22T20:24:40.092528857Z     sys.exit(main())
2024-04-22T20:24:40.092532764Z   File "/usr/local/lib/python3.10/dist-packages/patroni/__main__.py", line 344, in main
2024-04-22T20:24:40.092536210Z     return patroni_main(args.configfile)
2024-04-22T20:24:40.092539026Z   File "/usr/local/lib/python3.10/dist-packages/patroni/__main__.py", line 232, in patroni_main
2024-04-22T20:24:40.092541752Z     abstract_main(Patroni, configfile)
2024-04-22T20:24:40.092544878Z   File "/usr/local/lib/python3.10/dist-packages/patroni/daemon.py", line 174, in abstract_main
2024-04-22T20:24:40.092547503Z     controller.run()
2024-04-22T20:24:40.092550138Z   File "/usr/local/lib/python3.10/dist-packages/patroni/__main__.py", line 192, in run
2024-04-22T20:24:40.092553353Z     super(Patroni, self).run()
2024-04-22T20:24:40.092556340Z   File "/usr/local/lib/python3.10/dist-packages/patroni/daemon.py", line 143, in run
2024-04-22T20:24:40.092597159Z     self._run_cycle()
2024-04-22T20:24:40.092629341Z   File "/usr/local/lib/python3.10/dist-packages/patroni/__main__.py", line 201, in _run_cycle
    logger.info(self.ha.run_cycle())
  File "/usr/local/lib/python3.10/dist-packages/patroni/ha.py", line 1972, in run_cycle
2024-04-22T20:24:40.092890068Z     info = self._run_cycle()
2024-04-22T20:24:40.092893124Z   File "/usr/local/lib/python3.10/dist-packages/patroni/ha.py", line 1786, in _run_cycle
2024-04-22T20:24:40.093229808Z     return self.post_bootstrap()
2024-04-22T20:24:40.093242893Z   File "/usr/local/lib/python3.10/dist-packages/patroni/ha.py", line 1670, in post_bootstrap
2024-04-22T20:24:40.093246650Z     self.cancel_initialization()
2024-04-22T20:24:40.093249766Z   File "/usr/local/lib/python3.10/dist-packages/patroni/ha.py", line 1663, in cancel_initialization
2024-04-22T20:24:40.093458201Z     raise PatroniFatalException('Failed to bootstrap cluster')
2024-04-22T20:24:40.093469363Z patroni.exceptions.PatroniFatalException: Failed to bootstrap cluster
/etc/runit/runsvdir/default/patroni: finished with code=1 signal=0
/etc/runit/runsvdir/default/patroni: sleeping 30 seconds
2024-04-22 20:25:10,423 WARNING: Kubernetes RBAC doesn't allow GET access to the 'kubernetes' endpoint in the 'default' namespace. Disabling 'bypass_api_service'.
2024-04-22 20:25:10,477 INFO: No PostgreSQL configuration items changed, nothing to reload.
2024-04-22 20:25:10,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:25:10.515940500Z 2024-04-22 20:25:10,515 INFO: waiting for leader to bootstrap
2024-04-22 20:25:20,480 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:25:20.480596592Z 2024-04-22 20:25:20,480 INFO: waiting for leader to bootstrap
2024-04-22 20:25:30,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:25:30.480479365Z 2024-04-22 20:25:30,479 INFO: waiting for leader to bootstrap
2024-04-22 20:25:40,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:25:40.480508688Z 2024-04-22 20:25:40,480 INFO: waiting for leader to bootstrap
2024-04-22 20:25:50,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:25:50.480380930Z 2024-04-22 20:25:50,479 INFO: waiting for leader to bootstrap
2024-04-22 20:26:00,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:26:00.480370860Z 2024-04-22 20:26:00,479 INFO: waiting for leader to bootstrap
2024-04-22 20:26:10,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:26:10.480395288Z 2024-04-22 20:26:10,480 INFO: waiting for leader to bootstrap
2024-04-22 20:26:20,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:26:20.480497695Z 2024-04-22 20:26:20,480 INFO: waiting for leader to bootstrap
2024-04-22 20:26:30,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:26:30.480660839Z 2024-04-22 20:26:30,480 INFO: waiting for leader to bootstrap
2024-04-22 20:26:40,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:26:40.480538343Z 2024-04-22 20:26:40,480 INFO: waiting for leader to bootstrap
2024-04-22 20:26:50,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:26:50.480304368Z 2024-04-22 20:26:50,480 INFO: waiting for leader to bootstrap
2024-04-22 20:27:00,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:27:00.480117198Z 2024-04-22 20:27:00,479 INFO: waiting for leader to bootstrap
2024-04-22 20:27:10,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:27:10.480413282Z 2024-04-22 20:27:10,480 INFO: waiting for leader to bootstrap
2024-04-22 20:27:20,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:27:20.480537085Z 2024-04-22 20:27:20,480 INFO: waiting for leader to bootstrap
2024-04-22 20:27:30,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:27:30.480450208Z 2024-04-22 20:27:30,480 INFO: waiting for leader to bootstrap
2024-04-22 20:27:40,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:27:40.480487837Z 2024-04-22 20:27:40,479 INFO: waiting for leader to bootstrap
2024-04-22 20:27:50,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:27:50.534507151Z 2024-04-22 20:27:50,533 INFO: trying to bootstrap a new cluster
2024-04-22T20:27:50.534524686Z 2024-04-22 20:27:50,533 INFO: Running custom bootstrap script: envdir "/run/etc/wal-e.d/env-clone-acid-test2" python3 /scripts/clone_with_wale.py --recovery-target-time="2024-04-22T18:04:39+00:00"
2024-04-22 20:27:50,572 INFO: Trying s3://test-postgres-operator-k8s/spilo/test-postgres2-acid-test2/wal/14/ for clone
2024-04-22 20:27:51,194 INFO: cloning cluster acid-test-test using wal-g backup-fetch /home/postgres/pgdata/pgroot/data base_00000034000000AB00000052
INFO: 2024/04/22 20:27:51.210487 Selecting the backup with name base_00000034000000AB00000052...
2024-04-22 20:28:00,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:28:00.480646916Z 2024-04-22 20:28:00,479 INFO: not healthy enough for leader race
2024-04-22 20:28:00,527 INFO: bootstrap in progress
INFO: 2024/04/22 20:28:06.203702 Finished extraction of part_010.tar.lz4
2024-04-22T20:28:06.204406093Z ERROR: 2024/04/22 20:28:06.203724 Extraction error in part_010.tar.lz4: extractOne: Interpret failed: Interpret: copy failed: read tcp 10.2.7.11:37442->38.143.146.100:443: read: connection reset by peer
2024-04-22 20:28:10,497 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:28:10.500200215Z 2024-04-22 20:28:10,497 INFO: not healthy enough for leader race
2024-04-22T20:28:10.500205885Z 2024-04-22 20:28:10,497 INFO: bootstrap in progress
INFO: 2024/04/22 20:28:10.796523 Finished extraction of part_008.tar.lz4
2024-04-22T20:28:10.797238420Z ERROR: 2024/04/22 20:28:10.796547 Extraction error in part_008.tar.lz4: extractOne: Interpret failed: Interpret: copy failed: read tcp 10.2.7.11:37476->38.143.146.100:443: read: connection reset by peer
2024-04-22 20:28:20,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:28:20.480244822Z 2024-04-22 20:28:20,479 INFO: not healthy enough for leader race
2024-04-22T20:28:20.480250462Z 2024-04-22 20:28:20,479 INFO: bootstrap in progress
2024-04-22 20:28:30,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:28:30.480378114Z 2024-04-22 20:28:30,479 INFO: not healthy enough for leader race
2024-04-22T20:28:30.480384396Z 2024-04-22 20:28:30,479 INFO: bootstrap in progress
INFO: 2024/04/22 20:28:31.307509 Finished extraction of part_004.tar.lz4
2024-04-22 20:28:40,479 INFO: Lock owner: ; I am acid-test-test-0
2024-04-22T20:28:40.480107174Z 2024-04-22 20:28:40,479 INFO: not healthy enough for leader race
2024-04-22T20:28:40.480113397Z 2024-04-22 20:28:40,479 INFO: bootstrap in progress
INFO: 2024/04/22 20:28:41.087284 Finished extraction of part_002.tar.lz4

Nothing notable in operator logs
operator_logs.txt

@FxKu FxKu added the spilo Issue more related to Spilo label Apr 24, 2024
@FxKu
Copy link
Member

FxKu commented Apr 24, 2024

We usually see these "extractOne: Interpret failed: Interpret: copy failed" messages when there's no disk space left and the specified volume is too small for the database cluster that is about to get cloned. To me the logs looks like the operator is working as expected - which is only setting the right environment variables for Spilo so wal-e will be called to pull a backup and apply WAL files.

Wal-e crashed ("wal-e backup-fetch exited with exit code -9"), hence clone is retried. Maybe specify more memory?

@FxKu FxKu added the question label Apr 24, 2024
@jonathon2nd
Copy link
Author

I had provisioned the same size PV, and had given up with cloning by s3 and just manually restored by base backup.

@jonathon2nd
Copy link
Author

jonathon2nd commented Apr 24, 2024

Had to redo test cluster for new tests. This time I attempted to restore to an exact replica, same pod specs and everything, failed twice.

acid-example-test6-0_postgres.log
acid-example-test7-0_postgres.log
postgres-operator-7469cf8c5b-7pbcf_postgres-operator.log

@jonathon2nd
Copy link
Author

Cloning from existing master works, but is greatly limited by the fact that it has to be the exact same namespace. We are only using it right now cause we are in a pinch and really want to get some tests done.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
question spilo Issue more related to Spilo
Projects
None yet
Development

No branches or pull requests

2 participants