tripleo

Tempest test: "test_create_second_image_when_first_image_is_being_saved" failing in featureset020 periodic job

Bug #1744907 reported by yatin
14
This bug affects 3 people
Affects Status Importance Assigned to Milestone
tripleo
Fix Committed
High
Unassigned
tripleo victoria-3 "tripleo victoria"

Bug Description

1 Tempest test(test_create_second_image_when_first_image_is_being_saved) is failing in featureset020 master periodic job.

Failure logs:-
https://logs.rdoproject.org/openstack-periodic/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-master/3f97360/undercloud/home/jenkins/tempest/tempest.html.gz
https://logs.rdoproject.org/openstack-periodic/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-master/3f97360/undercloud/home/jenkins/tempest_output.log.txt.gz#_2018-01-23_07_27_56

For comparison logs of job which passed this test:-
https://logs.rdoproject.org/openstack-periodic/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-master/60f5231/undercloud/home/jenkins/tempest_output.log.txt.gz#_2018-01-20_10_59_44_536
https://logs.rdoproject.org/openstack-periodic/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-master/5937f4f/undercloud/home/jenkins/tempest_output.log.txt.gz#_2018-01-20_16_01_49_345
https://logs.rdoproject.org/openstack-periodic/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-master/f4445e9/undercloud/home/jenkins/tempest_output.log.txt.gz#_2018-01-19_10_58_02_075

The test tries to create an image from server twice: 1st should pass(return 202) and 2nd should return 409(as server task state is image_pending_upload).

In the failing job 2nd try also return 202 so the test is failing.
The thing i noted is that 2nd request in failing job is taking 4+second while in passing jobs it takes less than .5 seconds, so it might be related to some performance.

See original description
Tags: ci tempest
Alfredo Moralejo (amoralej)
tags: added: ci promotion-blocker
Changed in tripleo:
importance: Undecided → Critical
yatin (yatinkarel)
description: updated
Revision history for this message
Alan Pevec (apevec) wrote :

This is a race that failing negative testcase [1] is supposed to catch
# Disallow creating another image when first image is being saved
and failing test taking longer is an indication that another image is created when it should not.

[1] https://git.openstack.org/cgit/openstack/tempest/tree/tempest/api/compute/images/test_images_oneserver_negative.py#n96

Revision history for this message
yatin (yatinkarel) wrote :

Update: Failed tempest test in last run of fs20 passed:- https://review.rdoproject.org/jenkins/job/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-master/607

wes hayutin (weshayutin)
tags: removed: promotion-blocker
Emilien Macchi (emilienm)
Changed in tripleo:
status: New → Triaged
milestone: none → queens-3
Revision history for this message
melanie witt (melwitt) wrote :

Agreed, test_create_second_image_when_first_image_is_being_saved appears brittle as it expects the first image is still busy being created when the second image create is attempted and expects to fail the second image create.

If there is unexpected delay in the CI environment between the first image create and the second image create attempt, the second image create will succeed if the first image has already finished.

Emilien Macchi (emilienm)
Changed in tripleo:
milestone: queens-3 → queens-rc1
Revision history for this message
Alex Schultz (alex-schultz) wrote :

Since this is not currently failing consistently I think it's a High bug. If it starts failing consistently we need to figure out a plan to address it and should raid the priority.

Changed in tripleo:
importance: Critical → High
Revision history for this message
wes hayutin (weshayutin) wrote :

The quality of this tests is still uncertain. It has passed the last three attempts where tempest was executed [1]. It passed twice on the 20th and once on the 21st.

If this test fails in tempest again it will be moved to the skip list [2]

[1] https://review.rdoproject.org/jenkins/job/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-queens/
[2] https://github.com/openstack/tripleo-quickstart-extras/blob/master/roles/validate-tempest/vars/tempest_skip_queens.yml

Alex Schultz (alex-schultz)
Changed in tripleo:
milestone: queens-rc1 → rocky-1
Revision history for this message
yatin (yatinkarel) wrote :

Seeing the failure in fs20 queens last run:- https://logs.rdoproject.org/openstack-periodic/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-queens/165b64e/undercloud/home/jenkins/tempest/tempest.html.gz

1st image create request:- https://logs.rdoproject.org/openstack-periodic/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-queens/165b64e/overcloud-controller-0/var/log/containers/nova/nova-api.log.txt.gz#_2018-04-17_01_18_54_018 time: 0.266061

Request in middle of both the image create requests.
Possibly culprit:- https://logs.rdoproject.org/openstack-periodic/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-queens/165b64e/overcloud-controller-0/var/log/containers/nova/nova-api.log.txt.gz#_2018-04-17_01_18_58_701 time: 4.679591. This /os-interface task took 4.679591 sec so in this time image should have successfully created.

2nd image create request:- https://logs.rdoproject.org/openstack-periodic/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-queens/165b64e/overcloud-controller-0/var/log/containers/nova/nova-api.log.txt.gz#_2018-04-17_01_18_58_992 time: 0.290046

So need to find why tempest waited to fire the above second request. These two image request should be too quick to get the test succeeded.

Alex Schultz (alex-schultz)
Changed in tripleo:
milestone: rocky-1 → rocky-2
Revision history for this message
yatin (yatinkarel) wrote :

Seen again:- https://logs.rdoproject.org/openstack-periodic/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-queens/f7a11fa/undercloud/home/jenkins/tempest/tempest.html.gz

1st Request:- https://logs.rdoproject.org/openstack-periodic/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-queens/f7a11fa/overcloud-controller-0/var/log/containers/nova/nova-api.log.txt.gz#_2018-05-02_01_12_46_021

middle request that takes time:- https://logs.rdoproject.org/openstack-periodic/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-queens/f7a11fa/overcloud-controller-0/var/log/containers/nova/nova-api.log.txt.gz#_2018-05-02_01_12_49_897 3.874891
Good to find why this request is taking around 4 seconds, is this expected.

2nd request:- https://logs.rdoproject.org/openstack-periodic/periodic-tripleo-ci-centos-7-ovb-1ctlr_1comp-featureset020-queens/f7a11fa/overcloud-controller-0/var/log/containers/nova/nova-api.log.txt.gz#_2018-05-02_01_12_50_111

Emilien Macchi (emilienm)
Changed in tripleo:
milestone: rocky-2 → rocky-3
Emilien Macchi (emilienm)
Changed in tripleo:
milestone: rocky-3 → rocky-rc1
Alex Schultz (alex-schultz)
Changed in tripleo:
milestone: rocky-rc1 → stein-1
Juan Antonio Osorio Robles (juan-osorio-robles)
Changed in tripleo:
milestone: stein-1 → stein-2
Emilien Macchi (emilienm)
Changed in tripleo:
milestone: stein-2 → stein-3
Alex Schultz (alex-schultz)
Changed in tripleo:
milestone: stein-3 → stein-rc1
Alex Schultz (alex-schultz)
Changed in tripleo:
milestone: stein-rc1 → train-1
Alex Schultz (alex-schultz)
Changed in tripleo:
milestone: train-1 → train-2
Alex Schultz (alex-schultz)
Changed in tripleo:
milestone: train-2 → train-3
Alex Schultz (alex-schultz)
Changed in tripleo:
milestone: train-3 → ussuri-1
Emilien Macchi (emilienm)
Changed in tripleo:
milestone: ussuri-1 → ussuri-2
wes hayutin (weshayutin)
tags: added: tempest
wes hayutin (weshayutin)
Changed in tripleo:
milestone: ussuri-2 → ussuri-3
wes hayutin (weshayutin)
Changed in tripleo:
status: Triaged → Incomplete
wes hayutin (weshayutin)
Changed in tripleo:
milestone: ussuri-3 → ussuri-rc3
wes hayutin (weshayutin)
Changed in tripleo:
milestone: ussuri-rc3 → victoria-1
Emilien Macchi (emilienm)
Changed in tripleo:
milestone: victoria-1 → victoria-3
Kevin Carter (kevin-carter)
Changed in tripleo:
status: Incomplete → Fix Committed
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

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