yahoo-eng-team team mailing list archive

[Charles Volzka <cjvolzka@xxxxxxxxxx>]

Public bug reported:

We ran into an issue using a March ocata build. We have some
system_metadata that we need to save very early in a VM's life.
Previously we did this during scheduling. After the switch to cells v2,
we now listen for the compute.instance.create.start and add the key to
the instance's system_metadata then. The problem is that because of how
nova.objects.Instance.save() works when saving metadata there is a race
condition that causes some of the system_metadata to be lost.


Basic setup of the instance.save() problem:
test_uuid = <uuid>
inst_ref_1 = nova.objects.Instance.get_by_uuid(context, test_uuid)
inst_ref_2 = nova.objects.Instance.get_by_uuid(context, test_uuid)

inst_ref_1.system_metadata.update({'key1': 'val1'})
inst_ref_2.system_metadata.update({'key2': 'val2'})
(Note: You need to read or update inst_ref_2.system_metadata at least once before calling inst_ref_1.save() the first time otherwise the lazy load on inst_ref_2.system_metadata will pick up inst_ref_1's change and hide the issue.)
inst_ref_1.save()
(Note: can check db before the next save to confirm the first save worked)
inst_ref_2.save()

Afterward, nova.objects.Instance.get_by_uuid(context, test_uuid).system_metadata returns {'key2': 'val2'} instead of the desired {'key1': 'val1', 'key2': 'val2'}
Watching the db also reflects that the key1 was present after inst_ref_1.save() but was then removed and replaced with key2 after inst_ref_2.save().

The issue is the flow of Instance.save(). It eventually calls nova.db.sqlalchemy.api._instance_metadata_update_in_place(). That method assumes if a key is found in the db but is not in the passed metadata dict, that it should delete the key from the db.
So in the example above, because the inst_ref_2.system_metadata dictionary does not have the key added by inst_ref_1.save(), the inst_ref2.save() is deleting the entry added by inst_ref_1.save().


Issue this creates:
nova.compute.manager._build_and_run_instance() starts by sending the compute.instance.create.start notification. Immediately after that a recent unrelated change (https://github.com/openstack/nova/commit/6d8b58dc6f1cbda8d664b3487674f87049491c74) calls instance.system_metadata.update({'boot_roles': ','.join(context.roles)}). The first instance.save() in _build_and_run_instance() is called as a side effect of 'with rt.instance_claim(context, instance, node, limits)'. (FWIW it's also called again very shortly after that in _build_and_run_instance() itself when vm_state and task_state are set).

This creates the race condition mentioned at the top. Our listener gets
the compute.instance.create.start notification is also attempting to
update the instance's system_metadata. The listener has to create it's
own reference to the same instance so depending on which instance
reference's save() is called first (the one in our listener or the one
from _build_and_run_instance()) one of the updates to system_metadata
gets lost.

Expected result:
Independent Instance.save() calls containing don't wipe out non-conflicting key changes.

Actual result:
They do.

** 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/1674003

Title:
  Race condition cause instance system_updates to be lost

Status in OpenStack Compute (nova):
  New

Bug description:
  We ran into an issue using a March ocata build. We have some
  system_metadata that we need to save very early in a VM's life.
  Previously we did this during scheduling. After the switch to cells
  v2, we now listen for the compute.instance.create.start and add the
  key to the instance's system_metadata then. The problem is that
  because of how nova.objects.Instance.save() works when saving metadata
  there is a race condition that causes some of the system_metadata to
  be lost.

  
  Basic setup of the instance.save() problem:
  test_uuid = <uuid>
  inst_ref_1 = nova.objects.Instance.get_by_uuid(context, test_uuid)
  inst_ref_2 = nova.objects.Instance.get_by_uuid(context, test_uuid)

  inst_ref_1.system_metadata.update({'key1': 'val1'})
  inst_ref_2.system_metadata.update({'key2': 'val2'})
  (Note: You need to read or update inst_ref_2.system_metadata at least once before calling inst_ref_1.save() the first time otherwise the lazy load on inst_ref_2.system_metadata will pick up inst_ref_1's change and hide the issue.)
  inst_ref_1.save()
  (Note: can check db before the next save to confirm the first save worked)
  inst_ref_2.save()

  Afterward, nova.objects.Instance.get_by_uuid(context, test_uuid).system_metadata returns {'key2': 'val2'} instead of the desired {'key1': 'val1', 'key2': 'val2'}
  Watching the db also reflects that the key1 was present after inst_ref_1.save() but was then removed and replaced with key2 after inst_ref_2.save().

  The issue is the flow of Instance.save(). It eventually calls nova.db.sqlalchemy.api._instance_metadata_update_in_place(). That method assumes if a key is found in the db but is not in the passed metadata dict, that it should delete the key from the db.
  So in the example above, because the inst_ref_2.system_metadata dictionary does not have the key added by inst_ref_1.save(), the inst_ref2.save() is deleting the entry added by inst_ref_1.save().

  
  Issue this creates:
  nova.compute.manager._build_and_run_instance() starts by sending the compute.instance.create.start notification. Immediately after that a recent unrelated change (https://github.com/openstack/nova/commit/6d8b58dc6f1cbda8d664b3487674f87049491c74) calls instance.system_metadata.update({'boot_roles': ','.join(context.roles)}). The first instance.save() in _build_and_run_instance() is called as a side effect of 'with rt.instance_claim(context, instance, node, limits)'. (FWIW it's also called again very shortly after that in _build_and_run_instance() itself when vm_state and task_state are set).

  This creates the race condition mentioned at the top. Our listener
  gets the compute.instance.create.start notification is also attempting
  to update the instance's system_metadata. The listener has to create
  it's own reference to the same instance so depending on which instance
  reference's save() is called first (the one in our listener or the one
  from _build_and_run_instance()) one of the updates to system_metadata
  gets lost.

  Expected result:
  Independent Instance.save() calls containing don't wipe out non-conflicting key changes.

  Actual result:
  They do.

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