Bug 1318766

Summary:	live migration without shared storage fails in pre_live_migration after upgrade to 2015.1.2-18.2
Product:	Red Hat OpenStack	Reporter:	Lee Yarwood <lyarwood>
Component:	openstack-nova	Assignee:	Eoghan Glynn <eglynn>
Status:	CLOSED ERRATA	QA Contact:	Prasanth Anbalagan <panbalag>
Severity:	urgent	Docs Contact:
Priority:	urgent
Version:	6.0 (Juno)	CC:	berrange, dasmith, eglynn, kchamart, lyarwood, mschuppe, ndipanov, nlevinki, sbauza, sferdjao, sgordon, srevivo, vromanso
Target Milestone:	---	Keywords:	ZStream
Target Release:	6.0 (Juno)
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	openstack-nova-2014.2.3-66.el7ost	Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:	1318722	Environment:
Last Closed:	2016-04-18 15:04:42 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:
Bug Depends On:	1318722
Bug Blocks:

Description Lee Yarwood 2016-03-17 18:22:09 UTC

+++ This bug was initially created as a clone of Bug #1318722 +++

Description of problem:

After the upgrade to nova 2015.1.2-18.2 - CVE-2016-2140 fix, live migration fails without shared storage.

Version-Release number of selected component (if applicable):
* python-nova-2015.1.2-18.2.el7ost.noarch

How reproducible:
always

Steps to Reproduce:
1. configure live migration without shared storage
2. nova live-migration --block-migrate 8e972bd1-7e82-4868-9ac4-b80cc2eb098e osp7-compute
3. migration fails in pre_live_migration:

Actual results:
2016-03-17 11:02:45.192 5674 ERROR nova.compute.manager [req-da974863-f48d-4a20-8d95-133ddc39acda 4b730783a9af469b8168a8e8a58e510f 342bdc50ad5c415594975e762bdd8456 - - -] [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] Pre live migration failed at osp7-compute
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] Traceback (most recent call last):
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 5308, in _do_live_migration
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     block_migration, disk, dest, migrate_data)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/nova/compute/rpcapi.py", line 627, in pre_live_migration
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     disk=disk, migrate_data=migrate_data)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 156, in call
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     retry=self.retry)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 90, in _send
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     timeout=timeout, retry=retry)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 350, in send
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     retry=retry)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 341, in _send
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     raise result
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] TypeError: string indices must be integers
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] Traceback (most recent call last):
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     executor_callback))
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     executor_callback)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 130, in _do_dispatch
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     result = func(ctxt, **new_args)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 6845, in pre_live_migration
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     disk, migrate_data=migrate_data)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 461, in decorated_function
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     return function(self, context, *args, **kwargs)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 88, in wrapped
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     payload)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     six.reraise(self.type_, self.value, self.tb)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 71, in wrapped
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     return f(self, context, *args, **kw)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 369, in decorated_function
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     kwargs['instance'], e, sys.exc_info())
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     six.reraise(self.type_, self.value, self.tb)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 357, in decorated_function
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     return function(self, context, *args, **kwargs)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 5272, in pre_live_migration
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     migrate_data)
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 6003, in pre_live_migration
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e]     image_file = os.path.basename(info['path'])
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] TypeError: string indices must be integers
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 
2016-03-17 11:02:45.192 5674 TRACE nova.compute.manager [instance: 8e972bd1-7e82-4868-9ac4-b80cc2eb098e] 


   5997             # Recreate the disk.info file and in doing so stop the
   5998             # imagebackend from recreating it incorrectly by inspecting the
   5999             # contents of each file when using the Raw backend.
   6000             if disk_info:
   6001                 image_disk_info = {}
   6002                 for info in disk_info:
-->   6003                     image_file = os.path.basename(info['path'])
   6004                     image_path = os.path.join(instance_dir, image_file)
   6005                     image_disk_info[image_path] = info['type']
   6006 


Expected results:
migration works

Additional info:

when downgrade to 2015.1.2-18 migration works.

--- Additional comment from Martin Schuppert on 2016-03-17 11:45:43 EDT ---

disk_info is:

2016-03-17 11:37:42.637 6497 DEBUG nova.virt.libvirt.driver [req-8c0157c2-adf7-41c4-bbf3-7117c96d5fa8 4b730783a9af469b8168a8e8a58e510f 342bdc50ad5c415594975e762bdd8456 - - -] disk_info: u'[{"disk_size": 1703936, "backing_file": "7aadcb85f689579f6b1cf9b7d21bfaed4212f42f", "virt_disk
_size": 1073741824, "path": "/var/lib/nova/instances/8e972bd1-7e82-4868-9ac4-b80cc2eb098e/disk", "type": "qcow2", "over_committed_disk_size": 1072037888}]' pre_live_migration /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:6000

--- Additional comment from Lee Yarwood on 2016-03-17 12:10:42 EDT ---

This is happening due to self.driver.get_instance_disk_info being called by the compute manager when block_migration is enabled :

nova/compute/manager.py

5293     def _do_live_migration(self, context, dest, instance, block_migration,
5294                            migrate_data):
5295         # Create a local copy since we'll be modifying the dictionary
5296         migrate_data = dict(migrate_data or {})
5297         try:
5298             if block_migration:
5299                 block_device_info = self._get_instance_block_device_info(
5300                     context, instance)
5301                 disk = self.driver.get_instance_disk_info(
5302                     instance, block_device_info=block_device_info)
5303             else:
5304                 disk = None
5305 
5306             pre_migration_data = self.compute_rpcapi.pre_live_migration(
5307                 context, instance,
5308                 block_migration, disk, dest, migrate_data)
5309             migrate_data['pre_live_migration_result'] = pre_migration_data

nova/virt/libvirt/driver.py

6418     def get_instance_disk_info(self, instance,
6419                                block_device_info=None):
6420         try:
6421             dom = self._host.get_domain(instance)
6422             xml = dom.XMLDesc(0)
6423         except libvirt.libvirtError as ex: 
6424             error_code = ex.get_error_code()
6425             msg = (_('Error from libvirt while getting description of '
6426                      '%(instance_name)s: [Error Code %(error_code)s] '
6427                      '%(ex)s') %
6428                    {'instance_name': instance.name,
6429                     'error_code': error_code,
6430                     'ex': ex})
6431             LOG.warn(msg)
6432             raise exception.InstanceNotFound(instance_id=instance.name)
6433 
6434         return jsonutils.dumps(
6435                 self._get_instance_disk_info(instance.name, xml,
6436                                              block_device_info))

This sets disk_info to an encoded JSON string (for example u'[{"foo":"bar},{"bar":"foo"}]'), causing the failure documented in c#0.

The get_instance_disk_info method switched back to plain strings for Liberty with the following change :

libvirt: Remove unnecessary JSON conversions
https://review.openstack.org/#/c/177437/6

Comment 2 Prasanth Anbalagan 2016-04-13 01:27:54 UTC

*****************
VERSION
*****************

[root@lynx13 ~(keystone_admin)]# yum list installed | grep openstack-nova
openstack-nova-api.noarch            2014.2.3-66.el7ost      @rhelosp-6.0-puddle
openstack-nova-cert.noarch           2014.2.3-66.el7ost      @rhelosp-6.0-puddle
openstack-nova-common.noarch         2014.2.3-66.el7ost      @rhelosp-6.0-puddle
openstack-nova-compute.noarch        2014.2.3-66.el7ost      @rhelosp-6.0-puddle
openstack-nova-conductor.noarch      2014.2.3-66.el7ost      @rhelosp-6.0-puddle
openstack-nova-console.noarch        2014.2.3-66.el7ost      @rhelosp-6.0-puddle
openstack-nova-novncproxy.noarch     2014.2.3-66.el7ost      @rhelosp-6.0-puddle
openstack-nova-scheduler.noarch      2014.2.3-66.el7ost      @rhelosp-6.0-puddle
[root@lynx13 ~(keystone_admin)]# 

*****************
LOGS
*****************


[root@lynx13 ~(keystone_admin)]# nova list
+--------------------------------------+------+--------+------------+-------------+---------------------+
| ID                                   | Name | Status | Task State | Power State | Networks            |
+--------------------------------------+------+--------+------------+-------------+---------------------+
| f39fa56e-b362-4178-a632-7104497a1088 | vm1  | ACTIVE | -          | Running     | public=172.24.4.234 |
| 5d950e0d-a96b-4924-91a3-7b47dbcd7be4 | vm2  | ACTIVE | -          | Running     | public=172.24.4.233 |
+--------------------------------------+------+--------+------------+-------------+---------------------+
[root@lynx13 ~(keystone_admin)]# nova live-migration --block-migrate vm1 lynx13.qa.lab.tlv.redhat.com

[root@lynx13 ~(keystone_admin)]# nova show vm1
+--------------------------------------+----------------------------------------------------------+
| Property                             | Value                                                    |
+--------------------------------------+----------------------------------------------------------+
| OS-DCF:diskConfig                    | MANUAL                                                   |
| OS-EXT-AZ:availability_zone          | nova                                                     |
| OS-EXT-SRV-ATTR:host                 | rhos-compute-node-02.lab.eng.rdu2.redhat.com             |
| OS-EXT-SRV-ATTR:hypervisor_hostname  | rhos-compute-node-02.lab.eng.rdu2.redhat.com             |
| OS-EXT-SRV-ATTR:instance_name        | instance-00000007                                        |
| OS-EXT-STS:power_state               | 1                                                        |
| OS-EXT-STS:task_state                | migrating                                                |
| OS-EXT-STS:vm_state                  | active                                                   |
| OS-SRV-USG:launched_at               | 2016-04-13T01:22:58.000000                               |
| OS-SRV-USG:terminated_at             | -                                                        |
| accessIPv4                           |                                                          |
| accessIPv6                           |                                                          |
| config_drive                         |                                                          |
| created                              | 2016-04-13T01:22:33Z                                     |
| flavor                               | m1.tiny (1)                                              |
| hostId                               | 95bb8a2f6487f032146fcf91dd40857188d626a08ff2e5726b5180d7 |
| id                                   | f39fa56e-b362-4178-a632-7104497a1088                     |
| image                                | cirros (1e6f59d4-2fe2-4dea-900e-954166a64dbc)            |
| key_name                             | -                                                        |
| metadata                             | {}                                                       |
| name                                 | vm1                                                      |
| os-extended-volumes:volumes_attached | []                                                       |
| public network                       | 172.24.4.234                                             |
| security_groups                      | default                                                  |
| status                               | MIGRATING                                                |
| tenant_id                            | 930a1e314c874915b8586081fa9f4373                         |
| updated                              | 2016-04-13T01:24:21Z                                     |
| user_id                              | 2d28203653654af78d7c2decb4eead1d                         |
+--------------------------------------+----------------------------------------------------------+
[root@lynx13 ~(keystone_admin)]# 
[root@lynx13 ~(keystone_admin)]# 
[root@lynx13 ~(keystone_admin)]# nova show vm1
+--------------------------------------+----------------------------------------------------------+
| Property                             | Value                                                    |
+--------------------------------------+----------------------------------------------------------+
| OS-DCF:diskConfig                    | MANUAL                                                   |
| OS-EXT-AZ:availability_zone          | nova                                                     |
| OS-EXT-SRV-ATTR:host                 | lynx13.qa.lab.tlv.redhat.com                             |
| OS-EXT-SRV-ATTR:hypervisor_hostname  | lynx13.qa.lab.tlv.redhat.com                             |
| OS-EXT-SRV-ATTR:instance_name        | instance-00000007                                        |
| OS-EXT-STS:power_state               | 1                                                        |
| OS-EXT-STS:task_state                | -                                                        |
| OS-EXT-STS:vm_state                  | active                                                   |
| OS-SRV-USG:launched_at               | 2016-04-13T01:22:58.000000                               |
| OS-SRV-USG:terminated_at             | -                                                        |
| accessIPv4                           |                                                          |
| accessIPv6                           |                                                          |
| config_drive                         |                                                          |
| created                              | 2016-04-13T01:22:33Z                                     |
| flavor                               | m1.tiny (1)                                              |
| hostId                               | ea88a39294686566b566cb9f0290ffcac2841a4f88feb38becae366a |
| id                                   | f39fa56e-b362-4178-a632-7104497a1088                     |
| image                                | cirros (1e6f59d4-2fe2-4dea-900e-954166a64dbc)            |
| key_name                             | -                                                        |
| metadata                             | {}                                                       |
| name                                 | vm1                                                      |
| os-extended-volumes:volumes_attached | []                                                       |
| progress                             | 96                                                       |
| public network                       | 172.24.4.234                                             |
| security_groups                      | default                                                  |
| status                               | ACTIVE                                                   |
| tenant_id                            | 930a1e314c874915b8586081fa9f4373                         |
| updated                              | 2016-04-13T01:24:52Z                                     |
| user_id                              | 2d28203653654af78d7c2decb4eead1d                         |
+--------------------------------------+----------------------------------------------------------+
[root@lynx13 ~(keystone_admin)]#

Comment 4 errata-xmlrpc 2016-04-18 15:04:42 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/RHBA-2016-0639.html