Bug 888455

Summary: Traceback when non-ASCII in snapshot name
Product: Red Hat OpenStack Reporter: Russell Bryant <rbryant>
Component: python-glanceclientAssignee: Jakub Ruzicka <jruzicka>
Status: CLOSED ERRATA QA Contact: Attila Fazekas <afazekas>
Severity: medium Docs Contact:
Priority: medium    
Version: 2.1CC: apevec, dallan, fpercoco, zbitter
Target Milestone: snapshot5Keywords: i18n, Triaged
Target Release: 2.1   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: 0.8.0-1 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-04-04 13:58:30 EDT Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:

Description Russell Bryant 2012-12-18 13:16:55 EST
Description of problem:

Trying to create a snapshot from nova with non-ASCII characters in the name causes a failure in glanceclient.  No snapshot is created.


Version-Release number of selected component (if applicable):

python-novaclient-2.10.0-1.el6ost.noarch
openstack-nova-common-2012.2.1-2.el6ost.noarch
openstack-nova-compute-2012.2.1-2.el6ost.noarch
openstack-nova-scheduler-2012.2.1-2.el6ost.noarch
openstack-nova-novncproxy-0.4-2.el6.noarch
python-nova-2012.2.1-2.el6ost.noarch
openstack-nova-console-2012.2.1-2.el6ost.noarch
openstack-nova-api-2012.2.1-2.el6ost.noarch
openstack-nova-volume-2012.2.1-2.el6ost.noarch
openstack-nova-cert-2012.2.1-2.el6ost.noarch
openstack-nova-2012.2.1-2.el6ost.noarch
openstack-nova-network-2012.2.1-2.el6ost.noarch
openstack-nova-objectstore-2012.2.1-2.el6ost.noarch
openstack-glance-2012.2.1-1.el6ost.noarch
python-glance-2012.2.1-1.el6ost.noarch
python-glanceclient-0.5.1-1.el6.noarch


How reproducible:

Every time.


Steps to Reproduce / Results:

[root@rhel ~(keystone_username)]# nova image-create 7cdab80a-286b-4bab-be94-ad35ae481b7f "El Niño"
ERROR: The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-76ff5c85-37a2-4cd9-bfc6-5e334cee6656)


in nova/api.log:

2012-12-18 13:06:47 INFO nova.api.openstack.wsgi [req-76ff5c85-37a2-4cd9-bfc6-5e334cee6656 01d9cc70566849a39c3f0ab63622cb9d 34e9ef477d70492db00e28d130d5584c] POST http://127.0.0.1:8774/v1.1/34e9ef477d70492db00e28d130d5584c/servers/7cdab80a-286b-4bab-be94-ad35ae481b7f/action
2012-12-18 13:06:48 ERROR nova.api.openstack [req-76ff5c85-37a2-4cd9-bfc6-5e334cee6656 01d9cc70566849a39c3f0ab63622cb9d 34e9ef477d70492db00e28d130d5584c] Caught error: 'ascii' codec can't encode character u'\xf1' in position 5: ordinal not in range(128)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack Traceback (most recent call last):
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/nova/api/openstack/__init__.py", line 78, in __call__
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     return req.get_response(self.application)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/WebOb-1.0.8-py2.6.egg/webob/request.py", line 1053, in get_response
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     application, catch_exc_info=False)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/WebOb-1.0.8-py2.6.egg/webob/request.py", line 1022, in call_application
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     app_iter = application(self.environ, start_response)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/WebOb-1.0.8-py2.6.egg/webob/dec.py", line 159, in __call__
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     return resp(environ, start_response)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/keystone/middleware/auth_token.py", line 278, in __call__
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     return self.app(env, start_response)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/WebOb-1.0.8-py2.6.egg/webob/dec.py", line 159, in __call__
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     return resp(environ, start_response)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/WebOb-1.0.8-py2.6.egg/webob/dec.py", line 159, in __call__
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     return resp(environ, start_response)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/WebOb-1.0.8-py2.6.egg/webob/dec.py", line 159, in __call__
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     return resp(environ, start_response)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/Routes-1.12.3-py2.6.egg/routes/middleware.py", line 131, in __call__
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     response = self.app(environ, start_response)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/WebOb-1.0.8-py2.6.egg/webob/dec.py", line 159, in __call__
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     return resp(environ, start_response)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/WebOb-1.0.8-py2.6.egg/webob/dec.py", line 147, in __call__
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     resp = self.call_func(req, *args, **self.kwargs)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/WebOb-1.0.8-py2.6.egg/webob/dec.py", line 208, in call_func
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     return self.func(req, *args, **kwargs)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 894, in __call__
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     content_type, body, accept)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 942, in _process_stack
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     action_result = self.dispatch(meth, request, action_args)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 1030, in dispatch
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     return method(req=request, **action_args)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/nova/api/openstack/common.py", line 422, in inner
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     return f(*args, **kwargs)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/nova/api/openstack/compute/servers.py", line 1302, in _action_create_image
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     extra_properties=props)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/nova/compute/api.py", line 115, in wrapped
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     return func(self, context, target, *args, **kwargs)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/nova/compute/api.py", line 95, in inner
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     return f(self, context, instance, *args, **kw)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/nova/compute/api.py", line 1221, in snapshot
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     extra_properties=extra_properties)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/nova/compute/api.py", line 1286, in _create_image
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     recv_meta = self.image_service.create(context, sent_meta)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/nova/image/glance.py", line 235, in create
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     **sent_service_image_meta)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/nova/image/glance.py", line 138, in call
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     return getattr(client.images, method)(*args, **kwargs)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/glanceclient/v1/images.py", line 207, in create
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     hdrs = self._image_meta_to_headers(fields)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack   File "/usr/lib/python2.6/site-packages/glanceclient/v1/images.py", line 77, in _image_meta_to_headers
2012-12-18 13:06:48 17332 TRACE nova.api.openstack     headers['x-image-meta-%s' % key] = str(value)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack UnicodeEncodeError: 'ascii' codec can't encode character u'\xf1' in position 5: ordinal not in range(128)
2012-12-18 13:06:48 17332 TRACE nova.api.openstack 
2012-12-18 13:06:48 INFO nova.api.openstack [req-76ff5c85-37a2-4cd9-bfc6-5e334cee6656 01d9cc70566849a39c3f0ab63622cb9d 34e9ef477d70492db00e28d130d5584c] http://127.0.0.1:8774/v1.1/34e9ef477d70492db00e28d130d5584c/servers/7cdab80a-286b-4bab-be94-ad35ae481b7f/action returned with HTTP 500
2012-12-18 13:06:48 INFO nova.osapi_compute.wsgi.server [req-76ff5c85-37a2-4cd9-bfc6-5e334cee6656 01d9cc70566849a39c3f0ab63622cb9d 34e9ef477d70492db00e28d130d5584c] 127.0.0.1 - - [18/Dec/2012 13:06:48] "POST /v1.1/34e9ef477d70492db00e28d130d5584c/servers/7cdab80a-286b-4bab-be94-ad35ae481b7f/action HTTP/1.1" 500 335 0.543720
Comment 2 Alan Pevec 2012-12-21 04:03:54 EST
Looks like there's upstream work required to cleanup i18n issues across all openstack clients (see also novaclient bug 888483)
Comment 3 Zane Bitter 2013-01-25 15:33:47 EST
I did some digging and asked some questions on the upstream mailing list:

http://lists.openstack.org/pipermail/openstack-dev/2013-January/005027.html
Comment 4 Flavio Percoco 2013-01-25 18:08:17 EST
Nice message.

This crash here (as for novaclient) is more related to a python pitfall. What happens is that headers are correctly encoded to UTF-8 and then, when it tries to build the request with http, it tries to re-encode[0] because `self.endpoint`[1] and `self.auth_token`[2] are unicode strings.

So, basically what happens is:

conn.request(...) gets headers like:

{
 "header1": "value", 
 "header2": u"value2", 
 "header3": "value3"
}

That will be converted in something like:

["header1: value", u"header2: value2", "header3: value3"] #note the unicode string

which will then joined inside httplib in order to build the final request like:

"\r\n".join(self._buffer) 

This line of code here blows everything because Python joins the first item as normal utf8, then finds the second one and notices it is unicode and encodes it as utf8 and then it tries to encode the next string which already encoded because the previous one wasn't. 

Live example:

python2.7 -c "print '\r\n'.join(['a', u'b', '\xc3\xb1'])" # Fails

python2.7 -c "print '\r\n'.join(['a', 'b', '\xc3\xb1'])" # Prints

This all comes down to what you said in that thread, "encoding inconsistency within clients and / or servers" so, hopefully, that patch waiting for review (first oslo, then clients) will help to give this modules some standard way to encode / decode strings throughout OS.

Btw, glanceclient also fails when it tries to log the request, same reason as described above and depending on the terminal input encoding it might also just like the traceback used for this bug.

Hope this helps.

Cheers.

[0] https://github.com/openstack/python-glanceclient/blob/master/glanceclient/common/http.py#L158
[1]https://github.com/openstack/python-glanceclient/blob/master/glanceclient/common/http.py#L48
[2] https://github.com/openstack/python-glanceclient/blob/master/glanceclient/common/http.py#L59
Comment 8 Attila Fazekas 2013-03-20 10:38:50 EDT
[root@node-01 ~(keystone_admin)]$ nova image-create 6fdcafa3-b86b-479e-b1cf-5e6859912e65 "El Niño"

[root@node-01 ~(keystone_admin)]$ glance image-list
+--------------------------------------+----------+-------------+------------------+-----------+--------+
| ID                                   | Name     | Disk Format | Container Format | Size      | Status |
+--------------------------------------+----------+-------------+------------------+-----------+--------+
| a3b5eca5-f9a7-41cb-9814-cca7b0fe934c | El Niño  |             |                  |           | queued |

[root@node-01 ~(keystone_admin)]$ glance image-list
+--------------------------------------+----------+-------------+------------------+-----------+--------+
| ID                                   | Name     | Disk Format | Container Format | Size      | Status |
+--------------------------------------+----------+-------------+------------------+-----------+--------+
| a3b5eca5-f9a7-41cb-9814-cca7b0fe934c | El Niño  | qcow2       | bare             | 661848064 | active |

LGTM
Comment 10 errata-xmlrpc 2013-04-04 13:58:30 EDT
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHBA-2013-0706.html