+--------------------------------------+------------+--------------------+----------------------+
| id | stack_name | stack_status | creation_time |
+--------------------------------------+------------+--------------------+----------------------+
| d9fc79f6-24d1-47da-b0ea-b7f8306a4d2f | overcloud | CREATE_IN_PROGRESS | 2014-04-25T13:44:56Z |
+--------------------------------------+------------+--------------------+----------------------+
of 27 nodes using nova bare-metal has run for 2.5 hours and not concluded.
from looking tough the logs we see:
heat-api.log:
2014-04-25 14:59:43.015 5186 WARNING heat.openstack.common.rpc.amqp [req-a868cae8-9aec-4ec2-bebc-e6e7f0b060d2 None] Number of call waiters is greater than warning threshold: 10. There could be a MulticallProxyWaiter leak.
heat-api-cfn.log:
2014-04-25 14:23:11.784 5208 WARNING heat.openstack.common.rpc.amqp [req-506142ca-cbd6-4203-b453-bd522104374e None] Number of call waiters is greater than warning threshold: 10. There could be a MulticallProxyWaiter leak.
heat-engine.log:
2014-04-25 14:44:28.263 5274 ERROR heat.engine.resource [-] CREATE : StructuredDeployment "NovaCompute25Config" Stack "overcloud" [d9fc79f6-24d1-47da-b0ea-b7f8306a4d2f]
2014-04-25 14:44:28.263 5274 TRACE heat.engine.resource Traceback (most recent call last):
2014-04-25 14:44:28.263 5274 TRACE heat.engine.resource File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/heat/engine/resource.py", line 387, in _do_action
2014-04-25 14:44:28.263 5274 TRACE heat.engine.resource pre_func()
2014-04-25 14:44:28.263 5274 TRACE heat.engine.resource File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/heat/engine/properties.py", line 314, in validate
2014-04-25 14:44:28.263 5274 TRACE heat.engine.resource raise exception.StackValidationFailed(message=msg)
2014-04-25 14:44:28.263 5274 TRACE heat.engine.resource StackValidationFailed: Property error : NovaCompute25Config: input_values The server could not comply with the request since it is either malformed or otherwise incorrect. (HTTP 400) (Request-ID: req-c65df80b-91ec-416d-b9e2-3a3092b6df11)
2014-04-25 14:44:28.263 5274 TRACE heat.engine.resource
2014-04-25 14:44:30.031 5274 WARNING heat.common.keystoneclient [req-af57f763-4549-4198-adff-94480e80935d None] stack_user_domain ID not set in heat.conf falling back to using default
2014-04-25 14:44:30.864 5274 WARNING heat.common.keystoneclient [req-bd0d54d1-15d8-4e89-8b29-262c26838bf3 None] stack_user_domain ID not set in heat.conf falling back to using default
2014-04-25 14:44:31.476 5274 WARNING heat.common.keystoneclient [req-54c93cff-0486-4321-aaaf-7bbe6cfe0523 None] stack_user_domain ID not set in heat.conf falling back to using default
2014-04-25 14:44:31.615 5274 ERROR heat.openstack.common.db.sqlalchemy.session [-] DB exception wrapped.
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session Traceback (most recent call last):
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/heat/openstack/common/db/sqlalchemy/session.py", line 439, in _wrap
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session return f(self, *args, **kwargs)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/heat/openstack/common/db/sqlalchemy/session.py", line 705, in flush
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session return super(Session, self).flush(*args, **kwargs)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 1903, in flush
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session self._flush(objects)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 2021, in _flush
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session transaction.rollback(_capture_exception=True)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 57, in __exit__
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session compat.reraise(exc_type, exc_value, exc_tb)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 1985, in _flush
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session flush_context.execute()
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 370, in execute
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session rec.execute(self)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 523, in execute
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session uow
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 59, in save_obj
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session mapper, table, update)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 510, in _emit_update_statements
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session execute(statement, params)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 720, in execute
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session return meth(self, multiparams, params)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/sql/elements.py", line 317, in _execute_on_connection
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session return connection._execute_clauseelement(self, multiparams, params)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 817, in _execute_clauseelement
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session compiled_sql, distilled_params
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 947, in _execute_context
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session context)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1108, in _handle_dbapi_exception
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session exc_info
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 185, in raise_from_cause
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session reraise(type(exception), exception, tb=exc_tb)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 940, in _execute_context
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session context)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 435, in do_execute
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session cursor.execute(statement, parameters)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/MySQLdb/cursors.py", line 205, in execute
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session self.errorhandler(self, exc, value)
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session raise errorclass, errorvalue
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session DataError: (DataError) (1406, "Data too long for column 'status_reason' at row 1") 'UPDATE stack SET status=%s, status_reason=%s WHERE stack.id = %s' ('FAILED', 'Resource CREATE failed: StackValidationFailed: Property error : NovaCompute25Config: input_values The server could not comply with the request since it is either malformed or otherwise incorrect. (HTTP 400) (Request-ID: req-c65df80b-91ec-416d-b9e2-3a3092b6df11)', 'd9fc79f6-24d1-47da-b0ea-b7f8306a4d2f')
2014-04-25 14:44:31.615 5274 TRACE heat.openstack.common.db.sqlalchemy.session
Traceback (most recent call last):
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 346, in fire_timers
timer()
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/eventlet/hubs/timer.py", line 56, in __call__
cb(*args, **kw)
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/eventlet/greenthread.py", line 194, in main
result = function(*args, **kwargs)
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/heat/engine/service.py", line 498, in _stack_create
stack.create()
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/heat/engine/parser.py", line 456, in create
creator(timeout=self.timeout_secs())
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/heat/engine/scheduler.py", line 142, in __call__
self.run_to_completion(wait_time=wait_time)
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/heat/engine/scheduler.py", line 204, in run_to_completion
while not self.step():
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/heat/engine/scheduler.py", line 190, in step
next(self._runner)
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/heat/engine/scheduler.py", line 284, in wrapper
subtask = parent.throw(*sys.exc_info())
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/heat/engine/parser.py", line 501, in stack_task
self.state_set(action, stack_status, reason)
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/heat/engine/parser.py", line 414, in state_set
'status_reason': reason})
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/heat/db/sqlalchemy/models.py", line 74, in update_and_save
session.commit()
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 765, in commit
self.transaction.commit()
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 370, in commit
self._prepare_impl()
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 350, in _prepare_impl
self.session.flush()
File "/opt/stack/venvs/heat/local/lib/python2.7/site-packages/heat/openstack/common/db/sqlalchemy/session.py", line 461, in _wrap
raise exception.DBError(e)
DBError: (DataError) (1406, "Data too long for column 'status_reason' at row 1") 'UPDATE stack SET status=%s, status_reason=%s WHERE stack.id = %s' ('FAILED', 'Resource CREATE failed: StackValidationFailed: Property error : NovaCompute25Config: input_values The server could not comply with the request since it is either malformed or otherwise incorrect. (HTTP 400) (Request-ID: req-c65df80b-91ec-416d-b9e2-3a3092b6df11)', 'd9fc79f6-24d1-47da-b0ea-b7f8306a4d2f')
This patch was applied to heat: http://review.openstack.org/r/I80be5d3de8744813d974f2e9860c148ad258f385 and all it dependent
Heat sha1 at: ed84893b7dfda14a94b9d507baf14df2e33ca8e0
This can be re-produce by making sure all real H/W is powered off before deploying