A server creation fails due to adding interface failure

Bug #1334142 reported by Ken'ichi Ohmichi
30
This bug affects 4 people
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Fix Released
High
Ken'ichi Ohmichi
Icehouse
Fix Released
High
Vish Ishaya

Bug Description

http://logs.openstack.org/72/61972/27/gate/gate-tempest-dsvm-full/ed1ab55/logs/testr_results.html.gz

pythonlogging:'': {{{
2014-06-25 06:45:11,596 25675 INFO [tempest.common.rest_client] Request (DeleteServersTestXML:test_delete_server_while_in_verify_resize_state): 202 POST http://127.0.0.1:8774/v2/aedc849c2c1742b8b1077c85d609b127/servers 0.295s
2014-06-25 06:45:11,674 25675 INFO [tempest.common.rest_client] Request (DeleteServersTestXML:test_delete_server_while_in_verify_resize_state): 200 GET http://127.0.0.1:8774/v2/aedc849c2c1742b8b1077c85d609b127/servers/f9fb672b-f2e6-4303-b7d1-2c5aa324170f 0.077s
2014-06-25 06:45:12,977 25675 INFO [tempest.common.rest_client] Request (DeleteServersTestXML:test_delete_server_while_in_verify_resize_state): 200 GET http://127.0.0.1:8774/v2/aedc849c2c1742b8b1077c85d609b127/servers/f9fb672b-f2e6-4303-b7d1-2c5aa324170f 0.300s
2014-06-25 06:45:12,978 25675 INFO [tempest.common.waiters] State transition "BUILD/scheduling" ==> "BUILD/spawning" after 1 second wait
2014-06-25 06:45:14,150 25675 INFO [tempest.common.rest_client] Request (DeleteServersTestXML:test_delete_server_while_in_verify_resize_state): 200 GET http://127.0.0.1:8774/v2/aedc849c2c1742b8b1077c85d609b127/servers/f9fb672b-f2e6-4303-b7d1-2c5aa324170f 0.171s
2014-06-25 06:45:14,153 25675 INFO [tempest.common.waiters] State transition "BUILD/spawning" ==> "ERROR/None" after 3 second wait
2014-06-25 06:45:14,221 25675 INFO [tempest.common.rest_client] Request (DeleteServersTestXML:test_delete_server_while_in_verify_resize_state): 400 POST http://127.0.0.1:8774/v2/aedc849c2c1742b8b1077c85d609b127/servers/f9fb672b-f2e6-4303-b7d1-2c5aa324170f/action 0.066s
2014-06-25 06:45:14,404 25675 INFO [tempest.common.rest_client] Request (DeleteServersTestXML:test_delete_server_while_in_verify_resize_state): 204 DELETE http://127.0.0.1:8774/v2/aedc849c2c1742b8b1077c85d609b127/servers/f9fb672b-f2e6-4303-b7d1-2c5aa324170f 0.182s
}}}

Traceback (most recent call last):
  File "tempest/api/compute/servers/test_delete_server.py", line 97, in test_delete_server_while_in_verify_resize_state
    resp, server = self.create_test_server(wait_until='ACTIVE')
  File "tempest/api/compute/base.py", line 247, in create_test_server
    raise ex
BadRequest: Bad request
Details: {'message': 'The server could not comply with the request since it is either malformed or otherwise incorrect.', 'code': '400'}

Revision history for this message
Ken'ichi Ohmichi (oomichi) wrote :
Download full text (4.4 KiB)

nova-network failed with the following log:

2014-06-25 06:45:13.093 ERROR oslo.messaging.rpc.dispatcher [req-96792db6-1f4b-4582-a5a0-4b921af6f02d DeleteServersTestXML-119298985 DeleteServersTestXML-772603528] Exception during message handling: Failed
to add interface: Dump was interrupted and may be inconsistent.
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher incoming.message))
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher return self._do_dispatch(endpoint, method, ctxt, args)
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher result = getattr(endpoint, method)(ctxt, **new_args)
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/network/floating_ips.py", line 118, in allocate_for_instance
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher **kwargs)
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/network/manager.py", line 525, in allocate_for_instance
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher requested_networks=requested_networks)
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/network/manager.py", line 213, in _allocate_fixed_ips
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher vpn=vpn, address=address)
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/network/manager.py", line 945, in allocate_fixed_ip
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher exc_info=True)
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/network/manager.py", line 927, in allocate_fixed_ip
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher self._setup_network_on_host(context, network)
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/network/manager.py", line 1746, in _setup_network_on_host
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher self.l3driver.initialize_gateway(network)
2014-06-25 06:45:13.093 22817 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/network/l3.py", line 104, in i...

Read more...

summary: - A server creation fails due to ERROR state
+ A server creation fails due to adding interface failure
Changed in nova:
assignee: nobody → Ken'ichi Ohmichi (oomichi)
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (master)

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

Changed in nova:
status: New → In Progress
Sean Dague (sdague)
Changed in nova:
importance: Undecided → High
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (master)

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

commit c250696ba12ead71e741cf8f608ce5212b0cc7bb
Author: Ken'ichi Ohmichi <email address hidden>
Date: Wed Jun 25 18:15:39 2014 +0900

    Move the error check for "brctl addif"

    The git commit 873aad92944f8840e772d65eda4b3320d65a9ce7[1] has moved
    "brctl addif" command, but the commit did not move its error check.

    Now the error check sees the result of "ip addr show dev <interface>
    scope global" command wrongly, and the command outputs "Dump was
    interrupted and may be inconsistent" sometimes because of a kernel change.
    As the result, gate failures happen sometimes.

    This patch moves the error check to right place.

    [1]: https://github.com/openstack/nova/commit/873aad92944f8840e772d65eda4b3320d

    Change-Id: I92ee96e3aa34f7cd154a8ce4b33852b96cabe8c9
    Closes-Bug: #1334142

Changed in nova:
status: In Progress → Fix Committed
Changed in nova:
milestone: none → juno-2
status: Fix Committed → Fix Released
Revision history for this message
Vish Ishaya (vishvananda) wrote :

This error is still happening (now with a proper error message): https://bugs.launchpad.net/nova/+bug/1368344

Revision history for this message
Vish Ishaya (vishvananda) wrote :

So the error above is because this has not been backported yet.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (stable/icehouse)

Fix proposed to branch: stable/icehouse
Review: https://review.openstack.org/120843

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (stable/icehouse)

Reviewed: https://review.openstack.org/120843
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=311ab5777d02bd8a2277afd26cfbeae005b225cb
Submitter: Jenkins
Branch: stable/icehouse

commit 311ab5777d02bd8a2277afd26cfbeae005b225cb
Author: Ken'ichi Ohmichi <email address hidden>
Date: Wed Jun 25 18:15:39 2014 +0900

    Move the error check for "brctl addif"

    The git commit 873aad92944f8840e772d65eda4b3320d65a9ce7[1] has moved
    "brctl addif" command, but the commit did not move its error check.

    Now the error check sees the result of "ip addr show dev <interface>
    scope global" command wrongly, and the command outputs "Dump was
    interrupted and may be inconsistent" sometimes because of a kernel change.
    As the result, gate failures happen sometimes.

    This patch moves the error check to right place.

    [1]: https://github.com/openstack/nova/commit/873aad92944f8840e772d65eda4b3320d

    Change-Id: I92ee96e3aa34f7cd154a8ce4b33852b96cabe8c9
    Closes-Bug: #1334142
    (cherry picked from commit c250696ba12ead71e741cf8f608ce5212b0cc7bb)

tags: added: in-stable-icehouse
Thierry Carrez (ttx)
Changed in nova:
milestone: juno-2 → 2014.2
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.