yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1558679] [NEW] Live block migration fails with TypeError exception in driver.py

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Angela <anglam@xxxxxxxxx>
Date: Thu, 17 Mar 2016 16:59:37 -0000
Reply-to: Bug 1558679 <1558679@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Hi,

When I attempt to do a live block migration of my VM instance, I see the
following exception in my nova-compute.log and migration did not happen:

2016-03-15 12:27:48.121 15330 ERROR oslo_messaging.rpc.dispatcher [req-e41b3f49-8bf8-4a4e-8511-1f8eea811dff b567c533c6a842908a3888a4ce80117e 0a6eee33460e4c86ba591fd427cce163 - - -] Exception during message handling: string indices must be integers
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher Traceback (most recent call last):
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     executor_callback))
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     executor_callback)
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 130, in _do_dispatch
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     result = func(ctxt, **new_args)
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 6845, in pre_live_migration
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     disk, migrate_data=migrate_data)
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 461, in decorated_function
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 88, in wrapped
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     payload)
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 71, in wrapped
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     return f(self, context, *args, **kw)
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 369, in decorated_function
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     kwargs['instance'], e, sys.exc_info())
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 357, in decorated_function
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 5272, in pre_live_migration
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     migrate_data)
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 6003, in pre_live_migration
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     image_file = os.path.basename(info['path'])
2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher TypeError: string indices must be integers

The Nova/OpenStack version that I'm running is as follows (as shown in 'rpm -qa | grep nova'):
python-nova-2015.1.2-18.1.el7ost.noarch
python-novaclient-2.23.0-2.el7ost.noarch
openstack-nova-common-2015.1.2-18.1.el7ost.noarch
openstack-nova-compute-2015.1.2-18.1.el7ost.noarch

The '/nova/virt/libvirt/driver.py' file running on my system is dated
Mar 4, 2016.  Please note that I have other systems running an older
version of the '/nova/virt/libvirt/driver.py' file (dated Jan 22) and
live block migration is working fine on those systems.

Upon further investigation, it was noted that the following section of
the code in the '/nova/virt/libvirt/driver.py' file that throws
exception was added very recently:

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

                LOG.debug('Creating disk.info with the contents: %s',
                          image_disk_info, instance=instance)

                image_disk_info_path = os.path.join(instance_dir,
                                                    'disk.info')
                libvirt_utils.write_to_file(image_disk_info_path,
                                            jsonutils.dumps(image_disk_info))

The reason why it throws exception seems to be that the 'disk_info'
variable that was passed in to the pre_live_migration method was
previously encoded using jsonutils.dumps, but the 'disk_info' variable
was NOT decoded using jsonutils.loads in this block of code, which
causes the 'info' object not being read properly.

After updating the code to use jsonutils.loads as follows, the live
block migration seems to be working fine:

            if disk_info:
                disk_info_obj = jsonutils.loads(disk_info)
                image_disk_info = {}
                for info in disk_info_obj:
                    image_file = os.path.basename(info['path'])
                    image_path = os.path.join(instance_dir, image_file)
                    image_disk_info[image_path] = info['type']

Would you mind taking a look and share your findings?  If you could also
please let me know when the fix would be available, that would be great!
Thanks very much!

Regards,
Angela

** Affects: nova
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1558679

Title:
  Live block migration fails with TypeError exception in driver.py

Status in OpenStack Compute (nova):
  New

Bug description:
  Hi,

  When I attempt to do a live block migration of my VM instance, I see
  the following exception in my nova-compute.log and migration did not
  happen:

  2016-03-15 12:27:48.121 15330 ERROR oslo_messaging.rpc.dispatcher [req-e41b3f49-8bf8-4a4e-8511-1f8eea811dff b567c533c6a842908a3888a4ce80117e 0a6eee33460e4c86ba591fd427cce163 - - -] Exception during message handling: string indices must be integers
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher Traceback (most recent call last):
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     executor_callback))
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     executor_callback)
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 130, in _do_dispatch
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     result = func(ctxt, **new_args)
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 6845, in pre_live_migration
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     disk, migrate_data=migrate_data)
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 461, in decorated_function
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 88, in wrapped
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     payload)
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 71, in wrapped
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     return f(self, context, *args, **kw)
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 369, in decorated_function
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     kwargs['instance'], e, sys.exc_info())
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 357, in decorated_function
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 5272, in pre_live_migration
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     migrate_data)
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 6003, in pre_live_migration
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher     image_file = os.path.basename(info['path'])
  2016-03-15 12:27:48.121 15330 TRACE oslo_messaging.rpc.dispatcher TypeError: string indices must be integers

  The Nova/OpenStack version that I'm running is as follows (as shown in 'rpm -qa | grep nova'):
  python-nova-2015.1.2-18.1.el7ost.noarch
  python-novaclient-2.23.0-2.el7ost.noarch
  openstack-nova-common-2015.1.2-18.1.el7ost.noarch
  openstack-nova-compute-2015.1.2-18.1.el7ost.noarch

  The '/nova/virt/libvirt/driver.py' file running on my system is dated
  Mar 4, 2016.  Please note that I have other systems running an older
  version of the '/nova/virt/libvirt/driver.py' file (dated Jan 22) and
  live block migration is working fine on those systems.

  Upon further investigation, it was noted that the following section of
  the code in the '/nova/virt/libvirt/driver.py' file that throws
  exception was added very recently:

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

                  LOG.debug('Creating disk.info with the contents: %s',
                            image_disk_info, instance=instance)

                  image_disk_info_path = os.path.join(instance_dir,
                                                      'disk.info')
                  libvirt_utils.write_to_file(image_disk_info_path,
                                              jsonutils.dumps(image_disk_info))

  The reason why it throws exception seems to be that the 'disk_info'
  variable that was passed in to the pre_live_migration method was
  previously encoded using jsonutils.dumps, but the 'disk_info' variable
  was NOT decoded using jsonutils.loads in this block of code, which
  causes the 'info' object not being read properly.

  After updating the code to use jsonutils.loads as follows, the live
  block migration seems to be working fine:

              if disk_info:
                  disk_info_obj = jsonutils.loads(disk_info)
                  image_disk_info = {}
                  for info in disk_info_obj:
                      image_file = os.path.basename(info['path'])
                      image_path = os.path.join(instance_dir, image_file)
                      image_disk_info[image_path] = info['type']

  Would you mind taking a look and share your findings?  If you could
  also please let me know when the fix would be available, that would be
  great!  Thanks very much!

  Regards,
  Angela

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1558679/+subscriptions
Follow ups

[Bug 1558679] Re: Live block migration fails with TypeError exception in driver.py
From: Launchpad Bug Tracker, 2016-08-23