Confusing error message in BadRequest during floating ip assignment

[Inessa Vasilevskaya]

Seen on mos 10, 1 controller/1 compute.

Not very difficult to trigger, though isn't reproduced on every run (got 3 hits in ~15 runs).

The error was seen while running this script (sorry about my bash http://paste.openstack.org/show/545694/) on freshly deployed mos.

Steps to reproduce:
1). create floating id with nova floating-ip-create
2). boot a VM
3). right afterwards (not waiting for the VM to reach active state) assign a floating ip via nova floating-ip-associate

In ~20% of runs the following error was received:
ERROR (BadRequest): No nw_info cache associated with instance (HTTP 400) (Request-ID: req-907e70c0-b6f7-4368-ae66-c02dd216000d)

The VM didn't get floating ip during unsuccessful runs.

Expected result: nova would wait for the VM to become active before trying to assign a floating ip.

[Markus Zoeller (markus_z) (mzoeller)]

@Inessa:
What was your expectation when you executed these steps?
1) That the API waits for the instance to become ACTIVE and then assign the floating IP?
2) An API Bad Request with a more helpful information?
3) ?

FWIW, the error you see gets raised at https://github.com/openstack/nova/blob/5044db5fce2e952243cd5961cc1a107658c32a10/nova/api/openstack/compute/floating_ips.py#L225-L230

I'm not yet sure this is a bug. Please switch the status back to "New" after you provided your expected outcome in this situation.

[Inessa Vasilevskaya (ivasilevskaya)]

@Markus, sorry for not providing all the information.

I expected for the api to wait for ACTIVE state.

[Markus Zoeller (markus_z) (mzoeller)]

I'm clarifying this with the API experts, but I still think that the API doesn't wait for other calls to finish but uses the "current state" the deployment is in to decide if the call is valid or not.

[Alex Xu (xuhj)]

The API behavior is right at here. The only confuse thing is the error message. "nw_info cache" is something used inside nova, user can't understand what is it.

[Markus Zoeller (markus_z) (mzoeller)]

@Inessa: ^ Alex is one of the API experts. Let's use this bug report to make the error message more clear [1]. Should be something more easy to understand, like:
    "The instance doesn't yet have access to the network. This
    only happens if the instance is in ACTIVE state"

Just a proposal for the text.

[1] https://github.com/openstack/nova/blob/5044db5fce2e952243cd5961cc1a107658c32a10/nova/api/openstack/compute/floating_ips.py#L225-L230

[Augustina Ragwitz (auggy)]

Hi Inessa, this typically happens because you are trying to assign a floating ip before the network info for the instance is fully available. The instance itself is active and working fine. You might try putting small delay between creating the instance and assigning it the floating ip to see if that helps.

[Augustina Ragwitz (auggy)]

There appears to be some history behind this issue. I have submitted a patch to fix the error message but I am also double checking that this is not a variation of the original issue from before.

[Augustina Ragwitz (auggy)]

https://review.openstack.org/#/c/353687/

[Inessa Vasilevskaya (ivasilevskaya)]

@Marcus and others, sorry for long reply.

I wasn't aware of the --poll option to nova boot command which does precisely what I wanted - waits for the image to become active.
So making the error message is a perfect solution imo, Augustina's approach looks informative enough.

[Inessa Vasilevskaya (ivasilevskaya)]

"the image to become active" reads as "the network to become ready"

[OpenStack Infra (hudson-openstack)]

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

commit cdb9a8435b1f8d75818ecaff2beb630b8f7160af
Author: Augustina Ragwitz <email address hidden>
Date: Wed Aug 10 11:45:15 2016 -0700

    Improve error message for empty cached_nwinfo

    The error currently returned when NetworkInfo isn't yet available for an
    active instance is confusing for end users. This change updates that
    error message to something more informative.

    Change-Id: Ia1a88a63d2b1a2e595404e502f8094127135d7b0
    Closes-bug: #1608726

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 14.0.0.0b3 development milestone.