Tempest test "test_update_host_reservation" in "blazar_tempest_plugin.tests.scenario.test_host_reservation.TestHostReservationScenario" sometimes fails logging "End date must be later than current and start date" [1].
[1] http://logs.openstack.org/70/646070/1/check/blazar-devstack-dsvm-py35/0d56394/logs/testr_results.html.gz
Traceback
========
2019-03-24 21:24:34,167 28668 INFO [tempest.lib.common.rest_client] Request (TestHostReservationScenario:test_update_host_reservation): 200 GET http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df 0.371s
2019-03-24 21:24:34,168 28668 DEBUG [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
Body: None
Response - Headers: {'date': 'Sun, 24 Mar 2019 21:24:33 GMT', 'server': 'Apache/2.4.29 (Ubuntu)', 'content-length': '1556', 'content-type': 'application/json', 'openstack-api-version': 'compute 2.1', 'x-openstack-nova-api-version': '2.1', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version', 'x-openstack-request-id': 'req-cd505dfd-1a39-4b43-b9bd-1de0f8dadcba', 'x-compute-request-id': 'req-cd505dfd-1a39-4b43-b9bd-1de0f8dadcba', 'connection': 'close', 'status': '200', 'content-location': 'http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df'}
Body: b'{"server": {"id": "4c61a6b4-420b-4a81-9683-da79dae035df", "name": "tempest-TestHostReservationScenario-server-630329565", "status": "BUILD", "tenant_id": "f74493451f834d49b2e17796f6bd831b", "user_id": "d028d27b640244e0b5dc94ed3bd8944f", "metadata": {}, "hostId": "000b48872ab2e3eda1949255901112cc005c96079f218d355f3291ab", "image": {"id": "3f336be1-7456-4746-93e6-28858337a795", "links": [{"rel": "bookmark", "href": "http://158.69.73.137/compute/images/3f336be1-7456-4746-93e6-28858337a795"}]}, "flavor": {"id": "42", "links": [{"rel": "bookmark", "href": "http://158.69.73.137/compute/flavors/42"}]}, "created": "2019-03-24T21:24:28Z", "updated": "2019-03-24T21:24:30Z", "addresses": {}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df"}, {"rel": "bookmark", "href": "http://158.69.73.137/compute/servers/4c61a6b4-420b-4a81-9683-da79dae035df"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "blazar_0a20bba2-b0cd-48e2-978b-dba37826a240", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": null, "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-SRV-ATTR:host": "ubuntu-bionic-ovh-bhs1-0004188639", "OS-EXT-SRV-ATTR:instance_name": "instance-00000003", "OS-EXT-SRV-ATTR:hypervisor_hostname": "ubuntu-bionic-ovh-bhs1-0004188639", "OS-EXT-STS:task_state": "spawning", "OS-EXT-STS:vm_state": "building", "OS-EXT-STS:power_state": 0, "os-extended-volumes:volumes_attached": []}}'
2019-03-24 21:24:35,416 28668 INFO [tempest.lib.common.rest_client] Request (TestHostReservationScenario:test_update_host_reservation): 200 GET http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df 0.239s
2019-03-24 21:24:35,417 28668 DEBUG [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
Body: None
Response - Headers: {'date': 'Sun, 24 Mar 2019 21:24:35 GMT', 'server': 'Apache/2.4.29 (Ubuntu)', 'content-length': '1556', 'content-type': 'application/json', 'openstack-api-version': 'compute 2.1', 'x-openstack-nova-api-version': '2.1', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version', 'x-openstack-request-id': 'req-c02ba083-86ea-4575-915b-4caa6c14a0cf', 'x-compute-request-id': 'req-c02ba083-86ea-4575-915b-4caa6c14a0cf', 'connection': 'close', 'status': '200', 'content-location': 'http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df'}
Body: b'{"server": {"id": "4c61a6b4-420b-4a81-9683-da79dae035df", "name": "tempest-TestHostReservationScenario-server-630329565", "status": "BUILD", "tenant_id": "f74493451f834d49b2e17796f6bd831b", "user_id": "d028d27b640244e0b5dc94ed3bd8944f", "metadata": {}, "hostId": "000b48872ab2e3eda1949255901112cc005c96079f218d355f3291ab", "image": {"id": "3f336be1-7456-4746-93e6-28858337a795", "links": [{"rel": "bookmark", "href": "http://158.69.73.137/compute/images/3f336be1-7456-4746-93e6-28858337a795"}]}, "flavor": {"id": "42", "links": [{"rel": "bookmark", "href": "http://158.69.73.137/compute/flavors/42"}]}, "created": "2019-03-24T21:24:28Z", "updated": "2019-03-24T21:24:30Z", "addresses": {}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df"}, {"rel": "bookmark", "href": "http://158.69.73.137/compute/servers/4c61a6b4-420b-4a81-9683-da79dae035df"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "blazar_0a20bba2-b0cd-48e2-978b-dba37826a240", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": null, "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-SRV-ATTR:host": "ubuntu-bionic-ovh-bhs1-0004188639", "OS-EXT-SRV-ATTR:instance_name": "instance-00000003", "OS-EXT-SRV-ATTR:hypervisor_hostname": "ubuntu-bionic-ovh-bhs1-0004188639", "OS-EXT-STS:task_state": "spawning", "OS-EXT-STS:vm_state": "building", "OS-EXT-STS:power_state": 0, "os-extended-volumes:volumes_attached": []}}'
2019-03-24 21:24:36,609 28668 INFO [tempest.lib.common.rest_client] Request (TestHostReservationScenario:test_update_host_reservation): 200 GET http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df 0.183s
2019-03-24 21:24:36,609 28668 DEBUG [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
Body: None
Response - Headers: {'date': 'Sun, 24 Mar 2019 21:24:36 GMT', 'server': 'Apache/2.4.29 (Ubuntu)', 'content-length': '1743', 'content-type': 'application/json', 'openstack-api-version': 'compute 2.1', 'x-openstack-nova-api-version': '2.1', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version', 'x-openstack-request-id': 'req-a6978063-f031-434a-8a05-904b87fe2dab', 'x-compute-request-id': 'req-a6978063-f031-434a-8a05-904b87fe2dab', 'connection': 'close', 'status': '200', 'content-location': 'http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df'}
Body: b'{"server": {"id": "4c61a6b4-420b-4a81-9683-da79dae035df", "name": "tempest-TestHostReservationScenario-server-630329565", "status": "ACTIVE", "tenant_id": "f74493451f834d49b2e17796f6bd831b", "user_id": "d028d27b640244e0b5dc94ed3bd8944f", "metadata": {}, "hostId": "000b48872ab2e3eda1949255901112cc005c96079f218d355f3291ab", "image": {"id": "3f336be1-7456-4746-93e6-28858337a795", "links": [{"rel": "bookmark", "href": "http://158.69.73.137/compute/images/3f336be1-7456-4746-93e6-28858337a795"}]}, "flavor": {"id": "42", "links": [{"rel": "bookmark", "href": "http://158.69.73.137/compute/flavors/42"}]}, "created": "2019-03-24T21:24:28Z", "updated": "2019-03-24T21:24:36Z", "addresses": {"tempest-TestHostReservationScenario-263560572-network": [{"version": 4, "addr": "10.1.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:da:a3:7a"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df"}, {"rel": "bookmark", "href": "http://158.69.73.137/compute/servers/4c61a6b4-420b-4a81-9683-da79dae035df"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "blazar_0a20bba2-b0cd-48e2-978b-dba37826a240", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-03-24T21:24:35.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-SRV-ATTR:host": "ubuntu-bionic-ovh-bhs1-0004188639", "OS-EXT-SRV-ATTR:instance_name": "instance-00000003", "OS-EXT-SRV-ATTR:hypervisor_hostname": "ubuntu-bionic-ovh-bhs1-0004188639", "OS-EXT-STS:task_state": null, "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": []}}'
2019-03-24 21:24:36,617 28668 INFO [tempest.common.waiters] State transition "BUILD/spawning" ==> "ACTIVE/None" after 7 second wait
2019-03-24 21:26:01,546 28668 INFO [tempest.lib.common.rest_client] Request (TestHostReservationScenario:test_update_host_reservation): 400 PUT http://158.69.73.137/reservation/v1/leases/51a8d021-3b35-470b-9b11-14ed43b27a49 9.852s
2019-03-24 21:26:01,547 28668 DEBUG [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
Body: b'{"end_date": "2019-03-24 21:25"}'
Response - Headers: {'date': 'Sun, 24 Mar 2019 21:25:51 GMT', 'server': 'Apache/2.4.29 (Ubuntu)', 'content-type': 'application/json', 'content-length': '109', 'connection': 'close', 'status': '400', 'content-location': 'http://158.69.73.137/reservation/v1/leases/51a8d021-3b35-470b-9b11-14ed43b27a49'}
Body: b'{"error_code": 400, "error_message": "End date must be later than current and start date", "error_name": 400}'
2019-03-24 21:26:01,791 28668 INFO [tempest.lib.common.rest_client] Request (TestHostReservationScenario:_run_cleanups): 204 DELETE http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df 0.241s
2019-03-24 21:26:01,792 28668 DEBUG [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
Body: None
Response - Headers: {'date': 'Sun, 24 Mar 2019 21:26:01 GMT', 'server': 'Apache/2.4.29 (Ubuntu)', 'content-type': 'application/json', 'openstack-api-version': 'compute 2.1', 'x-openstack-nova-api-version': '2.1', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version', 'x-openstack-request-id': 'req-a8affa2c-9a99-4385-945a-a22b4aee3a63', 'x-compute-request-id': 'req-a8affa2c-9a99-4385-945a-a22b4aee3a63', 'connection': 'close', 'status': '204', 'content-location': 'http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df'}
Body: b''
2019-03-24 21:26:02,041 28668 INFO [tempest.lib.common.rest_client] Request (TestHostReservationScenario:_run_cleanups): 200 GET http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df 0.248s
2019-03-24 21:26:02,042 28668 DEBUG [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
Body: None
Response - Headers: {'date': 'Sun, 24 Mar 2019 21:26:01 GMT', 'server': 'Apache/2.4.29 (Ubuntu)', 'content-length': '1749', 'content-type': 'application/json', 'openstack-api-version': 'compute 2.1', 'x-openstack-nova-api-version': '2.1', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version', 'x-openstack-request-id': 'req-5e7cc466-a512-4e8b-a5a3-5d693c9f106d', 'x-compute-request-id': 'req-5e7cc466-a512-4e8b-a5a3-5d693c9f106d', 'connection': 'close', 'status': '200', 'content-location': 'http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df'}
Body: b'{"server": {"id": "4c61a6b4-420b-4a81-9683-da79dae035df", "name": "tempest-TestHostReservationScenario-server-630329565", "status": "ACTIVE", "tenant_id": "f74493451f834d49b2e17796f6bd831b", "user_id": "d028d27b640244e0b5dc94ed3bd8944f", "metadata": {}, "hostId": "000b48872ab2e3eda1949255901112cc005c96079f218d355f3291ab", "image": {"id": "3f336be1-7456-4746-93e6-28858337a795", "links": [{"rel": "bookmark", "href": "http://158.69.73.137/compute/images/3f336be1-7456-4746-93e6-28858337a795"}]}, "flavor": {"id": "42", "links": [{"rel": "bookmark", "href": "http://158.69.73.137/compute/flavors/42"}]}, "created": "2019-03-24T21:24:28Z", "updated": "2019-03-24T21:26:02Z", "addresses": {"tempest-TestHostReservationScenario-263560572-network": [{"version": 4, "addr": "10.1.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:da:a3:7a"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df"}, {"rel": "bookmark", "href": "http://158.69.73.137/compute/servers/4c61a6b4-420b-4a81-9683-da79dae035df"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "blazar_0a20bba2-b0cd-48e2-978b-dba37826a240", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-03-24T21:24:35.000000", "OS-SRV-USG:terminated_at": null, "security_groups": [{"name": "default"}], "OS-EXT-SRV-ATTR:host": "ubuntu-bionic-ovh-bhs1-0004188639", "OS-EXT-SRV-ATTR:instance_name": "instance-00000003", "OS-EXT-SRV-ATTR:hypervisor_hostname": "ubuntu-bionic-ovh-bhs1-0004188639", "OS-EXT-STS:task_state": "deleting", "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": []}}'
2019-03-24 21:26:05,754 28668 INFO [tempest.lib.common.rest_client] Request (TestHostReservationScenario:_run_cleanups): 200 GET http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df 2.698s
2019-03-24 21:26:05,755 28668 DEBUG [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
Body: None
Response - Headers: {'date': 'Sun, 24 Mar 2019 21:26:03 GMT', 'server': 'Apache/2.4.29 (Ubuntu)', 'content-length': '1707', 'content-type': 'application/json', 'openstack-api-version': 'compute 2.1', 'x-openstack-nova-api-version': '2.1', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version', 'x-openstack-request-id': 'req-04698563-eebf-44e2-a23f-cefa5bddbe22', 'x-compute-request-id': 'req-04698563-eebf-44e2-a23f-cefa5bddbe22', 'connection': 'close', 'status': '200', 'content-location': 'http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df'}
Body: b'{"server": {"id": "4c61a6b4-420b-4a81-9683-da79dae035df", "name": "tempest-TestHostReservationScenario-server-630329565", "status": "ACTIVE", "tenant_id": "f74493451f834d49b2e17796f6bd831b", "user_id": "d028d27b640244e0b5dc94ed3bd8944f", "metadata": {}, "hostId": "000b48872ab2e3eda1949255901112cc005c96079f218d355f3291ab", "image": {"id": "3f336be1-7456-4746-93e6-28858337a795", "links": [{"rel": "bookmark", "href": "http://158.69.73.137/compute/images/3f336be1-7456-4746-93e6-28858337a795"}]}, "flavor": {"id": "42", "links": [{"rel": "bookmark", "href": "http://158.69.73.137/compute/flavors/42"}]}, "created": "2019-03-24T21:24:28Z", "updated": "2019-03-24T21:26:02Z", "addresses": {"tempest-TestHostReservationScenario-263560572-network": [{"version": 4, "addr": "10.1.0.14", "OS-EXT-IPS:type": "fixed", "OS-EXT-IPS-MAC:mac_addr": "fa:16:3e:da:a3:7a"}]}, "accessIPv4": "", "accessIPv6": "", "links": [{"rel": "self", "href": "http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df"}, {"rel": "bookmark", "href": "http://158.69.73.137/compute/servers/4c61a6b4-420b-4a81-9683-da79dae035df"}], "OS-DCF:diskConfig": "MANUAL", "progress": 0, "OS-EXT-AZ:availability_zone": "blazar_0a20bba2-b0cd-48e2-978b-dba37826a240", "config_drive": "", "key_name": null, "OS-SRV-USG:launched_at": "2019-03-24T21:24:35.000000", "OS-SRV-USG:terminated_at": null, "OS-EXT-SRV-ATTR:host": "ubuntu-bionic-ovh-bhs1-0004188639", "OS-EXT-SRV-ATTR:instance_name": "instance-00000003", "OS-EXT-SRV-ATTR:hypervisor_hostname": "ubuntu-bionic-ovh-bhs1-0004188639", "OS-EXT-STS:task_state": "deleting", "OS-EXT-STS:vm_state": "active", "OS-EXT-STS:power_state": 1, "os-extended-volumes:volumes_attached": []}}'
2019-03-24 21:26:06,844 28668 INFO [tempest.lib.common.rest_client] Request (TestHostReservationScenario:_run_cleanups): 404 GET http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df 0.083s
2019-03-24 21:26:06,845 28668 DEBUG [tempest.lib.common.rest_client] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
Body: None
Response - Headers: {'date': 'Sun, 24 Mar 2019 21:26:06 GMT', 'server': 'Apache/2.4.29 (Ubuntu)', 'openstack-api-version': 'compute 2.1', 'x-openstack-nova-api-version': '2.1', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version', 'content-type': 'application/json; charset=UTF-8', 'content-length': '111', 'x-openstack-request-id': 'req-3010481b-0438-4d97-a3e6-dbf429080bf3', 'x-compute-request-id': 'req-3010481b-0438-4d97-a3e6-dbf429080bf3', 'connection': 'close', 'status': '404', 'content-location': 'http://158.69.73.137/compute/v2.1/servers/4c61a6b4-420b-4a81-9683-da79dae035df'}
Body: b'{"itemNotFound": {"code": 404, "message": "Instance 4c61a6b4-420b-4a81-9683-da79dae035df could not be found."}}'
}}}
Traceback (most recent call last):
File "/opt/stack/new/tempest/.tox/tempest/lib/python3.6/site-packages/blazar_tempest_plugin/tests/scenario/test_host_reservation.py", line 302, in test_update_host_reservation
body)['lease']
File "/opt/stack/new/tempest/.tox/tempest/lib/python3.6/site-packages/blazar_tempest_plugin/services/reservation/reservation_client.py", line 49, in update_lease
resp, body = self.put(self.lease_path % lease, body=body)
File "/opt/stack/new/tempest/tempest/lib/common/rest_client.py", line 347, in put
return self.request('PUT', url, extra_headers, headers, body, chunked)
File "/opt/stack/new/tempest/tempest/lib/common/rest_client.py", line 679, in request
self._error_checker(resp, resp_body)
File "/opt/stack/new/tempest/tempest/lib/common/rest_client.py", line 790, in _error_checker
raise exceptions.BadRequest(resp_body, resp=resp)
tempest.lib.exceptions.BadRequest: Bad request
Details: {'error_code': 400, 'error_message': 'End date must be later than current and start date', 'error_name': 400}
We try to update the lease by setting the end date to be utcnow(): https:/ /github. com/openstack/ blazar- tempest- plugin/ blob/master/ blazar_ tempest_ plugin/ tests/scenario/ test_host_ reservation. py#L296- L302
If utcnow() is near the end of a second, by the time the request reaches blazar-manager, the time may have reached the next second already.
We should use the same code as instance reservation: https:/ /github. com/openstack/ blazar- tempest- plugin/ blob/master/ blazar_ tempest_ plugin/ tests/scenario/ test_instance_ reservation. py#L201- L208