← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 1277027] [NEW] test_admin_delete_servers_of_others failure due to unexpected task state

 

Public bug reported:

I couldn't find an existing bug for this, apologies if it's a dupe,
looks like a nova bug:


https://review.openstack.org/#/c/70717/
http://logs.openstack.org/17/70717/1/gate/gate-tempest-dsvm-full/9adaf90/console.html

2014-02-06 08:04:16.350 | 2014-02-06 07:48:25,729 Response Body: {"server": {"status": "ERROR", "os-access-ips:access_ip_v6": "", "updated": "2014-02-06T07:48:25Z", "os-access-ips:access_ip_v4": "", "addresses": {}, "links": [{"href": "http://127.0.0.1:8774/v3/servers/1cbd2e01-d2f3-45a0-baee-1d16df3dc7fd";, "rel": "self"}, {"href": "http://127.0.0.1:8774/servers/1cbd2e01-d2f3-45a0-baee-1d16df3dc7fd";, "rel": "bookmark"}], "os-extended-status:task_state": null, "key_name": null, "image": {"id": "7e649e07-3cea-4d95-90b2-2bbea7fce698", "links": [{"href": "http://23.253.79.233:9292/images/7e649e07-3cea-4d95-90b2-2bbea7fce698";, "rel": "bookmark"}]}, "os-pci:pci_devices": [], "os-extended-availability-zone:availability_zone": "nova", "os-extended-status:power_state": 0, "os-config-drive:config_drive": "", "host_id": "10f0dc42e72572ed6d30e8dc32b41edc1d41a3dacda6571c5aeabe6e", "flavor": {"id": "42", "links": [{"href": "http://127.0.0.1:8774/flavors/42";, "rel": "bookmark"}]}, "id": "1cbd2e01-d2f3-45a0-baee-1d16df3dc7fd", "security_groups": [{"name": "default"}], "user_id": "f2262ed0a64c43359867456cfbccc153", "name": "ServersAdminV3Test-instance-1705049062", "created": "2014-02-06T07:48:21Z", "tenant_id": "8e932e11471a469e85a30195b2198f63", "os-extended-status:vm_state": "error", "os-server-usage:launched_at": null, "os-extended-volumes:volumes_attached": [], "os-server-usage:terminated_at": null, "os-extended-status:locked_by": null, "fault": {"message": "No valid host was found. ", "code": 500, "created": "2014-02-06T07:48:25Z"}, "metadata": {}}}
2014-02-06 08:04:16.350 | }}}
2014-02-06 08:04:16.350 | 
2014-02-06 08:04:16.350 | Traceback (most recent call last):
2014-02-06 08:04:16.350 |   File "tempest/api/compute/v3/admin/test_servers.py", line 85, in test_admin_delete_servers_of_others
2014-02-06 08:04:16.350 |     self.servers_client.wait_for_server_termination(server['id'])
2014-02-06 08:04:16.351 |   File "tempest/services/compute/v3/json/servers_client.py", line 179, in wait_for_server_termination
2014-02-06 08:04:16.351 |     raise exceptions.BuildErrorException(server_id=server_id)
2014-02-06 08:04:16.351 | BuildErrorException: Server 1cbd2e01-d2f3-45a0-baee-1d16df3dc7fd failed to build and is in ERROR status
2014-02-06 08:04:16.351 | 
2014-02-06 08:04:16.351 | 
2014-02-06 08:04:16.351 | ======================================================================
2014-02-06 08:04:16.351 | FAIL: process-returncode
2014-02-06 08:04:16.351 | process-returncode
2014-02-06 08:04:16.351 | ----------------------------------------------------------------------
2014-02-06 08:04:16.352 | _StringException: Binary content:
2014-02-06 08:04:16.352 |   traceback (test/plain; charset="utf8")
2014-02-06 08:04:16.352 | 
2014-02-06 08:04:16.352 | 
2014-02-06 08:04:16.352 | ----------------------------------------------------------------------
2014-02-06 08:04:16.352 | Ran 2101 tests in 2350.793s
2014-02-06 08:04:16.353 | 
2014-02-06 08:04:16.353 | FAILED (failures=2, skipped=130)
2014-02-06 08:04:16.353 | ERROR: InvocationError: '/bin/bash tools/pretty_tox.sh (?!.*\\[.*\\bslow\\b.*\\])(^tempest\\.(api|scenario|thirdparty|cli)) --concurrency=2'
2014-02-06 08:04:16.354 | ___________________________________ summary ____________________________________
2014-02-06 08:04:16.354 | ERROR:   full: commands failed
2014-02-06 08:04:16.463 | Checking logs...
2014-02-06 08:04:16.562 | Log File: n-net
2014-02-06 08:04:16.562 | 2014-02-06 07:34:40.598 30086 ERROR oslo.messaging._executors.base [-] Exception during message handling
2014-02-06 08:04:16.562 | 
2014-02-06 08:04:16.563 | 2014-02-06 07:34:40.601 30086 ERROR oslo.messaging._drivers.common [-] Returning exception Instance fcfcbace-c4dd-4214-957f-b01e0b47fcf4 could not be found.
2014-02-06 08:04:16.563 | 
2014-02-06 08:04:16.563 | 2014-02-06 07:34:40.601 30086 ERROR oslo.messaging._drivers.common [-] ['Traceback (most recent call last):\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/_executors/base.py", line 36, in _dispatch\n    incoming.reply(self.callback(incoming.ctxt, incoming.message))\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 134, in __call__\n    return self._dispatch(endpoint, method, ctxt, args)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 104, in _dispatch\n    result = getattr(endpoint, method)(ctxt, **new_args)\n', '  File "/opt/stack/new/nova/nova/network/floating_ips.py", line 117, in allocate_for_instance\n    **kwargs)\n', '  File "/opt/stack/new/nova/nova/network/manager.py", line 521, in allocate_for_instance\n    host)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/server.py", line 153, in inner\n    return func(*args, **kwargs)\n', '  File "/opt/stack/new/nova/nova/network/manager.py", line 579, in get_instance_nw_info\n    instance_uuid, use_slave=use_slave)\n', '  File "/opt/stack/new/nova/nova/objects/base.py", line 110, in wrapper\n    args, kwargs)\n', '  File "/opt/stack/new/nova/nova/conductor/rpcapi.py", line 470, in object_class_action\n    objver=objver, args=args, kwargs=kwargs)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/client.py", line 150, in call\n    wait_for_reply=True, timeout=timeout)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/transport.py", line 87, in _send\n    timeout=timeout)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/_drivers/amqpdriver.py", line 390, in send\n    return self._send(target, ctxt, message, wait_for_reply, timeout)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/_drivers/amqpdriver.py", line 383, in _send\n    raise result\n', 'InstanceNotFound_Remote: Instance fcfcbace-c4dd-4214-957f-b01e0b47fcf4 could not be found.\nTraceback (most recent call last):\n\n  File "/opt/stack/new/nova/nova/conductor/manager.py", line 572, in _object_dispatch\n    return getattr(target, method)(context, *args, **kwargs)\n\n  File "/opt/stack/new/nova/nova/objects/base.py", line 112, in wrapper\n    result = fn(cls, context, *args, **kwargs)\n\n  File "/opt/stack/new/nova/nova/objects/virtual_interface.py", line 98, in get_by_instance_uuid\n    use_slave=use_slave)\n\n  File "/opt/stack/new/nova/nova/db/api.py", line 594, in virtual_interface_get_by_instance\n    use_slave=use_slave)\n\n  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 128, in wrapper\n    return f(*args, **kwargs)\n\n  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 140, in wrapper\n    instance_get_by_uuid(context, instance_uuid)\n\n  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 128, in wrapper\n    return f(*args, **kwargs)\n\n  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 1701, in instance_get_by_uuid\n    columns_to_join=columns_to_join, use_slave=use_slave)\n\n  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 1713, in _instance_get_by_uuid\n    raise exception.InstanceNotFound(instance_id=uuid)\n\nInstanceNotFound: Instance fcfcbace-c4dd-4214-957f-b01e0b47fcf4 could not be found.\n\n']
2014-02-06 08:04:16.564 | 
2014-02-06 08:04:16.957 | Log File: n-cond
2014-02-06 08:04:16.957 | 2014-02-06 07:35:54.076 30662 ERROR oslo.messaging._executors.base [-] Exception during message handling
2014-02-06 08:04:16.957 | 
2014-02-06 08:04:16.958 | 2014-02-06 07:35:54.077 30662 ERROR oslo.messaging._drivers.common [-] Returning exception Unexpected task state: expecting [u'scheduling', None] but the actual state is deleting to caller
2014-02-06 08:04:16.958 | 
2014-02-06 08:04:16.958 | 2014-02-06 07:35:54.077 30662 ERROR oslo.messaging._drivers.common [-] ['Traceback (most recent call last):\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/_executors/base.py", line 36, in _dispatch\n    incoming.reply(self.callback(incoming.ctxt, incoming.message))\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 134, in __call__\n    return self._dispatch(endpoint, method, ctxt, args)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 104, in _dispatch\n    result = getattr(endpoint, method)(ctxt, **new_args)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/server.py", line 153, in inner\n    return func(*args, **kwargs)\n', '  File "/opt/stack/new/nova/nova/conductor/manager.py", line 129, in instance_update\n    context, instance_uuid, updates)\n', '  File "/opt/stack/new/nova/nova/db/api.py", line 740, in instance_update_and_get_original\n    columns_to_join=columns_to_join)\n', '  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 128, in wrapper\n    return f(*args, **kwargs)\n', '  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 2215, in instance_update_and_get_original\n    columns_to_join=columns_to_join)\n', '  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 2263, in _instance_update\n    actual=actual_state, expected=expected)\n', "UnexpectedDeletingTaskStateError: Unexpected task state: expecting [u'scheduling', None] but the actual state is deleting\n"]
2014-02-06 08:04:16.958 | 
2014-02-06 08:04:17.064 | 2014-02-06 07:40:36.034 30669 ERROR oslo.messaging._executors.base [-] Exception during message handling

** Affects: nova
     Importance: Undecided
         Status: New

** Affects: tempest
     Importance: Undecided
         Status: New

** Also 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/1277027

Title:
  test_admin_delete_servers_of_others failure due to unexpected task
  state

Status in OpenStack Compute (Nova):
  New
Status in Tempest:
  New

Bug description:
  I couldn't find an existing bug for this, apologies if it's a dupe,
  looks like a nova bug:

  
  https://review.openstack.org/#/c/70717/
  http://logs.openstack.org/17/70717/1/gate/gate-tempest-dsvm-full/9adaf90/console.html

  2014-02-06 08:04:16.350 | 2014-02-06 07:48:25,729 Response Body: {"server": {"status": "ERROR", "os-access-ips:access_ip_v6": "", "updated": "2014-02-06T07:48:25Z", "os-access-ips:access_ip_v4": "", "addresses": {}, "links": [{"href": "http://127.0.0.1:8774/v3/servers/1cbd2e01-d2f3-45a0-baee-1d16df3dc7fd";, "rel": "self"}, {"href": "http://127.0.0.1:8774/servers/1cbd2e01-d2f3-45a0-baee-1d16df3dc7fd";, "rel": "bookmark"}], "os-extended-status:task_state": null, "key_name": null, "image": {"id": "7e649e07-3cea-4d95-90b2-2bbea7fce698", "links": [{"href": "http://23.253.79.233:9292/images/7e649e07-3cea-4d95-90b2-2bbea7fce698";, "rel": "bookmark"}]}, "os-pci:pci_devices": [], "os-extended-availability-zone:availability_zone": "nova", "os-extended-status:power_state": 0, "os-config-drive:config_drive": "", "host_id": "10f0dc42e72572ed6d30e8dc32b41edc1d41a3dacda6571c5aeabe6e", "flavor": {"id": "42", "links": [{"href": "http://127.0.0.1:8774/flavors/42";, "rel": "bookmark"}]}, "id": "1cbd2e01-d2f3-45a0-baee-1d16df3dc7fd", "security_groups": [{"name": "default"}], "user_id": "f2262ed0a64c43359867456cfbccc153", "name": "ServersAdminV3Test-instance-1705049062", "created": "2014-02-06T07:48:21Z", "tenant_id": "8e932e11471a469e85a30195b2198f63", "os-extended-status:vm_state": "error", "os-server-usage:launched_at": null, "os-extended-volumes:volumes_attached": [], "os-server-usage:terminated_at": null, "os-extended-status:locked_by": null, "fault": {"message": "No valid host was found. ", "code": 500, "created": "2014-02-06T07:48:25Z"}, "metadata": {}}}
  2014-02-06 08:04:16.350 | }}}
  2014-02-06 08:04:16.350 | 
  2014-02-06 08:04:16.350 | Traceback (most recent call last):
  2014-02-06 08:04:16.350 |   File "tempest/api/compute/v3/admin/test_servers.py", line 85, in test_admin_delete_servers_of_others
  2014-02-06 08:04:16.350 |     self.servers_client.wait_for_server_termination(server['id'])
  2014-02-06 08:04:16.351 |   File "tempest/services/compute/v3/json/servers_client.py", line 179, in wait_for_server_termination
  2014-02-06 08:04:16.351 |     raise exceptions.BuildErrorException(server_id=server_id)
  2014-02-06 08:04:16.351 | BuildErrorException: Server 1cbd2e01-d2f3-45a0-baee-1d16df3dc7fd failed to build and is in ERROR status
  2014-02-06 08:04:16.351 | 
  2014-02-06 08:04:16.351 | 
  2014-02-06 08:04:16.351 | ======================================================================
  2014-02-06 08:04:16.351 | FAIL: process-returncode
  2014-02-06 08:04:16.351 | process-returncode
  2014-02-06 08:04:16.351 | ----------------------------------------------------------------------
  2014-02-06 08:04:16.352 | _StringException: Binary content:
  2014-02-06 08:04:16.352 |   traceback (test/plain; charset="utf8")
  2014-02-06 08:04:16.352 | 
  2014-02-06 08:04:16.352 | 
  2014-02-06 08:04:16.352 | ----------------------------------------------------------------------
  2014-02-06 08:04:16.352 | Ran 2101 tests in 2350.793s
  2014-02-06 08:04:16.353 | 
  2014-02-06 08:04:16.353 | FAILED (failures=2, skipped=130)
  2014-02-06 08:04:16.353 | ERROR: InvocationError: '/bin/bash tools/pretty_tox.sh (?!.*\\[.*\\bslow\\b.*\\])(^tempest\\.(api|scenario|thirdparty|cli)) --concurrency=2'
  2014-02-06 08:04:16.354 | ___________________________________ summary ____________________________________
  2014-02-06 08:04:16.354 | ERROR:   full: commands failed
  2014-02-06 08:04:16.463 | Checking logs...
  2014-02-06 08:04:16.562 | Log File: n-net
  2014-02-06 08:04:16.562 | 2014-02-06 07:34:40.598 30086 ERROR oslo.messaging._executors.base [-] Exception during message handling
  2014-02-06 08:04:16.562 | 
  2014-02-06 08:04:16.563 | 2014-02-06 07:34:40.601 30086 ERROR oslo.messaging._drivers.common [-] Returning exception Instance fcfcbace-c4dd-4214-957f-b01e0b47fcf4 could not be found.
  2014-02-06 08:04:16.563 | 
  2014-02-06 08:04:16.563 | 2014-02-06 07:34:40.601 30086 ERROR oslo.messaging._drivers.common [-] ['Traceback (most recent call last):\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/_executors/base.py", line 36, in _dispatch\n    incoming.reply(self.callback(incoming.ctxt, incoming.message))\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 134, in __call__\n    return self._dispatch(endpoint, method, ctxt, args)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 104, in _dispatch\n    result = getattr(endpoint, method)(ctxt, **new_args)\n', '  File "/opt/stack/new/nova/nova/network/floating_ips.py", line 117, in allocate_for_instance\n    **kwargs)\n', '  File "/opt/stack/new/nova/nova/network/manager.py", line 521, in allocate_for_instance\n    host)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/server.py", line 153, in inner\n    return func(*args, **kwargs)\n', '  File "/opt/stack/new/nova/nova/network/manager.py", line 579, in get_instance_nw_info\n    instance_uuid, use_slave=use_slave)\n', '  File "/opt/stack/new/nova/nova/objects/base.py", line 110, in wrapper\n    args, kwargs)\n', '  File "/opt/stack/new/nova/nova/conductor/rpcapi.py", line 470, in object_class_action\n    objver=objver, args=args, kwargs=kwargs)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/client.py", line 150, in call\n    wait_for_reply=True, timeout=timeout)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/transport.py", line 87, in _send\n    timeout=timeout)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/_drivers/amqpdriver.py", line 390, in send\n    return self._send(target, ctxt, message, wait_for_reply, timeout)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/_drivers/amqpdriver.py", line 383, in _send\n    raise result\n', 'InstanceNotFound_Remote: Instance fcfcbace-c4dd-4214-957f-b01e0b47fcf4 could not be found.\nTraceback (most recent call last):\n\n  File "/opt/stack/new/nova/nova/conductor/manager.py", line 572, in _object_dispatch\n    return getattr(target, method)(context, *args, **kwargs)\n\n  File "/opt/stack/new/nova/nova/objects/base.py", line 112, in wrapper\n    result = fn(cls, context, *args, **kwargs)\n\n  File "/opt/stack/new/nova/nova/objects/virtual_interface.py", line 98, in get_by_instance_uuid\n    use_slave=use_slave)\n\n  File "/opt/stack/new/nova/nova/db/api.py", line 594, in virtual_interface_get_by_instance\n    use_slave=use_slave)\n\n  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 128, in wrapper\n    return f(*args, **kwargs)\n\n  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 140, in wrapper\n    instance_get_by_uuid(context, instance_uuid)\n\n  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 128, in wrapper\n    return f(*args, **kwargs)\n\n  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 1701, in instance_get_by_uuid\n    columns_to_join=columns_to_join, use_slave=use_slave)\n\n  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 1713, in _instance_get_by_uuid\n    raise exception.InstanceNotFound(instance_id=uuid)\n\nInstanceNotFound: Instance fcfcbace-c4dd-4214-957f-b01e0b47fcf4 could not be found.\n\n']
  2014-02-06 08:04:16.564 | 
  2014-02-06 08:04:16.957 | Log File: n-cond
  2014-02-06 08:04:16.957 | 2014-02-06 07:35:54.076 30662 ERROR oslo.messaging._executors.base [-] Exception during message handling
  2014-02-06 08:04:16.957 | 
  2014-02-06 08:04:16.958 | 2014-02-06 07:35:54.077 30662 ERROR oslo.messaging._drivers.common [-] Returning exception Unexpected task state: expecting [u'scheduling', None] but the actual state is deleting to caller
  2014-02-06 08:04:16.958 | 
  2014-02-06 08:04:16.958 | 2014-02-06 07:35:54.077 30662 ERROR oslo.messaging._drivers.common [-] ['Traceback (most recent call last):\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/_executors/base.py", line 36, in _dispatch\n    incoming.reply(self.callback(incoming.ctxt, incoming.message))\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 134, in __call__\n    return self._dispatch(endpoint, method, ctxt, args)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 104, in _dispatch\n    result = getattr(endpoint, method)(ctxt, **new_args)\n', '  File "/opt/stack/new/oslo.messaging/oslo/messaging/rpc/server.py", line 153, in inner\n    return func(*args, **kwargs)\n', '  File "/opt/stack/new/nova/nova/conductor/manager.py", line 129, in instance_update\n    context, instance_uuid, updates)\n', '  File "/opt/stack/new/nova/nova/db/api.py", line 740, in instance_update_and_get_original\n    columns_to_join=columns_to_join)\n', '  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 128, in wrapper\n    return f(*args, **kwargs)\n', '  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 2215, in instance_update_and_get_original\n    columns_to_join=columns_to_join)\n', '  File "/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 2263, in _instance_update\n    actual=actual_state, expected=expected)\n', "UnexpectedDeletingTaskStateError: Unexpected task state: expecting [u'scheduling', None] but the actual state is deleting\n"]
  2014-02-06 08:04:16.958 | 
  2014-02-06 08:04:17.064 | 2014-02-06 07:40:36.034 30669 ERROR oslo.messaging._executors.base [-] Exception during message handling

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


Follow ups

References