WAL-Verify fails after upgrade from postgres 13 > 14

[Mahagon]

We are currently running PostgreSQL 13, deployed by the Zalando-Operator/PostgreSQL-Operator chart version 1.10.0. I sought to upgrade to PostgreSQL 14 by configuring major_version_upgrade_mode as "manual" and modifying the spec.postgres.version of the PostgreSQL custom resource (CR) to 14.

This upgrade proceeded smoothly as anticipated. The instance began operating in version 13 and transitioned to version 14 within a few minutes.

However, when I executed the wal-verify command, I encountered an issue where both the timeline and the integrity check failed. I also attempted to perform the upgrade manually by running python3 /scripts/inplace_upgrade.py N, but it led to the same error.

Is that expected? Is it a bug? What can i do?

BTW: this is just running in a dev environment atm :)

Wal-Verify Result:

PGUSER=$PGUSER_SUPERUSER PGPASSWORD=$PGPASSWORD_SUPERUSER wal-g wal-verify integrity


INFO: 2023/05/05 08:14:38.310664 Current WAL segment: 00000001000000000000000B
INFO: 2023/05/05 08:14:38.603488 Building check runner: integrity
INFO: 2023/05/05 08:14:38.695477 Detected earliest available backup: base_000000010000000000000002
INFO: 2023/05/05 08:14:38.695499 Running the check: integrity
[wal-verify] integrity check status: WARNING
[wal-verify] integrity check details:
+-----+--------------------------+--------------------------+----------------+-------------------+
| TLI | START                    | END                      | SEGMENTS COUNT |            STATUS |
+-----+--------------------------+--------------------------+----------------+-------------------+
|   1 | 000000010000000000000002 | 000000010000000000000003 |              2 |             FOUND |
|   1 | 000000010000000000000004 | 000000010000000000000008 |              5 | MISSING_UPLOADING |
|   1 | 000000010000000000000009 | 00000001000000000000000A |              2 |             FOUND |
+-----+--------------------------+--------------------------+----------------+-------------------+

Inplace Upgrade Log

python3 /scripts/inplace_upgrade.py 1

2023-05-05 08:13:10,302 inplace_upgrade INFO: No PostgreSQL configuration items changed, nothing to reload.
2023-05-05 08:13:10,318 inplace_upgrade INFO: establishing a new patroni connection to the postgres cluster
2023-05-05 08:13:10,438 inplace_upgrade INFO: Cluster postgres-postgres is ready to be upgraded
2023-05-05 08:13:10,438 inplace_upgrade INFO: initdb config: [{'locale': 'en_US.utf-8'}, {'encoding': 'UTF8'}]
The files belonging to this database system will be owned by user "postgres".
This user must also own the server process.

The database cluster will be initialized with locale "en_US.utf-8".
The default text search configuration will be set to "english".

Data page checksums are disabled.

creating directory /home/postgres/pgdata/pgroot/data_new ... ok
creating subdirectories ... ok
selecting dynamic shared memory implementation ... posix
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting default time zone ... Etc/UTC
creating configuration files ... ok
running bootstrap script ... ok
performing post-bootstrap initialization ... ok
syncing data to disk ... ok

initdb: warning: enabling "trust" authentication for local connections
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.

Success. You can now start the database server using:

    /usr/lib/postgresql/14/bin/pg_ctl -D /home/postgres/pgdata/pgroot/data_new -l logfile start

2023-05-05 08:13:13,887 inplace_upgrade INFO: Dropping extensions from the cluster which could be incompatible
2023-05-05 08:13:13,890 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS amcheck_next" in the database="postgres"
2023-05-05 08:13:13,890 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS pg_repack" in the database="postgres"
2023-05-05 08:13:13,892 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS amcheck_next" in the database="registry"
2023-05-05 08:13:13,893 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS pg_repack" in the database="registry"
2023-05-05 08:13:13,897 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS amcheck_next" in the database="template1"
2023-05-05 08:13:13,898 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS pg_repack" in the database="template1"
2023-05-05 08:13:13,898 inplace_upgrade INFO: Executing pg_upgrade --check
Performing Consistency Checks on Old Live Server
------------------------------------------------
Checking cluster versions                                   ok
Checking database user is the install user                  ok
Checking database connection settings                       ok
Checking for prepared transactions                          ok
Checking for system-defined composite types in user tables  ok
Checking for reg* data types in user tables                 ok
Checking for contrib/isn with bigint-passing mismatch       ok
Checking for user-defined encoding conversions              ok
Checking for user-defined postfix operators                 ok
Checking for incompatible polymorphic functions             ok
Checking for presence of required libraries                 ok
Checking database user is the install user                  ok
Checking for prepared transactions                          ok
Checking for new cluster tablespace directories             ok

*Clusters are compatible*
2023-05-05 08:13:15,310 inplace_upgrade INFO: Dropping objects from the cluster which could be incompatible
2023-05-05 08:13:15,313 inplace_upgrade INFO: Executing "REVOKE EXECUTE ON FUNCTION pg_catalog.pg_switch_wal() FROM admin" in the database="postgres"
2023-05-05 08:13:15,316 inplace_upgrade INFO: Executing "DROP FUNCTION metric_helpers.pg_stat_statements" in the database="postgres"
2023-05-05 08:13:15,320 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS pg_stat_kcache" in the database="postgres"
2023-05-05 08:13:15,324 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS pg_stat_statements" in the database="postgres"
2023-05-05 08:13:15,328 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS amcheck_next" in the database="postgres"
2023-05-05 08:13:15,328 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS pg_repack" in the database="postgres"
2023-05-05 08:13:15,331 inplace_upgrade INFO: Executing "REVOKE EXECUTE ON FUNCTION pg_catalog.pg_switch_wal() FROM admin" in the database="registry"
2023-05-05 08:13:15,333 inplace_upgrade INFO: Executing "DROP FUNCTION metric_helpers.pg_stat_statements" in the database="registry"
2023-05-05 08:13:15,402 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS pg_stat_kcache" in the database="registry"
2023-05-05 08:13:15,408 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS pg_stat_statements" in the database="registry"
2023-05-05 08:13:15,411 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS amcheck_next" in the database="registry"
2023-05-05 08:13:15,411 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS pg_repack" in the database="registry"
2023-05-05 08:13:15,414 inplace_upgrade INFO: Executing "REVOKE EXECUTE ON FUNCTION pg_catalog.pg_switch_wal() FROM admin" in the database="template1"
2023-05-05 08:13:15,417 inplace_upgrade INFO: Executing "DROP FUNCTION metric_helpers.pg_stat_statements" in the database="template1"
2023-05-05 08:13:15,421 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS pg_stat_kcache" in the database="template1"
2023-05-05 08:13:15,426 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS pg_stat_statements" in the database="template1"
2023-05-05 08:13:15,429 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS amcheck_next" in the database="template1"
2023-05-05 08:13:15,429 inplace_upgrade INFO: Executing "DROP EXTENSION IF EXISTS pg_repack" in the database="template1"
2023-05-05 08:13:15,430 inplace_upgrade INFO: Enabling maintenance mode
2023-05-05 08:13:16,504 inplace_upgrade INFO: Maintenance mode enabled
2023-05-05 08:13:16,504 inplace_upgrade INFO: Doing a clean shutdown of the cluster before pg_upgrade
2023-05-05 08:13:17,324 inplace_upgrade INFO: Executing pg_upgrade
Performing Consistency Checks
-----------------------------
Checking cluster versions                                   ok
Checking database user is the install user                  ok
Checking database connection settings                       ok
Checking for prepared transactions                          ok
Checking for system-defined composite types in user tables  ok
Checking for reg* data types in user tables                 ok
Checking for contrib/isn with bigint-passing mismatch       ok
Checking for user-defined encoding conversions              ok
Checking for user-defined postfix operators                 ok
Checking for incompatible polymorphic functions             ok
Creating dump of global objects                             ok
Creating dump of database schemas
                                                            ok
Checking for presence of required libraries                 ok
Checking database user is the install user                  ok
Checking for prepared transactions                          ok
Checking for new cluster tablespace directories             ok

If pg_upgrade fails after this point, you must re-initdb the
new cluster before continuing.

Performing Upgrade
------------------
Analyzing all rows in the new cluster                       ok
Freezing all rows in the new cluster                        ok
Deleting files from new pg_xact                             ok
Copying old pg_xact to new server                           ok
Setting oldest XID for new cluster                          ok
Setting next transaction ID and epoch for new cluster       ok
Deleting files from new pg_multixact/offsets                ok
Copying old pg_multixact/offsets to new server              ok
Deleting files from new pg_multixact/members                ok
Copying old pg_multixact/members to new server              ok
Setting next multixact ID and offset for new cluster        ok
Resetting WAL archives                                      ok
Setting frozenxid and minmxid counters in new cluster       ok
Restoring global objects in the new cluster                 ok
Restoring database schemas in the new cluster
                                                            ok
Adding ".old" suffix to old global/pg_control               ok

If you want to start the old cluster, you will need to remove
the ".old" suffix from /home/postgres/pgdata/pgroot/data/global/pg_control.old.
Because "link" mode was used, the old cluster cannot be safely
started once the new cluster has been started.

Linking user relation files
                                                            ok
Setting next OID for new cluster                            ok
Sync data directory to disk                                 ok
Creating script to delete old cluster                       ok
Checking for extension updates                              ok

Upgrade Complete
----------------
Optimizer statistics are not transferred by pg_upgrade.
Once you start the new server, consider running:
    /usr/lib/postgresql/14/bin/vacuumdb -U postgres --all --analyze-in-stages

Running this script will delete the old cluster's data files:
    ./delete_old_cluster.sh
2023-05-05 08:13:27,806 inplace_upgrade INFO: Updating configuration files
2023-05-05 08:13:27,824 inplace_upgrade INFO: Writing to file /run/postgres.yml
2023-05-05 08:13:27,825 inplace_upgrade INFO: Removing initialize key
2023-05-05 08:13:27,832 inplace_upgrade INFO: Restarting patroni
2023-05-05 08:13:28,835 inplace_upgrade INFO: Starting the primary postgres up
2023-05-05 08:13:30,422 inplace_upgrade INFO:    200 restarted successfully
2023-05-05 08:13:30,422 inplace_upgrade INFO: Upgrade downtime: 13.917689323425293
2023-05-05 08:13:30,903 inplace_upgrade INFO: establishing a new patroni connection to the postgres cluster
2023-05-05 08:13:30,912 inplace_upgrade INFO: Executing 'ALTER EXTENSION plpgsql UPDATE' in the database=template1
2023-05-05 08:13:30,912 inplace_upgrade INFO: Executing 'ALTER EXTENSION set_user UPDATE' in the database=template1
2023-05-05 08:13:30,915 inplace_upgrade INFO: Executing 'ALTER EXTENSION plpgsql UPDATE' in the database=registry
2023-05-05 08:13:30,915 inplace_upgrade INFO: Executing 'ALTER EXTENSION set_user UPDATE' in the database=registry
2023-05-05 08:13:30,918 inplace_upgrade INFO: Executing 'ALTER EXTENSION plpgsql UPDATE' in the database=postgres
2023-05-05 08:13:30,918 inplace_upgrade INFO: Executing 'ALTER EXTENSION pg_cron UPDATE' in the database=postgres
2023-05-05 08:13:30,918 inplace_upgrade INFO: Executing 'ALTER EXTENSION plpython3u UPDATE' in the database=postgres
2023-05-05 08:13:30,918 inplace_upgrade INFO: Executing 'ALTER EXTENSION file_fdw UPDATE' in the database=postgres
2023-05-05 08:13:30,918 inplace_upgrade INFO: Executing 'ALTER EXTENSION pg_auth_mon UPDATE' in the database=postgres
2023-05-05 08:13:30,919 inplace_upgrade INFO: Executing 'ALTER EXTENSION set_user UPDATE' in the database=postgres
2023-05-05 08:13:30,919 inplace_upgrade INFO: Resetting non-default statistics target before analyze
2023-05-05 08:13:30,919 inplace_upgrade INFO: Disabling maintenance mode
2023-05-05 08:13:31,014 inplace_upgrade INFO: Rebuilding statistics (vacuumdb --analyze-in-stages)
vacuumdb: processing database "registry": Generating minimal optimizer statistics (1 target)
vacuumdb: processing database "template1": Generating minimal optimizer statistics (1 target)
vacuumdb: processing database "postgres": Generating minimal optimizer statistics (1 target)
2023-05-05 08:13:31,927 inplace_upgrade INFO: Maintenance mode disabled
vacuumdb: processing database "registry": Generating medium optimizer statistics (10 targets)
vacuumdb: error: processing of database "postgres" failed: ERROR:  extra data after last expected column
CONTEXT:  COPY postgres_log_5, line 5262: "2023-05-05 08:13:15.003 UTC,,,533,,6454ba9a.215,1,,2023-05-05 08:13:14 UTC,,0,LOG,00000,"starting Po..."
vacuumdb: processing database "template1": Generating medium optimizer statistics (10 targets)
vacuumdb: processing database "registry": Generating default (full) optimizer statistics
vacuumdb: processing database "template1": Generating default (full) optimizer statistics
2023-05-05 08:13:33,904 inplace_upgrade INFO: Total upgrade time (with analyze): 17.39971351623535
DO
NOTICE:  role "admin" is already a member of role "cron_admin"
GRANT ROLE
DO
DO
NOTICE:  extension "pg_auth_mon" already exists, skipping
CREATE EXTENSION
NOTICE:  version "1.1" of extension "pg_auth_mon" is already installed
ALTER EXTENSION
GRANT
NOTICE:  extension "pg_cron" already exists, skipping
CREATE EXTENSION
DO
NOTICE:  version "1.4-1" of extension "pg_cron" is already installed
ALTER EXTENSION
ALTER POLICY
REVOKE
GRANT
REVOKE
GRANT
ALTER POLICY
REVOKE
GRANT
CREATE FUNCTION
REVOKE
GRANT
REVOKE
GRANT
NOTICE:  extension "file_fdw" already exists, skipping
CREATE EXTENSION
DO
NOTICE:  relation "postgres_log" already exists, skipping
CREATE TABLE
GRANT
NOTICE:  column "backend_type" of relation "postgres_log" already exists, skipping
ALTER TABLE
ALTER TABLE
ALTER TABLE
NOTICE:  relation "postgres_log_0" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
NOTICE:  relation "postgres_log_1" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
NOTICE:  relation "postgres_log_2" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
NOTICE:  relation "postgres_log_3" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
NOTICE:  relation "postgres_log_4" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
NOTICE:  relation "postgres_log_5" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
NOTICE:  relation "postgres_log_6" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
NOTICE:  relation "postgres_log_7" already exists, skipping
CREATE FOREIGN TABLE
GRANT
CREATE VIEW
ALTER VIEW
GRANT
RESET
SET
NOTICE:  drop cascades to 5 other objects
DETAIL:  drop cascades to function zmon_utils.get_database_cluster_information()
drop cascades to function zmon_utils.get_last_status_active_cronjobs()
drop cascades to type zmon_utils.system_information
drop cascades to function zmon_utils.get_database_cluster_system_information()
drop cascades to view zmon_utils.last_status_active_cronjobs
DROP SCHEMA
NOTICE:  extension "plpython3u" already exists, skipping
DO
NOTICE:  language "plpythonu" does not exist, skipping
DROP LANGUAGE
NOTICE:  function plpython_call_handler() does not exist, skipping
DROP FUNCTION
NOTICE:  function plpython_inline_handler(internal) does not exist, skipping
DROP FUNCTION
NOTICE:  function plpython_validator(oid) does not exist, skipping
DROP FUNCTION
CREATE SCHEMA
GRANT
SET
CREATE TYPE
CREATE FUNCTION
CREATE FUNCTION
CREATE FUNCTION
REVOKE
CREATE VIEW
REVOKE
GRANT
GRANT
You are now connected to database "template1" as user "postgres".
NOTICE:  schema "user_management" already exists, skipping
CREATE SCHEMA
GRANT
SET
CREATE FUNCTION
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
GRANT
RESET
CREATE EXTENSION
CREATE EXTENSION
NOTICE:  extension "set_user" already exists, skipping
CREATE EXTENSION
NOTICE:  version "3.0" of extension "set_user" is already installed
ALTER EXTENSION
GRANT
GRANT
GRANT
NOTICE:  schema "metric_helpers" already exists, skipping
CREATE SCHEMA
GRANT
SET
CREATE FUNCTION
CREATE VIEW
CREATE FUNCTION
CREATE VIEW
CREATE FUNCTION
CREATE VIEW
REVOKE
GRANT
REVOKE
GRANT
RESET
You are now connected to database "registry" as user "postgres".
NOTICE:  schema "user_management" already exists, skipping
CREATE SCHEMA
GRANT
SET
CREATE FUNCTION
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
GRANT
RESET
CREATE EXTENSION
CREATE EXTENSION
NOTICE:  extension "set_user" already exists, skipping
CREATE EXTENSION
NOTICE:  version "3.0" of extension "set_user" is already installed
ALTER EXTENSION
GRANT
GRANT
GRANT
NOTICE:  schema "metric_helpers" already exists, skipping
CREATE SCHEMA
GRANT
SET
CREATE FUNCTION
CREATE VIEW
CREATE FUNCTION
CREATE VIEW
CREATE FUNCTION
CREATE VIEW
REVOKE
GRANT
REVOKE
GRANT
RESET
You are now connected to database "postgres" as user "postgres".
NOTICE:  schema "user_management" already exists, skipping
CREATE SCHEMA
GRANT
SET
CREATE FUNCTION
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
CREATE FUNCTION
REVOKE
GRANT
COMMENT
GRANT
RESET
CREATE EXTENSION
CREATE EXTENSION
NOTICE:  extension "set_user" already exists, skipping
CREATE EXTENSION
NOTICE:  version "3.0" of extension "set_user" is already installed
ALTER EXTENSION
GRANT
GRANT
GRANT
NOTICE:  schema "metric_helpers" already exists, skipping
CREATE SCHEMA
GRANT
SET
CREATE FUNCTION
CREATE VIEW
CREATE FUNCTION
CREATE VIEW
CREATE FUNCTION
CREATE VIEW
REVOKE
GRANT
REVOKE
GRANT
RESET
2023-05-05 08:13:36,461 inplace_upgrade INFO: Removing /home/postgres/pgdata/pgroot/data_old
2023-05-05 08:13:36,612 inplace_upgrade INFO: Initiating a new backup...

---

Edit:

I may have an idea: We use azure://backups/$(SCOPE)/$(PGVERSION) as backup path, and BACKUP_SCHEDULE is set to every minute. When i change spec.postgres.version to 14 the pod still starts with version 13 but PGVERSION is already set to 14 -> as it takes some time until the zalando-operator triggers the actual upgrade the backup schedule triggers a postgres 13 backup into the azure://backups/postgres-postgres/14 folder. Unsure how to work around that issue :(