Project

General

Profile

Actions

Bug #8313

closed

'utf8' codec can't decode byte 0xfc in position 41: invalid start byte

Added by Sage Weil almost 10 years ago. Updated almost 9 years ago.

Status:
Resolved
Priority:
Urgent
Assignee:
Category:
-
% Done:

0%

Source:
Q/A
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Crash signature (v1):
Crash signature (v2):

Description

/a/ubuntu-2014-05-06_19:36:14-fs-wip-5021-testing-basic-plana/240661

and many others.

Actions #2

Updated by Zack Cerza almost 10 years ago

>>> print u'\xfc'
ü

I'd really like to know where that's coming from...

Actions #3

Updated by Anonymous almost 10 years ago

I dunno if this is it, but I did some playing around just now.

>>> z = u'\xfc'
>>> print z
ü
>>> import logging
>>> log = logging.getLogger(__name__)
>>> log.error(z)
No handlers could be found for logger "__main__" 
>>> log.error('xx')
>>> 

Actions #4

Updated by Zack Cerza almost 10 years ago

Finally caught the actual error in progress, on stdout. Note that this is not logged for some reason.

2014-05-08 16:46:59,267.267 INFO:teuthology.task.workunit.client.0.err:[vpm017.front.sepia.ceph.com]: + mkdir fstest_16d4173bd35d3e5b6e87c2ee649d1957
2014-05-08 16:46:59,267.267 INFO:teuthology.task.workunit.client.0.err:[vpm017.front.sepia.ceph.com]: + setfacl -m m::5 fstest_16d4173bd35d3e5b6e87c2ee649d1957
2014-05-08 16:46:59,267.267 INFO:teuthology.task.workunit.client.0.err:[vpm017.front.sepia.ceph.com]: + quick_exit
2014-05-08 16:46:59,267.267 INFO:teuthology.task.workunit.client.0.err:[vpm017.front.sepia.ceph.com]: + echo 1..1
2014-05-08 16:46:59,268.268 INFO:teuthology.task.workunit.client.0.err:[vpm017.front.sepia.ceph.com]: + echo 'ok 1'
2014-05-08 16:46:59,268.268 INFO:teuthology.task.workunit.client.0.err:[vpm017.front.sepia.ceph.com]: + exit 0
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/gevent/greenlet.py", line 390, in run
    result = self._run(*self.args, **self.kwargs)
  File "/home/ubuntu/zack/teuthology/teuthology/orchestra/run.py", line 150, in copy_file_to
    return handler(f, dst, host)
  File "/home/ubuntu/zack/teuthology/teuthology/orchestra/run.py", line 125, in copy_to_log
    for line in f.xreadlines():
  File "/home/ubuntu/zack/teuthology/virtualenv/local/lib/python2.7/site-packages/paramiko/file.py", line 100, in next
    line = self.readline()
  File "/home/ubuntu/zack/teuthology/virtualenv/local/lib/python2.7/site-packages/paramiko/file.py", line 251, in readline
    return line if self._flags & self.FLAG_BINARY else u(line)
  File "/home/ubuntu/zack/teuthology/virtualenv/local/lib/python2.7/site-packages/paramiko/py3compat.py", line 49, in u
    return s.decode(encoding)
  File "/home/ubuntu/zack/teuthology/virtualenv/lib/python2.7/encodings/utf_8.py", line 16, in decode
    return codecs.utf_8_decode(input, errors, True)
UnicodeDecodeError: 'utf8' codec can't decode byte 0xfc in position 41: invalid start byte
<Greenlet at 0x2cba0d8: copy_file_to(<paramiko.ChannelFile from <paramiko.Channel 44 (E, <logging.Logger object at 0x2cbd2d0>, u'vpm017.front.sepia.ceph.com')> failed with Unicod
eDecodeError
Actions #5

Updated by Zack Cerza almost 10 years ago

  • Status changed from New to Resolved
  • Assignee set to Zack Cerza
Actions #6

Updated by Loïc Dachary almost 9 years ago

  • Regression set to No

From https://github.com/ceph/teuthology/blob/master/teuthology/orchestra/run.py#L198 i get


2015-06-22 20:50:00,868.868 INFO:teuthology.orchestra.run.the-re011:Running: 'stat /dev/vdb && sudo dd if=/dev/vdb of=/dev/null count=1 && ! mount | grep -q /dev/vdb'
2015-06-22 20:50:00,938.938 INFO:teuthology.orchestra.run.the-re011.stdout:  File: ?/dev/vdb
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 851, in emit
    msg = self.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 724, in format
    return fmt.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 467, in format
    s = self._fmt % record.__dict__
UnicodeDecodeError: 'ascii' codec can't decode byte 0xe2 in position 8: ordinal not in range(128)
Logged from file run.py, line 199

On a teuthology worker installed on Ubuntu 14.04. The problem goes away with
diff --git a/teuthology/orchestra/run.py b/teuthology/orchestra/run.py
index 0af7db5..2670a50 100644
--- a/teuthology/orchestra/run.py
+++ b/teuthology/orchestra/run.py
@@ -196,7 +196,7 @@ def copy_to_log(f, logger, loglevel=logging.INFO):
         # Second part of work-around for http://tracker.ceph.com/issues/8313
         try:
             line = unicode(line, 'utf-8', 'replace').encode('utf-8')
-            logger.log(loglevel, line)
+            logger.log(loglevel, line.decode('utf-8'))
         except (UnicodeDecodeError, UnicodeEncodeError):
             logger.exception("Encountered unprintable line in command output")

Actions #7

Updated by Zack Cerza almost 9 years ago

In that case, what does the logged output look like? Also, can I see a full logfile?

Actions #8

Updated by Loïc Dachary almost 9 years ago

  • Status changed from Resolved to 12

The logged output is as pasted in http://tracker.ceph.com/issues/8313#note-6. The full output, including the offending strings which are accepted because of the line.decode('utf-8') workardound can be found at http://tracker.ceph.com/attachments/download/1827/tox-results.txt

The error can be reproduced by running the steps described at https://github.com/dachary/teuthology/tree/wip-6502-openstack#openstack-backend on OS1, without the workaround.

Actions

Also available in: Atom PDF