Ensure to store context in thread local after spawn/spawn_n

https://review.openstack.org/#/c/171299/ introduces a wrapper for utils.spawn_n
to update context in thread local store. However, there are other routines in
driver code which calls greenthread.spawn or greenthread.spawn_n, so that they
will not update context in thread local store. The commit adds utils.spawn as a
new wrapper, and also make those codes call spawn/spawn_n of utils, in order to
ensure the context of logging is correct.

Change-Id: I3623e60c49e442e2431cf017540422aa59bc285a
Related-Bug: 1404268

5 files changed, 44 insertions, 13 deletions

diff --git a/nova/tests/unit/test_utils.py b/nova/tests/unit/test_utils.py
index 008a5592a0..5ec764f9ba 100644
--- a/nova/tests/unit/test_utils.py
+++ b/nova/tests/unit/test_utils.py
@@ -1032,6 +1032,7 @@ class SpawnNTestCase(test.NoDBTestCase):
     def setUp(self):
         super(SpawnNTestCase, self).setUp()
         self.useFixture(context_fixture.ClearRequestContext())
+        self.spawn_name = 'spawn_n'
 
     def test_spawn_n_no_context(self):
         self.assertIsNone(common_context.get_current())
@@ -1044,8 +1045,8 @@ class SpawnNTestCase(test.NoDBTestCase):
         def fake(arg):
             pass
 
-        with mock.patch.object(eventlet, 'spawn_n', _fake_spawn):
-            utils.spawn_n(fake, 'test')
+        with mock.patch.object(eventlet, self.spawn_name, _fake_spawn):
+            getattr(utils, self.spawn_name)(fake, 'test')
         self.assertIsNone(common_context.get_current())
 
     def test_spawn_n_context(self):
@@ -1061,8 +1062,8 @@ class SpawnNTestCase(test.NoDBTestCase):
         def fake(context, kwarg1=None):
             pass
 
-        with mock.patch.object(eventlet, 'spawn_n', _fake_spawn):
-            utils.spawn_n(fake, ctxt, kwarg1='test')
+        with mock.patch.object(eventlet, self.spawn_name, _fake_spawn):
+            getattr(utils, self.spawn_name)(fake, ctxt, kwarg1='test')
         self.assertEqual(ctxt, common_context.get_current())
 
     def test_spawn_n_context_different_from_passed(self):
@@ -1081,6 +1082,12 @@ class SpawnNTestCase(test.NoDBTestCase):
         def fake(context, kwarg1=None):
             pass
 
-        with mock.patch.object(eventlet, 'spawn_n', _fake_spawn):
-            utils.spawn_n(fake, ctxt_passed, kwarg1='test')
+        with mock.patch.object(eventlet, self.spawn_name, _fake_spawn):
+            getattr(utils, self.spawn_name)(fake, ctxt_passed, kwarg1='test')
         self.assertEqual(ctxt, common_context.get_current())
+
+
+class SpawnTestCase(SpawnNTestCase):
+    def setUp(self):
+        super(SpawnTestCase, self).setUp()
+        self.spawn_name = 'spawn'
diff --git a/nova/tests/unit/virt/libvirt/test_driver.py b/nova/tests/unit/virt/libvirt/test_driver.py
index ddcf7523c9..b226eba7fd 100644
--- a/nova/tests/unit/virt/libvirt/test_driver.py
+++ b/nova/tests/unit/virt/libvirt/test_driver.py
@@ -6305,7 +6305,7 @@ class LibvirtConnTestCase(test.NoDBTestCase):
 
         self._test_live_migration_monitoring(domain_info_records, False)
 
-    @mock.patch.object(greenthread, "spawn")
+    @mock.patch.object(utils, "spawn")
     @mock.patch.object(libvirt_driver.LibvirtDriver, "_live_migration_monitor")
     @mock.patch.object(host.Host, "get_domain")
     @mock.patch.object(fakelibvirt.Connection, "_mark_running")
@@ -11035,7 +11035,7 @@ class LibvirtConnTestCase(test.NoDBTestCase):
                                                   dstfile, "qcow2")
             mock_define.assert_called_once_with(xmldoc)
 
-    @mock.patch.object(greenthread, "spawn")
+    @mock.patch.object(utils, "spawn")
     def test_live_migration_hostname_valid(self, mock_spawn):
         drvr = libvirt_driver.LibvirtDriver(fake.FakeVirtAPI(), False)
         drvr.live_migration(self.context, self.test_instance,
@@ -11044,7 +11044,7 @@ class LibvirtConnTestCase(test.NoDBTestCase):
                             lambda x: x)
         self.assertEqual(1, mock_spawn.call_count)
 
-    @mock.patch.object(greenthread, "spawn")
+    @mock.patch.object(utils, "spawn")
     @mock.patch.object(fake_libvirt_utils, "is_valid_hostname")
     def test_live_migration_hostname_invalid(self, mock_hostname, mock_spawn):
         drvr = libvirt_driver.LibvirtDriver(fake.FakeVirtAPI(), False)
diff --git a/nova/utils.py b/nova/utils.py
index de414ad4eb..1d3447f756 100644
--- a/nova/utils.py
+++ b/nova/utils.py
@@ -974,6 +974,29 @@ def validate_integer(value, name, min_value=None, max_value=None):
     return value
 
 
+def spawn(func, *args, **kwargs):
+    """Passthrough method for eventlet.spawn.
+
+    This utility exists so that it can be stubbed for testing without
+    interfering with the service spawns.
+
+    It will also grab the context from the threadlocal store and add it to
+    the store on the new thread.  This allows for continuity in logging the
+    context when using this method to spawn a new thread.
+    """
+    _context = common_context.get_current()
+
+    @functools.wraps(func)
+    def context_wrapper(*args, **kwargs):
+        # NOTE: If update_store is not called after spawn it won't be
+        # available for the logger to pull from threadlocal storage.
+        if _context is not None:
+            _context.update_store()
+        return func(*args, **kwargs)
+
+    return eventlet.spawn(context_wrapper, *args, **kwargs)
+
+
 def spawn_n(func, *args, **kwargs):
     """Passthrough method for eventlet.spawn_n.
 
diff --git a/nova/virt/libvirt/driver.py b/nova/virt/libvirt/driver.py
index de7df037b0..34a4e1e3f7 100644
--- a/nova/virt/libvirt/driver.py
+++ b/nova/virt/libvirt/driver.py
@@ -5288,7 +5288,7 @@ class LibvirtDriver(driver.ComputeDriver):
         if not libvirt_utils.is_valid_hostname(dest):
             raise exception.InvalidHostname(hostname=dest)
 
-        greenthread.spawn(self._live_migration, context, instance, dest,
+        utils.spawn(self._live_migration, context, instance, dest,
                           post_method, recover_method, block_migration,
                           migrate_data)
 
@@ -5679,7 +5679,7 @@ class LibvirtDriver(driver.ComputeDriver):
 
         dom = self._host.get_domain(instance)
 
-        opthread = greenthread.spawn(self._live_migration_operation,
+        opthread = utils.spawn(self._live_migration_operation,
                                      context, instance, dest,
                                      block_migration,
                                      migrate_data, dom)
diff --git a/nova/virt/vmwareapi/io_util.py b/nova/virt/vmwareapi/io_util.py
index d946ed0b19..aec271a7ec 100644
--- a/nova/virt/vmwareapi/io_util.py
+++ b/nova/virt/vmwareapi/io_util.py
@@ -27,6 +27,7 @@ from oslo_log import log as logging
 from nova import exception
 from nova.i18n import _, _LE
 from nova import image
+from nova import utils
 
 LOG = logging.getLogger(__name__)
 IMAGE_API = image.API()
@@ -138,7 +139,7 @@ class GlanceWriteThread(object):
                     self.stop()
                     self.done.send_exception(exc)
 
-        greenthread.spawn(_inner)
+        utils.spawn(_inner)
         return self.done
 
     def stop(self):
@@ -183,7 +184,7 @@ class IOThread(object):
                     LOG.exception(_LE('Read/Write data failed'))
                     self.done.send_exception(exc)
 
-        greenthread.spawn(_inner)
+        utils.spawn(_inner)
         return self.done
 
     def stop(self):