Patroni: replicas pg_xlog directory filling up

[bodymindarts]

Since running some patroni managed pg instances we have observed the pg_xlog directory for of the replicas seems to keep growing much continuously and larger than the leaders and regardless of whether data is being written to the leader or not.

Is this a known issue? Is there a part of the system that should clean up the data from the replicas that isn't configured properly or do we need to manage this ourselves?

[CyberDem0n]

First of all you need to figure out why it is happening.
I envision following possibilities:
1) Huge value of wal_keep_segments on replica.
2) There are some "staled" replication slots on replica.

In order to diagnose it properly please connect to the replica with psql and run following:
1) show wal_keep_segments -- if the value is big (unlikely), this is the reason, just fix the config and restart
2) SELECT * FROM pg_replication_slots -- if there are some replication slots exist, they will prevent wal segments from cleaning up. Try to drop them with SELECT pg_drop_replication_slot('<slot_name>');, it should help.

The only question would be, what names do these slots have? (Are the names matching with the names of other cluster nodes?)

[bodymindarts]

These are the results from one of the replicas:

postgres=> show wal_keep_segments;
 wal_keep_segments
-------------------
 8
(1 row)

postgres=> SELECT * FROM pg_replication_slots;
 slot_name | plugin | slot_type | datoid | database | active | active_pid | xmin | catalog_xmin | restart_lsn
-----------+--------+-----------+--------+----------+--------+------------+------+--------------+-------------
(0 rows)

postgres=>

[bodymindarts]

According to this article it is safe to remove all files older than the file given by pg_controldata at Latest checkpoint's REDO WAL file: 000000030000000E00000004

[bodymindarts]

running this command periodically to cleanup old files may be a solution:

pg_datadir=/path/to/pgsql/data

last_wal_file=$(pg_controldata $pg_datadir | grep "Latest checkpoint's REDO WAL file" | awk '{print $NF}')

find $pg_datadir/pg_xlog -maxdepth 1 -type f \
  \! -name $last_wal_file \
  \! -newer $pg_datadir/pg_xlog/$last_wal_file \
  -exec rm {} \;

Does someone see any downsides to it?

[alexeyklyukin]

Hi,

On 30 May 2016, at 21:51, Justin Carter [email protected] wrote:

These are the results from one of the replicas:

postgres=> show wal_keep_segments;

wal_keep_segments

8
(1 row)

postgres=> SELECT * FROM pg_replication_slots;
slot_name | plugin | slot_type | datoid | database | active | active_pid | xmin | catalog_xmin | restart_lsn
-----------+--------+-----------+--------+----------+--------+------------+------+--------------+-------------
(0 rows)

postgres=>
—

Do you see a significant amount (more than 2-3) of .ready files in the pg_xlog/archive_status subdirectory on the replica that accumulates the segments? If you do and they belong to not the most recent files - they might have been copied from the master, and you can rename them to .done a and do a checkpoint - that would remove the actual segments.

How many xlog segments do you have? Normally, the replica should leave not more than 3 * wal_keep_segments files.If you have more than that - something is likely preventing removal of those files. Perhaps set the log level to DEBUG1 and see if there are any unusual messages during checkpoint?

[bodymindarts]

there are currently 446 .ready files in pg_xlog/archive_status 461 files in pg_xlog even though wal_keep_segments is set to 8.

[alexeyklyukin]

On 30 May 2016, at 22:41, Justin Carter [email protected] wrote:

there are currently 446 .ready files in pg_xlog/archive_status 461 files in pg_xlog even though wal_keep_segments is set to 8.

Sorry, my bad, it’s not 3 * wal_keep_segments, but 3 * checkpoint_segments.

_On the replica_ you may try renaming the .ready files into the .done and do the checkpoint. This should cleanup the xlog.

Kind regards,

Oleksii Kliukin | 5432 Engineer | phone: [phone] | hipchat: @OleksiiKliukin

[bodymindarts]

Ok thank you for your help. That sounds like another option.

[bodymindarts]

renaming the .ready files did the trick! thank you @alexeyklyukin. Any idea what could have caused that? almost all files were named ready.

[alexeyklyukin]

It might happen if pg_xlog directory is copied verbatim from the master, and the master had some files that were not yet archived at the time when the copy took place. It's unlikely to happen if you use Patroni to initialize your replica and use the default base backup method.

[bodymindarts]

That is strange we are using the default pg_basebackup from patroni

cc/ @drnic.

[bodymindarts]

  recovery_conf:
    restore_command: ${restore_command}
    archive_cleanup_command: 'pg_archivecleanup -d $PGDATA/pg_xlog  %r'

Adding archive_cleanup_command: is what finally fixed this longterm.
I am confused as to why you don't have this issue even though I cannot see the archive_cleanup_command configured in spilo. No matter what configuration I try I get this behaviour when that command isn't specified. @alexeyklyukin

[alexeyklyukin]

@bodymindarts this is totally wrong. The archive_cleanup_command is supposed to clean your _WAL archive_, not the pg_xlog directory of your replica.

What does the archive_command on the master server do?

[bodymindarts]

This command only gets triggered on replicas, never on the master.
I read about the pgarchivecleanup command in this article that deals with pg_xlog filling up. But I guess I didn't see that it is meant only for cleaning up an external archive not the live pg_xlog.

From observing a 2 node cluster running in docker locally this is what is happening:

• leader cleans its own pg_xlog from time to time
• replica doesn't and all files that were cleaned up on master get made into .ready files on the replica.

With the archive_cleanup_command pointing locally those files get cleaned up too.
Failover and recovery continue to work with that command configured. If this is not how this option is intended to be used, I am even more confused as to how this is typically dealt with.

EDIT:
Master periodically purges the number of wall files down to:
wal_keep_segments: 8 but the same is not happening on the replica.

[alexeyklyukin]

No, you should never run pg_archivecleanup on the xlog directory. In the article you've linked to Craig Ringer says explicitly:

Removing still-required transaction logs will render your database unable to start and the recovery steps required may cause corruption. You should have a big fat warning about this.

The master and the replica do not remove transaction log files directly after they have dealt with them. Instead, those files are recycled for the future segments, unless the limit on the number of simultaneous WAL segments is reached. I don't know what happens if you mess with this process by removing your WAL files explicitly, but it won't be anything good.

Again, what does the archive_command on the master do?

[bodymindarts]

ENVDIR="envdir ${WALE_ENV_DIR}"
archive_command="${ENVDIR} wal-e wal-push \"%p\" -p 1"
(...)
cat <<EOF >>/patroni/postgres.yml
parameters:
    archive_command: ${archive_command}
EOF

Same as in splio just not using the --aws-instance-profile flag.

[alexeyklyukin]

Hm... I don't see the details of where the command actually puts the data. Any chances your archive_command copies the WAL segments directory into the pg_xlog directory of the replica?

[bodymindarts]

I don't quite understand what you mean with 'archive_command copies the WAL segments directory into the pg_xlog directory of the replica'. I cannot find up to now how our setup differs from spilo in this regard.

wal-e is pushing wal logs to s3 via wal-e push and replicas are being created via [wal_e,basebackups] (from observations the same issue occurs with both methods)

  wal_e:
    command: /patroni/scripts/wale_restore.py
    # {key: value} below are converted to options for wale_restore.py script
    envdir: ${WALE_ENV_DIR}
    threshold_megabytes: 10240
    threshold_backup_size_percentage: 30
    retries: 2
    use_iam: 0
    no_master: 1
  recovery_conf:
    restore_command: ${ENVDIR} wal-e wal-fetch \"%f\" \"%p\" -p 1

[alexeyklyukin]

You said you were observing the issue in a local docker container as well, do you?

From observing a 2 node cluster running in docker locally this is what is happening:
leader cleans its own pg_xlog from time to time
replica doesn't and all files that were cleaned up on master get made into .ready files on the replica.

[bodymindarts]

Perhaps that wasn't precise. 2 nodes = 2 docker containers each with 1 patroni/pg instance.
Based of off this docker-compose.yml

Observing means with a local setup of our images, including backups to s3, this issue is observable. I can check if it happens also without streaming to s3.

[bodymindarts]

Since updating wal-e and patroni to v0.90 issue hasn't occurred anymore