Instance error message truncation error in non-English locale

[Qin Zhao]

1. Change OpenStack server to Russian locale, LANG=ru_RU.utf8

2. Set firefox client browser locale to russian(ru)

3. Trigger an operational failure that has a message that tries to get written to a Nova instance fault

Stacktrace

2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 302, in decorated_function
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher pass
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/nova/openstack/common/excutils.py", line 82, in __exit__
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 288, in decorated_function
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher return function(self, context, *args, **kwargs)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 330, in decorated_function
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher kwargs['instance'], e, sys.exc_info())
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/nova/compute/utils.py", line 94, in add_instance_fault_from_exc
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher fault_obj.create()
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/nova/objects/base.py", line 204, in wrapper
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher return fn(self, ctxt, *args, **kwargs)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/nova/objects/instance_fault.py", line 75, in create
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher db_fault = db.instance_fault_create(context, values)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/nova/db/api.py", line 1816, in instance_fault_create
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher return IMPL.instance_fault_create(context, values)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/nova/db/sqlalchemy/api.py", line 5423, in instance_fault_create
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher fault_ref.save()
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/nova/db/sqlalchemy/models.py", line 62, in save
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher super(NovaBase, self).save(session=session)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/oslo/db/sqlalchemy/models.py", line 48, in save
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher session.flush()
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib64/python2.6/site-packages/sqlalchemy/orm/session.py", line 1818, in flush
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher self._flush(objects)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib64/python2.6/site-packages/sqlalchemy/orm/session.py", line 1936, in _flush
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher transaction.rollback(_capture_exception=True)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib64/python2.6/site-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher compat.reraise(exc_type, exc_value, exc_tb)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib64/python2.6/site-packages/sqlalchemy/orm/session.py", line 1900, in _flush
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher flush_context.execute()
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib64/python2.6/site-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher rec.execute(self)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib64/python2.6/site-packages/sqlalchemy/orm/unitofwork.py", line 525, in execute
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher uow
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib64/python2.6/site-packages/sqlalchemy/orm/persistence.py", line 64, in save_obj
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher table, insert)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib64/python2.6/site-packages/sqlalchemy/orm/persistence.py", line 569, in _emit_insert_statements
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher execute(statement, params)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib64/python2.6/site-packages/sqlalchemy/engine/base.py", line 662, in execute
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher params)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib64/python2.6/site-packages/sqlalchemy/engine/base.py", line 761, in _execute_clauseelement
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher compiled_sql, distilled_params
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib64/python2.6/site-packages/sqlalchemy/engine/base.py", line 874, in _execute_context
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher context)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/oslo/db/sqlalchemy/compat/handle_error.py", line 125, in _handle_dbapi_exception
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher six.reraise(type(newraise), newraise, sys.exc_info()[2])
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/oslo/db/sqlalchemy/compat/handle_error.py", line 102, in _handle_dbapi_exception
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher per_fn = fn(ctx)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/oslo/db/sqlalchemy/exc_filters.py", line 323, in handler
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher context.is_disconnect)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.6/site-packages/oslo/db/sqlalchemy/exc_filters.py", line 278, in _raise_for_remaining_DBAPIError
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher raise exception.DBError(error)
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher DBError: (DataError) ibm_db_dbi::DataError: Sending data failed: [IBM][CLI Driver] CLI0109E String data right truncation. SQLSTATE=22001 SQLCODE=-99999 'INSERT INTO instance_faults (deleted_at, deleted, created_at, updated_at, instance_uuid, code, message, details, host) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)' (None, 0, datetime.datetime(2014, 10, 30, 9, 55, 34, 42767), None, '1b73ce51-e2b2-4704-ab4a-1c2178e6b0b1', 500, 'NV-918894F \xd0\x92\xd0\xb8\xd1\x80\xd1\x82\xd1\x83\xd0\xb0\xd0\xbb\xd1\x8c\xd0\xbd\xd0\xb0\xd1\x8f \xd0\xbc\xd0\xb0\xd1\x88\xd0\xb8\xd0\xbd\xd0\xb0 Image_rhel65_-1b73ce51-00000001 \xd1\x80\xd0\xb0\xd0\xb1\xd0\xbe\xd1\x82\xd0\xb0\xd0\xbb\xd0\xb0 \xd0\xb2 \xd0\xbc\xd0\xbe\xd0\xbc\xd0\xb5\xd0\xbd\xd1\x82 \xd1\x81\xd0\xbe\xd0\xb7\xd0\xb4\xd0\xb0\xd0\xbd\xd0\xb8\xd1\x8f \xd0\xbc\xd0\xbe\xd0\xbc\xd0\xb5\xd0\xbd\xd1\x82\xd0\xb0\xd0\xbb\xd1\x8c\xd0\xbd\xd0\xbe\xd0\xb9 \xd0\xba\xd0\xbe\xd0\xbf\xd0\xb8\xd0\xb8. \xd0\x92\xd0\xb8\xd1\x80\xd1\x82\xd1\x83\xd0\xb0\xd0\xbb\xd1\x8c\xd0\xbd\xd1\x8b\xd0\xb5 \xd0\xbc\xd0\xb0\xd1\x88\xd0\xb8\xd0\xbd\xd1\x8b \xd0\xb4\xd0\xbe\xd0\xbb\xd0\xb6\xd0\xbd\xd1\x8b \xd0\xb1\xd1\x8b\xd1\x82\xd1\x8c \xd0\xbe\xd1\x81\xd1\x82\xd0\xb0\xd0\xbd\xd0\xbe\xd0\xb2\xd0\xbb\xd0\xb5\xd0\xbd\xd1\x8b \xd0\xbf\xd0\xb5\xd1\x80\xd0\xb5\xd0\xb4 \xd1\x81\xd0\xbe\xd0\xb7\xd0\xb4\xd0\xb0\xd0\xbd\xd0\xb8\xd0\xb5\xd0\xbc \xd0\xbc\xd0\xbe\xd0\xbc\xd0\xb5\xd0\xbd\xd1\x82\xd0\xb0\xd0\xbb\xd1\x8c\xd0\xbd\xd0\xbe\xd0\xb9 \xd0\xba\xd0\xbe\xd0\xbf\xd0\xb8\xd0\xb8.', ' File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 318, in decorated_function\n return function(self, context, *args, **kwargs)\n File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 378, in decorated_function\n instance=instance)\n File "/usr/lib/python2.6/site-packages/nova/openstack/common/excutils.py", line 82, in __exit__\n six.reraise(self.type_, self.value, self.tb)\n File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 368, in decorated_function\n *args, **kwargs)\n File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 3071, in snapshot_instance\n task_states.IMAGE_SNAPSHOT)\n File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 3106, in _snapshot_instance\n update_task_state)\n File "/usr/lib/python2.6/site-packages/powervc_nova/__init__.py", line 96, in wrapper\n r = f(*args, **kwds)\n File "/usr/lib/python2.6/site-packages/powervc_nova/virt/ibmpowervm/hmc/driver.py", line 683, in snapshot\n image.capture(context, host, instance, image_entry, update_task_state)\n File "/usr/lib/python2.6/site-packages/powervc_nova/__init__.py", line 96, in wrapper\n r = f(*args, **kwds)\n File "/usr/lib/python2.6/site-packages/powervc_nova/virt/ibmpowervm/hmc/image.py", line 280, in capture\n e)\n File "/usr/lib/python2.6/site-packages/nova/openstack/common/excutils.py", line 82, in __exit__\n six.reraise(self.type_, self.value, self.tb)\n File "/usr/lib/python2.6/site-packages/powervc_nova/virt/ibmpowervm/hmc/image.py", line 260, in capture\n self._wait_for_instance_to_stop(instance, host)\n File "/usr/lib/python2.6/site-packages/powervc_nova/__init__.py", line 96, in wrapper\n r = f(*args, **kwds)\n File "/usr/lib/python2.6/site-packages/powervc_nova/virt/ibmpowervm/hmc/image.py", line 339, in _wait_for_instance_to_stop\n instance_name=instance[\'name\'])\n', '828421A_TU00156')
2014-10-30 05:55:34.933 18371 TRACE oslo.messaging.rpc.dispatcher

[Qin Zhao (zhaoqin)]

The code in nova/compute/utils.py function exception_to_dict, is already trimming the message to 255 characters but it is doing this on the unicode string. The string must be trimmed to 255 characters in an encoded manner to avoid this issue for non-English locales.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/132642

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/132642
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=bd9c32289ff8cf1bc67c1395ad921c703aa4c489
Submitter: Jenkins
Branch: master

commit bd9c32289ff8cf1bc67c1395ad921c703aa4c489
Author: Qin Zhao <email address hidden>
Date: Tue Nov 4 16:57:45 2014 +0800

    Truncate encoded instance message to 255

    In nova/compute/utils.py function exception_to_dict truncates unicode
    message to 255. However, in non-English locales, instance message may
    be longer than 255 after encoding the unicode message to byte message.
    Need to truncate the encoded byte message to 255, in order to ensure
    db insert operation succeed.

    Change-Id: I70cd2d6e4590ea95510c1ea3d51287f0dea14956
    Closes-Bug: 1389102

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/juno
Review: https://review.openstack.org/134448

[OpenStack Infra (hudson-openstack)]

Change abandoned by Qin Zhao (<email address hidden>) on branch: stable/juno
Review: https://review.openstack.org/134448

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/134597

[Qin Zhao (zhaoqin)]

Need to take care of utf-8 byte character size when truncating the byte string. For example, '\xd0\x92' is a 2 bytes character. UnicodeDecodeError will occur, if we truncate it in the middle:

>>> a = '\xd0\x92' * 150
>>> encodeutils.safe_decode(a[:255])
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/lib/python2.6/site-packages/oslo/utils/encodeutils.py", line 57, in safe_decode
    return text.decode('utf-8', errors)
  File "/usr/lib64/python2.6/encodings/utf_8.py", line 16, in decode
    return codecs.utf_8_decode(input, errors, True)
UnicodeDecodeError: 'utf8' codec can't decode byte 0xd0 in position 254: unexpected end of data

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/134565
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=1a826012387838cbf741242047c8c622f635cb73
Submitter: Jenkins
Branch: master

commit 1a826012387838cbf741242047c8c622f635cb73
Author: Qin Zhao <email address hidden>
Date: Fri Nov 14 23:17:22 2014 +0800

    Revert "Truncate encoded instance message to 255"

    This reverts commit bd9c32289ff8cf1bc67c1395ad921c703aa4c489.

    UTF-8 character bytes size varies from 1 to 6. If truncating a long
    bytes string to 255, the last character may be cut in the middle,
    so that UnicodeDecodeError will occur when converting it back to
    unicode. Need to revert this code change and make a new patch.

    Related-Bug: 1389102

    Change-Id: Ie439cffe11d657e77397c9070a3923a61f68a678

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/134597
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=4e95505843d05f20ab01716ceee74f6757b16dd9
Submitter: Jenkins
Branch: master

commit 4e95505843d05f20ab01716ceee74f6757b16dd9
Author: Qin Zhao <email address hidden>
Date: Sat Nov 15 00:38:14 2014 +0800

    Truncate encoded instance message to 255 or fewer

    In nova/compute/utils.py function exception_to_dict truncates unicode
    message to 255. However, in non-English locales, instance message may
    be longer than 255 after encoding the unicode message to byte message.
    Need to truncate the encoded byte message to 255 or fewer, in order to
    ensure db insert operation succeed.

    Change-Id: I62fa2830b22e367eb9486d09d3c8818a18ebd20d
    Closes-Bug: 1389102

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/juno
Review: https://review.openstack.org/136544

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/136544
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=1e4088f46a54662449d9594f0c0942f1e8edab8e
Submitter: Jenkins
Branch: stable/juno

commit 1e4088f46a54662449d9594f0c0942f1e8edab8e
Author: Qin Zhao <email address hidden>
Date: Sat Nov 15 00:38:14 2014 +0800

    Truncate encoded instance message to 255 or fewer

    In nova/compute/utils.py function exception_to_dict truncates unicode
    message to 255. However, in non-English locales, instance message may
    be longer than 255 after encoding the unicode message to byte message.
    Need to truncate the encoded byte message to 255 or fewer, in order to
    ensure db insert operation succeed.

    Closes-Bug: 1389102
    (cherry picked from commit 4e95505843d05f20ab01716ceee74f6757b16dd9)

    Conflicts:
     nova/tests/unit/compute/test_compute_utils.py

    Change-Id: I62fa2830b22e367eb9486d09d3c8818a18ebd20d

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: master
Review: https://review.openstack.org/161549

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/161549
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=8ec6a73fef7d26301481935dcd5999c7cd419cba
Submitter: Jenkins
Branch: master

commit 8ec6a73fef7d26301481935dcd5999c7cd419cba
Author: Samuel Matzek <email address hidden>
Date: Wed Mar 4 20:17:08 2015 -0600

    Truncate encoded instance sys meta to 255 or less

    In nova/utils.py function get_system_metadata_from_image converts
    image metadata into instance system metadata. Since Nova's DB
    column is limited to 255 characters for system metadata, the image
    properties are truncated to 255 characters. However, the Glance
    image may have non-English unicode property values that are longer
    than 255 after being encoded to bytes. We need to truncate the
    encoded byte property value to 255 or fewer bytes in order to ensure
    the DB insert operation succeeds. The same encoding and truncation
    issue was fixed for the instance fault table under change id
    I62fa2830b22e367eb9486d09d3c8818a18ebd20d. This fix refactors
    that code fix into a utility method and uses it to fix both problems.

    Change-Id: Ie1051777dd09a2fb91afbadad3728956f83452cf
    Closes-Bug: #1425657
    Related-Bug: #1389102