[nailgun] [stats] ERROR update_action_log failed

[Aleksey Kasatkin]

{"build_id": "2014-12-26_14-25-46", "ostf_sha": "a9afb68710d809570460c29d6c3293219d3624d4", "build_number": "58", "auth_required": true, "api": "1.0", "nailgun_sha": "5f91157daa6798ff522ca9f6d34e7e135f150a90", "production": "docker", "fuelmain_sha": "81d38d6f2903b5a8b4bee79ca45a54b76c1361b8", "astute_sha": "16b252d93be6aaa73030b8100cf8c5ca6a970a91", "feature_groups": ["mirantis"], "release": "6.0", "release_versions": {"2014.2-6.0": {"VERSION": {"build_id": "2014-12-26_14-25-46", "ostf_sha": "a9afb68710d809570460c29d6c3293219d3624d4", "build_number": "58", "api": "1.0", "nailgun_sha": "5f91157daa6798ff522ca9f6d34e7e135f150a90", "production": "docker", "fuelmain_sha": "81d38d6f2903b5a8b4bee79ca45a54b76c1361b8", "astute_sha": "16b252d93be6aaa73030b8100cf8c5ca6a970a91", "feature_groups": ["mirantis"], "release": "6.0", "fuellib_sha": "fde8ba5e11a1acaf819d402c645c731af450aff0"}}}, "fuellib_sha": "fde8ba5e11a1acaf819d402c645c731af450aff0"}

1. Create environment (I tried with different simple configurations: 2-3 nodes, ubuntu, neutron, no additional componens).
2. Start deployment of environment.
3. ~10-15 minutes later such message appears:

2015-01-05 15:42:15 ERROR

[7f8c840ff740] (helpers) update_action_log failed: Instance '<Task at 0x45985d0>' has been deleted, or its row is otherwise not present.

4. Environment is deployed successfully.

[Artem Roma (aroma-x)]

After inspection of logs from attached snapshot and many attempts to reproduce on local dev env I want to say that description of this bug is not precisely correct as the problem occurs when user try to delete empty cluster via UI.

Main reason of such issue is that in described case we end up operating inside of nailgun task manager code with task object which corresponding entry has been deleted from env. To be more precise: there is action_log updating routine in _call_silently method that exploits the instance's "cashe" attribute marked as deffered in orm terms (meaning request to db is performed when access to attribute established) after deletion of task on which the routine is dependent.

I will provide fix for the bug in a short time.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/165876
Committed: https://git.openstack.org/cgit/stackforge/fuel-web/commit/?id=1b7edb5178248b083aacf04b715faf7fd659c749
Submitter: Jenkins
Branch: master

commit 1b7edb5178248b083aacf04b715faf7fd659c749
Author: Artem Roma <email address hidden>
Date: Thu Mar 19 17:02:19 2015 +0200

    Fix error with no updating of action log after empty cluster deletion

    In case user deletes empty cluster through api, action log is not updated
    for cluster_deletion task as orm related error occurs in updating routine.
    The reason for it is that we try to operate on task instance which
    corresponding row was removed from db and hence attempt to access
    attributes, marked on model as deffered, produces mentioned error.

    This patch wraps getting of task.cache attribute into separate
    try..except block in which case we only lose update for "output" section
    of additional_info for action_log entry.

    Unit test for implemented task helper routine, modeling situation with
    referring to "deffered" attribute of instance, which corresponding db row
    was deleted, added.

    Integration test that emulates user's action leading to the bug added.

    Change-Id: Id296c403423e314dd88063883141aff661c7aa9e
    Closes-Bug: #1407716

[Andrey Sledzinskiy (asledzinskiy)]

verified on {"build_id": "2015-04-17_15-24-00",
"ostf_sha": "4bab9b975ace8d9a305d6e0f112b734de587f847",
"build_number": "321",
"release_versions": {
"2014.2-6.1": {
"VERSION": {
"build_id": "2015-04-17_15-24-00",
"ostf_sha": "4bab9b975ace8d9a305d6e0f112b734de587f847",
"build_number": "321",
"api": "1.0",
"nailgun_sha": "939e5780cd0f7b1af3afd2926eda30f81bfc3e3f",
"openstack_version": "2014.2-6.1",
"production": "docker",
"python-fuelclient_sha": "0698062e9b044becf07bf9918fa16613aa3d93ad",
"astute_sha": "bf1751a4fe0d912325e3b4af629126a59c1b2b51",
"feature_groups":
["mirantis"],
"release": "6.1",
"fuelmain_sha": "5981d230e9484c196022a027c5c1600e36b17a72",
"fuellib_sha": "65617981bef34ea96b85d2d389cc037c304516e5"}}},
"auth_required": true,
"api": "1.0",
"nailgun_sha": "939e5780cd0f7b1af3afd2926eda30f81bfc3e3f",
"openstack_version": "2014.2-6.1",
"production": "docker",
"python-fuelclient_sha": "0698062e9b044becf07bf9918fa16613aa3d93ad",
"astute_sha": "bf1751a4fe0d912325e3b4af629126a59c1b2b51",
"feature_groups":
["mirantis"],
"release": "6.1",
"fuelmain_sha": "5981d230e9484c196022a027c5c1600e36b17a72",
"fuellib_sha": "65617981bef34ea96b85d2d389cc037c304516e5"}