Sahara

Deletion of cluster could result in ERROR logs

Bug #1274739 reported by Andrew Lazarev on 2014-01-30

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	Sahara	Fix Released	Low	Andrew Lazarev	Sahara 2014.2 "juno"

Bug Description

Steps to repro:
1. Start cluster creation
2. Delete cluster before it is created

Expected behavior:
Cluster is deleted. No messages on error log level in logs.

Observed behavior:
Cluster is deleted. Errors (ERROR and WARNING) in logs.

Logs:

2014-01-30 14:46:04.162 52891 WARNING savanna.service.engine [-] Can't start cluster 'al-data-locality' (reason: Instance could not be found (HTTP 404) (Request-ID: req-74db45d0-59c3-4312-bebc-edecac0cfc64))
2014-01-30 14:46:04.203 52891 ERROR root [-] Original exception being dropped: ['Traceback (most recent call last):\n', ' File "/Users/andrew/Savanna/savanna/savanna/service/direct_engine.py", line 57, in create_cluster\n self._assign_floating_ips(instances)\n', ' File "/Users/andrew/Savanna/savanna/savanna/service/direct_engine.py", line 255, in _assign_floating_ips\n node_group.floating_ip_pool)\n', ' File "/Users/andrew/Savanna/savanna/savanna/service/networks.py", line 60, in assign_floating_ip\n nova.client().servers.get(instance_id).add_floating_ip(ip)\n', ' File "/Users/andrew/Savanna/savanna/.tox/venv/lib/python2.7/site-packages/novaclient/v1_1/servers.py", line 370, in get\n return self._get("/servers/%s" % base.getid(server), "server")\n', ' File "/Users/andrew/Savanna/savanna/.tox/venv/lib/python2.7/site-packages/novaclient/base.py", line 140, in _get\n _resp, body = self.api.client.get(url)\n', ' File "/Users/andrew/Savanna/savanna/.tox/venv/lib/python2.7/site-packages/novaclient/client.py", line 229, in get\n return self._cs_request(url, \'GET\', **kwargs)\n', ' File "/Users/andrew/Savanna/savanna/.tox/venv/lib/python2.7/site-packages/novaclient/client.py", line 213, in _cs_request\n **kwargs)\n', ' File "/Users/andrew/Savanna/savanna/.tox/venv/lib/python2.7/site-packages/novaclient/client.py", line 195, in _time_request\n resp, body = self.request(url, method, **kwargs)\n', ' File "/Users/andrew/Savanna/savanna/.tox/venv/lib/python2.7/site-packages/novaclient/client.py", line 189, in request\n raise exceptions.from_response(resp, body, url, method)\n', 'NotFound: Instance could not be found (HTTP 404) (Request-ID: req-74db45d0-59c3-4312-bebc-edecac0cfc64)\n']
2014-01-30 14:46:04.204 52891 ERROR savanna.context [-] Thread 'cluster-creating-eeb64fd0-fe02-46c7-bc5c-6538feac9335' fails with exception: 'Cluster id 'eeb64fd0-fe02-46c7-bc5c-6538feac9335' not found!'
2014-01-30 14:46:04.204 52891 TRACE savanna.context Traceback (most recent call last):
2014-01-30 14:46:04.204 52891 TRACE savanna.context File "/Users/andrew/Savanna/savanna/savanna/context.py", line 124, in _wrapper
2014-01-30 14:46:04.204 52891 TRACE savanna.context func(*args, **kwargs)
2014-01-30 14:46:04.204 52891 TRACE savanna.context File "/Users/andrew/Savanna/savanna/savanna/service/api.py", line 203, in _provision_cluster
2014-01-30 14:46:04.204 52891 TRACE savanna.context INFRA.create_cluster(cluster)
2014-01-30 14:46:04.204 52891 TRACE savanna.context File "/Users/andrew/Savanna/savanna/savanna/service/direct_engine.py", line 79, in create_cluster
2014-01-30 14:46:04.204 52891 TRACE savanna.context "status_description": str(ex)})
2014-01-30 14:46:04.204 52891 TRACE savanna.context File "/Users/andrew/Savanna/savanna/savanna/conductor/resource.py", line 40, in handle
2014-01-30 14:46:04.204 52891 TRACE savanna.context ret = func(*args, **kwargs)
2014-01-30 14:46:04.204 52891 TRACE savanna.context File "/Users/andrew/Savanna/savanna/savanna/conductor/api.py", line 88, in cluster_update
2014-01-30 14:46:04.204 52891 TRACE savanna.context values)
2014-01-30 14:46:04.204 52891 TRACE savanna.context File "/Users/andrew/Savanna/savanna/savanna/conductor/manager.py", line 165, in cluster_update
2014-01-30 14:46:04.204 52891 TRACE savanna.context return self.db.cluster_update(context, cluster, values)
2014-01-30 14:46:04.204 52891 TRACE savanna.context File "/Users/andrew/Savanna/savanna/savanna/db/api.py", line 94, in decorator
2014-01-30 14:46:04.204 52891 TRACE savanna.context res = func(*args, **kwargs)
2014-01-30 14:46:04.204 52891 TRACE savanna.context File "/Users/andrew/Savanna/savanna/savanna/db/api.py", line 132, in cluster_update
2014-01-30 14:46:04.204 52891 TRACE savanna.context return IMPL.cluster_update(context, cluster, values)
2014-01-30 14:46:04.204 52891 TRACE savanna.context File "/Users/andrew/Savanna/savanna/savanna/db/sqlalchemy/api.py", line 184, in cluster_update
2014-01-30 14:46:04.204 52891 TRACE savanna.context "Cluster id '%s' not found!")
2014-01-30 14:46:04.204 52891 TRACE savanna.context NotFoundException: Cluster id 'eeb64fd0-fe02-46c7-bc5c-6538feac9335' not found!
2014-01-30 14:46:04.204 52891 TRACE savanna.context

Andrew Lazarev (alazarev) on 2014-01-30

summary:

- [Vanilla] Deletion of cluster could result in ERROR logs
+ Deletion of cluster could result in ERROR logs

Revision history for this message

Michael McCune (mimccune) wrote on 2014-05-27:

Download full text (3.5 KiB)

I was able to reproduce this bug with a trunk version of Sahara (commit c1d6d02ab7b6c8e50bbe637d9f68832f19dbcdc6) and a stable/icehouse devstack.

The error trace was very similar for me:

2014-05-27 11:04:24.944 WARNING sahara.service.engine [-] Can't start cluster '_unknown_' (reas
on: 'NoneType' object has no attribute 'node_groups')
2014-05-27 11:04:24.944 WARNING sahara.service.engine [-] Presumably the operation failed becau
se the cluster wasdeleted by a user during the process.
2014-05-27 11:04:24.963 ERROR root [-] Original exception being dropped: ['Traceback (most rece
nt call last):\n', ' File "/home/mimccune/venvs/sahara/lib/python2.7/site-packages/sahara/serv
ice/direct_engine.py", line 65, in create_cluster\n volumes.attach(cluster)\n', ' File "/ho
me/mimccune/venvs/sahara/lib/python2.7/site-packages/sahara/service/volumes.py", line 31, in at
tach\n for node_group in cluster.node_groups:\n', "AttributeError: 'NoneType' object has no
attribute 'node_groups'\n"]
2014-05-27 11:04:24.963 ERROR sahara.context [-] Thread 'cluster-creating-5c8c707c-88cd-4fd3-8c
4b-bebdd25b9e0a' fails with exception: 'Cluster id 'None' not found!'
2014-05-27 11:04:24.963 TRACE sahara.context Traceback (most recent call last):
2014-05-27 11:04:24.963 TRACE sahara.context File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/context.py", line 120, in _wrapper
2014-05-27 11:04:24.963 TRACE sahara.context func(*args, **kwargs)
2014-05-27 11:04:24.963 TRACE sahara.context File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/service/ops.py", line 130, in _provision_cluster
2014-05-27 11:04:24.963 TRACE sahara.context INFRA.create_cluster(cluster)
2014-05-27 11:04:24.963 TRACE sahara.context File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/service/direct_engine.py", line 80, in create_cluster
2014-05-27 11:04:24.963 TRACE sahara.context "status_description": str(ex)})
2014-05-27 11:04:24.963 TRACE sahara.context File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/conductor/resource.py", line 42, in handle
2014-05-27 11:04:24.963 TRACE sahara.context ret = func(*args, **kwargs)
2014-05-27 11:04:24.963 TRACE sahara.context File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/conductor/api.py", line 88, in cluster_update
2014-05-27 11:04:24.963 TRACE sahara.context values)
2014-05-27 11:04:24.963 TRACE sahara.context File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/conductor/manager.py", line 165, in cluster_update
2014-05-27 11:04:24.963 TRACE sahara.context return self.db.cluster_update(context, cluster
, values)
2014-05-27 11:04:24.963 TRACE sahara.context File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/db/api.py", line 94, in decorator
2014-05-27 11:04:24.963 TRACE sahara.context res = func(*args, **kwargs)
2014-05-27 11:04:24.963 TRACE sahara.context File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/db/api.py", line 132, in cluster_update
2014-05-27 11:04:24.963 TRACE sahara.context return IMPL.cluster_update(context, cluster, v
alues)
2014-05-27 11:04...

I was able to reproduce this bug with a trunk version of Sahara (commit c1d6d02ab7b6c8e50bbe637d9f68832f19dbcdc6) and a stable/icehouse devstack.

The error trace was very similar for me:

2014-05-27 11:04:24.944 WARNING sahara.service.engine [-] Can't start cluster '_unknown_' (reas
on: 'NoneType' object has no attribute 'node_groups')
2014-05-27 11:04:24.944 WARNING sahara.service.engine [-] Presumably the operation failed becau
se the cluster wasdeleted by a user during the process.
2014-05-27 11:04:24.963 ERROR root [-] Original exception being dropped: ['Traceback (most rece
nt call last):\n', '  File "/home/mimccune/venvs/sahara/lib/python2.7/site-packages/sahara/serv
ice/direct_engine.py", line 65, in create_cluster\n    volumes.attach(cluster)\n', '  File "/ho
me/mimccune/venvs/sahara/lib/python2.7/site-packages/sahara/service/volumes.py", line 31, in at
tach\n    for node_group in cluster.node_groups:\n', "AttributeError: 'NoneType' object has no 
attribute 'node_groups'\n"]
2014-05-27 11:04:24.963 ERROR sahara.context [-] Thread 'cluster-creating-5c8c707c-88cd-4fd3-8c
4b-bebdd25b9e0a' fails with exception: 'Cluster id 'None' not found!'
2014-05-27 11:04:24.963 TRACE sahara.context Traceback (most recent call last):
2014-05-27 11:04:24.963 TRACE sahara.context   File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/context.py", line 120, in _wrapper
2014-05-27 11:04:24.963 TRACE sahara.context     func(*args, **kwargs)
2014-05-27 11:04:24.963 TRACE sahara.context   File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/service/ops.py", line 130, in _provision_cluster
2014-05-27 11:04:24.963 TRACE sahara.context     INFRA.create_cluster(cluster)
2014-05-27 11:04:24.963 TRACE sahara.context   File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/service/direct_engine.py", line 80, in create_cluster
2014-05-27 11:04:24.963 TRACE sahara.context     "status_description": str(ex)})
2014-05-27 11:04:24.963 TRACE sahara.context   File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/conductor/resource.py", line 42, in handle
2014-05-27 11:04:24.963 TRACE sahara.context     ret = func(*args, **kwargs)
2014-05-27 11:04:24.963 TRACE sahara.context   File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/conductor/api.py", line 88, in cluster_update
2014-05-27 11:04:24.963 TRACE sahara.context     values)
2014-05-27 11:04:24.963 TRACE sahara.context   File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/conductor/manager.py", line 165, in cluster_update
2014-05-27 11:04:24.963 TRACE sahara.context     return self.db.cluster_update(context, cluster
, values)
2014-05-27 11:04:24.963 TRACE sahara.context   File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/db/api.py", line 94, in decorator
2014-05-27 11:04:24.963 TRACE sahara.context     res = func(*args, **kwargs)
2014-05-27 11:04:24.963 TRACE sahara.context   File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/db/api.py", line 132, in cluster_update
2014-05-27 11:04:24.963 TRACE sahara.context     return IMPL.cluster_update(context, cluster, v
alues)
2014-05-27 11:04:24.963 TRACE sahara.context   File "/home/mimccune/venvs/sahara/lib/python2.7/
site-packages/sahara/db/sqlalchemy/api.py", line 185, in cluster_update
2014-05-27 11:04:24.963 TRACE sahara.context     "Cluster id '%s' not found!")
2014-05-27 11:04:24.963 TRACE sahara.context NotFoundException: Cluster id 'None' not found!
2014-05-27 11:04:24.963 TRACE sahara.context

Changed in sahara:
status:	New → Confirmed

Andrew Lazarev (alazarev) on 2014-05-27

Changed in sahara:
importance:	Undecided → Low
milestone:	none → juno-1

Sergey Lukjanov (slukjanov) on 2014-05-27

Changed in sahara:
milestone:	juno-1 → juno-2

Andrew Lazarev (alazarev) on 2014-06-06

Changed in sahara:
assignee:	nobody → Andrew Lazarev (alazarev)

OpenStack Infra (hudson-openstack) on 2014-06-06

Changed in sahara:
status:	Confirmed → In Progress

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2014-06-16: Fix merged to sahara (master)

Reviewed: https://review.openstack.org/98556
Committed: https://git.openstack.org/cgit/openstack/sahara/commit/?id=d429c22a85a8637d805a6f66716688bc3e969180
Submitter: Jenkins
Branch: master

commit d429c22a85a8637d805a6f66716688bc3e969180
Author: Andrew Lazarev <email address hidden>
Date: Fri Jun 6 16:22:02 2014 -0700

Added several checks on deleted cluster to prevent error logs

    Change-Id: I8f867d7cc89abbdf407a170344be062f00ed50a2
    Closes-Bug: #1274739
    Closes-Bug: #1286391

Changed in sahara:
status:	In Progress → Fix Committed

Russell Bryant (russellb) on 2014-07-23

Changed in sahara:
status:	Fix Committed → Fix Released

Thierry Carrez (ttx) on 2014-10-16

Changed in sahara:
milestone:	juno-2 → 2014.2

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

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