restore from s3 doesn't work properly (from hippo to rhino)

[tirelibirefe]

Hello;

pgo 5.1
psql 14
eks 1.22

I follow the recipe here which is the last one; rhino.

I have backups in S3 for "tarabya"; I lost "tarabya" and I would like to restore "tarabya" to "tarabya1" from S3 backups.

Here is my manifest:

dataSource:
  pgbackrest:
    stanza: db
    configuration:
    - secret:
        name: psql-tarabya1-s3-creds
    - secret:
        name: tarabya1-pgbackrest-secrets
    global:
      repo1-path: /repo1/tarabya
      repo1-cipher-type: aes-256-cbc
    repo:
      name: repo1
      s3:
        bucket: ku-eksdev1-crunchydata-backups
        endpoint: s3.eu-central-1.amazonaws.com:443
        region: eu-central-1

When I run restore manifest, the restore cannot be completed. I get the following error:

$ k get pods -n $namespace -w
NAME                                READY   STATUS     RESTARTS   AGE
tarabya1-pgbackrest-restore-xbcdn   0/1     Init:0/1   0          7s
tarabya1-pgbackrest-restore-xbcdn   0/1     Init:0/1   0          12s
tarabya1-pgbackrest-restore-xbcdn   0/1     PodInitializing   0          13s
tarabya1-pgbackrest-restore-xbcdn   1/1     Running           0          14s
tarabya1-pgbackrest-restore-xbcdn   0/1     Error             0          52s
tarabya1-pgbackrest-restore-j2tmf   0/1     Pending           0          0s
tarabya1-pgbackrest-restore-j2tmf   0/1     Pending           0          0s
tarabya1-pgbackrest-restore-xbcdn   0/1     Error             0          52s
tarabya1-pgbackrest-restore-j2tmf   0/1     Init:0/1          0          0s
tarabya1-pgbackrest-restore-j2tmf   0/1     Init:0/1          0          10s
tarabya1-pgbackrest-restore-j2tmf   0/1     PodInitializing   0          11s
tarabya1-pgbackrest-restore-j2tmf   1/1     Running           0          12s
tarabya1-pgbackrest-restore-j2tmf   0/1     Error             0          14s
tarabya1-pgbackrest-restore-j2tmf   0/1     Error             0          14s
tarabya1-pgbackrest-restore-455mv   0/1     Pending           0          0s
tarabya1-pgbackrest-restore-455mv   0/1     Pending           0          0s
tarabya1-pgbackrest-restore-455mv   0/1     Init:0/1          0          0s
tarabya1-pgbackrest-restore-455mv   0/1     Init:0/1          0          6s
tarabya1-pgbackrest-restore-455mv   0/1     PodInitializing   0          7s
tarabya1-pgbackrest-restore-455mv   1/1     Running           0          8s
tarabya1-pgbackrest-restore-455mv   0/1     Error             0          11s
tarabya1-pgbackrest-restore-455mv   0/1     Error             0          11s
tarabya1-pgbackrest-restore-4w5cq   0/1     Pending           0          0s
tarabya1-pgbackrest-restore-4w5cq   0/1     Pending           0          0s
...
$ k logs -n psql-tarabya1 tarabya1-pgbackrest-restore-p9tl7
Defaulted container "pgbackrest-restore" out of: pgbackrest-restore, nss-wrapper-init (init)
WARN: unable to open log file '/pgdata/pgbackrest/log/db-restore.log': No such file or directory
      NOTE: process will continue without log file.
2022-09-03 18:15:06.763 GMT [17] LOG:  starting PostgreSQL 14.2 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 8.5.0 20210514 (Red Hat 8.5.0-4), 64-bit
2022-09-03 18:15:06.765 GMT [17] LOG:  listening on IPv6 address "::1", port 5432
2022-09-03 18:15:06.765 GMT [17] LOG:  listening on IPv4 address "127.0.0.1", port 5432
2022-09-03 18:15:06.780 GMT [17] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-09-03 18:15:06.787 GMT [18] LOG:  database system was interrupted; last known up at 2022-09-02 17:47:19 GMT
2022-09-03 18:15:06.896 GMT [18] LOG:  restored log file "00000002.history" from archive
2022-09-03 18:15:07.000 GMT [18] LOG:  starting archive recovery
2022-09-03 18:15:07.105 GMT [18] LOG:  restored log file "00000002.history" from archive
2022-09-03 18:15:07.292 GMT [18] LOG:  restored log file "00000002000000000000000D" from archive
2022-09-03 18:15:07.329 GMT [18] LOG:  redo starts at 0/D000028
2022-09-03 18:15:07.497 GMT [18] LOG:  restored log file "00000002000000000000000E" from archive
2022-09-03 18:15:07.616 GMT [18] LOG:  redo done at 0/E000C40 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.28 s
2022-09-03 18:15:07.616 GMT [18] LOG:  last completed transaction was at log time 2022-09-02 18:09:57.783236+00
2022-09-03 18:15:07.833 GMT [18] LOG:  restored log file "00000002000000000000000E" from archive
2022-09-03 18:15:07.865 GMT [18] FATAL:  WAL ends before end of online backup
2022-09-03 18:15:07.865 GMT [18] HINT:  All WAL generated while online backup was taken must be available at recovery.
2022-09-03 18:15:07.867 GMT [17] LOG:  startup process (PID 18) exited with exit code 1
2022-09-03 18:15:07.867 GMT [17] LOG:  terminating any other active server processes
2022-09-03 18:15:07.868 GMT [17] LOG:  shutting down due to startup process failure
2022-09-03 18:15:07.869 GMT [17] LOG:  database system is shut down
pg_ctl: could not start server
Examine the log output.

[benjaminjb]

There seem to be some issues involving S3 restores, particularly with encrypted buckets; see issues #3374 and #3382.

However I cannot replicate this problem. As noted on the other issues, I have some questions about the manifest you're using and the secrets that you're mounting.

[tirelibirefe]

Hello @benjaminjb,
This is a very important topic and I'll give more information about the topic, pls don't close it for a while.

Thanks & Regards

[tirelibirefe]

Hello @benjaminjb
As I cleaned up the environment, I had to re-install all stuff to reproduce issue. Pls excuse me for the latency.

let's go on alternative scenarios under this topic:

[benjaminjb]

OK, let's put a hold on this issue for a moment and look at that other one.

[andrewlecuyer]

With conversations around S3 restores continuing in #3374, proceeding with closing this issue.

If you still have an S3 issue unrelated to #3374, please submit a new issue.