cloudnative-pg icon indicating copy to clipboard operation
cloudnative-pg copied to clipboard
verified publisher icon cloudnative-pg

[Bug]: Major version upgrade timeline mismatch error

Open hasslert opened this issue 3 months ago • 4 comments

Is there an existing issue already for this bug?

  • [x] I have searched for an existing issue, and could not find anything. I believe this is a new bug.

I have read the troubleshooting guide

  • [x] I have read the troubleshooting guide and I think this is a new bug.

I am running a supported version of CloudNativePG

  • [x] I have read the troubleshooting guide and I think this is a new bug.

Contact Details

[email protected]

Version

1.27 (latest patch)

What version of Kubernetes are you using?

1.30

What is your Kubernetes environment?

Other

How did you install the operator?

OLM

What happened?

I am currently testing major version upgrades (from 16 to 17 (latest minor versions) on OpenShift . The primary (first instances as number 1) starts correctly, but the next instance doesn't start because of: FATAL: requested timeline 2 is not a child of this server's history Latest checkpoint is at 0/C0000B8 on timeline 1, but in the history of the requested timeline, the server forked off from that timeline at 0/C0000A0. (starts as number 4). I followed the instructions from the 1.27 documentation: Offline In-Place Major Upgrade via ImageCatalog. I tried this with both primaryUpdateMethod: switchover and restart; and Backups available and not and with and without parameters: max_slot_wal_keep_size: "-1"

Cluster resource

apiVersion: postgresql.cnpg.io/v1
kind: Cluster
metadata:
  labels:
    app.kubernetes.io/instance: cnpg-test-1
  name: cnpg-test-1
  namespace: cloud-native-pg-poc-staging
spec:
  imageCatalogRef:
    apiGroup: postgresql.cnpg.io
    kind: ImageCatalog
    major: 17
    name: cnpg-test-1-image-catalog
  instances: 3
  managed:
    roles:
      - comment: Database master user for database test-db-1 (No Login)
        createdb: true
        ensure: present
        inRoles:
          - pg_monitor
          - pg_signal_backend
        inherit: true
        name: test-db-1-role
        superuser: false
      - comment: Database master user for database test-db-2 (No Login)
        createdb: true
        ensure: present
        inRoles:
          - pg_monitor
          - pg_signal_backend
        inherit: true
        name: test-db-2-role
        superuser: false
      - comment: Database user
        connectionLimit: -1
        createrole: true
        ensure: present
        inRoles:
          - pg_monitor
          - pg_signal_backend
          - test-db-1
          - test-db-2
        inherit: true
        login: true
        name: testing
        passwordSecret:
          name: testing
        superuser: false
      - comment: Database user
        connectionLimit: -1
        createrole: true
        ensure: present
        inRoles:
          - pg_monitor
          - pg_signal_backend
          - test-db-2
        inherit: true
        login: true
        name: testuser2
        passwordSecret:
          name: user-credentials-testuser2
        superuser: false
  monitoring:
    enablePodMonitor: true
  plugins:
    - isWALArchiver: true
      name: barman-cloud.cloudnative-pg.io
      parameters:
        barmanObjectName: cnpg-test-1-objectstore
  postgresql:
    parameters:
      max_slot_wal_keep_size: '-1'
    shared_preload_libraries:
      - pgaudit
      - pg_stat_statements
      - pg_trgm
  primaryUpdateMethod: switchover
  primaryUpdateStrategy: unsupervised
  resources:
    limits:
      cpu: '1'
      memory: 1Gi
    requests:
      cpu: 150m
      memory: 1Gi
  storage:
    size: 1Gi

Relevant log output

{"level":"info","ts":"2025-08-26T08:18:29.979791409Z","msg":"Starting CloudNativePG Instance Manager","logger":"instance-manager","logging_pod":"cnpg-test-1-4","version":"1.27.0","build":{"Version":"1.27.0","Commit":"8b442dcc3","Date":"2025-08-12"}}
{"level":"info","ts":"2025-08-26T08:18:29.980002418Z","msg":"Checking for free disk space for WALs before starting PostgreSQL","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.344274437Z","msg":"starting tablespace manager","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.344321526Z","msg":"starting external server manager","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.344336276Z","msg":"starting controller-runtime manager","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.344584385Z","msg":"Starting EventSource","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-publication","controllerGroup":"postgresql.cnpg.io","controllerKind":"Publication","source":"kind source: *v1.Publication"}
{"level":"info","ts":"2025-08-26T08:18:30.344608795Z","msg":"Starting EventSource","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","source":"kind source: *v1.Cluster"}
{"level":"info","ts":"2025-08-26T08:18:30.344650205Z","msg":"Starting EventSource","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-database","controllerGroup":"postgresql.cnpg.io","controllerKind":"Database","source":"kind source: *v1.Database"}
{"level":"info","ts":"2025-08-26T08:18:30.344658155Z","logger":"roles_reconciler","msg":"starting up the runnable","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.344704355Z","msg":"Starting webserver","logger":"instance-manager","logging_pod":"cnpg-test-1-4","address":":8000","hasTLS":true}
{"level":"info","ts":"2025-08-26T08:18:30.344734495Z","msg":"Starting webserver","logger":"instance-manager","logging_pod":"cnpg-test-1-4","address":":9187","hasTLS":false}
{"level":"info","ts":"2025-08-26T08:18:30.344718905Z","msg":"Starting EventSource","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-subscription","controllerGroup":"postgresql.cnpg.io","controllerKind":"Subscription","source":"kind source: *v1.Subscription"}
{"level":"info","ts":"2025-08-26T08:18:30.344699655Z","msg":"Starting webserver","logger":"instance-manager","logging_pod":"cnpg-test-1-4","address":"localhost:8010","hasTLS":false}
{"level":"info","ts":"2025-08-26T08:18:30.344811934Z","msg":"Starting EventSource","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-tablespaces","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","source":"kind source: *v1.Cluster"}
{"level":"info","ts":"2025-08-26T08:18:30.344891694Z","msg":"Starting EventSource","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-external-server","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","source":"kind source: *v1.Cluster"}
{"level":"info","ts":"2025-08-26T08:18:30.344951364Z","logger":"roles_reconciler","msg":"skipping the RoleSynchronizer in replicas","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.344975044Z","logger":"roles_reconciler","msg":"setting up RoleSynchronizer loop","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.406292921Z","msg":"http: TLS handshake error from 10.129.4.198:45606: tls: no certificates configured\n"}
{"level":"info","ts":"2025-08-26T08:18:30.418394519Z","msg":"http: TLS handshake error from 10.129.4.198:45614: tls: no certificates configured\n"}
{"level":"info","ts":"2025-08-26T08:18:30.445635882Z","msg":"Starting Controller","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-external-server","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster"}
{"level":"info","ts":"2025-08-26T08:18:30.445650392Z","msg":"Starting workers","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-external-server","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","worker count":1}
{"level":"info","ts":"2025-08-26T08:18:30.445839621Z","msg":"Starting Controller","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-tablespaces","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster"}
{"level":"info","ts":"2025-08-26T08:18:30.445844541Z","msg":"Starting workers","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-tablespaces","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","worker count":1}
{"level":"info","ts":"2025-08-26T08:18:30.445842681Z","msg":"Starting Controller","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-publication","controllerGroup":"postgresql.cnpg.io","controllerKind":"Publication"}
{"level":"info","ts":"2025-08-26T08:18:30.445858261Z","msg":"Starting Controller","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster"}
{"level":"info","ts":"2025-08-26T08:18:30.445893261Z","msg":"Starting workers","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","worker count":1}
{"level":"info","ts":"2025-08-26T08:18:30.445889071Z","msg":"Starting Controller","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-subscription","controllerGroup":"postgresql.cnpg.io","controllerKind":"Subscription"}
{"level":"info","ts":"2025-08-26T08:18:30.445913791Z","msg":"Starting workers","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-subscription","controllerGroup":"postgresql.cnpg.io","controllerKind":"Subscription","worker count":1}
{"level":"info","ts":"2025-08-26T08:18:30.445877661Z","msg":"Starting workers","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-publication","controllerGroup":"postgresql.cnpg.io","controllerKind":"Publication","worker count":1}
{"level":"info","ts":"2025-08-26T08:18:30.445858231Z","msg":"Starting Controller","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-database","controllerGroup":"postgresql.cnpg.io","controllerKind":"Database"}
{"level":"info","ts":"2025-08-26T08:18:30.445941321Z","msg":"Starting workers","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-database","controllerGroup":"postgresql.cnpg.io","controllerKind":"Database","worker count":1}
{"level":"info","ts":"2025-08-26T08:18:30.469204551Z","msg":"Found previous run flag","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging"},"namespace":"cloud-native-pg-poc-staging","name":"cnpg-test-1","reconcileID":"2a706863-b400-485d-b5cf-8da5cea64f7a","logging_pod":"cnpg-test-1-4","filename":"/var/lib/postgresql/data/pgdata/cnpg_initialized-cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.471951689Z","msg":"Extracting pg_controldata information","logger":"instance-manager","logging_pod":"cnpg-test-1-4","reason":"postmaster start up"}
{"level":"info","ts":"2025-08-26T08:18:30.47413887Z","logger":"pg_controldata","msg":"pg_control version number:            1700\nCatalog version number:               202406281\nDatabase system identifier:           7542802303102705694\nDatabase cluster state:               in production\npg_control last modified:             Tue 26 Aug 2025 08:06:40 AM UTC\nLatest checkpoint location:           0/C0000B8\nLatest checkpoint's REDO location:    0/C000028\nLatest checkpoint's REDO WAL file:    00000001000000000000000C\nLatest checkpoint's TimeLineID:       1\nLatest checkpoint's PrevTimeLineID:   1\nLatest checkpoint's full_page_writes: on\nLatest checkpoint's NextXID:          0:776\nLatest checkpoint's NextOID:          16391\nLatest checkpoint's NextMultiXactId:  1\nLatest checkpoint's NextMultiOffset:  0\nLatest checkpoint's oldestXID:        722\nLatest checkpoint's oldestXID's DB:   1\nLatest checkpoint's oldestActiveXID:  776\nLatest checkpoint's oldestMultiXid:   1\nLatest checkpoint's oldestMulti's DB: 4\nLatest checkpoint's oldestCommitTsXid:0\nLatest checkpoint's newestCommitTsXid:0\nTime of latest checkpoint:            Tue 26 Aug 2025 08:06:35 AM UTC\nFake LSN counter for unlogged rels:   0/3E8\nMinimum recovery ending location:     0/0\nMin recovery ending loc's timeline:   0\nBackup start location:                0/0\nBackup end location:                  0/0\nEnd-of-backup record required:        no\nwal_level setting:                    logical\nwal_log_hints setting:                on\nmax_connections setting:              100\nmax_worker_processes setting:         32\nmax_wal_senders setting:              10\nmax_prepared_xacts setting:           0\nmax_locks_per_xact setting:           64\ntrack_commit_timestamp setting:       off\nMaximum data alignment:               8\nDatabase block size:                  8192\nBlocks per segment of large relation: 131072\nWAL block size:                       8192\nBytes per WAL segment:                16777216\nMaximum length of identifiers:        64\nMaximum columns in an index:          32\nMaximum size of a TOAST chunk:        1996\nSize of a large-object chunk:         2048\nDate/time type storage:               64-bit integers\nFloat8 argument passing:              by value\nData page checksum version:           0\nMock authentication nonce:            ed993327f8b69347fa27a17d6e41e553c448fc9f63fbf98f0fc9a80d71216916\n","pipe":"stdout","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.475073276Z","msg":"postmaster started","logger":"instance-manager","logging_pod":"cnpg-test-1-4","postMasterPID":43}
{"level":"info","ts":"2025-08-26T08:18:30.488213509Z","logger":"postgres","msg":"2025-08-26 08:18:30.488 UTC [43] LOG:  pgaudit extension initialized","pipe":"stderr","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.495899436Z","msg":"Instance is still down, will retry in 1 second","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging"},"namespace":"cloud-native-pg-poc-staging","name":"cnpg-test-1","reconcileID":"2a706863-b400-485d-b5cf-8da5cea64f7a","instance":"cnpg-test-1-4","cluster":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.502927386Z","logger":"postgres","msg":"2025-08-26 08:18:30.502 UTC [43] LOG:  redirecting log output to logging collector process","pipe":"stderr","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.502938826Z","logger":"postgres","msg":"2025-08-26 08:18:30.502 UTC [43] HINT:  Future log output will appear in directory \"/controller/log\".","pipe":"stderr","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.505114217Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:30.502 UTC","process_id":"43","session_id":"68ad6dd6.2b","session_line_num":"1","session_start_time":"2025-08-26 08:18:30 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":"2025-08-26T08:18:30.505232646Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:30.502 UTC","process_id":"43","session_id":"68ad6dd6.2b","session_line_num":"2","session_start_time":"2025-08-26 08:18:30 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"starting PostgreSQL 17.5 (Debian 17.5-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":"2025-08-26T08:18:30.505243976Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:30.503 UTC","process_id":"43","session_id":"68ad6dd6.2b","session_line_num":"3","session_start_time":"2025-08-26 08:18:30 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"listening on IPv4 address \"0.0.0.0\", port 5432","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:30.505252756Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:30.503 UTC","process_id":"43","session_id":"68ad6dd6.2b","session_line_num":"4","session_start_time":"2025-08-26 08:18:30 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"listening on IPv6 address \"::\", port 5432","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:30.505261706Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:30.504 UTC","process_id":"43","session_id":"68ad6dd6.2b","session_line_num":"5","session_start_time":"2025-08-26 08:18:30 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":"2025-08-26T08:18:30.505288256Z","logger":"postgres","msg":"2025-08-26 08:18:30.502 UTC [43] LOG:  ending log output to stderr","source":"/controller/log/postgres","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.505313296Z","logger":"postgres","msg":"2025-08-26 08:18:30.502 UTC [43] HINT:  Future log output will go to log destination \"csvlog\".","source":"/controller/log/postgres","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:30.511955088Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:30.511 UTC","process_id":"47","session_id":"68ad6dd6.2f","session_line_num":"1","session_start_time":"2025-08-26 08:18:30 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"database system was interrupted; last known up at 2025-08-26 08:06:40 UTC","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:30.737823909Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:30.737 UTC","user_name":"postgres","database_name":"postgres","process_id":"48","connection_from":"[local]","session_id":"68ad6dd6.30","session_line_num":"1","session_start_time":"2025-08-26 08:18:30 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:31.561239089Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:31.561 UTC","user_name":"postgres","database_name":"postgres","process_id":"50","connection_from":"[local]","session_id":"68ad6dd7.32","session_line_num":"1","session_start_time":"2025-08-26 08:18:31 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:31.562058585Z","msg":"Instance is still down, will retry in 1 second","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging"},"namespace":"cloud-native-pg-poc-staging","name":"cnpg-test-1","reconcileID":"af4d13d1-7da7-4921-91c8-884af9f54668","instance":"cnpg-test-1-4","cluster":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:32.107729126Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:32.107 UTC","user_name":"postgres","database_name":"postgres","process_id":"69","connection_from":"[local]","session_id":"68ad6dd8.45","session_line_num":"1","session_start_time":"2025-08-26 08:18:32 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:32.161351486Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:32.161 UTC","user_name":"postgres","database_name":"postgres","process_id":"71","connection_from":"[local]","session_id":"68ad6dd8.47","session_line_num":"1","session_start_time":"2025-08-26 08:18:32 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:32.162226522Z","msg":"Instance is still down, will retry in 1 second","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging"},"namespace":"cloud-native-pg-poc-staging","name":"cnpg-test-1","reconcileID":"e043ecc0-905f-410a-a57e-2f7253cd3092","instance":"cnpg-test-1-4","cluster":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:32.26781001Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:32.265 UTC","user_name":"postgres","database_name":"postgres","process_id":"72","connection_from":"[local]","session_id":"68ad6dd8.48","session_line_num":"1","session_start_time":"2025-08-26 08:18:32 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:32.280610615Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:32.280 UTC","user_name":"postgres","database_name":"postgres","process_id":"73","connection_from":"[local]","session_id":"68ad6dd8.49","session_line_num":"1","session_start_time":"2025-08-26 08:18:32 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:32.334850432Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:32.334 UTC","user_name":"postgres","database_name":"postgres","process_id":"74","connection_from":"[local]","session_id":"68ad6dd8.4a","session_line_num":"1","session_start_time":"2025-08-26 08:18:32 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:32.602802043Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:32.602 UTC","user_name":"postgres","database_name":"postgres","process_id":"76","connection_from":"[local]","session_id":"68ad6dd8.4c","session_line_num":"1","session_start_time":"2025-08-26 08:18:32 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:32.60360497Z","msg":"Instance is still down, will retry in 1 second","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging"},"namespace":"cloud-native-pg-poc-staging","name":"cnpg-test-1","reconcileID":"fdd5f788-5a03-40b7-bdfb-e45d09cde7ee","instance":"cnpg-test-1-4","cluster":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:32.612430702Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:32.612 UTC","user_name":"postgres","database_name":"postgres","process_id":"77","connection_from":"[local]","session_id":"68ad6dd8.4d","session_line_num":"1","session_start_time":"2025-08-26 08:18:32 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:32.987412094Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:32.987 UTC","process_id":"47","session_id":"68ad6dd6.2f","session_line_num":"2","session_start_time":"2025-08-26 08:18:30 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"00000002.history\" from archive","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:33.642838234Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:33.642 UTC","user_name":"postgres","database_name":"postgres","process_id":"100","connection_from":"[local]","session_id":"68ad6dd9.64","session_line_num":"1","session_start_time":"2025-08-26 08:18:33 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:33.643676601Z","msg":"Instance is still down, will retry in 1 second","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging"},"namespace":"cloud-native-pg-poc-staging","name":"cnpg-test-1","reconcileID":"9aca2ffa-9d14-472d-8f9c-777e084b0559","instance":"cnpg-test-1-4","cluster":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:33.667449779Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:33.667 UTC","user_name":"postgres","database_name":"postgres","process_id":"101","connection_from":"[local]","session_id":"68ad6dd9.65","session_line_num":"1","session_start_time":"2025-08-26 08:18:33 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:33.667485919Z","msg":"Unable to collect metrics","logging_pod":"cnpg-test-1-4","error":"failed to connect to `user=postgres database=postgres`: /controller/run/.s.PGSQL.5432 (/controller/run): server error: FATAL: the database system is starting up (SQLSTATE 57P03)"}
{"level":"info","ts":"2025-08-26T08:18:33.668673313Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:33.668 UTC","user_name":"postgres","database_name":"postgres","process_id":"102","connection_from":"[local]","session_id":"68ad6dd9.66","session_line_num":"1","session_start_time":"2025-08-26 08:18:33 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:33.887210937Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:33.886 UTC","user_name":"postgres","database_name":"postgres","process_id":"106","connection_from":"[local]","session_id":"68ad6dd9.6a","session_line_num":"1","session_start_time":"2025-08-26 08:18:33 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:34.142588812Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:34.142 UTC","user_name":"postgres","database_name":"postgres","process_id":"107","connection_from":"[local]","session_id":"68ad6dda.6b","session_line_num":"1","session_start_time":"2025-08-26 08:18:34 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:34.155271627Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:34.155 UTC","user_name":"postgres","database_name":"postgres","process_id":"108","connection_from":"[local]","session_id":"68ad6dda.6c","session_line_num":"1","session_start_time":"2025-08-26 08:18:34 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:34.212291693Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:34.212 UTC","user_name":"postgres","database_name":"postgres","process_id":"109","connection_from":"[local]","session_id":"68ad6dda.6d","session_line_num":"1","session_start_time":"2025-08-26 08:18:34 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:34.272465735Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:34.272 UTC","user_name":"postgres","database_name":"postgres","process_id":"111","connection_from":"[local]","session_id":"68ad6dda.6f","session_line_num":"1","session_start_time":"2025-08-26 08:18:34 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:34.273343271Z","msg":"startup probe failing","logging_pod":"cnpg-test-1-4","err":"server is alive but rejecting connections"}
{"level":"info","ts":"2025-08-26T08:18:34.357815929Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:34.357 UTC","process_id":"47","session_id":"68ad6dd6.2f","session_line_num":"3","session_start_time":"2025-08-26 08:18:30 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"starting backup recovery with redo LSN 0/C000028, checkpoint LSN 0/C0000B8, on timeline ID 1","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:34.47661541Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:34.476 UTC","user_name":"postgres","database_name":"postgres","process_id":"129","connection_from":"[local]","session_id":"68ad6dda.81","session_line_num":"1","session_start_time":"2025-08-26 08:18:34 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:34.6840243Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:34.683 UTC","user_name":"postgres","database_name":"postgres","process_id":"131","connection_from":"[local]","session_id":"68ad6dda.83","session_line_num":"1","session_start_time":"2025-08-26 08:18:34 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:34.684880837Z","msg":"Instance is still down, will retry in 1 second","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging"},"namespace":"cloud-native-pg-poc-staging","name":"cnpg-test-1","reconcileID":"b08bb172-bc90-40bc-ae22-36fb6ce060cd","instance":"cnpg-test-1-4","cluster":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:35.585891834Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:35.585 UTC","process_id":"47","session_id":"68ad6dd6.2f","session_line_num":"4","session_start_time":"2025-08-26 08:18:30 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"00000002.history\" from archive","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:35.72895295Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:35.728 UTC","user_name":"postgres","database_name":"postgres","process_id":"148","connection_from":"[local]","session_id":"68ad6ddb.94","session_line_num":"1","session_start_time":"2025-08-26 08:18:35 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:35.729823876Z","msg":"Instance is still down, will retry in 1 second","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging"},"namespace":"cloud-native-pg-poc-staging","name":"cnpg-test-1","reconcileID":"1473a2c8-5f19-4542-ae93-9637f87b194b","instance":"cnpg-test-1-4","cluster":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:35.836846448Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:35.836 UTC","user_name":"postgres","database_name":"postgres","process_id":"149","connection_from":"[local]","session_id":"68ad6ddb.95","session_line_num":"1","session_start_time":"2025-08-26 08:18:35 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:36.442123273Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:36.441 UTC","user_name":"postgres","database_name":"postgres","process_id":"150","connection_from":"[local]","session_id":"68ad6ddc.96","session_line_num":"1","session_start_time":"2025-08-26 08:18:36 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:36.453775653Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:36.453 UTC","user_name":"postgres","database_name":"postgres","process_id":"151","connection_from":"[local]","session_id":"68ad6ddc.97","session_line_num":"1","session_start_time":"2025-08-26 08:18:36 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:36.509509704Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:36.509 UTC","user_name":"postgres","database_name":"postgres","process_id":"152","connection_from":"[local]","session_id":"68ad6ddc.98","session_line_num":"1","session_start_time":"2025-08-26 08:18:36 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:36.764831739Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:36.764 UTC","user_name":"postgres","database_name":"postgres","process_id":"153","connection_from":"[local]","session_id":"68ad6ddc.99","session_line_num":"1","session_start_time":"2025-08-26 08:18:36 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:36.863057248Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:36.862 UTC","process_id":"47","session_id":"68ad6dd6.2f","session_line_num":"5","session_start_time":"2025-08-26 08:18:30 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"00000002000000000000000C\" from archive","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:36.868030386Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:36.867 UTC","process_id":"47","session_id":"68ad6dd6.2f","session_line_num":"6","session_start_time":"2025-08-26 08:18:30 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"WAL file is from different database system: WAL file database system identifier is 7537668262568423456, pg_control database system identifier is 7542802303102705694","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:36.880507733Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:36.880 UTC","process_id":"154","session_id":"68ad6ddc.9a","session_line_num":"1","session_start_time":"2025-08-26 08:18:36 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"started streaming WAL from primary at 0/C000000 on timeline 1","backend_type":"walreceiver","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:36.907645567Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:36.907 UTC","process_id":"47","session_id":"68ad6dd6.2f","session_line_num":"7","session_start_time":"2025-08-26 08:18:30 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"entering standby mode","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:36.907674587Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:36.907 UTC","process_id":"47","session_id":"68ad6dd6.2f","session_line_num":"8","session_start_time":"2025-08-26 08:18:30 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"XX000","message":"requested timeline 2 is not a child of this server's history","detail":"Latest checkpoint is at 0/C0000B8 on timeline 1, but in the history of the requested timeline, the server forked off from that timeline at 0/C0000A0.","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:36.90918886Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:36.909 UTC","process_id":"43","session_id":"68ad6dd6.2b","session_line_num":"6","session_start_time":"2025-08-26 08:18:30 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"startup process (PID 47) exited with exit code 1","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:36.90920611Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:36.909 UTC","process_id":"43","session_id":"68ad6dd6.2b","session_line_num":"7","session_start_time":"2025-08-26 08:18:30 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"aborting startup due to startup process failure","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2025-08-26T08:18:36.910578394Z","logger":"postgres","msg":"record","logging_pod":"cnpg-test-1-4","record":{"log_time":"2025-08-26 08:18:36.910 UTC","process_id":"43","session_id":"68ad6dd6.2b","session_line_num":"8","session_start_time":"2025-08-26 08:18:30 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":"2025-08-26T08:18:36.93256258Z","msg":"Instance is still down, will retry in 1 second","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging"},"namespace":"cloud-native-pg-poc-staging","name":"cnpg-test-1","reconcileID":"2df89bbf-5c92-4013-a90a-6d063e13f5e5","instance":"cnpg-test-1-4","cluster":"cnpg-test-1","namespace":"cloud-native-pg-poc-staging","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:36.962288112Z","msg":"postmaster exited","logger":"instance-manager","logging_pod":"cnpg-test-1-4","postmasterExitStatus":"exit status 1","postMasterPID":43}
{"level":"info","ts":"2025-08-26T08:18:36.962318462Z","msg":"Extracting pg_controldata information","logger":"instance-manager","logging_pod":"cnpg-test-1-4","reason":"postmaster has exited"}
{"level":"info","ts":"2025-08-26T08:18:36.964686432Z","logger":"pg_controldata","msg":"pg_control version number:            1700\nCatalog version number:               202406281\nDatabase system identifier:           7542802303102705694\nDatabase cluster state:               in production\npg_control last modified:             Tue 26 Aug 2025 08:06:40 AM UTC\nLatest checkpoint location:           0/C0000B8\nLatest checkpoint's REDO location:    0/C000028\nLatest checkpoint's REDO WAL file:    00000001000000000000000C\nLatest checkpoint's TimeLineID:       1\nLatest checkpoint's PrevTimeLineID:   1\nLatest checkpoint's full_page_writes: on\nLatest checkpoint's NextXID:          0:776\nLatest checkpoint's NextOID:          16391\nLatest checkpoint's NextMultiXactId:  1\nLatest checkpoint's NextMultiOffset:  0\nLatest checkpoint's oldestXID:        722\nLatest checkpoint's oldestXID's DB:   1\nLatest checkpoint's oldestActiveXID:  776\nLatest checkpoint's oldestMultiXid:   1\nLatest checkpoint's oldestMulti's DB: 4\nLatest checkpoint's oldestCommitTsXid:0\nLatest checkpoint's newestCommitTsXid:0\nTime of latest checkpoint:            Tue 26 Aug 2025 08:06:35 AM UTC\nFake LSN counter for unlogged rels:   0/3E8\nMinimum recovery ending location:     0/0\nMin recovery ending loc's timeline:   0\nBackup start location:                0/0\nBackup end location:                  0/0\nEnd-of-backup record required:        no\nwal_level setting:                    logical\nwal_log_hints setting:                on\nmax_connections setting:              100\nmax_worker_processes setting:         32\nmax_wal_senders setting:              10\nmax_prepared_xacts setting:           0\nmax_locks_per_xact setting:           64\ntrack_commit_timestamp setting:       off\nMaximum data alignment:               8\nDatabase block size:                  8192\nBlocks per segment of large relation: 131072\nWAL block size:                       8192\nBytes per WAL segment:                16777216\nMaximum length of identifiers:        64\nMaximum columns in an index:          32\nMaximum size of a TOAST chunk:        1996\nSize of a large-object chunk:         2048\nDate/time type storage:               64-bit integers\nFloat8 argument passing:              by value\nData page checksum version:           0\nMock authentication nonce:            ed993327f8b69347fa27a17d6e41e553c448fc9f63fbf98f0fc9a80d71216916\n","pipe":"stdout","logging_pod":"cnpg-test-1-4"}
{"level":"error","ts":"2025-08-26T08:18:36.964713812Z","msg":"PostgreSQL process exited with errors","logger":"instance-manager","logging_pod":"cnpg-test-1-4","error":"exit status 1","stacktrace":"github.com/cloudnative-pg/machinery/pkg/log.(*logger).Error\n\tpkg/mod/github.com/cloudnative-pg/[email protected]/pkg/log/log.go:125\ngithub.com/cloudnative-pg/cloudnative-pg/internal/cmd/manager/instance/run/lifecycle.(*PostgresLifecycle).Start.func1\n\tinternal/cmd/manager/instance/run/lifecycle/lifecycle.go:108\ngithub.com/cloudnative-pg/cloudnative-pg/internal/cmd/manager/instance/run/lifecycle.(*PostgresLifecycle).Start\n\tinternal/cmd/manager/instance/run/lifecycle/lifecycle.go:116\nsigs.k8s.io/controller-runtime/pkg/manager.(*runnableGroup).reconcile.func1\n\tpkg/mod/sigs.k8s.io/[email protected]/pkg/manager/runnable_group.go:226"}
{"level":"info","ts":"2025-08-26T08:18:36.964791012Z","msg":"Stopping and waiting for non leader election runnables","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:36.964805722Z","msg":"Stopping and waiting for leader election runnables","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:36.964827781Z","msg":"Shutdown signal received, waiting for all workers to finish","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-database","controllerGroup":"postgresql.cnpg.io","controllerKind":"Database"}
{"level":"info","ts":"2025-08-26T08:18:36.964833251Z","msg":"Shutdown signal received, waiting for all workers to finish","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-publication","controllerGroup":"postgresql.cnpg.io","controllerKind":"Publication"}
{"level":"info","ts":"2025-08-26T08:18:36.964840691Z","msg":"Shutdown signal received, waiting for all workers to finish","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-subscription","controllerGroup":"postgresql.cnpg.io","controllerKind":"Subscription"}
{"level":"info","ts":"2025-08-26T08:18:36.964845331Z","msg":"Shutdown signal received, waiting for all workers to finish","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster"}
{"level":"info","ts":"2025-08-26T08:18:36.964849821Z","msg":"Shutdown signal received, waiting for all workers to finish","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-tablespaces","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster"}
{"level":"info","ts":"2025-08-26T08:18:36.964855691Z","msg":"Shutdown signal received, waiting for all workers to finish","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-external-server","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster"}
{"level":"info","ts":"2025-08-26T08:18:36.964861501Z","logger":"roles_reconciler","msg":"Terminated RoleSynchronizer loop","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}
{"level":"error","ts":"2025-08-26T08:18:36.964811172Z","msg":"error received after stop sequence was engaged","logger":"instance-manager","logging_pod":"cnpg-test-1-4","error":"exit status 1","stacktrace":"sigs.k8s.io/controller-runtime/pkg/manager.(*controllerManager).engageStopProcedure.func1\n\tpkg/mod/sigs.k8s.io/[email protected]/pkg/manager/internal.go:512"}
{"level":"info","ts":"2025-08-26T08:18:36.964874661Z","msg":"Exited log pipe","logger":"instance-manager","fileName":"/controller/log/postgres","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:36.964880651Z","msg":"Exited log pipe","logger":"instance-manager","fileName":"/controller/log/postgres.json","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:36.964886871Z","msg":"Exited log pipe","logger":"instance-manager","fileName":"/controller/log/postgres.csv","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:36.964887051Z","msg":"All workers finished","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster"}
{"level":"info","ts":"2025-08-26T08:18:36.964892451Z","msg":"All workers finished","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-database","controllerGroup":"postgresql.cnpg.io","controllerKind":"Database"}
{"level":"info","ts":"2025-08-26T08:18:36.964899481Z","msg":"All workers finished","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-publication","controllerGroup":"postgresql.cnpg.io","controllerKind":"Publication"}
{"level":"info","ts":"2025-08-26T08:18:36.964902101Z","msg":"All workers finished","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-subscription","controllerGroup":"postgresql.cnpg.io","controllerKind":"Subscription"}
{"level":"info","ts":"2025-08-26T08:18:36.964905561Z","msg":"All workers finished","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-external-server","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster"}
{"level":"info","ts":"2025-08-26T08:18:36.964911591Z","msg":"All workers finished","logger":"instance-manager","logging_pod":"cnpg-test-1-4","controller":"instance-tablespaces","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster"}
{"level":"info","ts":"2025-08-26T08:18:36.965007051Z","msg":"Webserver exited","logger":"instance-manager","logging_pod":"cnpg-test-1-4","address":":9187"}
{"level":"info","ts":"2025-08-26T08:18:36.965040481Z","msg":"Webserver exited","logger":"instance-manager","logging_pod":"cnpg-test-1-4","address":"localhost:8010"}
{"level":"info","ts":"2025-08-26T08:18:36.96508012Z","msg":"Webserver exited","logger":"instance-manager","logging_pod":"cnpg-test-1-4","address":":8000"}
{"level":"info","ts":"2025-08-26T08:18:36.96509503Z","msg":"Stopping and waiting for caches","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:36.96518422Z","msg":"Stopping and waiting for webhooks","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:36.96519507Z","msg":"Stopping and waiting for HTTP servers","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:36.96520049Z","msg":"Wait completed, proceeding to shutdown the manager","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}
{"level":"info","ts":"2025-08-26T08:18:36.96521213Z","msg":"Checking for free disk space for WALs after PostgreSQL finished","logger":"instance-manager","logging_pod":"cnpg-test-1-4"}

Code of Conduct

  • [x] I agree to follow this project's Code of Conduct

hasslert avatar Aug 26 '25 08:08 hasslert

Based on everything found, this timeline mismatch error during major version upgrades from PostgreSQL 16 to 17 in CloudNativePG 1.27 does not appear to be a known or previously reported bug in the project or its WAL archiving plugins. The codebase does anticipate timeline and WAL continuity issues during upgrades, and has logic to handle and report them, but there are no documented troubleshooting steps or workarounds for this specific failure mode.

This suggests you may have encountered a new bug or an undocumented limitation in the upgrade process. The error typically means that the WAL/timeline history between instances is not perfectly aligned, which can happen if WAL archiving or restoration is incomplete or if the timeline history files are mismatched across pods. The operator's upgrade logic is designed to ensure WAL continuity and proper timeline management, but edge cases like this can still occur if something disrupts the expected flow.

If you want to dig deeper, collecting more diagnostic data about WAL archiving status and timeline history files across all instances before and after the upgrade may help pinpoint the root cause. If you need more technical details about how CloudNativePG handles WAL and timelines during upgrades, the relevant logic is in the WAL archiving and lifecycle management code (archiver.go, lifecycle.go).

Let me know if you want more details about the upgrade orchestration or specific troubleshooting steps for WAL/timeline alignment!

To reply, just mention @dosu.

How did I do? Good | Irrelevant | Incorrect | Verbose | Hallucination | Report 🐛 | Other  Chat with Dosu Join Discord Share on X

dosubot[bot] avatar Aug 26 '25 08:08 dosubot[bot]

I've upgrade from postgres 17 to 18, encountered this issue as well

xkratos avatar Sep 30 '25 02:09 xkratos

Hi guys,

Not sure it can help debugging, but upgrading from 17.5 to 18.0 doesn't work while 17.6 to 18.0 works like a charm. Here is the full yaml I'm using:

---
apiVersion: v1
kind: Namespace
metadata:
  name: demo
---
apiVersion: v1
kind: Secret
metadata:
  name: postgres-credentials-demo
  namespace: demo
stringData:
  password: demo
  username: demo
---
apiVersion: postgresql.cnpg.io/v1
kind: Cluster
metadata:
  name: postgres
  namespace: demo
spec:
  affinity:
    enablePodAntiAffinity: true
    podAntiAffinityType: required
    topologyKey: topology.kubernetes.io/zone
  bootstrap:
    initdb:
      database: demo
      owner: demo
      secret:
        name: postgres-credentials-demo
  imageName: ghcr.io/cloudnative-pg/postgresql:17.5
  inheritedMetadata:
    annotations:
      prometheus.io/port: "9187"
      prometheus.io/scrape: "true"
    labels:
      app: postgres
      app.kubernetes.io/name: postgres
  instances: 3
  managed:
    roles:
    - comment: Demo user
      ensure: present
      login: true
      name: demo
      passwordSecret:
        name: postgres-credentials-demo
      superuser: false
  postgresql:
    parameters:
      effective_cache_size: 128MB
      idle_in_transaction_session_timeout: "5000"
      maintenance_work_mem: 16MB
      max_connections: "20"
      max_slot_wal_keep_size: 32MB
      shared_buffers: 64MB
      statement_timeout: "5000"
      wal_keep_size: 32MB
      work_mem: 4MB
  resources:
    limits:
      cpu: 250m
      memory: 256Mi
    requests:
      cpu: 250m
      memory: 256Mi
  storage:
    pvcTemplate:
      accessModes:
      - ReadWriteOnce
      resources:
        requests:
          storage: 1Gi
      volumeMode: Filesystem

After digging a bit, it looks like it's due to setting max_slot_wal_keep_size, setting it even to its max 2147483647MB doesn't do the trick 🤔 On 17.6 it works with 32MB 🤷‍♂️

darkweaver87 avatar Oct 02 '25 16:10 darkweaver87

This issue is stale because it has been open for 60 days with no activity.

github-actions[bot] avatar Dec 02 '25 02:12 github-actions[bot]

This issue was closed because it has been inactive for 14 days since being marked as stale.

github-actions[bot] avatar Dec 17 '25 02:12 github-actions[bot]