Bug 1190837

Summary: Nova may not start instances when OS is installed with locale not en_US
Product: Red Hat OpenStack Reporter: jorge.gonzalez
Component: openstack-novaAssignee: Victor Stinner <vstinner>
Status: CLOSED ERRATA QA Contact: nlevinki <nlevinki>
Severity: medium Docs Contact:
Priority: medium    
Version: 6.0 (Juno)CC: berrange, dasmith, eglynn, kchamart, lyarwood, mriedem, ndipanov, pbrady, sasha, sbauza, sferdjao, sgordon, slong, vromanso, vstinner, yeylon
Target Milestone: ---Keywords: ZStream
Target Release: 5.0 (RHEL 6)   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: openstack-nova-2014.1.5-9.el6ost, openstack-nova-2014.1.5-9.el7ost Doc Type: Bug Fix
Doc Text:
In some cases, Compute did not start instances when RHEL was installed with a locale other than en_US. The update ensures that logging an exception no longer causes Unicode issues.
 Story Points: ---
Clone Of: Environment:
Last Closed: 2015-12-21 18:44:55 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description jorge.gonzalez 2015-02-09 17:21:41 UTC 
Description of problem:

Nova fails to start instances on compute nodes. The error is traceable to an exception here:

2015-02-09 17:09:25.875 6875 INFO nova.virt.libvirt.firewall [-] [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3] Ensuring static filters
2015-02-09 17:09:25.878 6875 ERROR nova.compute.manager [-] [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3] Instance failed to spawn
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3] Traceback (most recent call last):
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2243, in _build_resources
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]     yield resources
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2113, in _build_and_run_instance
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]     block_device_info=block_device_info)
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2621, in spawn
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]     block_device_info, disk_info=disk_info)
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4406, in _create_domain_and_network
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]     network_info)
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/firewall.py", line 307, in setup_basic_filtering
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]     self.nwfilter.setup_basic_filtering(instance, network_info)
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/firewall.py", line 130, in setup_basic_filtering
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]     vif))
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/firewall.py", line 179, in _get_instance_filter_xml
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]     uuid = self._get_filter_uuid(instance_filter_name)
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/firewall.py", line 247, in _get_filter_uuid
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3]     LOG.debug(u"Cannot find UUID for filter '%s': '%s'" % (name, e))
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3] UnicodeDecodeError: 'ascii' codec can't decode byte 0xc3 in position 13: ordinal not in range(128)
2015-02-09 17:09:25.878 6875 TRACE nova.compute.manager [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3] 
2015-02-09 17:09:25.880 6875 AUDIT nova.compute.manager [req-d251acfb-4979-4e93-849d-0502f6821442 None] [instance: 753fed9e-e2de-4e4d-9039-345c9d07aad3] Terminating instance


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

* CentOS 7
* python-nova-2014.2.1-1.el7.centos.noarch

How reproducible:

Always

Steps to Reproduce:

1. Install CentOS 7 on 2 nodes (controller and compute), selecting "Spanish" as system language, and "SPanish" as keyboard layout. The system will be installed with the "es_ES.UTF-8" locale as the system locale.

2. Install Openstack Juno following instructions from http://docs.openstack.org/juno/install-guide/install/yum/content/index.html
up to (and including) point "6. Add a networking component", and select legacy (nova) networking.

3. Try to launch a CirrOS instance.

Actual results:

The instance won't start correctly, and the former trace can be seen in /var/log/nova/nova-compute.log on the compute node. 



Expected results:

The instance should start correctly.


Additional info:

The error has been traced to line 247 in file /usr/lib/python2.7/site-packages/nova/virt/libvirt/firewall.py:

LOG.debug("Cannot find UUID for filter '%s': '%s'" % (name, e))

The error comes from variable 'e' which is a libvirtException. When the system locale is es_ES.UTF-8 (Spanish system install), so it is the locale for the libvirtd daemon.

The libvirtd errors are also in Spanish, and so they may contain (and in fact do contain!) Unicode characters.

The "LOG.debug..." line tries to format the debug message as ASCII and python throws an exception due to the unexpected characters.

The end result is that the nova daemons fails, and so the instance is not started, even though the debug line should not have such a hard side effect.

A possible workaround would be to use the %r formatter in the debug line instead of the %s, which would not try to decode the Unicode characters as ASCII but instead put them raw in the log file.

Another possible solution is to ensure that the system locale is set to en_US.UTF_8 by editing /etc/locale.conf and rebooting. The official docs would be a good place to insert this advise.
Comment 3 Matt Riedemann 2015-03-10 15:49:17 UTC 
Reported and 'fixed' in openstack nova here:

https://bugs.launchpad.net/nova/+bug/1419905

That's being reworked here though:

https://bugs.launchpad.net/nova/+bug/1430383
Comment 4 Stephen Gordon 2015-03-19 18:32:33 UTC 
*** Bug 1203825 has been marked as a duplicate of this bug. ***
Comment 5 Victor Stinner 2015-04-24 14:58:16 UTC 
I proposed a patch to oslo.utils to ensure that logging an exception doesn't cause unicode issue, the patch is under review:
"Add exception_to_unicode() function"
https://review.openstack.org/#/c/163507/
Comment 6 Victor Stinner 2015-04-30 16:06:43 UTC 
FYI this issue will be fixed in RHEL-OSP6 A3 by #1210455 (Rebase openstack-nova to 2014.2.3).
Comment 7 Victor Stinner 2015-10-20 13:13:15 UTC 
FYI oslo_utils.encodeutils.exception_to_unicode() was added to oslo.utils 1.6.
Comment 8 Victor Stinner 2015-11-27 17:21:19 UTC 
Victor Stinner 2015-11-27 12:20:07 EST
Status: ASSIGNED → MODIFIED
Fixed In Version: openstack-nova-2014.1.5-9.el6ost
Flags: rhos-5.0.z-rhel-6+ → rhos-5.0.z-rhel-6?

Oops, I modified "rhos-5.0.z-rhel-6+" by mistake, sorry. Anyway, a new package is available for tests. Enjoy :-)
Comment 11 errata-xmlrpc 2015-12-21 18:44:55 UTC 
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.

https://rhn.redhat.com/errata/RHSA-2015-2684.html