glusterfs icon indicating copy to clipboard operation
glusterfs copied to clipboard

geo-replication UnicodeEncodeError

Open zhuxiaochun1995 opened this issue 5 years ago • 17 comments

the error log is

[2020-01-02 01:59:43.23426] D [master(worker /tank/gfs):1491:changelogs_batch_process] _GMaster: processing changes     batch=['/var/lib/misc/gluster/gsyncd/vol_slave_vol/tank-gfs/.history/.processing/CHANGELOG.1577771441']
[2020-01-02 01:59:43.23581] D [master(worker /tank/gfs):1326:process] _GMaster: processing change       changelog=/var/lib/misc/gluster/gsyncd/vol_slave_vol/tank-gfs/.history/.processing/CHANGELOG.1577771441
[2020-01-02 01:59:43.26501] D [master(worker /tank/gfs):1205:process_change] _GMaster: entries: [{'entry': '.gfid/00000000-0000-0000-0000-000000000001/0d5a4e1c.0', 'stat': {'gid': 0, 'mode': 41471, 'atime': 1577765080.6083024, 'uid': 0, 'mtime': 1577478313.1825879}, 'op': 'SYMLINK', 'skip_entry': False, 'link': 'T\udcc3\udc9cRKTRUST_Elektronik_Sertifika_Hizmet_Sa\udcc4\udc9flay\udcc4\udcb1c\udcc4\udcb1s\udcc4\udcb1_H5.pem', 'gfid': '451cee0a-9cbd-4e90-ac0b-460cc0b70aa9'}]
[2020-01-02 01:59:43.47237] D [repce(worker /tank/gfs):197:push] RepceClient: call 5371:140639090104064:1577930383.0471745 entry_ops([{'entry': '.gfid/00000000-0000-0000-0000-000000000001/0d5a4e1c.0', 'stat': {'gid': 0, 'mode': 41471, 'atime': 1577765080.6083024, 'uid': 0, 'mtime': 1577478313.1825879}, 'op': 'SYMLINK', 'skip_entry': False, 'link': 'T\udcc3\udc9cRKTRUST_Elektronik_Sertifika_Hizmet_Sa\udcc4\udc9flay\udcc4\udcb1c\udcc4\udcb1s\udcc4\udcb1_H5.pem', 'gfid': '451cee0a-9cbd-4e90-ac0b-460cc0b70aa9'}],) ...
[2020-01-02 01:59:43.52649] E [repce(worker /tank/gfs):215:__call__] RepceClient: call failed   error=UnicodeEncodeError        call=5371:140639090104064:1577930383.0471745    method=entry_ops
[2020-01-02 01:59:43.52944] E [syncdutils(worker /tank/gfs):339:log_raise_exception] <top>: FAIL:
Traceback (most recent call last):
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/gsyncd.py", line 330, in main
    func(args)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/subcmds.py", line 82, in subcmd_worker
    local.service_loop(remote)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/resource.py", line 1290, in service_loop
    g3.crawlwrap(oneshot=True)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 602, in crawlwrap
    self.crawl()
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 1592, in crawl
    self.changelogs_batch_process(changes)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 1492, in changelogs_batch_process
    self.process(batch)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 1327, in process
    self.process_change(change, done, retry)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 1221, in process_change
    failures = self.slave.server.entry_ops(entries)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/repce.py", line 234, in __call__
    return self.ins(self.meth, *a)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/repce.py", line 216, in __call__
    raise res
UnicodeEncodeError: 'utf-8' codec can't encode character '\udcc3' in position 1: surrogates not allowed

environment

Ubuntu 16.04.1 LTS glusterfs 6.6 Python 3.5.2

how to reproduce it.

  1. start a geo-replication session
  2. cp /etc/ssl/certs/0d5a4e1c.0 to master gluster fs. it's a link to TÜRKTRUST_Elektronik_Sertifika_Hizmet_Sağlayıcısı_H5.pem

zhuxiaochun1995 avatar Jan 02 '20 02:01 zhuxiaochun1995

cd glusterfs-mountpoint on client. touch TÜRKTRUST_Elektronik_Sertifika_Hizmet_Sağlayıcısı_H5.pem will get 'UnicodeDecodeError: 'ascii' codec can't decode byte 0xc3'. the err log is

[2020-01-02 09:57:28.471212] E [syncdutils(worker /tank/gfs):339:log_raise_exception] <top>: FAIL: 
Traceback (most recent call last):
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/gsyncd.py", line 330, in main
    func(args)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/subcmds.py", line 82, in subcmd_worker
    local.service_loop(remote)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/resource.py", line 1290, in service_loop
    g3.crawlwrap(oneshot=True)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 602, in crawlwrap
    self.crawl()
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 1599, in crawl
    self.changelogs_batch_process(changes)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 1499, in changelogs_batch_process
    self.process(batch)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 1334, in process
    self.process_change(change, done, retry)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 1024, in process_change
    clist = f.readlines()
  File "/usr/lib/python3.5/encodings/ascii.py", line 26, in decode
    return codecs.ascii_decode(input, self.errors)[0]
UnicodeDecodeError: 'ascii' codec can't decode byte 0xc3 in position 99: ordinal not in range(128)
[2020-01-02 09:57:28.496879] I [repce(agent /tank/gfs):98:service_loop] RepceServer: terminating on reaching EOF.
[2020-01-02 09:57:29.169372] I [monitor(monitor):278:monitor] Monitor: worker died in startup phase     brick=/tank/gfs
[2020-01-02 09:57:29.183552] I [gsyncdstatus(monitor):248:set_worker_status] GeorepStatus: Worker Status Change status=Faulty

zhuxiaochun1995 avatar Jan 02 '20 10:01 zhuxiaochun1995

What I understand from "UnicodeDecodeError: 'ascii' codec can't decode byte" it happens when we try to convert a str that contains non-ASCII to a Unicode string without specifying the encoding of the original string. (could be issue of py2-py3) Can you run into python interpreter on master and slave and see what is default encoding :

import sys sys.getdefaultencoding()

and share the result.

I tried to reproduce on Fedora 31 with Gluser 6.6 it NOT reproduciable.

sunnyku avatar Jan 06 '20 14:01 sunnyku

>>> import sys
>>> sys.getdefaultencoding()
'utf-8'
>>>

the environment LANG and LC_ALL is en_US.UTF-8.

zhuxiaochun1995 avatar Jan 07 '20 05:01 zhuxiaochun1995

debug with pysnooper:

244 07:45:25.870313 line      1017         try:
245 07:45:25.870473 line      1018             f = open(change, "r")
246 New var:....... f = <_io.TextIOWrapper name='/var/lib/misc/gluster/g...G.1578383125' mode='r' encoding='ANSI_X3.4-1968'>
247 07:45:25.870691 line      1019             clist = f.readlines()
248 07:45:25.870986 exception 1019             clist = f.readlines()
249 UnicodeDecodeError: 'ascii' codec can't decode byte 0xc3 in position 93: ordinal not in range(128)
250 07:45:25.871333 line      1021         except IOError:

The CHANGELOG file is open with encoding ANSI_X3.4-1968, but the encoding of file content is utf-8. This may be the reason?

If I add the parameter encoding='utf-8' , the sync will succeed.

zhuxiaochun1995 avatar Jan 07 '20 08:01 zhuxiaochun1995

Thank you for your contributions. Noticed that this issue is not having any activity in last ~6 months! We are marking this issue as stale because it has not had recent activity. It will be closed in 2 weeks if no one responds with a comment here.

stale[bot] avatar Aug 04 '20 09:08 stale[bot]

Closing this issue as there was no update since my last update on issue. If this is an issue which is still valid, feel free to open it.

stale[bot] avatar Aug 19 '20 10:08 stale[bot]

I've got a similar (in fact I think it's the same) issue:

[2021-10-29 12:02:06.872878] E [syncdutils(worker /path/to/brick):363:log_raise_exception] <top>: FAIL:
Traceback (most recent call last):
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/gsyncd.py", line 317, in main
    func(args)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/subcmds.py", line 86, in subcmd_worker
    local.service_loop(remote)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/resource.py", line 1298, in service_loop
    g3.crawlwrap(oneshot=True)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 604, in crawlwrap
    self.crawl()
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 1598, in crawl
    self.changelogs_batch_process(changes)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 1494, in changelogs_batch_process
    self.process(batch)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 1329, in process
    self.process_change(change, done, retry)
  File "/usr/lib/x86_64-linux-gnu/glusterfs/python/syncdaemon/master.py", line 1020, in process_change
    clist = f.readlines()
  File "/usr/lib/python3.5/codecs.py", line 321, in decode
    (result, consumed) = self._buffer_decode(data, self.errors, final)
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xfc in position 2893: invalid start byte

Adding encoding="utf-8" to the open() call didn't help either - sys.getdefaultencoding() also returns utf-8

So it seems to me that GlusterFS sometimes writes invalid UTF-8 to the changelogs?

KirbyDE avatar Oct 29 '21 12:10 KirbyDE

I was able to identify the CHANGELOG.XXX file that was causing the problem and it seems that the file has iso-8859-1 encoding, not utf-8.

I was also able to reproduice the exact same issue with a fresh installation of GlusterFS 9.4 on Debian Bullseye.

Is it possible that this is reated to volume option changelog.encoding? By default this option seems to be ascii, but as the default encoding (as reported by sys.getdefaultencoding()) is utf-8, the file does get opened with utf-8 encoding.

KirbyDE avatar Nov 11 '21 12:11 KirbyDE

Please share the Changelog file that caused the issue. I will try to reproduce and patch.

aravindavk avatar Nov 11 '21 14:11 aravindavk

Here you go: CHANGELOG.zip

This file was produced by GlusterFS 9.4 installed from Debian Bullseye backports repository (9.4-2~bpo11+1)

KirbyDE avatar Nov 11 '21 15:11 KirbyDE

@aravindavk Did you have success reproducing the issue?

KirbyDE avatar Dec 21 '21 10:12 KirbyDE

I can still reproduce this issue with GlusterFS 10.1 on Debian Bullseye. Did you find time already to look into this @aravindavk?

KirbyDE avatar Feb 17 '22 20:02 KirbyDE

Bug still present for glusterfs 10.3

fails on file name containeing IMPORTAÇÃO

File "/usr/lib/python3.7/codecs.py", line 322, in decode (result, consumed) = self._buffer_decode(data, self.errors, final) UnicodeDecodeError: 'utf-8' codec can't decode byte 0xc7 in position 684: invalid continuation byte

Is there any info when this be fixed?

usertana avatar May 26 '23 09:05 usertana

could be useful for someone, the problem appears when file names contains non ascii or non utf-8 symbols. (for example upload via ftp of utf8 file names and latin recoding of names) OS allows storing this, no issues for brick syncs.

but errors appers when python parsing CHANGELOG file to continue geo repl. particular chnagelog caould be pathed with removal of problem entries

usertana avatar May 26 '23 10:05 usertana

Why has this been closed? It is NOT fixed. Running latest GlusterFS-Version (10.1-3) on Debian 11.

kartoffelheinz avatar Jun 27 '25 20:06 kartoffelheinz

Why has this been closed? It is NOT fixed. Running latest GlusterFS-Version (10.1-3) on Debian 11.

Inactive issues/pull requests are closed after 6 months of inactivity by default I think.

pranithk avatar Jun 30 '25 01:06 pranithk

BUG is present for sure in glusterfs 10.3 (Debian GNU/Linux 10)

could be useful for someone, to continue GEO replication find erroneous bytes in CHANGELOG.*

volume1/brick1/brick/.glusterfs/changelogs/2025/07/08/ grep -P -n "[^\x00-\x7F]" *

and remove it.

usertana avatar Jul 10 '25 06:07 usertana