stack failed to reach DELETE_COMPLETE status (timeout)

[Emilien Macchi]

Puppet OpenStack CI is frequently failing on Heat tempest tests, when deleting a stack:

http://logs.openstack.org/67/373967/2/check/gate-puppet-openstack-integration-3-scenario003-tempest-centos-7/a7960f6/console.html#_2016-09-21_15_01_51_162438

Details: Stack tempest-heat-1257562728 failed to reach DELETE_COMPLETE status (current: DELETE_IN_PROGRESS) within the required time (1200 s).

We're reaching the 1200s timeout!

All the logs are available here:
http://logs.openstack.org/67/373967/2/check/gate-puppet-openstack-integration-3-scenario003-tempest-centos-7/a7960f6/logs/

But we need to carefully look this Heat Engine error:
http://logs.openstack.org/67/373967/2/check/gate-puppet-openstack-integration-3-scenario003-tempest-centos-7/a7960f6/logs/heat/heat-engine.txt.gz#_2016-09-21_14_41_38_553

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/374340

[Zane Bitter (zaneb)]

Logstash query:

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22DBReferenceError%3A%20(pymysql.err.IntegrityError)%20(1452%2C%20u'Cannot%20add%20or%20update%20a%20child%20row%3A%20a%20foreign%20key%20constraint%20fails%20(%60heat%60.%60stack%60%2C%20CONSTRAINT%20%60stack_ibfk_3%60%5C%22

[Zane Bitter (zaneb)]

The patch I had actually fixed a different foreign key constraint error (which I raised as bug 1626256). So I have no idea what's causing this one:

DBReferenceError: (pymysql.err.IntegrityError) (1452, u'Cannot add or update a child row: a foreign key constraint fails (`heat`.`stack`, CONSTRAINT `stack_ibfk_3` FOREIGN KEY (`user_creds_id`) REFERENCES `user_creds` (`id`))') [SQL: u'UPDATE stack SET action=%s, status=%s, status_reason=%s, name=%s, raw_template_id=%s, prev_raw_template_id=%s, username=%s, tenant=%s, user_creds_id=%s, owner_id=%s, parent_resource_name=%s, timeout=%s, disable_rollback=%s, stack_user_project_id=%s, backup=%s, nested_depth=%s, convergence=%s, current_traversal=%s, current_deps=%s, updated_at=%s WHERE stack.id = %s AND stack.current_traversal = %s'] [parameters: ('DELETE', 'IN_PROGRESS', 'Stack DELETE started', u'tempest-heat-1257562728', 3, 2, u'tempest-StacksTestJSON-160219659', u'41e181c888d94e63a6d2b584b2de5116', 1, None, None, 60, 1, u'd46670b1041c49e9883bafaf3303db08', 0, 0, 1, '66cede28-8848-4f4b-83c3-66e574866564', '{"edges": []}', datetime.datetime(2016, 9, 21, 14, 41, 38, 457816), u'4260505e-8c52-4486-aeb6-dcaceef59d13', u'66cede28-8848-4f4b-83c3-66e574866564')]

The user_creds ID is 1, and evidently that entry does not exist in the DB.

[OpenStack Infra (hudson-openstack)]

Related fix proposed to branch: master
Review: https://review.openstack.org/374440

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/374440
Committed: https://git.openstack.org/cgit/openstack/heat/commit/?id=e1f161a19a9eef3edb05612aad905e2e7ae7c674
Submitter: Jenkins
Branch: master

commit e1f161a19a9eef3edb05612aad905e2e7ae7c674
Author: Crag Wolfe <email address hidden>
Date: Wed Sep 21 19:06:36 2016 -0400

    Do not attempt deletion of a DELETE_COMPLETE stack in service api

    A stack may be in transient state where it is DELETE_COMPLETE, but has
    has not actually been soft-deleted yet. For the purposes of
    delete_stack in service.py, consider a DELETE_COMPLETE stack as
    equivalent to a soft-deleted one (it soon will be), thereby avoiding a
    race where we would have attempted to update the stack, running into a
    foreign-key constraint issue for a non-existing user_cred.

    Change-Id: Iec021e6a0df262d447fdf9ee1789603c7a1c55f8
    Closes-Bug: #1626173
    Closes-Bug: #1626107

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/newton
Review: https://review.openstack.org/374918

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/374918
Committed: https://git.openstack.org/cgit/openstack/heat/commit/?id=fb26ec9da5ee6fd051d3d0b39588972ecc86f1d9
Submitter: Jenkins
Branch: stable/newton

commit fb26ec9da5ee6fd051d3d0b39588972ecc86f1d9
Author: Crag Wolfe <email address hidden>
Date: Wed Sep 21 19:06:36 2016 -0400

    Do not attempt deletion of a DELETE_COMPLETE stack in service api

    A stack may be in transient state where it is DELETE_COMPLETE, but has
    has not actually been soft-deleted yet. For the purposes of
    delete_stack in service.py, consider a DELETE_COMPLETE stack as
    equivalent to a soft-deleted one (it soon will be), thereby avoiding a
    race where we would have attempted to update the stack, running into a
    foreign-key constraint issue for a non-existing user_cred.

    Change-Id: Iec021e6a0df262d447fdf9ee1789603c7a1c55f8
    Closes-Bug: #1626173
    Closes-Bug: #1626107
    (cherry picked from commit e1f161a19a9eef3edb05612aad905e2e7ae7c674)

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/heat 7.0.0.0rc2 release candidate.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/heat 7.0.0 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/heat 8.0.0.0b1 development milestone.