Multiple VM creation with unicode-containing names fails

[Anna Babich]

It happens when creating more than one instance with unicode-containing name. The first attempt to boot an instance with unicode-containing name is successful, but if to boot one more vm with unicode-containing name, it will fall to ERROR state with the message like:
'Returning exception 'ascii' codec can't decode byte 0xe2 in position 359: ordinal not in range(128) to caller'

Moreover, if after this to try to boot any instance with ascii characters, it will fall to ERROR state with the same message.

It has been reproduced on env (3 controllers+2 computes, Cinder LVM):
[root@nailgun ~]# shotgun2 short-report
cat /etc/fuel_build_id:
 154
cat /etc/fuel_build_number:
 154
cat /etc/fuel_release:
 9.0
cat /etc/fuel_openstack_version:
 mitaka-9.0
rpm -qa | egrep 'fuel|astute|network-checker|nailgun|packetary|shotgun':
 fuel-misc-9.0.0-1.mos8259.noarch
 python-fuelclient-9.0.0-1.mos301.noarch
 fuel-9.0.0-1.mos6325.noarch
 fuel-provisioning-scripts-9.0.0-1.mos8611.noarch
 fuelmenu-9.0.0-1.mos263.noarch
 fuel-ui-9.0.0-1.mos2641.noarch
 fuel-migrate-9.0.0-1.mos8259.noarch
 fuel-ostf-9.0.0-1.mos921.noarch
 shotgun-9.0.0-1.mos87.noarch
 python-packetary-9.0.0-1.mos130.noarch
 fuel-bootstrap-cli-9.0.0-1.mos272.noarch
 fuel-nailgun-9.0.0-1.mos8611.noarch
 fuel-setup-9.0.0-1.mos6325.noarch
 rubygem-astute-9.0.0-1.mos733.noarch
 fuel-mirror-9.0.0-1.mos130.noarch
 fuel-openstack-metadata-9.0.0-1.mos8611.noarch
 fuel-notify-9.0.0-1.mos8259.noarch
 fuel-release-9.0.0-1.mos6325.noarch
 nailgun-mcagents-9.0.0-1.mos733.noarch
 network-checker-9.0.0-1.mos72.x86_64
 fuel-utils-9.0.0-1.mos8259.noarch
 fuel-library9.0-9.0.0-1.mos8259.noarch
 fuel-agent-9.0.0-1.mos272.noarch
[root@nailgun ~]#

Steps to reproduce:
1. Create a first instance with unicode characters in its name:
a=$'\u2234\u2192\u263f\u2605'
nova boot --flavor m1.micro --image TestVM --nic net-id=$(neutron net-list | awk '/admin_internal_net/{print $2}') vm$a
scheduler's log of creation process - http://paste.openstack.org/show/492900/
2. Check that it's in ACTIVE state:
root@node-1:~# nova show vm∴→☿★ | grep status
| status | ACTIVE |
3. Create another instance with unicode characters in its name:
nova boot --flavor m1.micro --image TestVM --nic net-id=$(neutron net-list | awk '/admin_internal_net/{print $2}') vm1$a
scheduler's log of creation process - http://paste.openstack.org/show/492901/
Expected result: the instance's booting is successful
Actual result: the instance's booting failed

[Andrey Volkov (avolkov)]

Can't reproduce on my devstack: http://paste.openstack.org/show/497650/
On horizon.ssl.mirantis.net error shows immediately on first request: http://paste.openstack.org/show/497651/
It can be useful to see result of script: http://paste.openstack.org/show/497652/

[Andrey Volkov (avolkov)]

I've checked on MOS installation: ssh -l root -p 8022 172.18.204.8
Same result: http://paste.openstack.org/show/497717/

[Andrey Volkov (avolkov)]

Same check on fresh, just deployed MOS: http://paste.openstack.org/show/498030/

[Roman Podoliaka (rpodolyaka)]

Anna, could you please give it another try? ^

[Anna Babich (ababich)]

Andrey, please, try to reproduce it with debug=True in nova.conf

[Roman Podoliaka (rpodolyaka)]

As long as it's only reproduced with debugging logging enabled (which is not true for production), let's downgrade this to Medium and fix in 10.0.

[Andrey Volkov (avolkov)]

Yes, with debug=True it is reproducible.

[Andrey Volkov (avolkov)]

There are problems in oslo library related to encoding:

1. If in python 2.7 I try to log string like:

logging.warning('test message with unicode %s', u'☢ ☯ ☭ ∑ ∞ ♀ ♂ ♥'.encode('utf8'))

it's ok, but with olso:

from oslo_log import log as logging
LOG = logging.getLogger(__name__)
LOG.warning('test message with unicode %s', u'☢ ☯ ☭ ∑ ∞ ♀ ♂ ♥'.encode('utf8'))

UnicodeDecodeError: 'ascii' codec can't decode byte 0xe2 in position
0: ordinal not in range(128)

On https://github.com/openstack/oslo.log/blob/master/oslo_log/log.py#L129
ensure_unicode is only for message but not for args.

2. If I replace previous code to:

LOG.warning(u'test message with unicode ☢ ☯ ☭ ∑ ∞ ♀ ♂ ♥'.encode('utf8'))

with syslog, I've got error like:
ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo_log/handlers.py", line 57, in emit
ERROR oslo_messaging.rpc.dispatcher self.format(record))
ERROR oslo_messaging.rpc.dispatcher TypeError: [priority,] message string

May be it's related to https://bugs.launchpad.net/oslo.log/+bug/1483842.

I'll make workraround to remove non ascii characters in log.

[Andrey Volkov (avolkov)]

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

[Andrey Volkov (avolkov)]

Checked on MOS mitaka-9.0, iso 376.
Logs look like http://paste.openstack.org/show/505588/.
Non ascii symbols encoded: display_name='barbaris1-∴→☿★'

[Andrey Volkov (avolkov)]

Waiting for solving of two oslo bug:
https://bugs.launchpad.net/oslo.log/+bug/1563295
https://bugs.launchpad.net/oslo.log/+bug/1483842.

[Roman Podoliaka (rpodolyaka)]

^ both bugs are fixed in Newton.