EnterpriseDB / barman

Barman - Backup and Recovery Manager for PostgreSQL
https://www.pgbarman.org/
GNU General Public License v3.0
2.07k stars 191 forks source link

Backup fails using postgresql method #174

Closed mwuttke closed 6 years ago

mwuttke commented 6 years ago

I've updated the barman version from 2.3 to 2.4 (debian strech package from the pgdg repository ) and now I've problems using the postgresql basebackup method. The basebackup process seems to completing the data transfer but the backup ends with an error:

cat /var/log/barman/barman.log | grep 32434
2018-05-28 11:45:46,894 [32434] barman.config DEBUG: Including configuration file: pgcluster.conf
2018-05-28 11:45:46,899 [32434] barman.cli DEBUG: Initialised Barman version 2.4 (config: /etc/barman.conf, args: {'reuse_backup': None, 'jobs': None, 'server_name': ['pgcluster'], 'format': 'console', 'quiet': False, 'retry_times': None, 'command': 'backup', 'retry_sleep': None, 'debug': False})
2018-05-28 11:45:46,960 [32434] barman.backup_executor DEBUG: The default backup strategy for postgres backup_method is: concurrent_backup
2018-05-28 11:45:46,960 [32434] barman.server DEBUG: Retention policy for server pgcluster: RECOVERY WINDOW OF 7 DAYS
2018-05-28 11:45:46,960 [32434] barman.server DEBUG: WAL retention policy for server pgcluster: MAIN
2018-05-28 11:45:46,960 [32434] barman.server DEBUG: Starting check: WAL archive
2018-05-28 11:45:46,961 [32434] barman.server DEBUG: Starting check: empty incoming directory
2018-05-28 11:45:46,961 [32434] barman.server DEBUG: Starting check: empty streaming directory
2018-05-28 11:45:46,961 [32434] barman.server DEBUG: Starting check: PostgreSQL
2018-05-28 11:45:47,005 [32434] barman.command_wrappers DEBUG: Command: ['/usr/bin/pg_receivewal', '--version']
2018-05-28 11:45:47,056 [32434] barman.command_wrappers DEBUG: Command return code: 0
2018-05-28 11:45:47,057 [32434] barman.command_wrappers DEBUG: Command stdout: pg_receivewal (PostgreSQL) 10.4 (Debian 10.4-2.pgdg90+1)
2018-05-28 11:45:47,057 [32434] barman.command_wrappers DEBUG: Command stderr: could not change directory to "/root": Keine Berechtigung
2018-05-28 11:45:47,060 [32434] barman.wal_archiver DEBUG: Look for 'barman_receive_wal' in 'synchronous_standby_names': ['']
2018-05-28 11:45:47,061 [32434] barman.wal_archiver DEBUG: Synchronous WAL streaming for barman_receive_wal: False
2018-05-28 11:45:47,061 [32434] barman.command_wrappers DEBUG: Command: ['/usr/bin/pg_basebackup', '--version']
2018-05-28 11:45:47,123 [32434] barman.command_wrappers DEBUG: Command return code: 0
2018-05-28 11:45:47,123 [32434] barman.command_wrappers DEBUG: Command stdout: pg_basebackup (PostgreSQL) 10.4 (Debian 10.4-2.pgdg90+1)
2018-05-28 11:45:47,123 [32434] barman.command_wrappers DEBUG: Command stderr: could not change directory to "/root": Keine Berechtigung
2018-05-28 11:45:47,124 [32434] barman.server DEBUG: Check 'PostgreSQL' succeeded for server 'pgcluster'
2018-05-28 11:45:47,125 [32434] barman.server DEBUG: Starting check: is_superuser
2018-05-28 11:45:47,125 [32434] barman.server DEBUG: Check 'is_superuser' succeeded for server 'pgcluster'
2018-05-28 11:45:47,125 [32434] barman.server DEBUG: Starting check: PostgreSQL streaming
2018-05-28 11:45:47,125 [32434] barman.server DEBUG: Check 'PostgreSQL streaming' succeeded for server 'pgcluster'
2018-05-28 11:45:47,125 [32434] barman.server DEBUG: Starting check: wal_level
2018-05-28 11:45:47,125 [32434] barman.server DEBUG: Check 'wal_level' succeeded for server 'pgcluster'
2018-05-28 11:45:47,125 [32434] barman.server DEBUG: Starting check: replication slot
2018-05-28 11:45:47,126 [32434] barman.server DEBUG: Check 'replication slot' succeeded for server 'pgcluster'
2018-05-28 11:45:47,126 [32434] barman.server DEBUG: Starting check: directories
2018-05-28 11:45:47,126 [32434] barman.server DEBUG: Check 'directories' succeeded for server 'pgcluster'
2018-05-28 11:45:47,126 [32434] barman.server DEBUG: Starting check: retention policy settings
2018-05-28 11:45:47,126 [32434] barman.server DEBUG: Check 'retention policy settings' succeeded for server 'pgcluster'
2018-05-28 11:45:47,126 [32434] barman.server DEBUG: Starting check: backup maximum age
2018-05-28 11:45:47,127 [32434] barman.server DEBUG: Check 'backup maximum age' succeeded for server 'pgcluster'
2018-05-28 11:45:47,127 [32434] barman.server DEBUG: Starting check: compression settings
2018-05-28 11:45:47,127 [32434] barman.server DEBUG: Check 'compression settings' succeeded for server 'pgcluster'
2018-05-28 11:45:47,127 [32434] barman.server DEBUG: Starting check: failed backups
2018-05-28 11:45:47,130 [32434] barman.server INFO: Ignoring failed check 'failed backups' for server 'pgcluster'
2018-05-28 11:45:47,130 [32434] barman.server DEBUG: Starting check: minimum redundancy requirements
2018-05-28 11:45:47,130 [32434] barman.server DEBUG: Check 'minimum redundancy requirements' succeeded for server 'pgcluster'
2018-05-28 11:45:47,130 [32434] barman.server DEBUG: Starting check: pg_basebackup
2018-05-28 11:45:47,130 [32434] barman.server DEBUG: Check 'pg_basebackup' succeeded for server 'pgcluster'
2018-05-28 11:45:47,130 [32434] barman.server DEBUG: Starting check: pg_basebackup compatible
2018-05-28 11:45:47,130 [32434] barman.server DEBUG: Check 'pg_basebackup compatible' succeeded for server 'pgcluster'
2018-05-28 11:45:47,131 [32434] barman.server DEBUG: Starting check: pg_basebackup supports tablespaces mapping
2018-05-28 11:45:47,133 [32434] barman.server DEBUG: Check 'pg_basebackup supports tablespaces mapping' succeeded for server 'pgcluster'
2018-05-28 11:45:47,134 [32434] barman.server DEBUG: Starting check: configuration
2018-05-28 11:45:47,134 [32434] barman.server DEBUG: Starting check: pg_receivexlog
2018-05-28 11:45:47,134 [32434] barman.server DEBUG: Check 'pg_receivexlog' succeeded for server 'pgcluster'
2018-05-28 11:45:47,134 [32434] barman.server DEBUG: Starting check: pg_receivexlog compatible
2018-05-28 11:45:47,134 [32434] barman.server DEBUG: Check 'pg_receivexlog compatible' succeeded for server 'pgcluster'
2018-05-28 11:45:47,134 [32434] barman.server DEBUG: Starting check: receive-wal running
2018-05-28 11:45:47,134 [32434] barman.server DEBUG: Check 'receive-wal running' succeeded for server 'pgcluster'
2018-05-28 11:45:47,134 [32434] barman.server DEBUG: Starting check: archiver errors
2018-05-28 11:45:47,135 [32434] barman.server DEBUG: Check 'archiver errors' succeeded for server 'pgcluster'
2018-05-28 11:45:47,135 [32434] barman.backup DEBUG: initialising backup information
2018-05-28 11:45:47,139 [32434] barman.backup INFO: Starting backup using postgres method for server pgcluster in /var/lib/barman/pgcluster/base/20180528T114547
2018-05-28 11:45:47,141 [32434] barman.backup_executor DEBUG: detecting data directory
2018-05-28 11:45:47,146 [32434] barman.backup_executor DEBUG: detecting tablespaces
2018-05-28 11:45:47,147 [32434] barman.backup_executor DEBUG: issuing start backup command
2018-05-28 11:45:47,150 [32434] barman.backup_executor INFO: Backup start at LSN: 17/50000140 (000000010000001700000050, 00000140)
2018-05-28 11:45:47,152 [32434] barman.backup_executor INFO: Starting backup copy via pg_basebackup for 20180528T114547
2018-05-28 11:45:47,153 [32434] barman.command_wrappers DEBUG: Command: ['/usr/bin/pg_basebackup', '--dbname=dbname=replication host=pgcluster options=-cdatestyle=iso replication=true user=postgres application_name=barman_streaming_backup', '-v', '--no-password', '--pgdata=/var/lib/barman/pgcluster/base/20180528T114547/data', '--no-slot', '--wal-method=none']
2018-05-28 11:48:33,543 [32434] barman.command_wrappers DEBUG: Command return code: 0
2018-05-28 11:48:33,545 [32434] barman.backup ERROR: Backup failed copying files.
DETAILS: 'ascii' codec can't encode character u'\xf6' in position 216: ordinal not in range(128)
cat /var/lib/barman/bareos/base/20180528T114547/backup.info 
backup_label=None
begin_offset=320
begin_time=2018-05-28 11:45:47.144933+02:00
begin_wal=000000010000001700000050
begin_xlog=17/50000140
config_file=/etc/postgresql/10/main/postgresql.conf
copy_stats=None
deduplicated_size=None
end_offset=None
end_time=None
end_wal=None
end_xlog=None
error=failure copying files ('ascii' codec can't encode character u'\xf6' in position 216: ordinal not in range(128))
hba_file=/etc/postgresql/10/main/pg_hba.conf
ident_file=/etc/postgresql/10/main/pg_ident.conf
included_files=None
mode=postgres
pgdata=/var/lib/postgresql/10/main
server_name=bareos
size=None
status=FAILED
tablespaces=None
timeline=1
version=100004
xlog_segment_size=16777216
 barman diagnose
{
    "global": {
        "config": {
            "barman_home": "/var/lib/barman", 
            "barman_user": "barman", 
            "configuration_files_directory": "/etc/barman.d", 
            "errors_list": [], 
            "log_file": "/var/log/barman/barman.log", 
            "log_level": "DEBUG"
        }, 
        "system_info": {
            "barman_ver": "2.4", 
            "kernel_ver": "Linux barman 4.16.0-0.bpo.1-amd64 #1 SMP Debian 4.16.5-1~bpo9+1 (2018-05-06) x86_64 GNU/Linux", 
            "python_ver": "", 
            "release": "Distributor ID:\tDebian\nDescription:\tDebian GNU/Linux 9.4 (stretch)\nRelease:\t9.4\nCodename:\tstretch", 
            "rsync_ver": "rsync  version 3.1.2  protocol version 31", 
            "ssh_ver": ""
        }
    }, 
    "servers": {
        "pgcluster": {
            "backups": {
                "20180526T225302": {
                    "backup_id": "20180526T225302", 
                    "backup_label": null, 
                    "begin_offset": 40, 
                    "begin_time": "Sat May 26 22:53:03 2018", 
                    "begin_wal": "0000000100000016000000B9", 
                    "begin_xlog": "16/B9000028", 
                    "config_file": "/etc/postgresql/10/main/postgresql.conf", 
                    "copy_stats": {
                        "copy_time": 163.11997, 
                        "total_time": 163.11997
                    }, 
                    "deduplicated_size": 18417589383, 
                    "end_offset": 0, 
                    "end_time": "Sat May 26 22:55:45 2018", 
                    "end_wal": "0000000100000016000000B9", 
                    "end_xlog": "16/BA000000", 
                    "error": null, 
                    "hba_file": "/etc/postgresql/10/main/pg_hba.conf", 
                    "ident_file": "/etc/postgresql/10/main/pg_ident.conf", 
                    "included_files": null, 
                    "mode": "postgres", 
                    "pgdata": "/var/lib/postgresql/10/main", 
                    "server_name": "pgcluster", 
                    "size": 18417589383, 
                    "status": "DONE", 
                    "tablespaces": null, 
                    "timeline": 1, 
                    "version": 100004, 
                    "xlog_segment_size": 16777216
                }, 
                "20180528T112307": {
                    "backup_id": "20180528T112307", 
                    "backup_label": null, 
                    "begin_offset": 10348264, 
                    "begin_time": "Mon May 28 11:23:07 2018", 
                    "begin_wal": "00000001000000170000004E", 
                    "begin_xlog": "17/4E9DE6E8", 
                    "config_file": "/etc/postgresql/10/main/postgresql.conf", 
                    "copy_stats": null, 
                    "deduplicated_size": null, 
                    "end_offset": null, 
                    "end_time": null, 
                    "end_wal": null, 
                    "end_xlog": null, 
                    "error": "failure copying files ('ascii' codec can't encode character u'\\xf6' in position 216: ordinal not in range(128))", 
                    "hba_file": "/etc/postgresql/10/main/pg_hba.conf", 
                    "ident_file": "/etc/postgresql/10/main/pg_ident.conf", 
                    "included_files": null, 
                    "mode": "postgres", 
                    "pgdata": "/var/lib/postgresql/10/main", 
                    "server_name": "pgcluster", 
                    "size": null, 
                    "status": "FAILED", 
                    "tablespaces": null, 
                    "timeline": 1, 
                    "version": 100004, 
                    "xlog_segment_size": 16777216
                }, 
                "20180528T114547": {
                    "backup_id": "20180528T114547", 
                    "backup_label": null, 
                    "begin_offset": 320, 
                    "begin_time": "Mon May 28 11:45:47 2018", 
                    "begin_wal": "000000010000001700000050", 
                    "begin_xlog": "17/50000140", 
                    "config_file": "/etc/postgresql/10/main/postgresql.conf", 
                    "copy_stats": null, 
                    "deduplicated_size": null, 
                    "end_offset": null, 
                    "end_time": null, 
                    "end_wal": null, 
                    "end_xlog": null, 
                    "error": "failure copying files ('ascii' codec can't encode character u'\\xf6' in position 216: ordinal not in range(128))", 
                    "hba_file": "/etc/postgresql/10/main/pg_hba.conf", 
                    "ident_file": "/etc/postgresql/10/main/pg_ident.conf", 
                    "included_files": null, 
                    "mode": "postgres", 
                    "pgdata": "/var/lib/postgresql/10/main", 
                    "server_name": "pgcluster", 
                    "size": null, 
                    "status": "FAILED", 
                    "tablespaces": null, 
                    "timeline": 1, 
                    "version": 100004, 
                    "xlog_segment_size": 16777216
                }
            }, 
            "config": {
                "active": true, 
                "archiver": false, 
                "archiver_batch_size": 0, 
                "backup_directory": "/var/lib/barman/pgcluster", 
                "backup_method": "postgres", 
                "backup_options": "concurrent_backup", 
                "bandwidth_limit": null, 
                "barman_home": "/var/lib/barman", 
                "barman_lock_directory": "/var/lib/barman", 
                "basebackup_retry_sleep": 30, 
                "basebackup_retry_times": 0, 
                "basebackups_directory": "/var/lib/barman/pgcluster/base", 
                "check_timeout": 30, 
                "compression": null, 
                "conninfo": "host=pgcluster user=postgres dbname=postgres", 
                "custom_compression_filter": null, 
                "custom_decompression_filter": null, 
                "description": "PostgreSQL Database on pgcluster", 
                "disabled": false, 
                "errors_directory": "/var/lib/barman/pgcluster/errors", 
                "immediate_checkpoint": false, 
                "incoming_wals_directory": "/var/lib/barman/pgcluster/incoming", 
                "last_backup_maximum_age": null, 
                "max_incoming_wals_queue": null, 
                "minimum_redundancy": 0, 
                "msg_list": [], 
                "name": "pgcluster", 
                "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, 
                "post_delete_retry_script": null, 
                "post_delete_script": null, 
                "post_recovery_retry_script": null, 
                "post_recovery_script": null, 
                "post_wal_delete_retry_script": null, 
                "post_wal_delete_script": null, 
                "pre_archive_retry_script": null, 
                "pre_archive_script": null, 
                "pre_backup_retry_script": null, 
                "pre_backup_script": null, 
                "pre_delete_retry_script": null, 
                "pre_delete_script": null, 
                "pre_recovery_retry_script": null, 
                "pre_recovery_script": null, 
                "pre_wal_delete_retry_script": null, 
                "pre_wal_delete_script": null, 
                "recovery_options": "", 
                "retention_policy": "window 7 d", 
                "retention_policy_mode": "auto", 
                "reuse_backup": null, 
                "slot_name": "barman", 
                "ssh_command": "ssh postgres@pgcluster", 
                "streaming_archiver": true, 
                "streaming_archiver_batch_size": 0, 
                "streaming_archiver_name": "barman_receive_wal", 
                "streaming_backup_name": "barman_streaming_backup", 
                "streaming_conninfo": "host=pgcluster user=postgres dbname=postgres", 
                "streaming_wals_directory": "/var/lib/barman/pgcluster/streaming", 
                "tablespace_bandwidth_limit": null, 
                "wal_retention_policy": "simple-wal 7 d", 
                "wals_directory": "/var/lib/barman/pgcluster/wals"
            }, 
            "status": {
                "config_file": "/etc/postgresql/10/main/postgresql.conf", 
                "connection_error": null, 
                "current_size": 18418710804.0, 
                "current_xlog": "000000010000001700000052", 
                "data_directory": "/var/lib/postgresql/10/main", 
                "hba_file": "/etc/postgresql/10/main/pg_hba.conf", 
                "ident_file": "/etc/postgresql/10/main/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": "/usr/bin/pg_basebackup", 
                "pg_basebackup_tbls_mapping": true, 
                "pg_basebackup_version": "10.4-2.pgdg90+1)", 
                "pg_receivexlog_compatible": true, 
                "pg_receivexlog_installed": true, 
                "pg_receivexlog_path": "/usr/bin/pg_receivewal", 
                "pg_receivexlog_supports_slots": true, 
                "pg_receivexlog_synchronous": false, 
                "pg_receivexlog_version": "10.4-2.pgdg90+1)", 
                "pgespresso_installed": false, 
                "replication_slot": [
                    "barman", 
                    true, 
                    "17/52000000"
                ], 
                "replication_slot_support": true, 
                "server_txt_version": "10.4", 
                "streaming": true, 
                "streaming_supported": true, 
                "synchronous_standby_names": [
                    ""
                ], 
                "systemid": "6536089255217622081", 
                "timeline": 1, 
                "wal_level": "replica", 
                "xlogpos": "17/52000140"
            }, 
            "wals": {
                "last_archived_wal_per_timeline": {
                    "00000001": {
                        "compression": null, 
                        "name": "000000010000001700000051", 
                        "size": 16777216, 
                        "time": 1527500912.2586727
                    }
                }
            }
        }, 

and:

barman check pgcluster
Server pgcluster:
    PostgreSQL: OK
    is_superuser: OK
    PostgreSQL streaming: OK
    wal_level: OK
    replication slot: OK
    directories: OK
    retention policy settings: OK
    backup maximum age: OK (no last_backup_maximum_age provided)
    compression settings: OK
    failed backups: FAILED (there are 2 failed backups)
    minimum redundancy requirements: OK (have 1 backups, expected at least 0)
    pg_basebackup: OK
    pg_basebackup compatible: OK
    pg_basebackup supports tablespaces mapping: OK
    pg_receivexlog: OK
    pg_receivexlog compatible: OK
    receive-wal running: OK
    archiver errors: OK

Any idea what is wrong? Or any hints? Thanks & Greetings, Michael

mnencia commented 6 years ago

It looks like that pg_basebackup output contains some non-unicode character. Could you please check what is the default locale of the barman server?

mwuttke commented 6 years ago

de_DE.UTF-8 is the default locale

mnencia commented 6 years ago

Could you please search your barman logs to see if there is one or more stacktraces? It would be useful.

mwuttke commented 6 years ago

Hello Marco,

no I could'nt find any other stacktraces at the moment.

Shoud I change the default locale?

Thanks & Greetings, Michael

mnencia commented 6 years ago

Another small question: could you please run the following query on your PostgreSQL server?

SELECT name, setting FROM pg_settings WHERE name ~ '(encoding|lc_)';
mwuttke commented 6 years ago

Sure:

postgres=# SELECT name, setting FROM pgsettings WHERE name ~ '(encoding|lc)';

      name       |   setting   
-----------------+-------------
 client_encoding | UTF8
 lc_collate      | de_DE.UTF-8
 lc_ctype        | de_DE.UTF-8
 lc_messages     | de_DE.UTF-8
 lc_monetary     | de_DE.UTF-8
 lc_numeric      | de_DE.UTF-8
 lc_time         | de_DE.UTF-8
 server_encoding | UTF8

(8 Zeilen)

Thanks, Michael

mnencia commented 6 years ago

Ok, thanks. That's enough information. I'll look at the code.

Meantime as a workaround, you could try to set the shell locale to C before running Barman.

export LC_ALL=C

If that doesn't work you can try also setting

lc_messages = C

in the PostgreSQL configuration.

mwuttke commented 6 years ago

Hello Marco,

Sorry, but neither works for me. Neither the changes in the shell nor on the posgresql server.

Thanks, Michael

mnencia commented 6 years ago

ok, thanks

mlachal commented 6 years ago

Hello,

I have the same problem than moodlebeuth. Here is the information I can provide:

Installed Packages
barman.noarch    2.4-1.rhel6    @pgdg94

which got updated yesterday.

barman diagnose
{
    "global": {
        "config": {
            "archiver": "off", 
            "barman_home": "/data/barman", 
            "barman_user": "barman", 
            "basebackup_retry_sleep": "300", 
            "basebackup_retry_times": "2", 
            "compression": "gzip", 
            "configuration_files_directory": "/etc/barman.d", 
            "errors_list": [], 
            "immediate_checkpoint": "true", 
            "last_backup_maximum_age": "1 DAYS", 
            "log_file": "/var/log/barman/barman.log", 
            "minimum_redundancy": "1", 
            "retention_policy": "RECOVERY WINDOW OF 3 days", 
            "retention_policy_mode": "auto", 
            "reuse_backup": "off", 
            "wal_retention_policy": "main"
        }, 
        "system_info": {
            "barman_ver": "2.4", 
            "kernel_ver": "Linux vmpostgre-pbarman1 2.6.32-696.30.1.el6.x86_64 #1 SMP Tue May 22 03:28:18 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux", 
            "python_ver": "", 
            "release": "LSB Version:\t:base-4.0-amd64:base-4.0-noarch:core-4.0-amd64:core-4.0-noarch:graphics-4.0-amd64:graphics-4.0-noarch:printing-4.0-amd64:printing-4.0-noarch\nDistributor ID:\tCentOS\nDescription:\tCentOS release 6.9 (Final)\nRelease:\t6.9\nCodename:\tFinal", 
            "rsync_ver": "rsync  version 3.0.6  protocol version 30", 
            "ssh_ver": ""
        }
    }, 
    "servers": {
        "vmpostgre-pdsi1": {
            "backups": {
[...]
                "20180606T233001": {
                    "backup_id": "20180606T233001", 
                    "backup_label": null, 
                    "begin_offset": 40, 
                    "begin_time": "Wed Jun  6 23:30:02 2018", 
                    "begin_wal": "0000000100000039000000A4", 
                    "begin_xlog": "39/A4000028", 
                    "config_file": "/data/pgsql/9.6/postgresql.conf", 
                    "copy_stats": {
                        "copy_time": 5.0719139999999996, 
                        "total_time": 5.0719139999999996
                    }, 
                    "deduplicated_size": 528815511, 
                    "end_offset": 0, 
                    "end_time": "Wed Jun  6 23:30:07 2018", 
                    "end_wal": "0000000100000039000000A4", 
                    "end_xlog": "39/A5000000", 
                    "error": null, 
                    "hba_file": "/data/pgsql/9.6/pg_hba.conf", 
                    "ident_file": "/data/pgsql/9.6/pg_ident.conf", 
                    "included_files": null, 
                    "mode": "postgres", 
                    "pgdata": "/data/pgsql/9.6", 
                    "server_name": "vmpostgre-pdsi1", 
                    "size": 528815511, 
                    "status": "DONE", 
                    "tablespaces": null, 
                    "timeline": 1, 
                    "version": 90609, 
                    "xlog_segment_size": 16777216
                }, 
                "20180607T233002": {
                    "backup_id": "20180607T233002", 
                    "backup_label": null, 
                    "begin_offset": 2316312, 
                    "begin_time": "Thu Jun  7 23:30:02 2018", 
                    "begin_wal": "0000000100000039000000DB", 
                    "begin_xlog": "39/DB235818", 
                    "config_file": "/data/pgsql/9.6/postgresql.conf", 
                    "copy_stats": null, 
                    "deduplicated_size": null, 
                    "end_offset": null, 
                    "end_time": null, 
                    "end_wal": null, 
                    "end_xlog": null, 
                    "error": **"failure copying files ('ascii' codec can't encode character u'\\xe9' in position 175: ordinal not in range(128))"**, 
                    "hba_file": "/data/pgsql/9.6/pg_hba.conf", 
                    "ident_file": "/data/pgsql/9.6/pg_ident.conf", 
                    "included_files": null, 
                    "mode": "postgres", 
                    "pgdata": "/data/pgsql/9.6", 
                    "server_name": "vmpostgre-pdsi1", 
                    "size": null, 
                    "status": "FAILED", 
                    "tablespaces": null, 
                    "timeline": 1, 
                    "version": 90609, 
                    "xlog_segment_size": 16777216
                }
postgres=# SELECT name, setting FROM pg_settings WHERE name ~ '(encoding|lc_)';
      name       |   setting   
-----------------+-------------
 client_encoding | UTF8
 lc_collate      | fr_FR.UTF-8
 lc_ctype        | fr_FR.UTF-8
 lc_messages     | fr_FR.UTF-8
 lc_monetary     | fr_FR.UTF-8
 lc_numeric      | fr_FR.UTF-8
 lc_time         | fr_FR.UTF-8
 server_encoding | UTF8
(8 rows)
export LC_ALL=C
export lc_messages=C
barman backup vmpostgre-tdsi1
Starting backup using postgres method for server vmpostgre-tdsi1 in /data/barman/vmpostgre-tdsi1/base/20180608T123003
Backup start at LSN: 1E/3E000060 (000000010000001E0000003E, 00000060)
Starting backup copy via pg_basebackup for 20180608T123003
ERROR: Backup failed copying files.
DETAILS: 'ascii' codec can't encode character u'\xe9' in position 175: ordinal not in range(128)

Thank you for your help, Mikaël

dawncold commented 6 years ago
SELECT name, setting FROM pg_settings WHERE name ~ '(encoding|lc_)';

      name       |   setting   
-----------------+-------------
 client_encoding | UTF8
 lc_collate      | C
 lc_ctype        | C
 lc_messages     | zh_CN.UTF-8
 lc_monetary     | zh_CN.UTF-8
 lc_numeric      | zh_CN.UTF-8
 lc_time         | zh_CN.UTF-8
 server_encoding | UTF8
(8 rows)

I modified backup.py and got a traceback

Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/barman/backup.py", line 393, in backup
    self.executor.backup(backup_info)
  File "/usr/lib/python2.7/dist-packages/barman/backup_executor.py", line 324, in backup
    self.backup_copy(backup_info)
  File "/usr/lib/python2.7/dist-packages/barman/backup_executor.py", line 553, in backup_copy
    pg_basebackup()
  File "/usr/lib/python2.7/dist-packages/barman/command_wrappers.py", line 262, in __call__
    self.get_output(*args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/barman/command_wrappers.py", line 294, in get_output
    return self._get_output_once(*args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/barman/command_wrappers.py", line 355, in _get_output_once
    self.err = _str(self.err)
  File "/usr/lib/python2.7/dist-packages/barman/command_wrappers.py", line 51, in _str
    return cmd_out.decode('utf-8', 'replace')
  File "/usr/lib/python2.7/encodings/utf_8.py", line 16, in decode
    return codecs.utf_8_decode(input, errors, True)
UnicodeEncodeError: 'ascii' codec can't encode characters in position 110-111: ordinal not in range(128)

then I print cmd_out in _str, it is

pg_basebackup: initiating base backup, waiting for checkpoint to complete
pg_basebackup: checkpoint completed
警告:  跳过特殊文件 "./postgresql.conf"
警告:  跳过特殊文件 "./pg_ident.conf"
警告:  跳过特殊文件 "./pg_hba.conf"
注意:  没有启用WAL归档;您必须确保所有的WAL段已通过其他的方法拷贝,这样才能完成备份
pg_basebackup: base backup completed

some Chinese with English, I think set lc_message to C is a workaround method.

dawncold commented 6 years ago

_str argument cmd_out is str or unicode, if a unicode cmd_out with non-English chars execute cmd_out.decode('utf-8', 'replace'), it raises 'UnicodeEncodeError: 'ascii' codec can't encode characters in position...', so if cmd_out is unicode, just return it.

This is a modified _str, it works for me.

def _str(cmd_out):
    """
    Make a string from the output of a CommandWrapper execution.
    If input is None returns a literal 'None' string

    :param cmd_out: String or ByteString to convert
    :return str: a string
    """
    if isinstance(cmd_out, unicode):
        return cmd_out
    if hasattr(cmd_out, 'decode') and callable(cmd_out.decode):
        return cmd_out.decode('utf-8', 'replace')
    else:
        return str(cmd_out)

P.S. this function return a str or unicode?

mwuttke commented 6 years ago

Hello,

this issue is known more than two month now. Are you still willing to solve the problem or should I look for a better solution to backup my postgresql databases?

Cheers, Michael

bsmr commented 6 years ago

I just hit the the problem. Server Environmenr is "de_DE.UTF-8". Also the DBs are using "de_DE.UTF-8".

I tried to use LANG=en_US.UTF-8 and PYTHONIOENCODING=UTF-8 (an internet search suggested this), but those did not help.

Is there any progress on this bug or an easy workaround, please? The customer doesn't want me to fiddle in the sources.

mgvel commented 6 years ago

same problem here

This is the first backup for server server-name
ERROR: The backup has failed starting backup
Asking PostgreSQL server to finalize the backup.
ERROR: Backup failed starting backup.
DETAILS: invalid literal for int() with base 10: 'content'

Processing xlog segments from file archival for server-name
    00000001000000BE0000007A
    00000001000000BE0000007B
    00000001000000BE0000007B.00000028.backup

In postgres server

postgres=# SELECT name, setting FROM pg_settings WHERE name ~ '(encoding|lc_)';
      name       |   setting   
-----------------+-------------
 client_encoding | UTF8
 lc_collate      | en_US.UTF-8
 lc_ctype        | en_US.UTF-8
 lc_messages     | en_US.UTF-8
 lc_monetary     | en_US.UTF-8
 lc_numeric      | en_US.UTF-8
 lc_time         | en_US.UTF-8
 server_encoding | UTF8

LOCALE in barman server

LANG=en_US.UTF-8
LC_CTYPE="C"
LC_NUMERIC="C"
LC_TIME="C"
LC_COLLATE="C"
LC_MONETARY="C"
LC_MESSAGES="C"
LC_PAPER="C"
LC_NAME="C"
LC_ADDRESS="C"
LC_TELEPHONE="C"
LC_MEASUREMENT="C"
LC_IDENTIFICATION="C"
LC_ALL=C