yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1368344] Re: Failure in test_server_actions

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Vish Ishaya <vishvananda@xxxxxxxxx>
Date: Thu, 11 Sep 2014 17:14:10 -0000
Reply-to: Bug 1368344 <1368344@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
*** This bug is a duplicate of bug 1334142 ***
    https://bugs.launchpad.net/bugs/1334142

so the fix for https://bugs.launchpad.net/bugs/1334142 is correct, it
just needs to be backported to stable/icehouse

** This bug has been marked a duplicate of bug 1334142
   A server creation fails due to adding interface failure

-- 
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/1368344

Title:
  Failure in test_server_actions

Status in OpenStack Compute (Nova):
  New

Bug description:
  2014-09-09 23:07:28.235 | tempest.api.compute.servers.test_server_actions.ServerActionsTestJSON.test_resize_server_confirm_from_stopped[gate,smoke]
  2014-09-09 23:07:28.235 | -------------------------------------------------------------------------------------------------------------------------
  2014-09-09 23:07:28.235 | 
  2014-09-09 23:07:28.235 | Captured traceback:
  2014-09-09 23:07:28.235 | ~~~~~~~~~~~~~~~~~~~
  2014-09-09 23:07:28.235 |     Traceback (most recent call last):
  2014-09-09 23:07:28.235 |       File "tempest/api/compute/servers/test_server_actions.py", line 237, in test_resize_server_confirm_from_stopped
  2014-09-09 23:07:28.236 |         self._test_resize_server_confirm(stop=True)
  2014-09-09 23:07:28.236 |       File "tempest/api/compute/servers/test_server_actions.py", line 214, in _test_resize_server_confirm
  2014-09-09 23:07:28.236 |         self.client.wait_for_server_status(self.server_id, 'VERIFY_RESIZE')
  2014-09-09 23:07:28.236 |       File "tempest/services/compute/json/servers_client.py", line 182, in wait_for_server_status
  2014-09-09 23:07:28.236 |         raise_on_error=raise_on_error)
  2014-09-09 23:07:28.236 |       File "tempest/common/waiters.py", line 77, in wait_for_server_status
  2014-09-09 23:07:28.236 |         server_id=server_id)
  2014-09-09 23:07:28.236 |     BuildErrorException: Server fca40e7e-7092-42ba-abdf-bd32835ed2bc failed to build and is in ERROR status
  2014-09-09 23:07:28.236 |     Details: {u'message': u'Failed to add interface: Dump was interrupted and may be inconsistent.\n', u'code': 500, u'created': u'2014-09-09T23:01:51Z'}
  2014-09-09 23:07:28.236 |     Traceback (most recent call last):
  2014-09-09 23:07:28.236 |     _StringException: Empty attachments:
  2014-09-09 23:07:28.236 |       stderr
  2014-09-09 23:07:28.236 |       stdout
  2014-09-09 23:07:28.236 |     
  2014-09-09 23:07:28.236 |     pythonlogging:'': {{{
  2014-09-09 23:07:28.236 |     2014-09-09 23:01:47,808 5470 INFO     [tempest.common.rest_client] Request (ServerActionsTestJSON:setUp): 200 GET http://127.0.0.1:8774/v2/d311a7f7b54c4f7cab4fc2cf86135e74/servers/fca40e7e-7092-42ba-abdf-bd32835ed2bc 0.057s
  2014-09-09 23:07:28.236 |     2014-09-09 23:01:47,873 5470 INFO     [tempest.common.rest_client] Request (ServerActionsTestJSON:test_resize_server_confirm_from_stopped): 200 GET http://127.0.0.1:8774/v2/d311a7f7b54c4f7cab4fc2cf86135e74/servers/fca40e7e-7092-42ba-abdf-bd32835ed2bc 0.049s
  2014-09-09 23:07:28.236 |     2014-09-09 23:01:48,053 5470 INFO     [tempest.common.rest_client] Request (ServerActionsTestJSON:test_resize_server_confirm_from_stopped): 202 POST http://127.0.0.1:8774/v2/d311a7f7b54c4f7cab4fc2cf86135e74/servers/fca40e7e-7092-42ba-abdf-bd32835ed2bc/action 0.168s
  2014-09-09 23:07:28.236 |     2014-09-09 23:01:48,117 5470 INFO     [tempest.common.rest_client] Request (ServerActionsTestJSON:test_resize_server_confirm_from_stopped): 200 GET http://127.0.0.1:8774/v2/d311a7f7b54c4f7cab4fc2cf86135e74/servers/fca40e7e-7092-42ba-abdf-bd32835ed2bc 0.062s
  2014-09-09 23:07:28.236 |     2014-09-09 23:01:49,227 5470 INFO     [tempest.common.rest_client] Request (ServerActionsTestJSON:test_resize_server_confirm_from_stopped): 200 GET http://127.0.0.1:8774/v2/d311a7f7b54c4f7cab4fc2cf86135e74/servers/fca40e7e-7092-42ba-abdf-bd32835ed2bc 0.095s
  2014-09-09 23:07:28.236 |     2014-09-09 23:01:49,239 5470 INFO     [tempest.common.waiters] State transition "ACTIVE/powering-off" ==> "SHUTOFF/None" after 1 second wait
  2014-09-09 23:07:28.236 |     2014-09-09 23:01:49,542 5470 INFO     [tempest.common.rest_client] Request (ServerActionsTestJSON:test_resize_server_confirm_from_stopped): 202 POST http://127.0.0.1:8774/v2/d311a7f7b54c4f7cab4fc2cf86135e74/servers/fca40e7e-7092-42ba-abdf-bd32835ed2bc/action 0.302s
  2014-09-09 23:07:28.236 |     2014-09-09 23:01:49,594 5470 INFO     [tempest.common.rest_client] Request (ServerActionsTestJSON:test_resize_server_confirm_from_stopped): 200 GET http://127.0.0.1:8774/v2/d311a7f7b54c4f7cab4fc2cf86135e74/servers/fca40e7e-7092-42ba-abdf-bd32835ed2bc 0.051s
  2014-09-09 23:07:28.236 |     2014-09-09 23:01:50,663 5470 INFO     [tempest.common.rest_client] Request (ServerActionsTestJSON:test_resize_server_confirm_from_stopped): 200 GET http://127.0.0.1:8774/v2/d311a7f7b54c4f7cab4fc2cf86135e74/servers/fca40e7e-7092-42ba-abdf-bd32835ed2bc 0.056s
  2014-09-09 23:07:28.236 |     2014-09-09 23:01:50,718 5470 INFO     [tempest.common.waiters] State transition "RESIZE/resize_prep" ==> "RESIZE/resize_migrating" after 1 second wait
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:51,845 5470 INFO     [tempest.common.rest_client] Request (ServerActionsTestJSON:test_resize_server_confirm_from_stopped): 200 GET http://127.0.0.1:8774/v2/d311a7f7b54c4f7cab4fc2cf86135e74/servers/fca40e7e-7092-42ba-abdf-bd32835ed2bc 0.124s
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:51,857 5470 INFO     [tempest.common.waiters] State transition "RESIZE/resize_migrating" ==> "ERROR/None" after 2 second wait
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:52,022 5470 INFO     [tempest.common.rest_client] Request (ServerActionsTestJSON:tearDown): 200 GET http://127.0.0.1:8774/v2/d311a7f7b54c4f7cab4fc2cf86135e74/servers/fca40e7e-7092-42ba-abdf-bd32835ed2bc 0.163s
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:52,163 5470 INFO     [tempest.common.rest_client] Request (ServerActionsTestJSON:tearDown): 200 GET http://127.0.0.1:8774/v2/d311a7f7b54c4f7cab4fc2cf86135e74/servers/fca40e7e-7092-42ba-abdf-bd32835ed2bc 0.128s
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:53,266 5470 INFO     [tempest.common.rest_client] Request (ServerActionsTestJSON:tearDown): 200 GET http://127.0.0.1:8774/v2/d311a7f7b54c4f7cab4fc2cf86135e74/servers/fca40e7e-7092-42ba-abdf-bd32835ed2bc 0.089s
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:53,279 5470 ERROR    [tempest.api.compute.base] Server fca40e7e-7092-42ba-abdf-bd32835ed2bc failed to build and is in ERROR status
  2014-09-09 23:07:28.237 |     Details: {u'message': u'Failed to add interface: Dump was interrupted and may be inconsistent.\n', u'code': 500, u'created': u'2014-09-09T23:01:51Z'}
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:53.279 5470 TRACE tempest.api.compute.base Traceback (most recent call last):
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:53.279 5470 TRACE tempest.api.compute.base   File "tempest/api/compute/base.py", line 168, in server_check_teardown
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:53.279 5470 TRACE tempest.api.compute.base     'ACTIVE')
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:53.279 5470 TRACE tempest.api.compute.base   File "tempest/services/compute/json/servers_client.py", line 182, in wait_for_server_status
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:53.279 5470 TRACE tempest.api.compute.base     raise_on_error=raise_on_error)
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:53.279 5470 TRACE tempest.api.compute.base   File "tempest/common/waiters.py", line 77, in wait_for_server_status
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:53.279 5470 TRACE tempest.api.compute.base     server_id=server_id)
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:53.279 5470 TRACE tempest.api.compute.base BuildErrorException: Server fca40e7e-7092-42ba-abdf-bd32835ed2bc failed to build and is in ERROR status
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:53.279 5470 TRACE tempest.api.compute.base Details: {u'message': u'Failed to add interface: Dump was interrupted and may be inconsistent.\n', u'code': 500, u'created': u'2014-09-09T23:01:51Z'}
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:53.279 5470 TRACE tempest.api.compute.base 
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:53,568 5470 INFO     [tempest.common.rest_client] Request (ServerActionsTestJSON:tearDown): 204 DELETE http://127.0.0.1:8774/v2/d311a7f7b54c4f7cab4fc2cf86135e74/servers/fca40e7e-7092-42ba-abdf-bd32835ed2bc 0.288s
  2014-09-09 23:07:28.237 |     2014-09-09 23:01:53,731 5470 INFO     [tempest.common.rest_client] Request (ServerActionsTestJSON:tearDown): 200 GET http://127.0.0.1:8774/v2/d311a7f7b54c4f7cab4fc2cf86135e74/servers/fca40e7e-7092-42ba-abdf-bd32835ed2bc 0.162s
  2014-09-09 23:07:28.237 |     }}}
  2014-09-09 23:07:28.237 |     
  2014-09-09 23:07:28.237 |     traceback-1: {{{
  2014-09-09 23:07:28.237 |     Traceback (most recent call last):
  2014-09-09 23:07:28.238 |       File "tempest/api/compute/servers/test_server_actions.py", line 51, in tearDown
  2014-09-09 23:07:28.238 |         self.server_check_teardown()
  2014-09-09 23:07:28.238 |       File "tempest/api/compute/base.py", line 172, in server_check_teardown
  2014-09-09 23:07:28.238 |         cls.servers_client.wait_for_server_termination(cls.server_id)
  2014-09-09 23:07:28.238 |       File "tempest/services/compute/json/servers_client.py", line 195, in wait_for_server_termination
  2014-09-09 23:07:28.238 |         raise exceptions.BuildErrorException(server_id=server_id)
  2014-09-09 23:07:28.238 |     BuildErrorException: Server fca40e7e-7092-42ba-abdf-bd32835ed2bc failed to build and is in ERROR status
  2014-09-09 23:07:28.238 |     }}}
  2014-09-09 23:07:28.238 |     
  2014-09-09 23:07:28.238 |     Traceback (most recent call last):
  2014-09-09 23:07:28.238 |       File "tempest/api/compute/servers/test_server_actions.py", line 237, in test_resize_server_confirm_from_stopped
  2014-09-09 23:07:28.238 |         self._test_resize_server_confirm(stop=True)
  2014-09-09 23:07:28.238 |       File "tempest/api/compute/servers/test_server_actions.py", line 214, in _test_resize_server_confirm
  2014-09-09 23:07:28.238 |         self.client.wait_for_server_status(self.server_id, 'VERIFY_RESIZE')
  2014-09-09 23:07:28.238 |       File "tempest/services/compute/json/servers_client.py", line 182, in wait_for_server_status
  2014-09-09 23:07:28.238 |         raise_on_error=raise_on_error)
  2014-09-09 23:07:28.238 |       File "tempest/common/waiters.py", line 77, in wait_for_server_status
  2014-09-09 23:07:28.238 |         server_id=server_id)
  2014-09-09 23:07:28.238 |     BuildErrorException: Server fca40e7e-7092-42ba-abdf-bd32835ed2bc failed to build and is in ERROR status
  2014-09-09 23:07:28.238 |     Details: {u'message': u'Failed to add interface: Dump was interrupted and may be inconsistent.\n', u'code': 500, u'created': u'2014-09-09T23:01:51Z'}

  2014-09-09 23:01:51.434 2124 ERROR oslo.messaging.rpc.dispatcher [-] Exception during message handling: Failed to add interface: Dump was interrupted and may be inconsistent.
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher     incoming.message))
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/old/nova/nova/network/manager.py", line 1314, in setup_networks_on_host
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher     call_func(context, network)
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/old/nova/nova/network/manager.py", line 1660, in _setup_network_on_host
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher     self.l3driver.initialize_gateway(network)
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/old/nova/nova/network/l3.py", line 104, in initialize_gateway
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher     gateway=(network_ref['gateway'] is not None))
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/old/nova/nova/network/linux_net.py", line 1384, in plug
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher     return _get_interface_driver().plug(network, mac_address, gateway)
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/old/nova/nova/network/linux_net.py", line 1432, in plug
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher     network, gateway)
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/old/nova/nova/openstack/common/lockutils.py", line 249, in inner
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher     return f(*args, **kwargs)
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/old/nova/nova/network/linux_net.py", line 1575, in ensure_bridge
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher     raise exception.NovaException(msg)
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher NovaException: Failed to add interface: Dump was interrupted and may be inconsistent.
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher 
  2014-09-09 23:01:51.434 2124 TRACE oslo.messaging.rpc.dispatcher 

  The fix for bug #1334142 didn't actually catch the exception, it just
  raises a proper error message. We need some logic to either ignore the
  new kernel exception or to retry.

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

[Bug 1368344] [NEW] Failure in test_server_actions
From: Vish Ishaya, 2014-09-11