UnicodeDecodeError in the nova gate logs

[Attila Fazekas]

http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOiBcIlVuaWNvZGVEZWNvZGVFcnJvclwiIiwiZmllbGRzIjpbXSwib2Zmc2V0IjowLCJ0aW1lZnJhbWUiOiI2MDQ4MDAiLCJncmFwaG1vZGUiOiJjb3VudCIsInRpbWUiOnsidXNlcl9pbnRlcnZhbCI6MH0sInN0YW1wIjoxNDAwNDI3ODM3NzE0LCJtb2RlIjoiIiwiYW5hbHl6ZV9maWVsZCI6IiJ9
message: "UnicodeDecodeError"

Looks like the n-cpu tries to long something not unicide.

[Michael Still (mikal)]

Joe and I have come up with a theory that this is a problem with python-glanceclient. I'm testing it out now.

[Mark Washenberger (markwash)]

Note from chat with mikal:

mikal: markwash: commenting out the LOG.debug lines "fixes" the tracebacks, but makes those logging methods useless
mikal: i.e. we need to think harder than that

[Zhi Yan Liu (lzy-dev)]

https://review.openstack.org/#/c/100412/

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/100412
Committed: https://git.openstack.org/cgit/openstack/python-glanceclient/commit/?id=dec9c9f3525577dd865bd12d43e4578ae32e4d3c
Submitter: Jenkins
Branch: master

commit dec9c9f3525577dd865bd12d43e4578ae32e4d3c
Author: Michael Still <email address hidden>
Date: Tue Jun 17 17:45:47 2014 +1000

    Change a debug line to prevent UnicodeDecodeError issue

    This debug line is causing tracebacks in the n-cpu logs for
    tempest runs. Its because the logged data is sometimes unicode:

    Traceback (most recent call last):
      File "/usr/lib/python2.7/logging/__init__.py", line 846, in emit
        msg = self.format(record)
      File "/opt/stack/new/nova/nova/openstack/common/log.py", line 710, in format
        return logging.StreamHandler.format(self, record)
      File "/usr/lib/python2.7/logging/__init__.py", line 723, in format
        return fmt.format(record)
      File "/opt/stack/new/nova/nova/openstack/common/log.py", line 674, in format
        return logging.Formatter.format(self, 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 0xc3 in position 1234: ordinal not in range(128)
    Logged from file http.py, line 153

    The change used correct encoding error handling policy for the log
    which may includes non-ascii char.

    Closes-bug: 1320655
    Change-Id: I97f5f14b9beddcceb7fbd371062caf5a38a62a20

[Matt Riedemann (mriedem)]

Looks like this has cropped back up elsewhere:

http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOlwiVW5pY29kZURlY29kZUVycm9yXCIgQU5EIHRhZ3M6XCJzY3JlZW4tbi1jcHUudHh0XCIgQU5EIGJ1aWxkX3N0YXR1czpcIkZBSUxVUkVcIiIsImZpZWxkcyI6W10sIm9mZnNldCI6MCwidGltZWZyYW1lIjoiNjA0ODAwIiwiZ3JhcGhtb2RlIjoiY291bnQiLCJ0aW1lIjp7InVzZXJfaW50ZXJ2YWwiOjB9LCJzdGFtcCI6MTQxMDgxNDI2Mzk3OSwibW9kZSI6IiIsImFuYWx5emVfZmllbGQiOiIifQ==

[Matt Riedemann (mriedem)]

Failing here in log_http_response:

http://git.openstack.org/cgit/openstack/python-glanceclient/tree/glanceclient/common/http.py#n133

http://logs.openstack.org/35/118135/5/gate/gate-tempest-dsvm-full/8e230bc/logs/screen-n-cpu.txt.gz#_2014-09-10_14_27_45_271

2014-09-10 14:27:45.271 28251 INFO nova.compute.manager [-] [instance: 3634459f-2177-4a17-bc57-074610d2f6e5] VM Started (Lifecycle Event)
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 851, in emit
    msg = self.format(record)
  File "/opt/stack/new/nova/nova/openstack/common/log.py", line 705, in format
    return logging.StreamHandler.format(self, record)
  File "/usr/lib/python2.7/logging/__init__.py", line 724, in format
    return fmt.format(record)
  File "/opt/stack/new/nova/nova/openstack/common/log.py", line 632, in format
    record.msg = six.text_type(record.msg)
UnicodeDecodeError: 'ascii' codec can't decode byte 0xc3 in position 319: ordinal not in range(128)
Logged from file http.py, line 133

[Matt Riedemann (mriedem)]

I opened bug 1369756 for the new failure.

[Cyril Roelandt (cyril-roelandt)]

This is old and looks Py2-related, so we won't be fixing this.