Postgresql – Error Receiving WAL files with barman

barmanpostgresql

I'm having a similar issue reported here but no solutions have helped: Unable to receive WAL files with barman

Trying to get streaming replication to work. PostgreSQL 9.6 on the master. Barman 2.3 installed on backup server.

barman cron is running every minute

barman switch-wal –archive –archive-timeout 90 pg

    The WAL file 00000001000000000000001D has been closed on server 'pg'
    Waiting for the WAL file 00000001000000000000001D from server 'pg' (max: 90             seconds)
    ERROR: The WAL file 00000001000000000000001D has not been received in 90 seconds

barman check pg

Server pg:
        WAL archive: FAILED (please make sure WAL shipping is setup)
        PostgreSQL: OK
        is_superuser: OK
        PostgreSQL streaming: OK
        wal_level: OK
        replication slot: FAILED (slot 'barman' not initialised: is 'receive-wal' running?)
        directories: OK
        retention policy settings: OK
        backup maximum age: FAILED (interval provided: 3 days, latest backup age: No available backups)
        compression settings: OK
        failed backups: OK (there are 0 failed backups)
        minimum redundancy requirements: FAILED (have 0 backups, expected at least 3)
        pg_basebackup: OK
        pg_basebackup compatible: OK
        pg_basebackup supports tablespaces mapping: OK
        pg_receivexlog: OK
        pg_receivexlog compatible: OK
        receive-wal running: FAILED (See the Barman log file for more details)
        archiver errors: OK

Edit pg.conf

[pg]
conninfo = host=pg user=barman dbname=db
streaming_conninfo = host=pg user=rep dbname=db
backup_method = postgres
streaming_archiver = on
slot_name = barman

SSH is configured but not being used as far as I can tell since all my config is for streaming. Not sure if my "archive_command" parameter on the master is wrong … not sure what to put, right now it's copying files to an archive folder on the master…

One interesting difference for me is that this command hangs, no error received:
barman receive-wal pg

Starting receive-wal for server pg
pg: pg_receivexlog: starting log streaming at 0/1F000000 (timeline 1)

Also:
barman diagnose

{
    "global": {
        "config": {
            "bandwidth_limit": "0",
            "barman_home": "/var/lib/barman",
            "barman_user": "barman",
            "compression": "gzip",
            "configuration_files_directory": "/etc/barman.d",
            "errors_list": [],
            "immediate_checkpoint": "true",
            "last_backup_maximum_age": "3 DAYS",
            "log_file": "/var/log/barman/barman.log",
            "log_level": "DEBUG",
            "minimum_redundancy": "3",
            "retention_policy": "RECOVERY WINDOW OF 4 WEEKS"
        },
        "system_info": {
            "barman_ver": "2.3",
            "kernel_ver": "Linux srv 3.10.0-693.5.2.el7.x86_64 #1 SMP Fri Oct 20 20:32:50 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux",
            "python_ver": "",
            "release": "RedHat Linux CentOS Linux release 7.4.1708 (Core)",
            "rsync_ver": "rsync  version 3.0.9  protocol version 30",
            "ssh_ver": ""
        }
    },
    "servers": {
        "pg": {
            "backups": {},
            "config": {
                "active": true,
                "archiver": false,
                "archiver_batch_size": 0,
                "backup_directory": "/var/lib/barman/pg",
                "backup_method": "postgres",
                "backup_options": "concurrent_backup",
                "bandwidth_limit": 0,
                "barman_home": "/var/lib/barman",
                "barman_lock_directory": "/var/lib/barman",
                "basebackup_retry_sleep": 30,
                "basebackup_retry_times": 0,
                "basebackups_directory": "/var/lib/barman/pg/base",
                "check_timeout": 30,
                "compression": "gzip",
                "conninfo": "host=pg user=barman dbname=db",
                "custom_compression_filter": null,
                "custom_decompression_filter": null,
                "description": "replication and backups of pg",
                "disabled": false,
                "errors_directory": "/var/lib/barman/pg/errors",
                "immediate_checkpoint": true,
                "incoming_wals_directory": "/var/lib/barman/pg/incoming",
                "last_backup_maximum_age": "3 days",
                "max_incoming_wals_queue": null,
                "minimum_redundancy": 3,
                "msg_list": [],
                "name": "pg",
                "network_compression": false,
                "parallel_jobs": 1,
                "path_prefix": null,
                "post_archive_retry_script": null,
                "post_archive_script": null,
                "post_backup_retry_script": null,
                "post_backup_script": null,
                "pre_archive_retry_script": null,
                "pre_archive_script": null,
                "pre_backup_retry_script": null,
                "pre_backup_script": null,
                "recovery_options": "",
                "retention_policy": "window 4 w",
                "retention_policy_mode": "auto",
                "reuse_backup": null,
                "slot_name": "barman",
                "ssh_command": null,
                "streaming_archiver": true,
                "streaming_archiver_batch_size": 0,
                "streaming_archiver_name": "barman_receive_wal",
                "streaming_backup_name": "barman_streaming_backup",
                "streaming_conninfo": "host=pg user=rep dbname=db",
                "streaming_wals_directory": "/var/lib/barman/pg/streaming",
                "tablespace_bandwidth_limit": null,
                "wal_retention_policy": "simple-wal 4 w",
                "wals_directory": "/var/lib/barman/pg/wals"
            },
            "status": {
                "config_file": "/var/lib/pgsql/9.6/data/postgresql.conf",
                "connection_error": null,
                "current_size": 73211260.0,
                "current_xlog": "00000001000000000000001F",
                "data_directory": "/var/lib/pgsql/9.6/data",
                "hba_file": "/var/lib/pgsql/9.6/data/pg_hba.conf",
                "ident_file": "/var/lib/pgsql/9.6/data/pg_ident.conf",
                "is_in_recovery": false,
                "is_superuser": true,
                "pg_basebackup_bwlimit": true,
                "pg_basebackup_compatible": true,
                "pg_basebackup_installed": true,
                "pg_basebackup_path": "/bin/pg_basebackup",
                "pg_basebackup_tbls_mapping": true,
                "pg_basebackup_version": "9.6.5",
                "pg_receivexlog_compatible": true,
                "pg_receivexlog_installed": true,
                "pg_receivexlog_path": "/usr/pgsql-9.6/bin/pg_receivexlog",
                "pg_receivexlog_supports_slots": true,
                "pg_receivexlog_synchronous": false,
                "pg_receivexlog_version": "9.6.5",
                "pgespresso_installed": false,
                "replication_slot": [
                    "barman",
                    false,
                    "0/1F000000"
                ],
                "replication_slot_support": true,
                "server_txt_version": "9.6.5",
                "streaming": true,
                "streaming_supported": true,
                "synchronous_standby_names": [
                    ""
                ],
                "systemid": "6484222452465421803",
                "timeline": 1,
                "wal_level": "replica",
                "xlogpos": "0/1F000680"
            },
            "wals": {
                "last_archived_wal_per_timeline": null
            }
        }
    }
}

This is what I see in the log

2017-12-17 22:57:01,251 [10459] barman.config DEBUG: Including configuration file: pg.conf
2017-12-17 22:57:01,251 [10459] barman.cli DEBUG: Initialised Barman version 2.3 (config: /etc/barman.conf, args: {'debug': False, 'command': 'cron', 'quiet': False, 'format': 'console'})
2017-12-17 22:57:01,251 [10461] barman.config DEBUG: Including configuration file: pg.conf
2017-12-17 22:57:01,252 [10461] barman.cli DEBUG: Initialised Barman version 2.3 (config: /etc/barman.conf, args: {'debug': False, 'command': 'cron', 'quiet': True, 'format': 'console'})
2017-12-17 22:57:01,261 [10459] barman.backup_executor DEBUG: The default backup strategy for postgres backup_method is: concurrent_backup
2017-12-17 22:57:01,261 [10459] barman.command_wrappers DEBUG: Command: ['/usr/bin/pg_basebackup', '--version']
2017-12-17 22:57:01,261 [10461] barman.backup_executor DEBUG: The default backup strategy for postgres backup_method is: concurrent_backup
2017-12-17 22:57:01,261 [10461] barman.command_wrappers DEBUG: Command: ['/usr/bin/pg_basebackup', '--version']
2017-12-17 22:57:01,265 [10461] barman.command_wrappers DEBUG: Command return code: 0
2017-12-17 22:57:01,265 [10461] barman.command_wrappers DEBUG: Command stdout: pg_basebackup (PostgreSQL) 9.6.5

2017-12-17 22:57:01,265 [10461] barman.command_wrappers DEBUG: Command stderr:
2017-12-17 22:57:01,266 [10461] barman.server DEBUG: Retention policy for server pg: RECOVERY WINDOW OF 4 WEEKS
2017-12-17 22:57:01,266 [10461] barman.server DEBUG: WAL retention policy for server pg: MAIN
2017-12-17 22:57:01,266 [10461] barman.command_wrappers DEBUG: BarmanSubProcess: ['/usr/bin/python', '/usr/bin/barman', '-c', '/etc/barman.conf', '-q', 'archive-wal', 'pg']
2017-12-17 22:57:01,266 [10459] barman.command_wrappers DEBUG: Command return code: 0
2017-12-17 22:57:01,266 [10459] barman.command_wrappers DEBUG: Command stdout: pg_basebackup (PostgreSQL) 9.6.5

2017-12-17 22:57:01,266 [10459] barman.command_wrappers DEBUG: Command stderr:
2017-12-17 22:57:01,267 [10459] barman.server DEBUG: Retention policy for server pg: RECOVERY WINDOW OF 4 WEEKS
2017-12-17 22:57:01,267 [10459] barman.server DEBUG: WAL retention policy for server pg: MAIN
2017-12-17 22:57:01,267 [10459] barman.server INFO: Another cron process is already running on server pg. Skipping to the next server
2017-12-17 22:57:01,277 [10461] barman.command_wrappers DEBUG: BarmanSubProcess: subprocess started. pid: 10464
2017-12-17 22:57:01,277 [10461] barman.command_wrappers DEBUG: BarmanSubProcess: ['/usr/bin/python', '/usr/bin/barman', '-c', '/etc/barman.conf', '-q', 'receive-wal', 'pg']
2017-12-17 22:57:01,288 [10461] barman.command_wrappers DEBUG: BarmanSubProcess: subprocess started. pid: 10467
2017-12-17 22:57:01,362 [10464] barman.config DEBUG: Including configuration file: pg.conf
2017-12-17 22:57:01,362 [10464] barman.cli DEBUG: Initialised Barman version 2.3 (config: /etc/barman.conf, args: {'command': 'archive_wal', 'server_name': 'pg', 'format': 'console', 'debug': False, 'config': '/etc/barman.conf', 'quiet': True})
2017-12-17 22:57:01,370 [10467] barman.config DEBUG: Including configuration file: pg.conf
2017-12-17 22:57:01,371 [10467] barman.cli DEBUG: Initialised Barman version 2.3 (config: /etc/barman.conf, args: {'reset': False, 'server_name': 'pg', 'format': 'console', 'stop': False, 'create_slot': False, 'quiet': True, 'command': 'receive_wal', 'debug': False, 'drop_slot': False, 'config': '/etc/barman.conf'})
2017-12-17 22:57:01,372 [10464] barman.backup_executor DEBUG: The default backup strategy for postgres backup_method is: concurrent_backup
2017-12-17 22:57:01,372 [10464] barman.command_wrappers DEBUG: Command: ['/usr/bin/pg_basebackup', '--version']
2017-12-17 22:57:01,376 [10464] barman.command_wrappers DEBUG: Command return code: 0
2017-12-17 22:57:01,376 [10464] barman.command_wrappers DEBUG: Command stdout: pg_basebackup (PostgreSQL) 9.6.5

2017-12-17 22:57:01,376 [10464] barman.command_wrappers DEBUG: Command stderr:
2017-12-17 22:57:01,376 [10464] barman.server DEBUG: Retention policy for server pg: RECOVERY WINDOW OF 4 WEEKS
2017-12-17 22:57:01,376 [10464] barman.server DEBUG: WAL retention policy for server pg: MAIN
2017-12-17 22:57:01,377 [10464] barman.server DEBUG: Starting archive-wal for server pg
2017-12-17 22:57:01,377 [10464] barman.wal_archiver INFO: No xlog segments found from streaming for pg.
2017-12-17 22:57:01,381 [10467] barman.backup_executor DEBUG: The default backup strategy for postgres backup_method is: concurrent_backup
2017-12-17 22:57:01,381 [10467] barman.command_wrappers DEBUG: Command: ['/usr/bin/pg_basebackup', '--version']
2017-12-17 22:57:01,385 [10467] barman.command_wrappers DEBUG: Command return code: 0
2017-12-17 22:57:01,385 [10467] barman.command_wrappers DEBUG: Command stdout: pg_basebackup (PostgreSQL) 9.6.5

2017-12-17 22:57:01,385 [10467] barman.command_wrappers DEBUG: Command stderr:
2017-12-17 22:57:01,385 [10467] barman.server DEBUG: Retention policy for server pg: RECOVERY WINDOW OF 4 WEEKS
2017-12-17 22:57:01,385 [10467] barman.server DEBUG: WAL retention policy for server pg: MAIN
2017-12-17 22:57:01,386 [10467] barman.server INFO: Starting receive-wal for server pg
2017-12-17 22:57:01,390 [10467] barman.command_wrappers DEBUG: Error invoking PgReceiveXlog: command not in PATH, tried: pg_receivewal pg_receivexlog
2017-12-17 22:57:01,391 [10467] barman.server ERROR: ArchiverFailure:pg_receivexlog not present in $PATH

Best Answer

added the following to crontab

* * * * * export PATH=$PATH:/usr/pgsql-9.6/bin; barman cron >/dev/null 2>&1