Unable to restore from backups

[samip5]

Unfortunately it seems that the backed up archives are not able to be restored..

ghcr.io/tensorchord/cloudnative-pgvecto.rs:16.2-v0.2.1

Cluster CRD:

---
apiVersion: postgresql.cnpg.io/v1
kind: Cluster
metadata:
  name: cluster16-vector
  namespace: databases
spec:
  instances: 2
  imageName: ghcr.io/tensorchord/cloudnative-pgvecto.rs:16.2-v0.2.1
  primaryUpdateStrategy: unsupervised
  storage:
    size: 15Gi
    storageClass: local-hostpath
  superuserSecret:
    name: cloudnative-pg-secret
  enableSuperuserAccess: true
  resources:
    requests:
      memory: 1Gi
    limits:
      memory: 2Gi
#  bootstrap:
#    initdb:
#      postInitSQL:
#        - ALTER SYSTEM SET search_path TO "$user", public, vectors;
#        - CREATE EXTENSION IF NOT EXISTS "vectors";
  bootstrap:
    recovery:
      source: &previousCluster postgres-vector-v11
  affinity:
    enablePodAntiAffinity: true
    topologyKey: kubernetes.io/hostname
    podAntiAffinityType: required
    nodeSelector:
      kubernetes.io/arch: amd64

  postgresql:
    shared_preload_libraries:
      - "vectors.so"
    enableAlterSystem: true
    parameters:
      max_connections: "600"
      shared_buffers: 512MB
  monitoring:
    enablePodMonitor: true
    # https://github.com/cloudnative-pg/cloudnative-pg/issues/2501
    podMonitorMetricRelabelings:
        - { sourceLabels: [ "cluster" ], targetLabel: cnpg_cluster, action: replace }
        - { regex: cluster, action: labeldrop }
  backup:
    retentionPolicy: "30d"
    barmanObjectStore:
      wal:
        compression: bzip2
        maxParallel: 4
      data:
        compression: bzip2
      destinationPath: s3://cnpg-main/
      endpointURL: https://s3.skym.fi
      serverName: &currentCluster postgres-vector-v12
      s3Credentials:
        accessKeyId:
          name: cloudnative-pg-secret
          key: aws-access-key-id
        secretAccessKey:
          name: cloudnative-pg-secret
          key: aws-secret-access-key
  externalClusters:
    - name: *previousCluster
      barmanObjectStore:
        wal:
          compression: bzip2
          maxParallel: 8
        destinationPath: s3://cnpg-main/
        endpointURL: https://s3.skym.fi
        s3Credentials:
          accessKeyId:
            name: cloudnative-pg-secret
            key: aws-access-key-id
          secretAccessKey:
            name: cloudnative-pg-secret
            key: aws-secret-access-key

{"level":"info","ts":"2024-10-16T09:49:40Z","msg":"barman-cloud-check-wal-archive checking the first wal","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:49:40Z","msg":"Recovering from external cluster","logging_pod":"cluster16-vector-1-full-recovery","sourceName":"postgres-vector-v11"}
{"level":"info","ts":"2024-10-16T09:49:42Z","msg":"Target backup found","logging_pod":"cluster16-vector-1-full-recovery","backup":{"backup_name":"backup-20241016083833","backup_label":"'START WAL LOCATION: 46/8E0000E8 (file 00000007000000460000008E)\\nCHECKPOINT LOCATION: 46/8F000060\\nBACKUP METHOD: streamed\\nBACKUP FROM: standby\\nSTART TIME: 2024-10-16 08:38:34 UTC\\nLABEL: Barman backup cloud 20241016T083833\\nSTART TIMELINE: 7\\n'","begin_time":"Wed Oct 16 08:38:34 2024","end_time":"Wed Oct 16 08:38:56 2024","BeginTime":"2024-10-16T08:38:34Z","EndTime":"2024-10-16T08:38:56Z","begin_wal":"00000007000000460000008E","end_wal":"000000070000004600000090","begin_xlog":"46/8E0000E8","end_xlog":"46/90000000","systemid":"7368693795026370580","backup_id":"20241016T083833","error":"","timeline":7}}
{"level":"info","ts":"2024-10-16T09:49:42Z","msg":"Starting barman-cloud-restore","logging_pod":"cluster16-vector-1-full-recovery","options":["--endpoint-url","https://s3.skym.fi","s3://cnpg-main/","postgres-vector-v11","20241016T083833","--cloud-provider","aws-s3","/var/lib/postgresql/data/pgdata"]}
{"level":"info","ts":"2024-10-16T09:49:53Z","msg":"Restore completed","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:49:53Z","msg":"Creating new data directory","logging_pod":"cluster16-vector-1-full-recovery","pgdata":"/controller/recovery/datadir_1530716887","initDbOptions":["--username","postgres","-D","/controller/recovery/datadir_1530716887","--no-sync"]}
{"level":"info","ts":"2024-10-16T09:49:54Z","logger":"initdb","msg":"The files belonging to this database system will be owned by user \"postgres\".\nThis user must also own the server process.\n\nThe database cluster will be initialized with locale \"en_US.utf8\".\nThe default database encoding has accordingly been set to \"UTF8\".\nThe default text search configuration will be set to \"english\".\n\nData page checksums are disabled.\n\nfixing permissions on existing directory /controller/recovery/datadir_1530716887 ... ok\ncreating subdirectories ... ok\nselecting dynamic shared memory implementation ... posix\nselecting default max_connections ... 100\nselecting default shared_buffers ... 128MB\nselecting default time zone ... Etc/UTC\ncreating configuration files ... ok\nrunning bootstrap script ... ok\nperforming post-bootstrap initialization ... ok\n\nSync to disk skipped.\nThe data directory might become corrupt if the operating system crashes.\n\n\nSuccess. You can now start the database server using:\n\n    pg_ctl -D /controller/recovery/datadir_1530716887 -l logfile start\n\n","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:49:54Z","logger":"initdb","msg":"initdb: warning: enabling \"trust\" authentication for local connections\ninitdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.\n","pipe":"stderr","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:49:54Z","msg":"Installed configuration file","logging_pod":"cluster16-vector-1-full-recovery","pgdata":"/controller/recovery/datadir_1530716887","filename":"pg_hba.conf"}
{"level":"info","ts":"2024-10-16T09:49:54Z","msg":"Installed configuration file","logging_pod":"cluster16-vector-1-full-recovery","pgdata":"/controller/recovery/datadir_1530716887","filename":"pg_ident.conf"}
{"level":"info","ts":"2024-10-16T09:49:54Z","msg":"Installed configuration file","logging_pod":"cluster16-vector-1-full-recovery","pgdata":"/controller/recovery/datadir_1530716887","filename":"custom.conf"}
{"level":"info","ts":"2024-10-16T09:49:54Z","msg":"Generated recovery configuration","logging_pod":"cluster16-vector-1-full-recovery","configuration":"recovery_target_action = promote\nrestore_command = 'barman-cloud-wal-restore --endpoint-url https://s3.skym.fi s3://cnpg-main/ postgres-vector-v11 --cloud-provider aws-s3 %f %p'\n"}
{"level":"info","ts":"2024-10-16T09:49:54Z","msg":"Aligned PostgreSQL configuration to satisfy both pg_controldata and cluster spec","logging_pod":"cluster16-vector-1-full-recovery","enforcedParams":{"max_connections":"600","max_locks_per_transaction":"64","max_prepared_transactions":"0","max_wal_senders":"10","max_worker_processes":"32"},"controldataParams":{"max_connections":600,"max_locks_per_transaction":64,"max_prepared_transactions":0,"max_wal_senders":10,"max_worker_processes":32},"clusterParams":{"max_connections":600,"max_worker_processes":32}}
{"level":"info","ts":"2024-10-16T09:49:54Z","msg":"Starting up instance","logging_pod":"cluster16-vector-1-full-recovery","pgdata":"/var/lib/postgresql/data/pgdata","options":["start","-w","-D","/var/lib/postgresql/data/pgdata","-o","-c port=5432 -c unix_socket_directories=/controller/run","-t 40000000","-o","-c listen_addresses='127.0.0.1'"]}
{"level":"info","ts":"2024-10-16T09:49:54Z","logger":"pg_ctl","msg":"waiting for server to start....2024-10-16 09:49:54.578 UTC [38] LOG:  redirecting log output to logging collector process","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:49:54Z","logger":"pg_ctl","msg":"2024-10-16 09:49:54.578 UTC [38] HINT:  Future log output will appear in directory \"/controller/log\".","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:49:54Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:54.578 UTC","process_id":"38","session_id":"670f8c42.26","session_line_num":"1","session_start_time":"2024-10-16 09:49:54 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":"2024-10-16T09:49:54Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:54.578 UTC","process_id":"38","session_id":"670f8c42.26","session_line_num":"2","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"starting PostgreSQL 16.2 (Debian 16.2-1.pgdg110+2) 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":"2024-10-16T09:49:54Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:54.578 UTC","process_id":"38","session_id":"670f8c42.26","session_line_num":"3","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"listening on IPv4 address \"127.0.0.1\", port 5432","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:49:54Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:54.582 UTC","process_id":"38","session_id":"670f8c42.26","session_line_num":"4","session_start_time":"2024-10-16 09:49:54 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":"2024-10-16T09:49:54Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:54.587 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"1","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"database system was interrupted while in recovery at log time 2024-10-16 07:51:31 UTC","hint":"If this has occurred more than once some data might be corrupted and you might need to choose an earlier recovery target.","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:49:54Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:54.587 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"2","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"creating missing WAL directory \"pg_wal/archive_status\"","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:49:55Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:55.732 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"3","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"starting archive recovery","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:49:55Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:55.737 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"4","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"starting backup recovery with redo LSN 46/8E0000E8, checkpoint LSN 46/8F000060, on timeline ID 7","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:49:56Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:56.254 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"5","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"00000007.history\" from archive","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:49:56Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:56.852 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"6","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"00000007000000460000008F\" from archive","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:49:57Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:57.509 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"7","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"00000007000000460000008E\" from archive","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:49:58Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:58.720 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"8","session_start_time":"2024-10-16 09:49:54 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"redo starts at 46/8E0000E8","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:49:59Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:59.270 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"9","session_start_time":"2024-10-16 09:49:54 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"00000007000000460000008F\" from archive","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:49:59Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:59.831 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"10","session_start_time":"2024-10-16 09:49:54 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"completed backup recovery with redo LSN 46/8E0000E8 and end LSN 46/90000000","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:49:59Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:59.831 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"11","session_start_time":"2024-10-16 09:49:54 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"consistent recovery state reached at 46/90000000","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:49:59Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:49:59.831 UTC","process_id":"38","session_id":"670f8c42.26","session_line_num":"5","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"database system is ready to accept read-only connections","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:49:59Z","logger":"pg_ctl","msg":"..... done","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:49:59Z","logger":"pg_ctl","msg":"server started","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:00Z","msg":"Checking if the server is still in recovery","logging_pod":"cluster16-vector-1-full-recovery","recovery":true}
{"level":"info","ts":"2024-10-16T09:50:00Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:00.316 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"12","session_start_time":"2024-10-16 09:49:54 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"redo done at 46/8F000110 system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 1.59 s","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:00Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:00.957 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"13","session_start_time":"2024-10-16 09:49:54 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"00000007000000460000008F\" from archive","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:01Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:01.506 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"14","session_start_time":"2024-10-16 09:49:54 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"selected new timeline ID: 8","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:02Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:02.112 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"15","session_start_time":"2024-10-16 09:49:54 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"00000007.history\" from archive","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:02Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:02.120 UTC","process_id":"42","session_id":"670f8c42.2a","session_line_num":"16","session_start_time":"2024-10-16 09:49:54 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive recovery complete","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:02Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:02.122 UTC","process_id":"40","session_id":"670f8c42.28","session_line_num":"1","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"checkpoint starting: end-of-recovery immediate wait","backend_type":"checkpointer","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:02Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:02.132 UTC","process_id":"40","session_id":"670f8c42.28","session_line_num":"2","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"checkpoint complete: wrote 2 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.004 s, total=0.013 s; sync files=3, longest=0.002 s, average=0.002 s; distance=32767 kB, estimate=32767 kB; lsn=46/90000028, redo lsn=46/90000028","backend_type":"checkpointer","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:02Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:02.138 UTC","process_id":"38","session_id":"670f8c42.26","session_line_num":"6","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"database system is ready to accept connections","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:02Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:02.139 UTC","process_id":"85","session_id":"670f8c4a.55","session_line_num":"1","session_start_time":"2024-10-16 09:50:02 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:03Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:03.140 UTC","process_id":"85","session_id":"670f8c4a.55","session_line_num":"2","session_start_time":"2024-10-16 09:50:02 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:04Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:04.141 UTC","process_id":"85","session_id":"670f8c4a.55","session_line_num":"3","session_start_time":"2024-10-16 09:50:02 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:04Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:04.141 UTC","process_id":"85","session_id":"670f8c4a.55","session_line_num":"4","session_start_time":"2024-10-16 09:50:02 UTC","transaction_id":"0","error_severity":"WARNING","sql_state_code":"01000","message":"archiving write-ahead log file \"00000008.history\" failed too many times, will try again later","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:05Z","msg":"Checking if the server is still in recovery","logging_pod":"cluster16-vector-1-full-recovery","recovery":false}
{"level":"info","ts":"2024-10-16T09:50:05Z","logger":"pg_ctl","msg":"pg_ctl: server is running (PID: 38)\n/usr/lib/postgresql/16/bin/postgres \"-D\" \"/var/lib/postgresql/data/pgdata\" \"-c\" \"port=5432\" \"-c\" \"unix_socket_directories=/controller/run\" \"-c\" \"listen_addresses=127.0.0.1\"\n","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:05Z","msg":"Shutting down instance","logging_pod":"cluster16-vector-1-full-recovery","pgdata":"/var/lib/postgresql/data/pgdata","mode":"fast","timeout":null}
{"level":"info","ts":"2024-10-16T09:50:05Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:05.047 UTC","process_id":"38","session_id":"670f8c42.26","session_line_num":"7","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"received fast shutdown request","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:05Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:05.049 UTC","process_id":"38","session_id":"670f8c42.26","session_line_num":"8","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"aborting any active transactions","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:05Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:05.050 UTC","process_id":"38","session_id":"670f8c42.26","session_line_num":"9","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"background worker \"logical replication launcher\" (PID 86) exited with exit code 1","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:05Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:05.052 UTC","process_id":"40","session_id":"670f8c42.28","session_line_num":"3","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"shutting down","backend_type":"checkpointer","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:05Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:05.129 UTC","process_id":"85","session_id":"670f8c4a.55","session_line_num":"5","session_start_time":"2024-10-16 09:50:02 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:05Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:05.129 UTC","process_id":"40","session_id":"670f8c42.28","session_line_num":"4","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"checkpoint starting: shutdown immediate","backend_type":"checkpointer","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:05Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:05.199 UTC","process_id":"40","session_id":"670f8c42.28","session_line_num":"5","session_start_time":"2024-10-16 09:49:54 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"checkpoint complete: wrote 0 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.071 s; sync files=0, longest=0.000 s, average=0.000 s; distance=16384 kB, estimate=31129 kB; lsn=46/91000028, redo lsn=46/91000028","backend_type":"checkpointer","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:05Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:05.202 UTC","process_id":"85","session_id":"670f8c4a.55","session_line_num":"6","session_start_time":"2024-10-16 09:50:02 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:06Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:06.203 UTC","process_id":"85","session_id":"670f8c4a.55","session_line_num":"7","session_start_time":"2024-10-16 09:50:02 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:06Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:06.203 UTC","process_id":"85","session_id":"670f8c4a.55","session_line_num":"8","session_start_time":"2024-10-16 09:50:02 UTC","transaction_id":"0","error_severity":"WARNING","sql_state_code":"01000","message":"archiving write-ahead log file \"00000008.history\" failed too many times, will try again later","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:06Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:06.204 UTC","process_id":"85","session_id":"670f8c4a.55","session_line_num":"9","session_start_time":"2024-10-16 09:50:02 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:07Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:07.205 UTC","process_id":"85","session_id":"670f8c4a.55","session_line_num":"10","session_start_time":"2024-10-16 09:50:02 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.206 UTC","process_id":"85","session_id":"670f8c4a.55","session_line_num":"11","session_start_time":"2024-10-16 09:50:02 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.206 UTC","process_id":"85","session_id":"670f8c4a.55","session_line_num":"12","session_start_time":"2024-10-16 09:50:02 UTC","transaction_id":"0","error_severity":"WARNING","sql_state_code":"01000","message":"archiving write-ahead log file \"00000008.history\" failed too many times, will try again later","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.216 UTC","process_id":"38","session_id":"670f8c42.26","session_line_num":"10","session_start_time":"2024-10-16 09:49:54 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":"2024-10-16T09:50:08Z","logger":"pg_ctl","msg":"waiting for server to shut down....... done","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"pg_ctl","msg":"server stopped","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:08Z","msg":"Exited log pipe","fileName":"/controller/log/postgres.csv","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:08Z","msg":"Updated replication settings","logging_pod":"cluster16-vector-1-full-recovery","filename":"override.conf"}
{"level":"info","ts":"2024-10-16T09:50:08Z","msg":"Starting up instance","logging_pod":"cluster16-vector-1-full-recovery","pgdata":"/var/lib/postgresql/data/pgdata","options":["start","-w","-D","/var/lib/postgresql/data/pgdata","-o","-c port=5432 -c unix_socket_directories=/controller/run","-t 40000000","-o","-c listen_addresses='127.0.0.1'"]}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"pg_ctl","msg":"waiting for server to start....2024-10-16 09:50:08.321 UTC [102] LOG:  redirecting log output to logging collector process","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"pg_ctl","msg":"2024-10-16 09:50:08.321 UTC [102] HINT:  Future log output will appear in directory \"/controller/log\".","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.321 UTC","process_id":"102","session_id":"670f8c50.66","session_line_num":"1","session_start_time":"2024-10-16 09:50:08 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":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.321 UTC","process_id":"102","session_id":"670f8c50.66","session_line_num":"2","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"starting PostgreSQL 16.2 (Debian 16.2-1.pgdg110+2) 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":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.321 UTC","process_id":"102","session_id":"670f8c50.66","session_line_num":"3","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"listening on IPv4 address \"127.0.0.1\", port 5432","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.324 UTC","process_id":"102","session_id":"670f8c50.66","session_line_num":"4","session_start_time":"2024-10-16 09:50:08 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":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.329 UTC","process_id":"106","session_id":"670f8c50.6a","session_line_num":"1","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"database system was shut down at 2024-10-16 09:50:05 UTC","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.334 UTC","process_id":"102","session_id":"670f8c50.66","session_line_num":"5","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"database system is ready to accept connections","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.335 UTC","process_id":"114","session_id":"670f8c50.72","session_line_num":"1","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"pg_ctl","msg":" done","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"pg_ctl","msg":"server started","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:08Z","msg":"Configuring new PostgreSQL instance","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:08Z","msg":"Executing post-init SQL instructions","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:08Z","msg":"Executing post-init template SQL instructions","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"pg_ctl","msg":"pg_ctl: server is running (PID: 102)\n/usr/lib/postgresql/16/bin/postgres \"-D\" \"/var/lib/postgresql/data/pgdata\" \"-c\" \"port=5432\" \"-c\" \"unix_socket_directories=/controller/run\" \"-c\" \"listen_addresses=127.0.0.1\"\n","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:08Z","msg":"Shutting down instance","logging_pod":"cluster16-vector-1-full-recovery","pgdata":"/var/lib/postgresql/data/pgdata","mode":"fast","timeout":null}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.488 UTC","process_id":"102","session_id":"670f8c50.66","session_line_num":"6","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"received fast shutdown request","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.490 UTC","process_id":"102","session_id":"670f8c50.66","session_line_num":"7","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"aborting any active transactions","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.492 UTC","process_id":"102","session_id":"670f8c50.66","session_line_num":"8","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"background worker \"logical replication launcher\" (PID 115) exited with exit code 1","backend_type":"postmaster","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.494 UTC","process_id":"104","session_id":"670f8c50.68","session_line_num":"1","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"shutting down","backend_type":"checkpointer","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:08Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:08.565 UTC","process_id":"104","session_id":"670f8c50.68","session_line_num":"2","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"checkpoint starting: shutdown immediate","backend_type":"checkpointer","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:09Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:09.336 UTC","process_id":"114","session_id":"670f8c50.72","session_line_num":"2","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:09Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:09.603 UTC","process_id":"104","session_id":"670f8c50.68","session_line_num":"3","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.002 s, sync=0.004 s, total=1.041 s; sync files=4, longest=0.002 s, average=0.001 s; distance=16384 kB, estimate=16384 kB; lsn=46/92000028, redo lsn=46/92000028","backend_type":"checkpointer","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:09Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:09.606 UTC","process_id":"114","session_id":"670f8c50.72","session_line_num":"3","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:09Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:09.606 UTC","process_id":"114","session_id":"670f8c50.72","session_line_num":"4","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"WARNING","sql_state_code":"01000","message":"archiving write-ahead log file \"00000008.history\" failed too many times, will try again later","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:09Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:09.607 UTC","process_id":"114","session_id":"670f8c50.72","session_line_num":"5","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:10Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:10.608 UTC","process_id":"114","session_id":"670f8c50.72","session_line_num":"6","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:11Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:11.609 UTC","process_id":"114","session_id":"670f8c50.72","session_line_num":"7","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"archive command failed with exit code 1","detail":"The failed archive command was: false","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:11Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:11.609 UTC","process_id":"114","session_id":"670f8c50.72","session_line_num":"8","session_start_time":"2024-10-16 09:50:08 UTC","transaction_id":"0","error_severity":"WARNING","sql_state_code":"01000","message":"archiving write-ahead log file \"00000008.history\" failed too many times, will try again later","backend_type":"archiver","query_id":"0"}}
{"level":"info","ts":"2024-10-16T09:50:11Z","logger":"postgres","msg":"record","logging_pod":"cluster16-vector-1-full-recovery","record":{"log_time":"2024-10-16 09:50:11.619 UTC","process_id":"102","session_id":"670f8c50.66","session_line_num":"9","session_start_time":"2024-10-16 09:50:08 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":"2024-10-16T09:50:11Z","logger":"pg_ctl","msg":"waiting for server to shut down....... done","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:11Z","logger":"pg_ctl","msg":"server stopped","pipe":"stdout","logging_pod":"cluster16-vector-1-full-recovery"}
{"level":"info","ts":"2024-10-16T09:50:11Z","msg":"Exited log pipe","fileName":"/controller/log/postgres.csv","logging_pod":"cluster16-vector-1-full-recovery"}

[bo0tzz]

There's errors in there, but none that are particularly clear about what's going on (as far as I can see). Can you give some more detail about what the Cluster resource does, jobs/pods that are going around, logs from the cnpg operator, etc?

[samip5]

I think this is the problem of the name being too long?

[VoVAllen]

We have patched it in tensorchord/pgvecto.rs#588. However updating version with immich database is quite complicated. We'll work with immich when we have a new production release ready

[bw210343]

Encountered this issue today after deleting a cloudpg pod & pvc.

{"level":"info","ts":"2024-11-30T09:31:26.034648069Z","logger":"pg_basebackup","msg":"pg_basebackup: error: backup failed: ERROR:  file name too long for tar format: \"pg_vectors/indexes/000000000000000000000000000000006747a0ed798020150000400100019e7d/segments/2b3bf6d0-682c-4488-bf92-f2ef6c500353\"","pipe":"stderr","logging_pod":"cloudpg-immich-cluster-4-join"}

Thanks for for patching. It looks like the fix is in 0.4.0 but as yet immich only supports < 0.4.0. I tried, it wouldn't start 😢 .

I have database dumps for a full restore so all is good. Just wondering if it would it be possible to fix on 0.3.0 also? Thanks!

[VoVAllen]

@beyondwatts Are you experiencing problem at restore or backup?

[bw210343]

This was after deleting a pod & pvc in the cluster so I guess restoring

[syntax922]

Came here after running into the same issue, for the same reason (immich only supporting <0.4.0) and my HA postgres deployment can't scale or recover a secondary node because of this error.

[hagak]

Seeing the same issue, even tried recovering with 0.4.0 and same error. I suspect because that fix is for going forward?

Is the only way forward to recover to a single pod instance (which works fine) Create a new cluster and do pg_dumps from the old to the new one?

[VoVAllen]

@hagak You can just drop all the vector index and rebuild them.

[hagak]

@hagak You can just drop all the vector index and rebuild them.

Any info on this procedure? Do I just drop the index via sql on the single instance that came up and the replicas will then start up? After that just add the vector index back?

[hagak]

@VoVAllen So I deployed a single CNPG instance from backup and it starts. I then deleted the 2 vector indexes I could find in immich db. Then tried to deploy a replicate instance and same file name too long error.

The two indexes i found are under the "face_search" and "smart_search" tables. Did I miss one?

[whezzel]

@hagak, I'm not a db expert and used the help of grok to resolve this issue. Make sure you have backups.

For context, this is the error i was getting when trying to rebuild my cluster:

pg_basebackup: error: backup failed: ERROR: file name too long for tar format: "pg_vectors/indexes/000000000000000000000000000000006797019500ff10200000419800004672/segments/fda89865-9b1c-4838-92c7-0d6e44c1abaf"

i started my cluster with 1 instance, let it rebuild from s3, then i searched for indexes with:

SELECT indexname, indexdef, schemaname
FROM pg_indexes
WHERE indexdef ILIKE '%USING vectors%';

and got the following output:

indexname  |                                                        indexdef                                                        | schemaname
------------+------------------------------------------------------------------------------------------------------------------------+------------
 clip_index | CREATE INDEX clip_index ON public.smart_search USING vectors (embedding vector_cos_ops) WITH (options='[indexing.hnsw]+| public
            | m = 16                                                                                                                +|
            | ef_construction = 300')                                                                                                |
 face_index | CREATE INDEX face_index ON public.face_search USING vectors (embedding vector_cos_ops) WITH (options='[indexing.hnsw] +| public
            | m = 16                                                                                                                +|
            | ef_construction = 300')                                                                                                |
(2 rows)

I dropped the 2 indexes with:

DROP INDEX public.clip_index;
DROP INDEX public.face_index;

i was then able to scale up the number of instances without error. After verifying immich was running as expected, i recreated the indexes with:

CREATE INDEX clip_index ON public.smart_search USING vectors (embedding vector_cos_ops) WITH (options = $$
[indexing.hnsw]
m=16
ef_construction=300
$$);

and

CREATE INDEX face_index ON public.face_search USING vectors (embedding vector_cos_ops) WITH (options = $$
[indexing.hnsw]
m=16
ef_construction=300
$$);

If anyone here, with more knowledge, notices anything wrong about this, please let me know so I can correct it.