reschedule fails with ip already allocated error

[Matthew Edmonds]

Tried to create a server in a multi-host environment. The create failed on the first host that was attempted due to a ClientException raised by nova.volume.cinder.API.initialize_connection while trying to attach a volume. When the build was rescheduled on a different host, it should have realized that the network was already allocated by the first attempt and reused that, but the network_allocated=True from instance.system_metadata somehow disappeared, leading to the following exception that causes the reschedule to fail:

2016-10-13 04:48:29.007 16273 WARNING nova.network.neutronv2.api [req-9b343ef7-e8d9-4a61-b86c-a61908afe4df 0688b01e6439ca32d698d20789d52169126fb41fb1a4ddafcebb97d854e836c9 94e1baed634145e0aade858973ae88e8 - - -] [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] Neutron error creating port on network 5038a36b-cb1e-4a61-b26c-a05a80b37ed6
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] Traceback (most recent call last):
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 392, in _create_port_minimal
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] port_response = port_client.create_port(port_req_body)
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 98, in wrapper
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] ret = obj(*args, **kwargs)
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 750, in create_port
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] return self.post(self.ports_path, body=body)
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 98, in wrapper
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] ret = obj(*args, **kwargs)
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 365, in post
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] headers=headers, params=params)
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 98, in wrapper
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] ret = obj(*args, **kwargs)
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 300, in do_request
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] self._handle_fault_response(status_code, replybody, resp)
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 98, in wrapper
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] ret = obj(*args, **kwargs)
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 275, in _handle_fault_response
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] exception_handler_v20(status_code, error_body)
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 91, in exception_handler_v20
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] request_ids=request_ids)
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] Conflict: IP address 9.114.25.215 already allocated in subnet e2d1b84e-2308-48ab-9101-0d48721c9fd2
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b] Neutron server returns request_ids: ['req-682b2d6b-768f-413d-862c-32490cad5589']
2016-10-13 04:48:29.007 16273 ERROR nova.network.neutronv2.api [instance: b85d6c6c-e385-4601-aa47-5c580f893c9b]

found in newton

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/393805

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/393805
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=9345ed40e85e291d2f9e9aac24d468f40140ae0e
Submitter: Jenkins
Branch: master

commit 9345ed40e85e291d2f9e9aac24d468f40140ae0e
Author: Brent Tang <email address hidden>
Date: Fri Nov 4 07:35:25 2016 -0700

    Instance obj_clone leaves metadata as changed

    When performing an obj_clone on an Instance object, it relies on the
    base obj_clone's deep copy method which just goes through all of the
    fields and duplicates them on the clone. However, the Instance object
    has internal tracking attributes for metadata and system_metadata that
    keep track of which keys have changed. Since these don't get copied
    over on the deep copy, these will show up as having changed on the
    cloned Instance (if they had metadata set originally) and on a save
    on this cloned object will end up updating the metadata in the db
    which if these have stale information will wipe out other changes.

    Such a scenario to this is occurring during build_instance where the
    Claim constructor is saving off a clone of the Instance object
    so that it will have the current copy. In the case of a failure
    during the build_instance, the claim will use this current copy
    to then set the value of the host on the instance to None. Since
    the clone reflects that the system_metadata has changed, it will
    as part of the save try to update the system_metadata in the db,
    which since it is stale will wipe out changes made.

    In the case of the issue being fixed here, the value in the
    system_metdata being wiped out is the network_allocated=True
    attribute. By this being wiped out then reschedules of that
    build_instance fail in cases where the IP address has been
    assigned to the instance.

    Change-Id: Ie49a90993fb9643c04d75402dbaaa933c6b5222e
    Closes-Bug: #1639230

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/newton
Review: https://review.openstack.org/396782

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/396782
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=bc620681ff2d7aa6c40c961da76d598c9f23281d
Submitter: Jenkins
Branch: stable/newton

commit bc620681ff2d7aa6c40c961da76d598c9f23281d
Author: Brent Tang <email address hidden>
Date: Fri Nov 4 07:35:25 2016 -0700

    Instance obj_clone leaves metadata as changed

    When performing an obj_clone on an Instance object, it relies on the
    base obj_clone's deep copy method which just goes through all of the
    fields and duplicates them on the clone. However, the Instance object
    has internal tracking attributes for metadata and system_metadata that
    keep track of which keys have changed. Since these don't get copied
    over on the deep copy, these will show up as having changed on the
    cloned Instance (if they had metadata set originally) and on a save
    on this cloned object will end up updating the metadata in the db
    which if these have stale information will wipe out other changes.

    Such a scenario to this is occurring during build_instance where the
    Claim constructor is saving off a clone of the Instance object
    so that it will have the current copy. In the case of a failure
    during the build_instance, the claim will use this current copy
    to then set the value of the host on the instance to None. Since
    the clone reflects that the system_metadata has changed, it will
    as part of the save try to update the system_metadata in the db,
    which since it is stale will wipe out changes made.

    In the case of the issue being fixed here, the value in the
    system_metdata being wiped out is the network_allocated=True
    attribute. By this being wiped out then reschedules of that
    build_instance fail in cases where the IP address has been
    assigned to the instance.

    Change-Id: Ie49a90993fb9643c04d75402dbaaa933c6b5222e
    Closes-Bug: #1639230
    (cherry picked from commit 9345ed40e85e291d2f9e9aac24d468f40140ae0e)

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 15.0.0.0b1 development milestone.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 14.0.3 release.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.