1

I'm running into this message but not able to make heads or tails out of why it's throwing this:

-bash-4.2$ /usr/pgsql-10/bin/postgres -D /data/patroni --config-file=/data/patroni/postgresql.conf
2019-05-23 08:26:34.561 EDT [10101] LOG:  listening on IPv4 address "192.168.0.108", port 5432
2019-05-23 08:26:34.565 EDT [10101] LOG:  listening on Unix socket "./.s.PGSQL.5432"
2019-05-23 08:26:34.591 EDT [10101] LOG:  redirecting log output to logging collector process
2019-05-23 08:26:34.591 EDT [10101] HINT:  Future log output will appear in directory "log".
^C-bash-4.2/usr/pgsql-10/bin/postgres -D /data/patroni --config-file=/data/patroni/postgresql.conf --hot_standby=on --listen_addresses=192.168.0.108 --max_worker_processes=8 --max_locks_per_transaction=64 --wal_level=replica --cluster_name=postgres --wal_log_hints=on --max_wal_senders=10 --track_commit_timestamp=off --max_prepared_transactions=0 --port=5432 --max_replication_slots=10 --max_connections=100
2019-05-23 08:26:45.707 EDT [10105] LOG:  listening on IPv4 address "192.168.0.108", port 5432
2019-05-23 08:26:45.715 EDT [10105] LOG:  listening on Unix socket "./.s.PGSQL.5432"
2019-05-23 08:26:45.740 EDT [10105] LOG:  redirecting log output to logging collector process
2019-05-23 08:26:45.740 EDT [10105] HINT:  Future log output will appear in directory "log".
^C-bash-4.2$ /usr/pgsql-10/bin/postgres -D /data/patroni --config-file=/data/patroni/postgresql.conf --hot_standby=on --listen_addresses=192.168.0.1 --max_worker_processes=8 --max_locks_per_transaction=64 --wal_level=replica --cluster_name=postgres --wal_log_hints=on --max_wal_senders=10 --track_commit_timestamp=off --max_prepared_transactions=0 --port=5432 --max_replication_slots=10 --max_connections=100
2019-05-23 08:29:36.014 EDT [10188] LOG:  listening on IPv4 address "192.168.0.108", port 5432
2019-05-23 08:29:36.017 EDT [10188] LOG:  listening on Unix socket "./.s.PGSQL.5432"
2019-05-23 08:29:36.040 EDT [10188] LOG:  redirecting log output to logging collector process
2019-05-23 08:29:36.040 EDT [10188] HINT:  Future log output will appear in directory "log".

The database logs only print out this:

2019-05-23 08:25:44.476 EDT [10088] HINT:  The database server will regularly poll the pg_wal subdirectory to check for files placed there.
2019-05-23 08:25:44.477 EDT [10088] LOG:  entering standby mode
2019-05-23 08:25:50.209 EDT [10086] LOG:  received fast shutdown request
2019-05-23 08:25:50.215 EDT [10089] LOG:  shutting down
2019-05-23 08:25:50.221 EDT [10086] LOG:  database system is shut down
2019-05-23 08:26:11.560 EDT [10094] LOG:  database system was shut down in recovery at 2019-05-23 08:25:50 EDT
2019-05-23 08:26:11.560 EDT [10094] WARNING:  recovery command file "recovery.conf" specified neither primary_conninfo nor restore_command
2019-05-23 08:26:11.560 EDT [10094] HINT:  The database server will regularly poll the pg_wal subdirectory to check for files placed there.
2019-05-23 08:26:11.562 EDT [10094] LOG:  entering standby mode
2019-05-23 08:26:17.817 EDT [10092] LOG:  received fast shutdown request
2019-05-23 08:26:17.824 EDT [10095] LOG:  shutting down
2019-05-23 08:26:17.831 EDT [10092] LOG:  database system is shut down
2019-05-23 08:26:34.596 EDT [10103] LOG:  database system was shut down in recovery at 2019-05-23 08:26:17 EDT
2019-05-23 08:26:34.596 EDT [10103] WARNING:  recovery command file "recovery.conf" specified neither primary_conninfo nor restore_command
2019-05-23 08:26:34.596 EDT [10103] HINT:  The database server will regularly poll the pg_wal subdirectory to check for files placed there.
2019-05-23 08:26:34.598 EDT [10103] LOG:  entering standby mode
2019-05-23 08:26:43.025 EDT [10101] LOG:  received fast shutdown request
2019-05-23 08:26:43.032 EDT [10104] LOG:  shutting down
2019-05-23 08:26:43.038 EDT [10101] LOG:  database system is shut down
2019-05-23 08:26:45.748 EDT [10107] LOG:  database system was shut down in recovery at 2019-05-23 08:26:43 EDT
2019-05-23 08:26:45.748 EDT [10107] WARNING:  recovery command file "recovery.conf" specified neither primary_conninfo nor restore_command
2019-05-23 08:26:45.748 EDT [10107] HINT:  The database server will regularly poll the pg_wal subdirectory to check for files placed there.

and when connecting, I get this cryptic message:

[root@psql01 log]# psql -U postgres -h 192.168.0.108
psql: FATAL:  the database system is starting up
[root@psql01 log]#

There's no space issue here. I'm wondering where else to look to figure out why it's failing to startup.

This postgresql is part of a 3 node patroni w/ etcd cluster. Trying to recover it from a recent power outage.

The system stays in recovery. This state doesn't change and the DB is inaccessible.

Update:

Ran the above in debug mode and got this:

DEBUG:  mmap(148897792) with MAP_HUGETLB failed, huge pages disabled: Cannot allocate memory

so I freed memory on the underlying physical this VM sits on but no luck. Same memory error and same result as above.

When patroni is started on just this one node (troubleshooting purposes) I get the message:

[root@psql01 ~]# ps -ef|grep -Ei "patroni|postgres"
root      2217  2188  0 00:38 pts/1    00:00:00 tail -f postgresql-Thu.log
postgres  2512     1  4 00:42 ?        00:00:01 /usr/bin/python2 /bin/patroni /etc/patroni.yml
postgres  2533     1  0 00:42 ?        00:00:00 /usr/pgsql-10/bin/postgres -D /data/patroni --config-file=/data/patroni/postgresql.conf --hot_standby=on --listen_addresses=192.168.0.108 --max_worker_processes=8 --max_locks_per_transaction=64 --wal_level=replica --cluster_name=postgres --wal_log_hints=on --max_wal_senders=10 --track_commit_timestamp=off --max_prepared_transactions=0 --port=5432 --max_replication_slots=10 --max_connections=100
postgres  2535  2533  0 00:42 ?        00:00:00 postgres: postgres: logger process
postgres  2536  2533  0 00:42 ?        00:00:00 postgres: postgres: startup process   waiting for 000000010000000000000008
root      2664  2039  0 00:42 pts/0    00:00:00 grep --color=auto -Ei patroni|postgres
[root@psql01 ~]#

The system prints "postgres: postgres: startup process waiting for 000000010000000000000008"

Seems it's trying to replay the history log but can't? Running an strace on the file reveals that it's looking for the following:

read(5, 0x7fff9cb4eb87, 1)              = -1 EAGAIN (Resource temporarily unavailable)
read(5, 0x7fff9cb4eb87, 1)              = -1 EAGAIN (Resource temporarily unavailable)
open("pg_wal/00000098.history", O_RDONLY) = -1 ENOENT (No such file or directory)
epoll_create1(EPOLL_CLOEXEC)            = 3

But this file doesn't exist in the directory on this particular cluster node.

Using a copy of the data files on another node (pgsql02), yields this error:

PANIC:  replication checkpoint has wrong magic 0 instead of 307747550

On the third cluster node (pgsql03) I get this error:

FATAL:  syntax error in history file: f2W

Hoping I'm able to recover the data from at least one of the nodes, make it primary, and get it to replicate to the others.

Thx, TK

  • Did you pause Patroni and modify recovery.conf? Patroni normally configures it correctly. – Laurenz Albe May 23 at 12:44
  • I did. It's one of the combinations I tried. – Tom K May 24 at 3:18
  • That might have wrecked your setup. The recovery.conf file is broken, so replication doesn't work. Hard to diagnose remotely. – Laurenz Albe May 24 at 5:16
  • recovery.conf got overwritten to whatever Patroni wanted in there despite any effort to modify the recovery.conf. So my attempts failed. ( Probably better off that it did fail? ) I tried to modify postgresql.conf ( or postgresql.base.conf) on the single node (while the others were stopped) to see if I can get into the DB on at least one node. No luck. I did a backup of the data directory and sub dir's on each node to /root/backup/ before I mucked around though. Same situation before and after. – Tom K May 24 at 22:48
  • To edit Postgres settings, you can do patronictl edit-config, and that will be persisted in your chosen DCS. There is basically nothing to change on recovery.conf otherwise. In any case, how much memory did you allocate to the VM Patroni is running on? – dezso Jul 17 at 12:35

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.