Bug 1250081

Summary: test_minimum_basic scenario failed to run on rdo-manager
Product: [Community] RDO Reporter: mathieu bultel <mbultel>
Component: tempestAssignee: David Kranz <dkranz>
Status: CLOSED EOL QA Contact: tkammer
Severity: medium Docs Contact:
Priority: medium    
Version: trunkCC: apevec, chris.brown, lhh, mbultel, slinaber, whayutin
Target Milestone: RCKeywords: Automation
Target Release: trunk   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-06-18 06:36:17 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
tempest.log none

Description mathieu bultel 2015-08-04 13:28:52 UTC
Created attachment 1059093 [details]
tempest.log

Description of problem:

When I run test_minimal_basic scenario on rdo-manager / centos
the test failed at the step :
self.nova_volume_attach()

(see attachment for more information)

When launching an instance manually and attaching a volume to the instance, there is no issue.
tempest.conf:

[DEFAULT]
debug = true
use_stderr = false
log_file = tempest.log

[auth]
tempest_roles = _member_

[compute]
image_ssh_user = fedora
allow_tenant_isolation = true
build_timeout = 900
ssh_user = fedora
flavor_ref = 2
flavor_ref_alt = 2
image_ref = 2e5e8ce2d2c043dea4754e56c0fc22df
image_ref_alt = 2e5e8ce2d2c043dea4754e56c0fc22df

[identity]
username = demo
tenant_name = demo
password = secrete
alt_username = alt_demo
alt_tenant_name = alt_demo
alt_password = secrete
admin_username = admin
admin_tenant_name = admin
admin_domain_name = Default
disable_ssl_certificate_validation = false
uri = http://192.0.2.6:5000/v2.0/
admin_password = aee8208bef006c91feec73fa4a3e61041a664079
uri_v3 = http://192.0.2.6:5000/v3/
admin_tenant_id = 2e5e8ce2d2c043dea4754e56c0fc22df

[object-storage]
operator_role = swiftoperator

[data_processing]
catalog_type = data-processing

[orchestration]

[scenario]
img_dir = etc
ssh_user = fedora

[oslo_concurrency]
lock_path = /tmp

[volume-feature-enabled]
bootable = true
api_extensions = OS-SCH-HNT,os-hosts,os-vol-tenant-attr,os-quota-sets,os-availability-zone,os-volume-encryption-metadata,os-volume-replication,backups,os-snapshot-actions,cgsnapshots,os-used-limits,os-volume-type-access,consistencygroups,os-vol-host-attr,encryption,os-types-manage,qos-specs,os-volume-actions,os-types-extra-specs,os-vol-mig-status-attr,os-volume-unmanage,os-image-create,os-extended-services,os-extended-snapshot-attributes,os-vol-image-meta,os-quota-class-sets,os-volume-transfer,os-volume-manage,os-admin-actions,os-services,scheduler-stats
api_v1 = True
api_v2 = True

[compute-feature-enabled]
live_migrate_paused_instances = true
preserve_ports = true
api_extensions = NMN,OS-DCF,OS-EXT-AZ,OS-EXT-IMG-SIZE,OS-EXT-IPS,OS-EXT-IPS-MAC,OS-EXT-SRV-ATTR,OS-EXT-STS,OS-EXT-VIF-NET,OS-FLV-DISABLED,OS-FLV-EXT-DATA,OS-SCH-HNT,OS-SRV-USG,os-admin-actions,os-agents,os-aggregates,os-assisted-volume-snapshots,os-attach-interfaces,os-availability-zone,os-baremetal-ext-status,os-baremetal-nodes,os-block-device-mapping-v2-boot,os-cell-capacities,os-cells,os-certificates,os-cloudpipe,os-cloudpipe-update,os-config-drive,os-console-auth-tokens,os-console-output,os-consoles,os-create-server-ext,os-deferred-delete,os-evacuate,os-extended-evacuate-find-host,os-extended-floating-ips,os-extended-hypervisors,os-extended-networks,os-extended-quotas,os-extended-rescue-with-image,os-extended-services,os-extended-services-delete,os-extended-volumes,os-fixed-ips,os-flavor-access,os-flavor-extra-specs,os-flavor-manage,os-flavor-rxtx,os-flavor-swap,os-floating-ip-dns,os-floating-ip-pools,os-floating-ips,os-floating-ips-bulk,os-fping,os-hide-server-addresses,os-hosts,os-hypervisor-status,os-hypervisors,os-instance-actions,os-instance_usage_audit_log,os-keypairs,os-migrations,os-multiple-create,os-networks,os-networks-associate,os-preserve-ephemeral-rebuild,os-quota-class-sets,os-quota-sets,os-rescue,os-security-group-default-rules,os-security-groups,os-server-diagnostics,os-server-external-events,os-server-group-quotas,os-server-groups,os-server-list-multi-status,os-server-password,os-server-sort-keys,os-server-start-stop,os-services,os-shelve,os-simple-tenant-usage,os-tenant-networks,os-used-limits,os-used-limits-for-admin,os-user-data,os-user-quotas,os-virtual-interfaces,os-volume-attachment-update,os-volumes

[network-feature-enabled]
ipv6_subnet_attributes = true
api_extensions = security-group,l3_agent_scheduler,net-mtu,ext-gw-mode,binding,provider,agent,quotas,subnet_allocation,dhcp_agent_scheduler,l3-ha,multi-provider,external-net,router,allowed-address-pairs,extraroute,extra_dhcp_opt,dvr

[network]
build_timeout = 500
public_network_id = c88c6cc1-aee6-443e-b48e-94c49abcfaff

[volume]
build_timeout = 500

[service_available]
glance = True
cinder = True
swift = True
nova = True
neutron = True
trove = False
ceilometer = True
sahara = False
ironic = False
heat = True
zaqar = False
horizon = True

[object-storage-feature-enabled]
discoverable_apis = formpost,staticweb,ratelimit,tempurl

[image-feature-enabled]
api_v1 = True
api_v2 = True

[identity-feature-enabled]
api_v2 = True
api_v3 = True

[boto]
ec2_url = http://192.0.2.9:8773/services/Cloud

[dashboard]
dashboard_url = http://192.0.2.6/dashboard/
login_url = http://192.0.2.6/dashboard/auth/login/

Comment 3 mathieu bultel 2015-08-04 13:47:00 UTC
            Body: {"server": {"status": "ACTIVE", "updated": "2015-08-04T13:45:45Z", "hostId": "6bd6a42ab88e97641305170fd759b30ad14583a6362f7cde3f230617", "addresses": {"TestMinimumBasicScenario-677603733-network": [{"OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:fc:a2:e4", "version": 4, "addr": "10.100.0.3", "OS-EXT-IPS:type": "fixed"}]}, "links": [{"href": "http://192.0.2.6:8774/v2/0fa854fb9aaa4d10862bd07b5a8dfcc3/servers/0780670b-21f8-463d-8279-c3de433acbea", "rel": "self"}, {"href": "http://192.0.2.6:8774/0fa854fb9aaa4d10862bd07b5a8dfcc3/servers/0780670b-21f8-463d-8279-c3de433acbea", "rel": "bookmark"}], "key_name": "TestMinimumBasicScenario-2106708450", "image": {"id": "80aaedc9-b90e-4d73-8205-0f37865b7dc8", "links": [{"href": "http://192.0.2.6:8774/0fa854fb9aaa4d10862bd07b5a8dfcc3/images/80aaedc9-b90e-4d73-8205-0f37865b7dc8", "rel": "bookmark"}]}, "OS-EXT-STS:task_state": "deleting", "OS-EXT-STS:vm_state": "active", "OS-SRV-USG:launched_at": "2015-08-04T13:37:38.000000", "flavor": {"id": "2", "links": [{"href": "http://192.0.2.6:8774/0fa854fb9aaa4d10862bd07b5a8dfcc3/flavors/2", "rel": "bookmark"}]}, "id": "0780670b-21f8-463d-8279-c3de433acbea", "security_groups": [{"name": "default"}], "OS-SRV-USG:terminated_at": null, "OS-EXT-AZ:availability_zone": "nova", "user_id": "6caef445d5cd41cca518982d6a66e1f3", "name": "TestMinimumBasicScenario-945558213", "created": "2015-08-04T13:37:28Z", "tenant_id": "0fa854fb9aaa4d10862bd07b5a8dfcc3", "OS-DCF:diskConfig": "MANUAL", "os-extended-volumes:volumes_attached": [{"id": "f49755c3-9b58-4560-8652-c195210a6291"}], "accessIPv4": "", "accessIPv6": "", "progress": 0, "OS-EXT-STS:power_state": 1, "config_drive": "", "metadata": {}}}
    2015-08-04 13:45:49,628 24546 INFO     [tempest_lib.common.rest_client] Request (TestMinimumBasicScenario:_run_cleanups): 200 GET http://192.0.2.6:8774/v2/0fa854fb9aaa4d10862bd07b5a8dfcc3/servers/0780670b-21f8-463d-8279-c3de433acbea 0.141s
    2015-08-04 13:45:49,629 24546 DEBUG    [tempest_lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
            Body: None
        Response - Headers: {'status': '200', 'content-length': '1468', 'content-location': 'http://192.0.2.6:8774/v2/0fa854fb9aaa4d10862bd07b5a8dfcc3/servers/0780670b-21f8-463d-8279-c3de433acbea', 'x-compute-request-id': 'req-e0aba47d-63c4-4417-9743-c8c3d99e3115', 'connection': 'close', 'date': 'Tue, 04 Aug 2015 13:45:49 GMT', 'content-type': 'application/json'}
            Body: {"server": {"status": "ACTIVE", "updated": "2015-08-04T13:45:45Z", "hostId": "6bd6a42ab88e97641305170fd759b30ad14583a6362f7cde3f230617", "addresses": {}, "links": [{"href": "http://192.0.2.6:8774/v2/0fa854fb9aaa4d10862bd07b5a8dfcc3/servers/0780670b-21f8-463d-8279-c3de433acbea", "rel": "self"}, {"href": "http://192.0.2.6:8774/0fa854fb9aaa4d10862bd07b5a8dfcc3/servers/0780670b-21f8-463d-8279-c3de433acbea", "rel": "bookmark"}], "key_name": "TestMinimumBasicScenario-2106708450", "image": {"id": "80aaedc9-b90e-4d73-8205-0f37865b7dc8", "links": [{"href": "http://192.0.2.6:8774/0fa854fb9aaa4d10862bd07b5a8dfcc3/images/80aaedc9-b90e-4d73-8205-0f37865b7dc8", "rel": "bookmark"}]}, "OS-EXT-STS:task_state": "deleting", "OS-EXT-STS:vm_state": "active", "OS-SRV-USG:launched_at": "2015-08-04T13:37:38.000000", "flavor": {"id": "2", "links": [{"href": "http://192.0.2.6:8774/0fa854fb9aaa4d10862bd07b5a8dfcc3/flavors/2", "rel": "bookmark"}]}, "id": "0780670b-21f8-463d-8279-c3de433acbea", "OS-SRV-USG:terminated_at": null, "OS-EXT-AZ:availability_zone": "nova", "user_id": "6caef445d5cd41cca518982d6a66e1f3", "name": "TestMinimumBasicScenario-945558213", "created": "2015-08-04T13:37:28Z", "tenant_id": "0fa854fb9aaa4d10862bd07b5a8dfcc3", "OS-DCF:diskConfig": "MANUAL", "os-extended-volumes:volumes_attached": [{"id": "f49755c3-9b58-4560-8652-c195210a6291"}], "accessIPv4": "", "accessIPv6": "", "progress": 0, "OS-EXT-STS:power_state": 1, "config_drive": "", "metadata": {}}}
    2015-08-04 13:45:50,702 24546 INFO     [tempest_lib.common.rest_client] Request (TestMinimumBasicScenario:_run_cleanups): 404 GET http://192.0.2.6:8774/v2/0fa854fb9aaa4d10862bd07b5a8dfcc3/servers/0780670b-21f8-463d-8279-c3de433acbea 0.053s
    2015-08-04 13:45:50,702 24546 DEBUG    [tempest_lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
            Body: None
        Response - Headers: {'status': '404', 'content-length': '111', 'x-compute-request-id': 'req-54d033ca-650c-49d4-b0df-874d3b591616', 'connection': 'close', 'date': 'Tue, 04 Aug 2015 13:45:50 GMT', 'content-type': 'application/json; charset=UTF-8'}
            Body: {"itemNotFound": {"message": "Instance 0780670b-21f8-463d-8279-c3de433acbea could not be found.", "code": 404}}
    2015-08-04 13:45:50,717 24546 INFO     [tempest_lib.common.rest_client] Request (TestMinimumBasicScenario:_run_cleanups): 202 DELETE http://192.0.2.6:8774/v2/0fa854fb9aaa4d10862bd07b5a8dfcc3/os-keypairs/TestMinimumBasicScenario-2106708450 0.014s
    2015-08-04 13:45:50,717 24546 DEBUG    [tempest_lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
            Body: None
        Response - Headers: {'status': '202', 'content-length': '0', 'x-compute-request-id': 'req-4ae37d7f-e35b-4a18-b923-9edf7b4dc8e4', 'connection': 'close', 'date': 'Tue, 04 Aug 2015 13:45:50 GMT', 'content-type': 'text/html; charset=UTF-8'}
            Body: 
    2015-08-04 13:45:51,485 24546 INFO     [tempest_lib.common.rest_client] Request (TestMinimumBasicScenario:_run_cleanups): 200 DELETE http://192.0.2.6:9292/v1/images/80aaedc9-b90e-4d73-8205-0f37865b7dc8 0.768s
    2015-08-04 13:45:51,486 24546 DEBUG    [tempest_lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
            Body: None
        Response - Headers: {'status': '200', 'content-length': '0', 'connection': 'close', 'date': 'Tue, 04 Aug 2015 13:45:51 GMT', 'content-type': 'text/html; charset=UTF-8', 'x-openstack-request-id': 'req-req-89dc3a4a-e2ec-443b-ae07-b76f9b704b19'}
            Body: 
    2015-08-04 13:45:51,532 24546 INFO     [tempest_lib.common.rest_client] Request (TestMinimumBasicScenario:_run_cleanups): 404 GET http://192.0.2.6:8774/v2/0fa854fb9aaa4d10862bd07b5a8dfcc3/servers/0780670b-21f8-463d-8279-c3de433acbea 0.046s
    2015-08-04 13:45:51,533 24546 DEBUG    [tempest_lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
            Body: None
        Response - Headers: {'status': '404', 'content-length': '111', 'x-compute-request-id': 'req-0a087ed7-7b4e-442c-90c9-86077b66f97d', 'connection': 'close', 'date': 'Tue, 04 Aug 2015 13:45:51 GMT', 'content-type': 'application/json; charset=UTF-8'}
            Body: {"itemNotFound": {"message": "Instance 0780670b-21f8-463d-8279-c3de433acbea could not be found.", "code": 404}}

Comment 4 mathieu bultel 2015-08-04 14:09:34 UTC
Captured traceback:
~~~~~~~~~~~~~~~~~~~
    Traceback (most recent call last):
      File "/home/stack/tempest/tempest/scenario/manager.py", line 89, in delete_wrapper
        delete_thing(*args, **kwargs)
      File "/home/stack/tempest/tempest/services/volume/json/volumes_client.py", line 96, in delete_volume
        resp, body = self.delete("volumes/%s" % str(volume_id))
      File "/usr/lib/python2.7/site-packages/tempest_lib/common/rest_client.py", line 283, in delete
        return self.request('DELETE', url, extra_headers, headers, body)
      File "/usr/lib/python2.7/site-packages/tempest_lib/common/rest_client.py", line 629, in request
        resp, resp_body)
      File "/usr/lib/python2.7/site-packages/tempest_lib/common/rest_client.py", line 680, in _error_checker
        raise exceptions.BadRequest(resp_body)
    BadRequest: Bad request
    Details: {u'message': u'Volume ae225be1-d03f-4616-a286-9211fbd6f318 is still attached, detach volume first.', u'code': 400}
    Traceback (most recent call last):
    _StringException: Empty attachments:
      stderr

    pythonlogging:'': {{{
    2015-08-04 13:58:01,436 26979 DEBUG    [tempest.scenario.manager] paths: img: etc/cirros-0.3.1-x86_64-disk.img, container_fomat: bare, disk_format: qcow2, properties: None, ami: etc/cirros-0.3.1-x86_64-blank.img, ari: etc/cirros-0.3.1-x86_64-initrd, aki: etc/cirros-0.3.1-x86_64-vmlinuz
    2015-08-04 13:58:01,641 26979 INFO     [tempest_lib.common.rest_client] Request (TestMinimumBasicScenario:test_minimum_basic_scenario): 200 POST http://192.0.2.6:5000/v2.0/tokens
    2015-08-04 13:58:01,642 26979 DEBUG    [tempest_lib.common.rest_client] Request - Headers: {}
            Body: None
        Response - Headers: {'status': '200', 'content-length': '4109', 'vary': 'X-Auth-Token', 'connection': 'close', 'date': 'Tue, 04 Aug 2015 13:58:01 GMT', 'content-type': 'application/json', 'x-openstack-request-id': 'req-a939f65f-be1d-4cd7-99ad-30d0dde644a2'}
            Body: None

Comment 5 mathieu bultel 2015-08-06 14:02:25 UTC
This issue is :
100% reproducible on RDO

The test passed on OSP-D on several config :
HA
with and without network isolation
BM
gre & ml2-vxlan

It appear with a basic virt setup with RDO (kilo) on ml2
like this job on centosci gate:

https://ci.centos.org/job/rdo_manager-gate_khaleesi-rdo-kilo/1128/console

Comment 6 David Kranz 2015-08-06 20:48:37 UTC
The following is what is happening as can be seen in the tempest.log:

A server and volume are created, and the volume is attached to the server.
There is a failed call to create a floating ip due to a misconfiguration issue.
The cleanup code in tempest detaches the volume and then deletes it, polling to see if the volume has been deleted. It never is, and eventually the test times out.

Oddly, I was able to reproduce this running tempest manually, but after the run I was able to delete the volume from the command line.

Comment 7 Christopher Brown 2017-06-17 16:40:50 UTC
Suggest this bug is stale can should be closed.

Comment 8 Red Hat Bugzilla 2023-09-14 03:03:08 UTC
The needinfo request[s] on this closed bug have been removed as they have been unresolved for 1000 days