Description
===========
nova.virt.libvirt./driver.py:LibvirtDriver._live_migration() spawn a thread to execute _live_migration_operation(called after threadA).Original thread execute _live_migration_monitor (called after threadB).
Assignment statement inst_type=instance.flavor call nova/objects/instance.py:obj_load_attr in function _live_migration_operation.
Function _live_migration_monitor call func _live_migration_data_gb。Assignment statement ram_gb = instance.flavor.memory_mb * units.Mi / units.Gi also call nova/objects/instance.py:obj_load_attr.
Function temporary_mutation is called by obj_load_attr. The mistack caused by the temporary_mutation is called by two threads simultaneously。
Time0: self._context[‘read_deleted’] is ‘no’
Time1: ThreadA called temporary_mutation, self._context[‘read_deleted’] is assigned a value of ‘yes’. Old value is ‘no’.
Time2: ThreadB called temporary_mutation, self._context[‘read_deleted’] is assigned a value of ‘yes’. Old value is ‘yes’.
Time3: ThreadA executing finally code of temporary_mutation, the value of self._context[‘read_deleted’] is restored to ‘no’.
Time3: ThreadA executing finally code of temporary_mutation, the value of self._context[‘read_deleted’] is restored to ‘yes’.
Result : Two calls to temporary_mutation cause the value of self._context[‘read_deleted’] to change from ‘no’ to ‘yes’. When Source host calling update_available_resource(ctxt) in _post_live_migration, calling of objects.InstanceList.get_by_host_and_node() will read deleted instances, which is time-consuming.
===========
Add the log
===========
Print self._context in obj_load_attr()
def obj_load_attr(self, attrname):
# NOTE(danms): We can't lazy-load anything without a context and a uuid
if not self._context:
raise exception.OrphanedObjectError(method='obj_load_attr',
objtype=self.obj_name())
if 'uuid' not in self:
raise exception.ObjectActionError(
action='obj_load_attr',
reason=_('attribute %s not lazy-loadable') % attrname)
- LOG.debug("Lazy-loading '%(attr)s' on %(name)s uuid %(uuid)s",
+ LOG.debug("Lazy-loading '%(attr)s' on %(name)s uuid %(uuid)s context %(context)s",
{'attr': attrname,
'name': self.obj_name(),
'uuid': self.uuid,
+ 'context': self._context,
})
===========
Logs
===========
2021-08-23 18:36:25.838 7 DEBUG nova.objects.instance [req-f3aa8a61-ca57-457e-a813-de5d226b2ff7 - - - - -] Lazy-loading 'flavor' on Instance uuid 18e4e517-7556-40be-8833-35290127c2e7 context <Context {'domain': None, 'project_name': u'admin', 'global_request_id': None, 'project_domain': u'default', 'timestamp': '2021-08-23T10:32:53.582673', 'auth_token': u'gAAAAABhI3lQbJgenzhpGw9daG5k1aUs3evWyZCQvujjhTZ0GZb2WIz_Eor4rlz9hPY-QxCBgH1z8nU2iTSMwPeJ5dEnEgPxmxrFq45XGXF9nLcrwCSUQfetie8k84OtEQYnhNVIE4uuPBJzRUNp9-rL6cRD8yhwXob9eSKsaZdtmTXxSBuOtJ8', 'remote_address': u'192.168.1.11', 'quota_class': None, 'resource_uuid': None, 'is_admin': True, 'user': u'5ca52b5e65df4d879dd490afa350a3f0', 'service_catalog': [{u'endpoints': [{u'adminURL': u'http://10.0.1.10:9292', u'region': u'RegionOne', u'internalURL': u'http://10.0.1.10:9292', u'publicURL': u'http://192.168.1.10:9292'}], u'type': u'image', u'name': u'glance'}, {u'endpoints': [{u'adminURL': u'http://10.0.1.10:8780', u'region': u'RegionOne', u'internalURL': u'http://10.0.1.10:8780', u'publicURL': u'http://192.168.1.10:8780'}], u'type': u'placement', u'name': u'placement'}, {u'endpoints': [{u'adminURL': u'http://10.0.1.10:8776/v3/76e23046831943bba571f0e3ea432182', u'region': u'RegionOne', u'internalURL': u'http://10.0.1.10:8776/v3/76e23046831943bba571f0e3ea432182', u'publicURL': u'http://192.168.1.10:8776/v3/76e23046831943bba571f0e3ea432182'}], u'type': u'volumev3', u'name': u'cinderv3'}, {u'endpoints': [{u'adminURL': u'http://10.0.1.10:9696', u'region': u'RegionOne', u'internalURL': u'http://10.0.1.10:9696', u'publicURL': u'http://192.168.1.10:9696'}], u'type': u'network', u'name': u'neutron'}], 'tenant': u'76e23046831943bba571f0e3ea432182', 'read_only': False, 'project_id': u'76e23046831943bba571f0e3ea432182', 'user_id': u'5ca52b5e65df4d879dd490afa350a3f0', 'show_deleted': False, 'system_scope': None, 'user_identity': u'5ca52b5e65df4d879dd490afa350a3f0 76e23046831943bba571f0e3ea432182 - default default', 'is_admin_project': True, 'project': u'76e23046831943bba571f0e3ea432182', 'read_deleted': u'no', 'request_id': u'req-cc913d2d-d257-40fd-8aa3-7e12a6c02288', 'roles': [u'admin', u'reader', u'heat_stack_owner', u'member'], 'user_domain': u'default', 'user_name': u'admin'}> obj_load_attr /var/lib/kolla/venv/lib/python2.7/site-packages/nova/objects/instance.py:1111
2021-08-23 18:36:25.844 7 DEBUG nova.virt.libvirt.driver [req-f3aa8a61-ca57-457e-a813-de5d226b2ff7 - - - - -] [instance: 18e4e517-7556-40be-8833-35290127c2e7] Starting monitoring of live migration _live_migration /var/lib/kolla/venv/lib/python2.7/site-packages/nova/virt/libvirt/driver.py:8049
2021-08-23 18:36:25.846 7 DEBUG nova.objects.instance [req-f3aa8a61-ca57-457e-a813-de5d226b2ff7 - - - - -] Lazy-loading 'flavor' on Instance uuid 18e4e517-7556-40be-8833-35290127c2e7 context <Context {'domain': None, 'project_name': u'admin', 'global_request_id': None, 'project_domain': u'default', 'timestamp': '2021-08-23T10:32:53.582673', 'auth_token': u'gAAAAABhI3lQbJgenzhpGw9daG5k1aUs3evWyZCQvujjhTZ0GZb2WIz_Eor4rlz9hPY-QxCBgH1z8nU2iTSMwPeJ5dEnEgPxmxrFq45XGXF9nLcrwCSUQfetie8k84OtEQYnhNVIE4uuPBJzRUNp9-rL6cRD8yhwXob9eSKsaZdtmTXxSBuOtJ8', 'remote_address': u'192.168.1.11', 'quota_class': None, 'resource_uuid': None, 'is_admin': True, 'user': u'5ca52b5e65df4d879dd490afa350a3f0', 'service_catalog': [{u'endpoints': [{u'adminURL': u'http://10.0.1.10:9292', u'region': u'RegionOne', u'internalURL': u'http://10.0.1.10:9292', u'publicURL': u'http://192.168.1.10:9292'}], u'type': u'image', u'name': u'glance'}, {u'endpoints': [{u'adminURL': u'http://10.0.1.10:8780', u'region': u'RegionOne', u'internalURL': u'http://10.0.1.10:8780', u'publicURL': u'http://192.168.1.10:8780'}], u'type': u'placement', u'name': u'placement'}, {u'endpoints': [{u'adminURL': u'http://10.0.1.10:8776/v3/76e23046831943bba571f0e3ea432182', u'region': u'RegionOne', u'internalURL': u'http://10.0.1.10:8776/v3/76e23046831943bba571f0e3ea432182', u'publicURL': u'http://192.168.1.10:8776/v3/76e23046831943bba571f0e3ea432182'}], u'type': u'volumev3', u'name': u'cinderv3'}, {u'endpoints': [{u'adminURL': u'http://10.0.1.10:9696', u'region': u'RegionOne', u'internalURL': u'http://10.0.1.10:9696', u'publicURL': u'http://192.168.1.10:9696'}], u'type': u'network', u'name': u'neutron'}], 'tenant': u'76e23046831943bba571f0e3ea432182', 'read_only': False, 'project_id': u'76e23046831943bba571f0e3ea432182', 'user_id': u'5ca52b5e65df4d879dd490afa350a3f0', 'show_deleted': False, 'system_scope': None, 'user_identity': u'5ca52b5e65df4d879dd490afa350a3f0 76e23046831943bba571f0e3ea432182 - default default', 'is_admin_project': True, 'project': u'76e23046831943bba571f0e3ea432182', 'read_deleted': 'yes', 'request_id': u'req-cc913d2d-d257-40fd-8aa3-7e12a6c02288', 'roles': [u'admin', u'reader', u'heat_stack_owner', u'member'], 'user_domain': u'default', 'user_name': u'admin'}> obj_load_attr /var/lib/kolla/venv/lib/python2.7/site-packages/nova/objects/instance.py:1111
2021-08-23 18:36:25.937 7 DEBUG nova.compute.manager [req-46572de8-769e-427d-b9c4-376a0e5c511a 35dd74911b384d3cb58dbec2e1afbdcd c4076a45bcac411bacf20eb4fecb50e0 - default default] [instance: 18e4e517-7556-40be-8833-35290127c2e7] Received event network-changed-c4615cdf-7ae0-4566-9402-c08b9544f04a external_instance_event /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:8683
2021-08-23 18:36:25.938 7 DEBUG nova.compute.manager [req-46572de8-769e-427d-b9c4-376a0e5c511a 35dd74911b384d3cb58dbec2e1afbdcd c4076a45bcac411bacf20eb4fecb50e0 - default default] [instance: 18e4e517-7556-40be-8833-35290127c2e7] Refreshing instance network info cache due to event network-changed-c4615cdf-7ae0-4566-9402-c08b9544f04a. external_instance_event /var/lib/kolla/venv/lib/python2.7/site-packages/nova/compute/manager.py:8687
2021-08-23 18:36:25.939 7 DEBUG oslo_concurrency.lockutils [req-46572de8-769e-427d-b9c4-376a0e5c511a 35dd74911b384d3cb58dbec2e1afbdcd c4076a45bcac411bacf20eb4fecb50e0 - default default] Acquired lock "refresh_cache-18e4e517-7556-40be-8833-35290127c2e7" lock /var/lib/kolla/venv/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:265
2021-08-23 18:36:25.940 7 DEBUG nova.network.neutronv2.api [req-46572de8-769e-427d-b9c4-376a0e5c511a 35dd74911b384d3cb58dbec2e1afbdcd c4076a45bcac411bacf20eb4fecb50e0 - default default] [instance: 18e4e517-7556-40be-8833-35290127c2e7] _get_instance_nw_info() _get_instance_nw_info /var/lib/kolla/venv/lib/python2.7/site-packages/nova/network/neutronv2/api.py:1846
===========
As far as I see this is a duplicate of https:/