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

Published 20 hours ago • verified publisher icon cloudnative-pg

[Bug]: Node fails to start after reboot

Open kfkawalec opened this issue 2 years ago • 9 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

No response

Version

1.20.3

What version of Kubernetes are you using?

1.26

What is your Kubernetes environment?

Self-managed: kind (evaluation)

How did you install the operator?

YAML manifest

What happened?

After rebooting one of the nodes, it will not start. I tried to read something from the logs but I cannot find the reason (and a way to fix it).

Cluster resource

No response

Relevant log output

{"level":"info","ts":"2023-11-15T07:03:42Z","logger":"setup","msg":"Starting CloudNativePG Instance Manager","logging_pod":"pgsql15-3","version":"1.20.2","build":{"Version":"1.20.2","Commit":"6f7f10b7","Date":"2023-07-27"}}
2023-11-15T08:03:42.742170040+01:00 {"level":"info","ts":"2023-11-15T07:03:42Z","logger":"setup","msg":"starting controller-runtime manager","logging_pod":"pgsql15-3"}
2023-11-15T08:03:42.742336360+01:00 {"level":"info","ts":"2023-11-15T07:03:42Z","msg":"Starting EventSource","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","source":"kind source: *v1.Cluster"}
{"level":"info","ts":"2023-11-15T07:03:42Z","msg":"Starting Controller","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster"}
2023-11-15T08:03:42.742711670+01:00 {"level":"info","ts":"2023-11-15T07:03:42Z","msg":"Starting webserver","logging_pod":"pgsql15-3","address":":9187"}
2023-11-15T08:03:42.743284866+01:00 {"level":"info","ts":"2023-11-15T07:03:42Z","logger":"roles_reconciler","msg":"starting up the runnable","logging_pod":"pgsql15-3"}
2023-11-15T08:03:42.743308185+01:00 {"level":"info","ts":"2023-11-15T07:03:42Z","logger":"roles_reconciler","msg":"skipping the RoleSynchronizer in replicas","logging_pod":"pgsql15-3"}
2023-11-15T08:03:42.743323992+01:00 {"level":"info","ts":"2023-11-15T07:03:42Z","msg":"Starting webserver","logging_pod":"pgsql15-3","address":"localhost:8010"}
2023-11-15T08:03:42.743542146+01:00 {"level":"info","ts":"2023-11-15T07:03:42Z","logger":"roles_reconciler","msg":"setting up RoleSynchronizer loop","logging_pod":"pgsql15-3"}
2023-11-15T08:03:42.743566374+01:00 {"level":"info","ts":"2023-11-15T07:03:42Z","msg":"Starting webserver","logging_pod":"pgsql15-3","address":":8000"}
2023-11-15T08:03:42.845851217+01:00 {"level":"info","ts":"2023-11-15T07:03:42Z","msg":"Starting workers","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","worker count":1}
{"level":"info","ts":"2023-11-15T07:03:42Z","msg":"Found previous run flag","logging_pod":"pgsql15-3","filename":"/var/lib/postgresql/data/pgdata/cnpg_initialized-pgsql15-3"}
2023-11-15T08:03:42.932422176+01:00 {"level":"info","ts":"2023-11-15T07:03:42Z","msg":"Extracting pg_controldata information","logging_pod":"pgsql15-3","reason":"postmaster start up"}
2023-11-15T08:03:42.934574796+01:00 {"level":"info","ts":"2023-11-15T07:03:42Z","logger":"pg_controldata","msg":"pg_control version number:            1300\nCatalog version number:               202209061\nDatabase system identifier:           7227586665997950999\nDatabase cluster state:               shut down in recovery\npg_control last modified:             Tue 14 Nov 2023 10:39:59 PM UTC\nLatest checkpoint location:           CA/33010BB8\nLatest checkpoint's REDO location:    CA/33010B80\nLatest checkpoint's REDO WAL file:    0000000A000000CA00000033\nLatest checkpoint's TimeLineID:       10\nLatest checkpoint's PrevTimeLineID:   10\nLatest checkpoint's full_page_writes: on\nLatest checkpoint's NextXID:          0:714194\nLatest checkpoint's NextOID:          50629\nLatest checkpoint's NextMultiXactId:  3144\nLatest checkpoint's NextMultiOffset:  6295\nLatest checkpoint's oldestXID:        716\nLatest checkpoint's oldestXID's DB:   1\nLatest checkpoint's oldestActiveXID:  714194\nLatest checkpoint's oldestMultiXid:   1\nLatest checkpoint's oldestMulti's DB: 1\nLatest checkpoint's oldestCommitTsXid:0\nLatest checkpoint's newestCommitTsXid:0\nTime of latest checkpoint:            Mon 13 Nov 2023 07:06:30 PM UTC\nFake LSN counter for unlogged rels:   0/3E8\nMinimum recovery ending location:     CA/35000000\nMin recovery ending loc's timeline:   10\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:            1527c7c996593b2ba147d001a5fd50051eefe2ee208395d490d357f44029e3f1\n","pipe":"stdout","logging_pod":"pgsql15-3"}
2023-11-15T08:03:42.934651561+01:00 {"level":"info","ts":"2023-11-15T07:03:42Z","msg":"The PID file content is wrong, deleting it and assuming it's stale","file":"/var/lib/postgresql/data/pgdata/postmaster.pid","logging_pod":"pgsql15-3","err":"file does not exist","pidFileContents":""}
2023-11-15T08:03:42.996000544+01:00 {"level":"info","ts":"2023-11-15T07:03:42Z","msg":"Instance is still down, will retry in 1 second","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"pgsql15","namespace":"services-postgresql"},"namespace":"services-postgresql","name":"pgsql15","reconcileID":"de892087-34d7-4b8f-a44f-ee40c57c1227","uuid":"1c94aeca-8385-11ee-b613-5e21884c1f50","logging_pod":"pgsql15-3"}
2023-11-15T08:03:43.005810907+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"2023-11-15 08:03:43.005 CET [24] LOG:  redirecting log output to logging collector process","pipe":"stderr","logging_pod":"pgsql15-3"}
2023-11-15T08:03:43.005862850+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"2023-11-15 08:03:43.005 CET [24] HINT:  Future log output will appear 
in directory \"/controller/log\".","pipe":"stderr","logging_pod":"pgsql15-3"}
2023-11-15T08:03:43.007300860+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:43.005 CET","process_id":"24","session_id":"65546d4e.18","session_line_num":"1","session_start_time":"2023-11-15 08:03:42 CET","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"}}
2023-11-15T08:03:43.007345782+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:43.005 CET","process_id":"24","session_id":"65546d4e.18","session_line_num":"2","session_start_time":"2023-11-15 08:03:42 CET","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"starting PostgreSQL 15.4 (Debian 15.4-2.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"}}
2023-11-15T08:03:43.007357171+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:43.005 CET","process_id":"24","session_id":"65546d4e.18","session_line_num":"3","session_start_time":"2023-11-15 08:03:42 CET","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"}}
2023-11-15T08:03:43.007366174+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:43.005 CET","process_id":"24","session_id":"65546d4e.18","session_line_num":"4","session_start_time":"2023-11-15 08:03:42 CET","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"listenin
g on IPv6 address \"::\", port 5432","backend_type":"postmaster","query_id":"0"}}
2023-11-15T08:03:43.007455479+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"2023-11-15 08:03:43.005 CET [24] LOG:  ending log output to stderr","source":"/controller/log/postgres","logging_pod":"pgsql15-3"}
2023-11-15T08:03:43.007503716+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"2023-11-15 08:03:43.005 CET [24] HINT:  Future log output will go to log destination \"csvlog\".","source":"/controller/log/postgres","logging_pod":"pgsql15-3"}
2023-11-15T08:03:43.008916700+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:43.008 CET","process_id":"24","session_id":"65546d4e.18","session_line_num":"5","session_start_time":"2023-11-15 08:03:42 CET","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"}}
2023-11-15T08:03:43.018218862+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:43.017 CET","process_id":"28","session_id":"65546d4f.1c","session_line_num":"1","session_start_time":"2023-11-15 08:03:43 CET","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"database system was shut down in recovery at 2023-11-14 23:39:59 CET","backend_type":"startup","query_id":"0"}}
2023-11-15T08:03:43.438842275+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:43.438 CET","user_name":"postgres","database_name":"postgres","process_id":"42","connection_from":"[local]","session_id":"65546d4f.2a","session_line_num":"1","session_start_time":"2023-11-15 08:03:43 CET","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"th
e database system is starting up","backend_type":"client backend","query_id":"0"}}
{"level":"info","ts":"2023-11-15T07:03:43Z","msg":"Instance status probe failing","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:43.457027227+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:43.456 CET","user_name":"postgres","database_name":"postgres","process_id":"43","connection_from":"[local]","session_id":"65546d4f.2b","session_line_num":"1","session_start_time":"2023-11-15 08:03:43 CET","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
2023-11-15T08:03:43.457071559+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","msg":"Readiness probe failing","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:43.719088641+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","msg":"Instance status probe failing","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:43.719264298+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:43.718 CET","user_name":"postgres","database_name":"postgres","process_id":"44","connection_from":"[local]","session_id":"65546d4f.2c","session_line_num":"1","session_start_time":"2023-11-15 08:03:43 CET","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
2023-11-15T08:03:43.733528651+01:00 {"
level":"info","ts":"2023-11-15T07:03:43Z","msg":"Instance status probe failing","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:43.733631521+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:43.733 CET","user_name":"postgres","database_name":"postgres","process_id":"45","connection_from":"[local]","session_id":"65546d4f.2d","session_line_num":"1","session_start_time":"2023-11-15 08:03:43 CET","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
2023-11-15T08:03:43.789723364+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","msg":"Instance status probe failing","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:43.790056753+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:43.789 CET","user_name":"postgres","database_name":"postgres","process_id":"46","connection_from":"[local]","session_id":"65546d4f.2e","session_line_num":"1","session_start_time":"2023-11-15 08:03:43 CET","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
2023-11-15T08:03:43.875876807+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"wal-restore","msg":"Restored WAL file","logging_pod":"pgsql15-3","walName":"0000000B.history","startTime":"2023-11-15T07:03:43Z","endTime":"2023-11-15T07:03:43Z","elapsedWalTime":0.661408141}
2023-11-15T08:03:43.875926647+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"wa
l-restore","msg":"WAL restore command completed (parallel)","logging_pod":"pgsql15-3","walName":"0000000B.history","maxParallel":1,"successfulWalRestore":1,"failedWalRestore":0,"endOfWALStream":false,"startTime":"2023-11-15T07:03:43Z","downloadStartTime":"2023-11-15T07:03:43Z","downloadTotalTime":0.661714141,"totalTime":0.822255043}
2023-11-15T08:03:43.879204398+01:00 {"level":"info","ts":"2023-11-15T07:03:43Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:43.878 CET","process_id":"28","session_id":"65546d4f.1c","session_line_num":"2","session_start_time":"2023-11-15 08:03:43 CET","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"0000000B.history\" from archive","backend_type":"startup","query_id":"0"}}
2023-11-15T08:03:44.050955884+01:00 {"level":"info","ts":"2023-11-15T07:03:44Z","msg":"Instance status probe failing","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:44.051059686+01:00 {"level":"info","ts":"2023-11-15T07:03:44Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:44.050 CET","user_name":"postgres","database_name":"postgres","process_id":"59","connection_from":"[local]","session_id":"65546d50.3b","session_line_num":"1","session_start_time":"2023-11-15 08:03:44 CET","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
2023-11-15T08:03:44.062130205+01:00 {"level":"info","ts":"2023-11-15T07:03:44Z","msg":"Readiness probe failing","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:44.062987695+01:00 {"level":"info","ts":"2023-11-15T07:03:44
Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:44.061 CET","user_name":"postgres","database_name":"postgres","process_id":"60","connection_from":"[local]","session_id":"65546d50.3c","session_line_num":"1","session_start_time":"2023-11-15 08:03:44 CET","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
2023-11-15T08:03:44.134314867+01:00 {"level":"info","ts":"2023-11-15T07:03:44Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:44.133 CET","user_name":"postgres","database_name":"postgres","process_id":"63","connection_from":"[local]","session_id":"65546d50.3f","session_line_num":"1","session_start_time":"2023-11-15 08:03:44 CET","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
2023-11-15T08:03:44.137014323+01:00 {"level":"info","ts":"2023-11-15T07:03:44Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"pgsql15","namespace":"services-postgresql"},"namespace":"services-postgresql","name":"pgsql15","reconcileID":"87c09a80-919d-4198-8207-1028f570a1bf","uuid":"1d4434ec-8385-11ee-b613-5e21884c1f50","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:44.137105474+01:00 {"level":"info","ts":"2023-11-15T07:03:44Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:44.136 CET","user_name":"postgres","database_name":"postgres","process_id":"64","connection_from":"[local]","session_id":"65546d50.40","session_line_num":"1","session_start_time":"2023-11-15 08:03:44 CET","transaction_id":"0","error_sev
erity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
2023-11-15T08:03:44.392636792+01:00 {"level":"info","ts":"2023-11-15T07:03:44Z","msg":"Unable to collect metrics","logging_pod":"pgsql15-3","error":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:44.392751926+01:00 {"level":"info","ts":"2023-11-15T07:03:44Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:44.392 CET","user_name":"postgres","database_name":"postgres","process_id":"65","connection_from":"[local]","session_id":"65546d50.41","session_line_num":"1","session_start_time":"2023-11-15 08:03:44 CET","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is starting up","backend_type":"client backend","query_id":"0"}}
2023-11-15T08:03:44.394269768+01:00 {"level":"info","ts":"2023-11-15T07:03:44Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:44.393 CET","user_name":"postgres","database_name":"postgres","process_id":"66","connection_from":"[local]","session_id":"65546d50.42","session_line_num":"1","session_start_time":"2023-11-15 08:03:44 CET","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":"2023-11-15T07:03:44Z","msg":"Readiness probe failing","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:44.462981406+01:00 {"level":"info","ts":"2023-11-15T07:03:44Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:44.462 CET","user_name":"postgres","database_name":"postgres","process_id":"67","connection_from":"[local]","session_id":"65546d50.43","session_line_num":"1","session_start_time":"2023-11-15 08:03:44 CET","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":"2023-11-15T07:03:44Z","logger":"wal-restore","msg":"Restored WAL file","logging_pod":"pgsql15-3","walName":"0000000C.history","startTime":"2023-11-15T07:03:44Z","endTime":"2023-11-15T07:03:44Z","elapsedWalTime":0.700228542}
2023-11-15T08:03:44.779809781+01:00 {"level":"info","ts":"2023-11-15T07:03:44Z","logger":"wal-restore","msg":"WAL restore command completed (parallel)","logging_pod":"pgsql15-3","walName":"0000000C.history","maxParallel":1,"successfulWalRestore":1,"failedWalRestore":0,"endOfWALStream":false,"startTime":"2023-11-15T07:03:43Z","downloadStartTime":"2023-11-15T07:03:44Z","downloadTotalTime":0.700498522,"totalTime":0.855732874}
{"level":"info","ts":"2023-11-15T07:03:44Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:44.783 CET","process_id":"28","session_id":"65546d4f.1c","session_line_num":"3","session_start_time":"2023-11-15 08:03:43 CET","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"0000000C.history\" from archive","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-15T07:03:45Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:45.254 CET","user_name":"postgres","database_name":"postgres","process_id":"82","connection_from":"[local]","session_id":"65546d51.52","session_line_num":"1","session_start_time":"2023-11-15 08:03:45 CET","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":"2023-11-15T07:03:45Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"pgsql15","namespace":"services-postgresql"},"namespace":"services-postgresql","name":"pgsql15","reconcileID":"49ed8d65-a36d-48f6-91fd-ae55dde738d8","uuid":"1df24ed2-8385-11ee-b613-5e21884c1f50","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:45.258140790+01:00 {"level":"info","ts":"2023-11-15T07:03:45Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:45.257 CET","user_name":"postgres","database_name":"postgres","process_id":"83","connection_from":"[local]","session_id":"65546d51.53","session_line_num":"1","session_start_time":"2023-11-15 08:03:45 CET","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":"2023-11-15T07:03:45Z","msg":"Instance status probe failing","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:45.361506337+01:00 {"level":"info","ts":"2023-11-15T07:03:45Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:45.360 CET","user_name":"postgres","database_name":"postgres","process_id":"84","connection_from":"[local]","session_id":"65546d51.54","session_line_num":"1","session_start_time":"2023-11-15 08:03:45 CET","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":"2023-11-15T07:03:45Z","logger":"wal-restore","msg":"WAL file not found in the recovery object store","logging_pod":"pgsql15-3","walName":"0000000D.history","options":["--endpoint-url","https://backup1.services-minio.svc:9000","--cloud-provider","aws-s3","s3://pgsql15-backups","pgsql15"],"startTime":"2023-11-15T07:03:44Z","endTime":"2023-11-15T07:03:45Z","elapsedWalTime":0.620937751}
{"level":"info","ts":"2023-11-15T07:03:45Z","msg":"Instance status probe failing","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
{"level":"info","ts":"2023-11-15T07:03:45Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:45.645 CET","user_name":"postgres","database_name":"postgres","process_id":"85","connection_from":"[local]","session_id":"65546d51.55","session_line_num":"1","session_start_time":"2023-11-15 08:03:45 CET","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":"2023-11-15T07:03:45Z","msg":"Instance status probe failing","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:45.663213320+01:00 {"level":"info","ts":"2023-11-15T07:03:45Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:45.662 CET","user_name":"postgres","database_name":"postgres","process_id":"86","connection_from":"[local]","session_id":"65546d51.56","session_line_num":"1","session_start_time":"2023-11-15 08:03:45 CET","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":"2023-11-15T07:03:45Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:45.695 CET","process_id":"28","session_id":"65546d4f.1c","session_line_num":"4","session_start_time":"2023-11-15 08:03:43 CET","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"entering standby mode","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-15T07:03:45Z","msg":"Instance status probe failing","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:45.726016581+01:00 {"level":"info","ts":"2023-11-15T07:03:45Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:45.725 CET","user_name":"postgres","database_name":"postgres","process_id":"97","connection_from":"[local]","session_id":"65546d51.61","session_line_num":"1","session_start_time":"2023-11-15 08:03:45 CET","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":"2023-11-15T07:03:45Z","msg":"Instance status probe failing","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:45.993841326+01:00 {"level":"info","ts":"2023-11-15T07:03:45Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:45.993 CET","user_name":"postgres","database_name":"postgres","process_id":"101","connection_from":"[local]","session_id":"65546d51.65","session_line_num":"1","session_start_time":"2023-11-15 08:03:45 CET","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":"2023-11-15T07:03:46Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:46.378 CET","user_name":"postgres","database_name":"postgres","process_id":"103","connection_from":"[local]","session_id":"65546d52.67","session_line_num":"1","session_start_time":"2023-11-15 08:03:46 CET","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":"2023-11-15T07:03:46Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"pgsql15","namespace":"services-postgresql"},"namespace":"services-postgresql","name":"pgsql15","reconcileID":"f74cdc83-913f-4003-ba51-780e5e02b843","uuid":"1e9d6b01-8385-11ee-b613-5e21884c1f50","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
{"level":"info","ts":"2023-11-15T07:03:46Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:46.381 CET","user_name":"postgres","database_name":"postgres","process_id":"104","connection_from":"[local]","session_id":"65546d52.68","session_line_num":"1","session_start_time":"2023-11-15 08:03:46 CET","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":"2023-11-15T07:03:46Z","logger":"wal-restore","msg":"Restored WAL file","logging_pod":"pgsql15-3","walName":"0000000C.history","startTime":"2023-11-15T07:03:45Z","endTime":"2023-11-15T07:03:46Z","elapsedWalTime":0.622316712}
2023-11-15T08:03:46.494627026+01:00 {"level":"info","ts":"2023-11-15T07:03:46Z","logger":"wal-restore","msg":"WAL restore command completed (parallel)","logging_pod":"pgsql15-3","walName":"0000000C.history","maxParallel":1,"successfulWalRestore":1,"failedWalRestore":0,"endOfWALStream":false,"startTime":"2023-11-15T07:03:45Z","downloadStartTime":"2023-11-15T07:03:45Z","downloadTotalTime":0.622730058,"totalTime":0.76213108}
{"level":"info","ts":"2023-11-15T07:03:46Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:46.497 CET","process_id":"28","session_id":"65546d4f.1c","session_line_num":"5","session_start_time":"2023-11-15 08:03:43 CET","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"0000000C.history\" from archive","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-15T07:03:47Z","msg":"Instance status probe failing","logging_pod":"pgsql15-3","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))"}
2023-11-15T08:03:47.349903448+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:47.349 CET","user_name":"postgres","database_name":"postgres","process_id":"118","connection_from":"[local]","session_id":"65546d53.76","session_line_num":"1","session_start_time":"2023-11-15 08:03:47 CET","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":"2023-11-15T07:03:47Z","logger":"wal-restore","msg":"Restored WAL file","logging_pod":"pgsql15-3","walName":"0000000A000000CA00000033","startTime":"2023-11-15T07:03:46Z","endTime":"2023-11-15T07:03:47Z","elapsedWalTime":0.783000987}
2023-11-15T08:03:47.483302502+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","logger":"wal-restore","msg":"WAL restore command completed (parallel)","logging_pod":"pgsql15-3","walName":"0000000A000000CA00000033","maxParallel":1,"successfulWalRestore":1,"failedWalRestore":0,"endOfWALStream":false,"startTime":"2023-11-15T07:03:46Z","downloadStartTime":"2023-11-15T07:03:46Z","downloadTotalTime":0.783424532,"totalTime":0.940842584}
{"level":"info","ts":"2023-11-15T07:03:47Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:47.486 CET","process_id":"28","session_id":"65546d4f.1c","session_line_num":"6","session_start_time":"2023-11-15 08:03:43 CET","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restored log file \"0000000A000000CA00000033\" from archive","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-15T07:03:47Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:47.500 CET","process_id":"28","session_id":"65546d4f.1c","session_line_num":"7","session_start_time":"2023-11-15 08:03:43 CET","transaction_id":"0","error_severity":"FATAL","sql_state_code":"XX000","message":"requested timeline 12 does not contain minimum recovery point CA/35000000 on timeline 10","backend_type":"startup","query_id":"0"}}
{"level":"info","ts":"2023-11-15T07:03:47Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:47.503 CET","process_id":"24","session_id":"65546d4e.18","session_line_num":"6","session_start_time":"2023-11-15 08:03:42 CET","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"startup process (PID 28) exited with exit code 1","backend_type":"postmaster","query_id":"0"}}
2023-11-15T08:03:47.503399532+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:47.503 CET","process_id":"24","session_id":"65546d4e.18","session_line_num":"7","session_start_time":"2023-11-15 08:03:42 CET","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":"2023-11-15T07:03:47Z","logger":"postgres","msg":"record","logging_pod":"pgsql15-3","record":{"log_time":"2023-11-15 08:03:47.507 CET","process_id":"24","session_id":"65546d4e.18","session_line_num":"8","session_start_time":"2023-11-15 08:03:42 CET","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":"2023-11-15T07:03:47Z","msg":"Extracting pg_controldata information","logging_pod":"pgsql15-3","reason":"postmaster has exited"}
2023-11-15T08:03:47.519806666+01:00 {"level":"error","ts":"2023-11-15T07:03:47Z","msg":"PostgreSQL process exited with errors","logging_pod":"pgsql15-3","error":"exit status 1","stacktrace":"github.com/cloudnative-pg/cloudnative-pg/pkg/management/log.(*logger).Error\n\tpkg/management/log/log.go:128\ngithub.com/cloudnative-pg/cloudnative-pg/internal/cmd/manager/instance/run/lifecycle.(*PostgresLifecycle).Start\n\tinternal/cmd/manager/instance/run/lifecycle/lifecycle.go:99\nsigs.k8s.io/controller-runtime/pkg/manager.(*runnableGroup).reconcile.func1\n\tpkg/mod/sigs.k8s.io/[email protected]/pkg/manager/runnable_group.go:219"}
2023-11-15T08:03:47.519892689+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","msg":"Stopping and waiting for non leader election runnables"}
2023-11-15T08:03:47.519975746+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","msg":"Stopping and waiting for leader election runnables"}
2023-11-15T08:03:47.520245001+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","logger":"Replicator","msg":"Terminated slot Replicator loop","logging_pod":"pgsql15-3"}
2023-11-15T08:03:47.520508729+01:00 {"level":"error","ts":"2023-11-15T07:03:47Z","msg":"error received after stop sequence was engaged","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:555"}
{"level":"error","ts":"2023-11-15T07:03:47Z","msg":"Error while getting cluster CA Server secret","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"pgsql15","namespace":"services-postgresql"},"namespace":"services-postgresql","name":"pgsql15","reconcileID":"0c8d5946-aff0-4735-a388-ed324ba1a852","uuid":"1f48fefc-8385-11ee-b613-5e21884c1f50","logging_pod":"pgsql15-3","error":"Get \"https://10.43.0.1:443/api/v1/namespaces/services-postgresql/secrets/pgsql15-server-tls\": context canceled","stacktrace":"github.com/cloudnative-pg/cloudnative-pg/pkg/management/log.(*logger).Error\n\tpkg/management/log/log.go:128\ngithub.com/cloudnative-pg/cloudnative-pg/internal/management/controller.(*InstanceReconciler).RefreshSecrets\n\tinternal/management/controller/instance_controller.go:861\ngithub.com/cloudnative-pg/cloudnative-pg/internal/management/controller.(*InstanceReconciler).Reconcile\n\tinternal/management/controller/instance_controller.go:130\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile\n\tpkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:118\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\n\tpkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:314\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\n\tpkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:265\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\n\tpkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:226"}
2023-11-15T08:03:47.521223502+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","msg":"Exited log pipe","fileName":"/controller/log/postgres.json","logging_pod":"pgsql15-3"}
2023-11-15T08:03:47.521258168+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","msg":"Exited log pipe","fileName":"/controller/log/postgres","logging_pod":"pgsql15-3"}
2023-11-15T08:03:47.521270186+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","logger":"roles_reconciler","msg":"Terminated RoleSynchronizer loop","logging_pod":"pgsql15-3"}
2023-11-15T08:03:47.521283563+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","msg":"Shutdown signal received, waiting for all workers to finish","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster"}
2023-11-15T08:03:47.521294907+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","msg":"Exited log pipe","fileName":"/controller/log/postgres.csv","logging_pod":"pgsql15-3"}
2023-11-15T08:03:47.521358877+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","msg":"Webserver exited","logging_pod":"pgsql15-3","address":":9187"}
2023-11-15T08:03:47.521372841+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","msg":"Webserver exited","logging_pod":"pgsql15-3","address":"localhost:8010"}
{"level":"info","ts":"2023-11-15T07:03:47Z","msg":"Webserver exited","logging_pod":"pgsql15-3","address":":8000"}
2023-11-15T08:03:47.521418984+01:00 {"level":"error","ts":"2023-11-15T07:03:47Z","msg":"Error while getting barman endpoint CA secret","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"pgsql15","namespace":"services-postgresql"},"namespace":"services-postgresql","name":"pgsql15","reconcileID":"0c8d5946-aff0-4735-a388-ed324ba1a852","uuid":"1f48fefc-8385-11ee-b613-5e21884c1f50","logging_pod":"pgsql15-3","error":"client rate limiter Wait returned an error: context canceled","stacktrace":"github.com/cloudnative-pg/cloudnative-pg/pkg/management/log.(*logger).Error\n\tpkg/management/log/log.go:128\ngithub.com/cloudnative-pg/cloudnative-pg/internal/management/controller.(*InstanceReconciler).RefreshSecrets\n\tinternal/management/controller/instance_controller.go:868\ngithub.com/cloudnative-pg/cloudnative-pg/internal/management/controller.(*InstanceReconciler).Reconcile\n\tinternal/management/controller/instance_controller.go:130\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile\n\tpkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:118\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\n\tpkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:314\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\n\tpkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:265\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\n\tpkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:226"}
2023-11-15T08:03:47.521803404+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","logger":"pg_controldata","msg":"pg_control version number:            1300\nCatalog version number:             
  202209061\nDatabase system identifier:           7227586665997950999\nDatabase cluster state:               shut down in recovery\npg_control last modified:             Tue 14 Nov 2023 10:39:59 PM UTC\nLatest checkpoint location:           CA/33010BB8\nLatest checkpoint's REDO location:    CA/33010B80\nLatest checkpoint's REDO WAL file:    0000000A000000CA00000033\nLatest checkpoint's TimeLineID:       10\nLatest checkpoint's PrevTimeLineID:   10\nLatest checkpoint's full_page_writes: on\nLatest checkpoint's NextXID:          0:714194\nLatest checkpoint's NextOID:          50629\nLatest checkpoint's NextMultiXactId:  3144\nLatest checkpoint's NextMultiOffset:  6295\nLatest checkpoint's oldestXID:        716\nLatest checkpoint's oldestXID's DB:   1\nLatest checkpoint's oldestActiveXID:  714194\nLatest checkpoint's oldestMultiXid:   1\nLatest checkpoint's oldestMulti's DB: 1\nLatest checkpoint's oldestCommitTsXid:0\nLatest checkpoint's newestCommitTsXid:0\nTime of latest checkpoint:            Mon 13 Nov 2023 07:06:30 PM UTC\nFake LSN counter for unlogged rels:   0/3E8\nMinimum recovery ending location:     CA/35000000\nMin recovery ending loc's timeline:   10\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\nDat
e/time type storage:               64-bit integers\nFloat8 argument passing:              by value\nData page checksum version:           0\nMock authentication nonce:            1527c7c996593b2ba147d001a5fd50051eefe2ee208395d490d357f44029e3f1\n","pipe":"stdout","logging_pod":"pgsql15-3"}
{"level":"info","ts":"2023-11-15T07:03:47Z","msg":"Instance is still down, will retry in 1 second","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"pgsql15","namespace":"services-postgresql"},"namespace":"services-postgresql","name":"pgsql15","reconcileID":"0c8d5946-aff0-4735-a388-ed324ba1a852","uuid":"1f48fefc-8385-11ee-b613-5e21884c1f50","logging_pod":"pgsql15-3"}
2023-11-15T08:03:47.565078624+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","msg":"All workers finished","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster"}
2023-11-15T08:03:47.565093879+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","msg":"Stopping and waiting for caches"}
2023-11-15T08:03:47.565127252+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","msg":"Stopping and waiting for webhooks"}
2023-11-15T08:03:47.565139524+01:00 {"level":"info","ts":"2023-11-15T07:03:47Z","msg":"Wait completed, proceeding to shutdown the manager"}

Code of Conduct

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

kfkawalec avatar Nov 15 '23 07:11 kfkawalec

I think the reason is this

requested timeline 12 does not contain minimum recovery point CA/35000000 on timeline 10

we've hit this several times as well, a workaround is to delete the pvc and pod, cnpg will then create a new replica. Not sure what the cause is though, something about replication and failover, probably...

jgillich avatar Nov 18 '23 17:11 jgillich

I know that deleting pvc and pod helps. But is there any other way? Delete only some files from PVC? On a large database recreating nodes from scratch will take a lot of time :(

kfkawalec avatar Nov 20 '23 10:11 kfkawalec

This problem should have been fixed by several commits that landed in 1.20.4 and 1.21.1. Please update and try again.

gbartolini avatar Nov 22 '23 08:11 gbartolini

Ok, I'll try 1.21.1

kfkawalec avatar Nov 28 '23 14:11 kfkawalec

Hi guys! i have an OKD cluster with 3masters 2workers 1manager to which IP addr the api server, console, api-int dns are attached. After shoot down of my network, i restarted all the nodes and now my OKD cluster does not start, the console is no more working. I encountered this error message : Get "https://api.okd-mz.example.com:6443/apis/config.openshift.io/v1/clusteroperators": EOF

Pwdak avatar Dec 12 '23 08:12 Pwdak

Problem persistens in 1.21.1

After Restarting the new primary Pod the not syncing Pod is working again

Controller Log:

{"level":"info","ts":"2023-12-23T16:51:43Z","msg":"Cannot extract Pod status","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"9e5c7082-cd05-4185-bb20-a2388c0a1c23","uuid":"8c4ace69-a1b3-11ee-9cb7-86f8d40bd790","name":"bzs-pg-1","error":"error status code: 500, body: failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))\n"}
{"level":"info","ts":"2023-12-23T16:51:58Z","msg":"Cannot extract Pod status","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"9ce12239-b26d-41f0-a9fa-4cbd23976398","uuid":"94f8d52a-a1b3-11ee-9cb7-86f8d40bd790","name":"bzs-pg-1","error":"error status code: 500, body: failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))\n"}

Pod Log:

postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"setup","msg":"Starting CloudNativePG Instance Manager","logging_pod":"bzs-pg-1","version":"1.21.1","build":{"Version":"1.21.1","Commit":"27f62cac","Date":"2023-11-03"}}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"setup","msg":"starting controller-runtime manager","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Starting EventSource","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","source":"kind source: *v1.Cluster"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Starting Controller","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"roles_reconciler","msg":"starting up the runnable","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"roles_reconciler","msg":"skipping the RoleSynchronizer in replicas","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"roles_reconciler","msg":"setting up RoleSynchronizer loop","logging_pod":"bzs-pg-1"}
bootstrap-controller {"level":"info","ts":"2023-12-23T16:49:35Z","msg":"Installing the manager executable","destination":"/controller/manager","version":"1.21.1","build":{"Version":"1.21.1","Commit":"27f62cac","Date":"2023-11-03"}}
bootstrap-controller {"level":"info","ts":"2023-12-23T16:49:36Z","msg":"Setting 0750 permissions"}
bootstrap-controller {"level":"info","ts":"2023-12-23T16:49:36Z","msg":"Bootstrap completed"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Starting webserver","logging_pod":"bzs-pg-1","address":":9187"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Starting webserver","logging_pod":"bzs-pg-1","address":"localhost:8010"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Starting webserver","logging_pod":"bzs-pg-1","address":":8000"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Starting workers","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","worker count":1}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Refreshed configuration file","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"bbdebc96-a42d-45af-9a01-5227b74eae14","uuid":"41dc4ca8-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","filename":"/controller/certificates/server.crt","secret":"bzs-pg-server"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Refreshed configuration file","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"bbdebc96-a42d-45af-9a01-5227b74eae14","uuid":"41dc4ca8-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","filename":"/controller/certificates/server.key","secret":"bzs-pg-server"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Refreshed configuration file","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"bbdebc96-a42d-45af-9a01-5227b74eae14","uuid":"41dc4ca8-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","filename":"/controller/certificates/streaming_replica.crt","secret":"bzs-pg-replication"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Refreshed configuration file","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"bbdebc96-a42d-45af-9a01-5227b74eae14","uuid":"41dc4ca8-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","filename":"/controller/certificates/streaming_replica.key","secret":"bzs-pg-replication"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Refreshed configuration file","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"bbdebc96-a42d-45af-9a01-5227b74eae14","uuid":"41dc4ca8-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","filename":"/controller/certificates/client-ca.crt","secret":"bzs-pg-ca"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Refreshed configuration file","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"bbdebc96-a42d-45af-9a01-5227b74eae14","uuid":"41dc4ca8-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","filename":"/controller/certificates/server-ca.crt","secret":"bzs-pg-ca"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Found previous run flag","logging_pod":"bzs-pg-1","filename":"/var/lib/postgresql/data/pgdata/cnpg_initialized-bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Extracting pg_controldata information","logging_pod":"bzs-pg-1","reason":"postmaster start up"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"pg_controldata","msg":"pg_control version number:            1300\nCatalog version number:               202209061\nDatabase system identifier:           7242590037021855768\nDatabase cluster state:               shut down in recovery\npg_control last modified:             Sat 23 Dec 2023 04:49:14 PM UTC\nLatest checkpoint location:           0/4F000060\nLatest checkpoint's REDO location:    0/4E00CE20\nLatest checkpoint's REDO WAL file:    00000007000000000000004E\nLatest checkpoint's TimeLineID:       7\nLatest checkpoint's PrevTimeLineID:   7\nLatest checkpoint's full_page_writes: on\nLatest checkpoint's NextXID:          0:827\nLatest checkpoint's NextOID:          16497\nLatest checkpoint's NextMultiXactId:  1\nLatest checkpoint's NextMultiOffset:  0\nLatest checkpoint's oldestXID:        716\nLatest checkpoint's oldestXID's DB:   1\nLatest checkpoint's oldestActiveXID:  827\nLatest checkpoint's oldestMultiXid:   1\nLatest checkpoint's oldestMulti's DB: 1\nLatest checkpoint's oldestCommitTsXid:0\nLatest checkpoint's newestCommitTsXid:0\nTime of latest checkpoint:            Sat 23 Dec 2023 03:27:11 PM UTC\nFake LSN counter for unlogged rels:   0/3E8\nMinimum recovery ending location:     0/50000028\nMin recovery ending loc's timeline:   7\nBackup start location:                0/4C001370\nBackup end location:                  0/50000028\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:            e644065f8d39cc30eeedc477c722fd7165efb917c247c9ddbf253d1e2f3a34b0\n","pipe":"stdout","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","msg":"Instance is still down, will retry in 1 second","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"bbdebc96-a42d-45af-9a01-5227b74eae14","uuid":"41dc4ca8-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"postgres","msg":"2023-12-23 16:49:37.280 UTC [21] LOG:  redirecting log output to logging collector process","pipe":"stderr","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"postgres","msg":"2023-12-23 16:49:37.280 UTC [21] HINT:  Future log output will appear in directory \"/controller/log\".","pipe":"stderr","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:37.280 UTC","process_id":"21","session_id":"65870fa1.15","session_line_num":"1","session_start_time":"2023-12-23 16:49:37 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"}}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:37.280 UTC","process_id":"21","session_id":"65870fa1.15","session_line_num":"2","session_start_time":"2023-12-23 16:49:37 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"starting PostgreSQL 15.1 (Debian 15.1-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"}}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"postgres","msg":"2023-12-23 16:49:37.280 UTC [21] LOG:  ending log output to stderr","source":"/controller/log/postgres","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"postgres","msg":"2023-12-23 16:49:37.280 UTC [21] HINT:  Future log output will go to log destination \"csvlog\".","source":"/controller/log/postgres","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:37.281 UTC","process_id":"21","session_id":"65870fa1.15","session_line_num":"3","session_start_time":"2023-12-23 16:49:37 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"}}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:37.281 UTC","process_id":"21","session_id":"65870fa1.15","session_line_num":"4","session_start_time":"2023-12-23 16:49:37 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"listening on IPv6 address \"::\", port 5432","backend_type":"postmaster","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:37.293 UTC","process_id":"21","session_id":"65870fa1.15","session_line_num":"5","session_start_time":"2023-12-23 16:49:37 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"}}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:37.319 UTC","process_id":"25","session_id":"65870fa1.19","session_line_num":"1","session_start_time":"2023-12-23 16:49:37 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"database system was shut down in recovery at 2023-12-23 16:49:14 UTC","backend_type":"startup","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:37.459 UTC","process_id":"25","session_id":"65870fa1.19","session_line_num":"2","session_start_time":"2023-12-23 16:49:37 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"entering standby mode","backend_type":"startup","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:37.933 UTC","process_id":"25","session_id":"65870fa1.19","session_line_num":"3","session_start_time":"2023-12-23 16:49:37 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"redo starts at 0/4E00CE20","backend_type":"startup","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:37Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:38Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-1"}
postgres {"level":"info","ts":"2023-12-23T16:49:38Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:38.213 UTC","process_id":"25","session_id":"65870fa1.19","session_line_num":"4","session_start_time":"2023-12-23 16:49:37 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"unexpected pageaddr 0/2C000000 in log segment 000000070000000000000050, offset 0","backend_type":"startup","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:38Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:38.213 UTC","process_id":"25","session_id":"65870fa1.19","session_line_num":"5","session_start_time":"2023-12-23 16:49:37 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"unexpected pageaddr 0/2C000000 in log segment 000000070000000000000050, offset 0","backend_type":"startup","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:38Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:38.235 UTC","process_id":"68","session_id":"65870fa2.44","session_line_num":"1","session_start_time":"2023-12-23 16:49:38 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"started streaming WAL from primary at 0/50000000 on timeline 7","backend_type":"walreceiver","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:38Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:38.357 UTC","user_name":"postgres","database_name":"postgres","process_id":"70","connection_from":"[local]","session_id":"65870fa2.46","session_line_num":"1","session_start_time":"2023-12-23 16:49:38 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:38Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:38.360 UTC","user_name":"postgres","database_name":"postgres","process_id":"71","connection_from":"[local]","session_id":"65870fa2.47","session_line_num":"1","session_start_time":"2023-12-23 16:49:38 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:38Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"9ec1ea54-c7ba-4720-943b-d99d8f54ed33","uuid":"428974a2-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:39Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:39.517 UTC","user_name":"postgres","database_name":"postgres","process_id":"73","connection_from":"[local]","session_id":"65870fa3.49","session_line_num":"1","session_start_time":"2023-12-23 16:49:39 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:39Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:39.523 UTC","user_name":"postgres","database_name":"postgres","process_id":"74","connection_from":"[local]","session_id":"65870fa3.4a","session_line_num":"1","session_start_time":"2023-12-23 16:49:39 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:39Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"109d16b1-fc1e-46f6-bf0a-589b4bab4000","uuid":"4331e5f3-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:40Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:40.583 UTC","user_name":"postgres","database_name":"postgres","process_id":"76","connection_from":"[local]","session_id":"65870fa4.4c","session_line_num":"1","session_start_time":"2023-12-23 16:49:40 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:40Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"871acb5c-a5e1-42cd-8e28-88186c7ba2d2","uuid":"43e38f91-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:40Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:40.584 UTC","user_name":"postgres","database_name":"postgres","process_id":"77","connection_from":"[local]","session_id":"65870fa4.4d","session_line_num":"1","session_start_time":"2023-12-23 16:49:40 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:41Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:41.641 UTC","user_name":"postgres","database_name":"postgres","process_id":"79","connection_from":"[local]","session_id":"65870fa5.4f","session_line_num":"1","session_start_time":"2023-12-23 16:49:41 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:41Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:41.643 UTC","user_name":"postgres","database_name":"postgres","process_id":"80","connection_from":"[local]","session_id":"65870fa5.50","session_line_num":"1","session_start_time":"2023-12-23 16:49:41 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:41Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"819d54de-6949-4fda-9514-548f3453e71e","uuid":"448529ef-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:42Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:42.694 UTC","user_name":"postgres","database_name":"postgres","process_id":"82","connection_from":"[local]","session_id":"65870fa6.52","session_line_num":"1","session_start_time":"2023-12-23 16:49:42 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:42Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"d7c18a01-5d6f-4b2d-8817-809a066b4ae8","uuid":"4526b6c6-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:42Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:42.696 UTC","user_name":"postgres","database_name":"postgres","process_id":"83","connection_from":"[local]","session_id":"65870fa6.53","session_line_num":"1","session_start_time":"2023-12-23 16:49:42 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:43Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:43.135 UTC","user_name":"postgres","database_name":"postgres","process_id":"84","connection_from":"[local]","session_id":"65870fa7.54","session_line_num":"1","session_start_time":"2023-12-23 16:49:43 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:43Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:43.149 UTC","user_name":"postgres","database_name":"postgres","process_id":"85","connection_from":"[local]","session_id":"65870fa7.55","session_line_num":"1","session_start_time":"2023-12-23 16:49:43 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:43Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:43.205 UTC","user_name":"postgres","database_name":"postgres","process_id":"86","connection_from":"[local]","session_id":"65870fa7.56","session_line_num":"1","session_start_time":"2023-12-23 16:49:43 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:43Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:43.356 UTC","user_name":"postgres","database_name":"postgres","process_id":"88","connection_from":"[local]","session_id":"65870fa7.58","session_line_num":"1","session_start_time":"2023-12-23 16:49:43 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:43Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"53567b8a-2bb9-4e47-9347-9124b940b98f","uuid":"457159f9-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:43Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:43.358 UTC","user_name":"postgres","database_name":"postgres","process_id":"89","connection_from":"[local]","session_id":"65870fa7.59","session_line_num":"1","session_start_time":"2023-12-23 16:49:43 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:43Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:43.479 UTC","user_name":"postgres","database_name":"postgres","process_id":"90","connection_from":"[local]","session_id":"65870fa7.5a","session_line_num":"1","session_start_time":"2023-12-23 16:49:43 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
Stream closed EOF for bzs/bzs-pg-1 (bootstrap-controller)
postgres {"level":"info","ts":"2023-12-23T16:49:43Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:43.750 UTC","user_name":"postgres","database_name":"postgres","process_id":"92","connection_from":"[local]","session_id":"65870fa7.5c","session_line_num":"1","session_start_time":"2023-12-23 16:49:43 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:43Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:43.752 UTC","user_name":"postgres","database_name":"postgres","process_id":"93","connection_from":"[local]","session_id":"65870fa7.5d","session_line_num":"1","session_start_time":"2023-12-23 16:49:43 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:43Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"b59b5b82-7fd7-4f22-8127-7ea54dda5804","uuid":"45c75e3c-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:44Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:44.818 UTC","user_name":"postgres","database_name":"postgres","process_id":"95","connection_from":"[local]","session_id":"65870fa8.5f","session_line_num":"1","session_start_time":"2023-12-23 16:49:44 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:44Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:44.822 UTC","user_name":"postgres","database_name":"postgres","process_id":"96","connection_from":"[local]","session_id":"65870fa8.60","session_line_num":"1","session_start_time":"2023-12-23 16:49:44 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:44Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:44.825 UTC","user_name":"postgres","database_name":"postgres","process_id":"97","connection_from":"[local]","session_id":"65870fa8.61","session_line_num":"1","session_start_time":"2023-12-23 16:49:44 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:44Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"91feefd7-77de-47f0-9daf-bf13c14b343b","uuid":"4668aa99-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:44Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:44.979 UTC","user_name":"postgres","database_name":"postgres","process_id":"99","connection_from":"[local]","session_id":"65870fa8.63","session_line_num":"1","session_start_time":"2023-12-23 16:49:44 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:44Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"602f04bf-31a2-4372-8b75-a3975ab586f5","uuid":"4681ee7c-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:44Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:44.983 UTC","user_name":"postgres","database_name":"postgres","process_id":"100","connection_from":"[local]","session_id":"65870fa8.64","session_line_num":"1","session_start_time":"2023-12-23 16:49:44 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:45Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:45.284 UTC","user_name":"postgres","database_name":"postgres","process_id":"102","connection_from":"[local]","session_id":"65870fa9.66","session_line_num":"1","session_start_time":"2023-12-23 16:49:45 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:45Z","msg":"Unable to collect metrics","logging_pod":"bzs-pg-1","error":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:45Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:45.516 UTC","user_name":"postgres","database_name":"postgres","process_id":"103","connection_from":"[local]","session_id":"65870fa9.67","session_line_num":"1","session_start_time":"2023-12-23 16:49:45 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:45Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:45.520 UTC","user_name":"postgres","database_name":"postgres","process_id":"104","connection_from":"[local]","session_id":"65870fa9.68","session_line_num":"1","session_start_time":"2023-12-23 16:49:45 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:45Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:45.799 UTC","user_name":"postgres","database_name":"postgres","process_id":"105","connection_from":"[local]","session_id":"65870fa9.69","session_line_num":"1","session_start_time":"2023-12-23 16:49:45 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:45Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:45.878 UTC","user_name":"postgres","database_name":"postgres","process_id":"107","connection_from":"[local]","session_id":"65870fa9.6b","session_line_num":"1","session_start_time":"2023-12-23 16:49:45 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:45Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"a280291e-c093-4ef4-b45f-8d8c327763cf","uuid":"470c6306-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:45Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:45.881 UTC","user_name":"postgres","database_name":"postgres","process_id":"108","connection_from":"[local]","session_id":"65870fa9.6c","session_line_num":"1","session_start_time":"2023-12-23 16:49:45 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:46Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:46.803 UTC","user_name":"postgres","database_name":"postgres","process_id":"109","connection_from":"[local]","session_id":"65870faa.6d","session_line_num":"1","session_start_time":"2023-12-23 16:49:46 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:46Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:46.929 UTC","user_name":"postgres","database_name":"postgres","process_id":"111","connection_from":"[local]","session_id":"65870faa.6f","session_line_num":"1","session_start_time":"2023-12-23 16:49:46 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:46Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"39f4603e-8d9d-4686-be37-7e194f641833","uuid":"47ad6107-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:46Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:46.931 UTC","user_name":"postgres","database_name":"postgres","process_id":"112","connection_from":"[local]","session_id":"65870faa.70","session_line_num":"1","session_start_time":"2023-12-23 16:49:46 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:47Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:47.989 UTC","user_name":"postgres","database_name":"postgres","process_id":"114","connection_from":"[local]","session_id":"65870fab.72","session_line_num":"1","session_start_time":"2023-12-23 16:49:47 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:47Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"09b5f8d9-ac48-41c5-9fe6-188e1cc356f7","uuid":"484db9b4-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:47Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:47.992 UTC","user_name":"postgres","database_name":"postgres","process_id":"115","connection_from":"[local]","session_id":"65870fab.73","session_line_num":"1","session_start_time":"2023-12-23 16:49:47 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:49Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:49.040 UTC","user_name":"postgres","database_name":"postgres","process_id":"117","connection_from":"[local]","session_id":"65870fad.75","session_line_num":"1","session_start_time":"2023-12-23 16:49:49 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:49Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"9d1c1965-377f-464f-bfec-e8ef0f6c5e40","uuid":"48ef751e-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:49Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:49.042 UTC","user_name":"postgres","database_name":"postgres","process_id":"118","connection_from":"[local]","session_id":"65870fad.76","session_line_num":"1","session_start_time":"2023-12-23 16:49:49 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:50Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:50.096 UTC","user_name":"postgres","database_name":"postgres","process_id":"120","connection_from":"[local]","session_id":"65870fae.78","session_line_num":"1","session_start_time":"2023-12-23 16:49:50 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:50Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"b843f7c2-5e1f-4ffd-a0cd-0a97df615f98","uuid":"498fd8f6-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:50Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:50.098 UTC","user_name":"postgres","database_name":"postgres","process_id":"121","connection_from":"[local]","session_id":"65870fae.79","session_line_num":"1","session_start_time":"2023-12-23 16:49:50 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:51Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:51.152 UTC","user_name":"postgres","database_name":"postgres","process_id":"123","connection_from":"[local]","session_id":"65870faf.7b","session_line_num":"1","session_start_time":"2023-12-23 16:49:51 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T16:49:51Z","msg":"DB not available, will retry","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"19a0e2f1-e255-4020-b3bc-083368153f9a","uuid":"4a30cd32-a1b3-11ee-a81c-4647014bd03f","logging_pod":"bzs-pg-1","err":"failed to connect to `host=/controller/run user=postgres database=postgres`: server error (FATAL: the database system is not yet accepting connections (SQLSTATE 57P03))"}
postgres {"level":"info","ts":"2023-12-23T16:49:51Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-1","record":{"log_time":"2023-12-23 16:49:51.155 UTC","user_name":"postgres","database_name":"postgres","process_id":"124","connection_from":"[local]","session_id":"65870faf.7c","session_line_num":"1","session_start_time":"2023-12-23 16:49:51 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P03","message":"the database system is not yet accepting connections","detail":"Consistent recovery state has not been yet reached.","backend_type":"client backend","query_id":"0"}}

Pod Primary

postgres {"level":"info","ts":"2023-11-30T15:10:21Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-11-30 15:10:21.390 UTC","process_id":"68","session_id":"6568a5bc.44","session_line_num":"2","session_start_time":"2023-11-30 15:09:48 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"replication terminated by primary server","detail":"End of WAL reached on timeline 6 at 0/4C0000A0.","backend_type":"walreceiver","query_id":"0"}}
postgres {"level":"info","ts":"2023-11-30T15:10:21Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-11-30 15:10:21.390 UTC","process_id":"68","session_id":"6568a5bc.44","session_line_num":"3","session_start_time":"2023-11-30 15:09:48 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"08006","message":"could not send end-of-streaming message to primary: SSL connection has been closed unexpectedly\nno COPY in progress","backend_type":"walreceiver","query_id":"0"}}
postgres {"level":"info","ts":"2023-11-30T15:10:21Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-11-30T15:10:21Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-11-30T15:10:21Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-11-30 15:10:21.666 UTC","process_id":"24","session_id":"6568a5ba.18","session_line_num":"7","session_start_time":"2023-11-30 15:09:46 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"record with incorrect prev-link 0/28000028 at 0/4C0000A0","backend_type":"startup","query_id":"0"}}
postgres {"level":"info","ts":"2023-11-30T15:10:21Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-11-30 15:10:21.673 UTC","process_id":"139","session_id":"6568a5dd.8b","session_line_num":"1","session_start_time":"2023-11-30 15:10:21 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"08006","message":"could not connect to the primary server: connection to server at \"bzs-pg-rw\" (10.43.15.25), port 5432 failed: Connection refused\n\tIs the server running on that host and accepting TCP/IP connections?","backend_type":"walreceiver","query_id":"0"}}
postgres {"level":"info","ts":"2023-11-30T15:10:21Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-11-30T15:10:21Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-11-30 15:10:21.824 UTC","process_id":"24","session_id":"6568a5ba.18","session_line_num":"8","session_start_time":"2023-11-30 15:09:46 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"waiting for WAL to become available at 0/4C0000B8","backend_type":"startup","query_id":"0"}}
postgres {"level":"info","ts":"2023-11-30T15:10:26Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-11-30T15:11:30Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-11-30 15:11:30.736 UTC","process_id":"157","session_id":"6568a5e2.9d","session_line_num":"1","session_start_time":"2023-11-30 15:10:26 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"started streaming WAL from primary at 0/4C000000 on timeline 6","backend_type":"walreceiver","query_id":"0"}}
postgres {"level":"info","ts":"2023-11-30T15:14:46Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-11-30 15:14:46.738 UTC","process_id":"22","session_id":"6568a5ba.16","session_line_num":"1","session_start_time":"2023-11-30 15:09:46 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restartpoint starting: time","backend_type":"checkpointer","query_id":"0"}}
postgres {"level":"info","ts":"2023-11-30T15:14:46Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-11-30 15:14:46.907 UTC","process_id":"22","session_id":"6568a5ba.16","session_line_num":"2","session_start_time":"2023-11-30 15:09:46 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restartpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.121 s, sync=0.009 s, total=0.170 s; sync files=2, longest=0.006 s, average=0.005 s; distance=32715 kB, estimate=32715 kB","backend_type":"checkpointer","query_id":"0"}}
postgres {"level":"info","ts":"2023-11-30T15:14:46Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-11-30 15:14:46.907 UTC","process_id":"22","session_id":"6568a5ba.16","session_line_num":"3","session_start_time":"2023-11-30 15:09:46 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"recovery restart point at 0/4C000028","detail":"Last completed transaction was at log time 2023-11-30 15:10:50.59597+00.","backend_type":"checkpointer","query_id":"0"}}
postgres {"level":"info","ts":"2023-11-30T15:19:47Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-11-30 15:19:47.005 UTC","process_id":"22","session_id":"6568a5ba.16","session_line_num":"4","session_start_time":"2023-11-30 15:09:46 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restartpoint starting: time","backend_type":"checkpointer","query_id":"0"}}
postgres {"level":"info","ts":"2023-11-30T15:19:47Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-11-30 15:19:47.063 UTC","process_id":"22","session_id":"6568a5ba.16","session_line_num":"5","session_start_time":"2023-11-30 15:09:46 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"restartpoint complete: wrote 0 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.001 s, sync=0.001 s, total=0.059 s; sync files=0, longest=0.000 s, average=0.000 s; distance=4 kB, estimate=29444 kB","backend_type":"checkpointer","query_id":"0"}}
postgres {"level":"info","ts":"2023-11-30T15:19:47Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-11-30 15:19:47.063 UTC","process_id":"22","session_id":"6568a5ba.16","session_line_num":"6","session_start_time":"2023-11-30 15:09:46 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"recovery restart point at 0/4C001370","detail":"Last completed transaction was at log time 2023-11-30 15:10:50.59597+00.","backend_type":"checkpointer","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T15:20:01Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:20:01.945 UTC","process_id":"157","session_id":"6568a5e2.9d","session_line_num":"2","session_start_time":"2023-11-30 15:10:26 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"08006","message":"terminating walreceiver due to timeout","backend_type":"walreceiver","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T15:20:02Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:20:02Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:20:02Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:20:02.326 UTC","process_id":"24","session_id":"6568a5ba.18","session_line_num":"9","session_start_time":"2023-11-30 15:09:46 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"unexpected pageaddr 0/2A000000 in log segment 00000006000000000000004E, offset 0","backend_type":"startup","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T15:22:10Z","msg":"Setting myself as primary","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"c4281f9b-67ee-4296-96e2-be6f3b15438a","uuid":"0a9baaf3-a1a7-11ee-8e2e-5e4c9d2daf0c","logging_pod":"bzs-pg-2","phase":"Failing over","currentTimestamp":"2023-12-23T15:22:10.518887Z","targetPrimaryTimestamp":"2023-12-23T15:22:10.388303Z","currentPrimaryTimestamp":"2023-11-25T11:13:29.949825Z","msPassedSinceTargetPrimaryTimestamp":130,"msPassedSinceCurrentPrimaryTimestamp":2434120569,"msDifferenceBetweenCurrentAndTargetPrimary":-2434120438}
postgres {"level":"info","ts":"2023-12-23T15:22:10Z","msg":"I'm the target primary, wait for the wal_receiver to be terminated","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"c4281f9b-67ee-4296-96e2-be6f3b15438a","uuid":"0a9baaf3-a1a7-11ee-8e2e-5e4c9d2daf0c","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:22:10Z","msg":"I'm the target primary, applying WALs and promoting my instance","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"c4281f9b-67ee-4296-96e2-be6f3b15438a","uuid":"0a9baaf3-a1a7-11ee-8e2e-5e4c9d2daf0c","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:22:10Z","msg":"Extracting pg_controldata information","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"c4281f9b-67ee-4296-96e2-be6f3b15438a","uuid":"0a9baaf3-a1a7-11ee-8e2e-5e4c9d2daf0c","logging_pod":"bzs-pg-2","reason":"promote"}
postgres {"level":"info","ts":"2023-12-23T15:22:10Z","logger":"pg_controldata","msg":"pg_control version number:            1300\nCatalog version number:               202209061\nDatabase system identifier:           7242590037021855768\nDatabase cluster state:               in archive recovery\npg_control last modified:             Thu 30 Nov 2023 03:24:47 PM UTC\nLatest checkpoint location:           0/4D000060\nLatest checkpoint's REDO location:    0/4C001370\nLatest checkpoint's REDO WAL file:    00000006000000000000004C\nLatest checkpoint's TimeLineID:       6\nLatest checkpoint's PrevTimeLineID:   6\nLatest checkpoint's full_page_writes: on\nLatest checkpoint's NextXID:          0:825\nLatest checkpoint's NextOID:          16497\nLatest checkpoint's NextMultiXactId:  1\nLatest checkpoint's NextMultiOffset:  0\nLatest checkpoint's oldestXID:        716\nLatest checkpoint's oldestXID's DB:   1\nLatest checkpoint's oldestActiveXID:  825\nLatest checkpoint's oldestMultiXid:   1\nLatest checkpoint's oldestMulti's DB: 1\nLatest checkpoint's oldestCommitTsXid:0\nLatest checkpoint's newestCommitTsXid:0\nTime of latest checkpoint:            Thu 30 Nov 2023 03:15:49 PM UTC\nFake LSN counter for unlogged rels:   0/3E8\nMinimum recovery ending location:     0/4E000000\nMin recovery ending loc's timeline:   6\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:            e644065f8d39cc30eeedc477c722fd7165efb917c247c9ddbf253d1e2f3a34b0\n","pipe":"stdout","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:22:10Z","msg":"Promoting instance","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"c4281f9b-67ee-4296-96e2-be6f3b15438a","uuid":"0a9baaf3-a1a7-11ee-8e2e-5e4c9d2daf0c","logging_pod":"bzs-pg-2","pgctl_options":["-D","/var/lib/postgresql/data/pgdata","-w","promote","-t 40000000"]}
postgres {"level":"info","ts":"2023-12-23T15:22:10Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:22:10.527 UTC","process_id":"24","session_id":"6568a5ba.18","session_line_num":"10","session_start_time":"2023-11-30 15:09:46 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"received promote request","backend_type":"startup","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T15:22:10Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:22:10.527 UTC","process_id":"1725111","session_id":"6586faa2.1a52b7","session_line_num":"1","session_start_time":"2023-12-23 15:20:02 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"57P01","message":"terminating walreceiver process due to administrator command","backend_type":"walreceiver","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T15:22:10Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:22:10Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:22:10Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:22:10.793 UTC","process_id":"24","session_id":"6568a5ba.18","session_line_num":"11","session_start_time":"2023-11-30 15:09:46 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"redo done at 0/4D000110 system usage: CPU: user: 10.95 s, system: 17.91 s, elapsed: 1987943.19 s","backend_type":"startup","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T15:22:10Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:22:10.793 UTC","process_id":"24","session_id":"6568a5ba.18","session_line_num":"12","session_start_time":"2023-11-30 15:09:46 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"last completed transaction was at log time 2023-11-30 15:10:50.59597+00","backend_type":"startup","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T15:22:10Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:22:10Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:22:11.086 UTC","process_id":"24","session_id":"6568a5ba.18","session_line_num":"13","session_start_time":"2023-11-30 15:09:46 UTC","virtual_transaction_id":"1/0","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"selected new timeline ID: 7","backend_type":"startup","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","logger":"wal-restore","msg":"tried restoring WALs, but no backup was configured","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:22:11.347 UTC","process_id":"24","session_id":"6568a5ba.18","session_line_num":"14","session_start_time":"2023-11-30 15:09:46 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"}}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:22:11.380 UTC","process_id":"22","session_id":"6568a5ba.16","session_line_num":"7","session_start_time":"2023-11-30 15:09:46 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"checkpoint starting: force","backend_type":"checkpointer","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:22:11.383 UTC","process_id":"20","session_id":"6568a5ba.14","session_line_num":"7","session_start_time":"2023-11-30 15:09:46 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"}}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","logger":"wal-archive","msg":"Backup not configured, skip WAL archiving","logging_pod":"bzs-pg-2","walName":"pg_wal/00000007.history","currentPrimary":"bzs-pg-1","targetPrimary":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","logger":"pg_ctl","msg":"waiting for server to promote.... done","pipe":"stdout","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","logger":"pg_ctl","msg":"server promoted","pipe":"stdout","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","msg":"Requesting a checkpoint","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"c4281f9b-67ee-4296-96e2-be6f3b15438a","uuid":"0a9baaf3-a1a7-11ee-8e2e-5e4c9d2daf0c","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:22:11.431 UTC","process_id":"22","session_id":"6568a5ba.16","session_line_num":"8","session_start_time":"2023-11-30 15:09:46 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.009 s, sync=0.009 s, total=0.052 s; sync files=2, longest=0.008 s, average=0.005 s; distance=32763 kB, estimate=32763 kB","backend_type":"checkpointer","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:22:11.437 UTC","process_id":"22","session_id":"6568a5ba.16","session_line_num":"9","session_start_time":"2023-11-30 15:09:46 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"checkpoint starting: immediate force wait","backend_type":"checkpointer","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:22:11.458 UTC","process_id":"22","session_id":"6568a5ba.16","session_line_num":"10","session_start_time":"2023-11-30 15:09:46 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.021 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=29486 kB","backend_type":"checkpointer","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","msg":"The PostgreSQL instance has been promoted successfully","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"c4281f9b-67ee-4296-96e2-be6f3b15438a","uuid":"0a9baaf3-a1a7-11ee-8e2e-5e4c9d2daf0c","logging_pod":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","logger":"wal-archive","msg":"Backup not configured, skip WAL archiving","logging_pod":"bzs-pg-2","walName":"pg_wal/00000002000000000000002D","currentPrimary":"bzs-pg-1","targetPrimary":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:22:11Z","msg":"Finished setting myself as primary","controller":"cluster","controllerGroup":"postgresql.cnpg.io","controllerKind":"Cluster","Cluster":{"name":"bzs-pg","namespace":"bzs"},"namespace":"bzs","name":"bzs-pg","reconcileID":"c4281f9b-67ee-4296-96e2-be6f3b15438a","uuid":"0a9baaf3-a1a7-11ee-8e2e-5e4c9d2daf0c","logging_pod":"bzs-pg-2","phase":"Failing over","currentTimestamp":"2023-12-23T15:22:11.503957Z","targetPrimaryTimestamp":"2023-12-23T15:22:10.388303Z","currentPrimaryTimestamp":"2023-12-23T15:22:11.458310Z","msPassedSinceTargetPrimaryTimestamp":1115,"msPassedSinceCurrentPrimaryTimestamp":45,"msDifferenceBetweenCurrentAndTargetPrimary":1070}
postgres {"level":"info","ts":"2023-12-23T15:22:29Z","logger":"Replicator","msg":"synchronizing replication slots","logging_pod":"bzs-pg-2","err":"getting replication slot status from primary: failed to connect to `host=bzs-pg-rw user=streaming_replica database=postgres`: dial error (timeout: dial tcp 10.43.15.25:5432: connect: connection timed out)"}
postgres {"level":"info","ts":"2023-12-23T15:27:11Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:27:11.557 UTC","process_id":"22","session_id":"6568a5ba.16","session_line_num":"11","session_start_time":"2023-11-30 15:09:46 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"checkpoint starting: time","backend_type":"checkpointer","query_id":"0"}}
postgres {"level":"info","ts":"2023-12-23T15:27:11Z","logger":"wal-archive","msg":"Backup not configured, skip WAL archiving","logging_pod":"bzs-pg-2","walName":"pg_wal/00000007000000000000004E","currentPrimary":"bzs-pg-2","targetPrimary":"bzs-pg-2"}
postgres {"level":"info","ts":"2023-12-23T15:27:12Z","logger":"postgres","msg":"record","logging_pod":"bzs-pg-2","record":{"log_time":"2023-12-23 15:27:12.755 UTC","process_id":"22","session_id":"6568a5ba.16","session_line_num":"12","session_start_time":"2023-11-30 15:09:46 UTC","transaction_id":"0","error_severity":"LOG","sql_state_code":"00000","message":"checkpoint complete: wrote 11 buffers (0.1%); 0 WAL file(s) added, 1 removed, 1 recycled; write=1.127 s, sync=0.019 s, total=1.198 s; sync files=8, longest=0.016 s, average=0.003 s; distance=51 kB, estimate=26543 kB","backend_type":"checkpointer","query_id":"0"}}
postgres {"level":"error","ts":"2023-12-23T15:31:18Z","msg":"pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229: Failed to watch *v1.Cluster: the server is currently unable to handle the request (get clusters.postgresql.cnpg.io)","stacktrace":"k8s.io/client-go/tools/cache.DefaultWatchErrorHandler\n\tpkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:147\nk8s.io/client-go/tools/cache.(*Reflector).Run.func1\n\tpkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:292\nk8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1\n\tpkg/mod/k8s.io/[email protected]/pkg/util/wait/backoff.go:226\nk8s.io/apimachinery/pkg/util/wait.BackoffUntil\n\tpkg/mod/k8s.io/[email protected]/pkg/util/wait/backoff.go:227\nk8s.io/client-go/tools/cache.(*Reflector).Run\n\tpkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:290\nk8s.io/client-go/tools/cache.(*controller).Run.(*Group).StartWithChannel.func2\n\tpkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:55\nk8s.io/apimachinery/pkg/util/wait.(*Group).Start.func1\n\tpkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:72"}
postgres {"level":"info","ts":"2023-12-23T15:32:12Z","logger":"wal-archive","msg":"Backup not configured, skip WAL archiving","logging_pod":"bzs-pg-2","walName":"pg_wal/00000007000000000000004F","currentPrimary":"bzs-pg-2","targetPrimary":"bzs-pg-2"}
postgres {"level":"error","ts":"2023-12-23T15:36:59Z","msg":"pkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:229: Failed to watch *v1.Cluster: the server is currently unable to handle the request (get clusters.postgresql.cnpg.io)","stacktrace":"k8s.io/client-go/tools/cache.DefaultWatchErrorHandler\n\tpkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:147\nk8s.io/client-go/tools/cache.(*Reflector).Run.func1\n\tpkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:292\nk8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1\n\tpkg/mod/k8s.io/[email protected]/pkg/util/wait/backoff.go:226\nk8s.io/apimachinery/pkg/util/wait.BackoffUntil\n\tpkg/mod/k8s.io/[email protected]/pkg/util/wait/backoff.go:227\nk8s.io/client-go/tools/cache.(*Reflector).Run\n\tpkg/mod/k8s.io/[email protected]/tools/cache/reflector.go:290\nk8s.io/client-go/tools/cache.(*controller).Run.(*Group).StartWithChannel.func2\n\tpkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:55\nk8s.io/apimachinery/pkg/util/wait.(*Group).Start.func1\n\tpkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:72"}
Stream closed EOF for bzs/bzs-pg-2 (bootstrap-controller)

NicoJDE avatar Dec 23 '23 16:12 NicoJDE

any updates on this?

NicoJDE avatar Mar 07 '24 10:03 NicoJDE

I also hit this problem with the same error message:

{"level":"info","ts":"2024-04-16T06:22:04Z","logger":"wal-restore","msg":"WAL file not found in the recovery object st
ore","logging_pod":"core-royalties-pg16-1","walName":"0000000A00000C6F000000C9","options":["--endpoint-url","https://redacted.example.com","--cloud-provider","aws-s3","s3://db-core-royalties-wal/cnpg/core-royalties-pg16/","core-roy
alties-g16"],"startTime":"2024-04-16T06:22:04Z","endTime":"2024-04-16T06:22:04Z","elapsedWalTime":0.333541198}
{"level":"info","ts":"2024-04-16T06:22:04Z","logger":"postgres","msg":"record","logging_pod":"core-royalties-pg16-1","
record":{"log_time":"2024-04-16 06:22:04.577 UTC","process_id":"40","session_id":"661e190a.28","session_line_num":"5",
"session_start_time":"2024-04-16 06:22:02 UTC","transaction_id":"0","error_severity":"FATAL","sql_state_code":"XX000",
"message":"requested timeline 11 does not contain minimum recovery point C70/2BFFED00 on timeline 10","backend_type":"
startup","query_id":"0"}}
{"level":"info","ts":"2024-04-16T06:22:04Z","logger":"postgres","msg":"record","logging_pod":"core-royalties-pg16-1","

ibotty avatar Apr 16 '24 06:04 ibotty

I have same issue

yxxhero avatar Apr 16 '24 10:04 yxxhero

I now had this happen on a small database (1GB), so it's easy to experiment. It might have also been because of a not-working failover or anything like that. But I cannot reconstruct that ATM.

Doing a barman backup directly before creating a new replica does not work. Restarting the primary before creating a new replica does not work as well.

Anything I can do to debug?

ibotty avatar Sep 18 '24 07:09 ibotty