Reproduced.

Nodes on Director are provisioned. Task Label: Actions::Fusor::Deployment::OpenStack::Deploy fails on timeout. Output from the UI:

{"task"=>true, "poll_attempts"=>{"total"=>88, "failed"=>0}}

Director shows 6 of 7 steps completed in the overview, after I click on that it strangely shows everything checked except "Register Nodes". I can see all roles assigned and one of my nodes assigned to compute and the other to controller.

From nova-compute.log:

2016-01-06 08:43:26.638 20224 DEBUG keystoneclient.session [req-af6806ad-864d-4e46-ac72-ef61d1a9a9aa - - - - -] REQ: curl -g -i -X GET http://192.0.2.1:9696/v2.0/floatingips.json?fixed_ip_address=192.0.2.8&port_id=a4ca7b58-68ab-4fa3-9830-46c89dfb691d -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}cfee068ae1b44bd7e6e6a7166b2f7c726952dc06" _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:195
2016-01-06 08:43:26.642 20224 DEBUG keystoneclient.session [req-af6806ad-864d-4e46-ac72-ef61d1a9a9aa - - - - -] RESP: _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:224
2016-01-06 08:43:26.642 20224 DEBUG neutronclient.v2_0.client [req-af6806ad-864d-4e46-ac72-ef61d1a9a9aa - - - - -] Error message: 404 Not Found

The resource could not be found.

    _handle_fault_response /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:176

2016-01-06 08:42:26.559 20224 DEBUG keystoneclient.session [req-af6806ad-864d-4e46-ac72-ef61d1a9a9aa - - - - -] REQ: curl -g -i -X GET http://192.0.2.1:9696/v2.0/floatingips.json?fixed_ip_address=192.0.2.7&port_id=2516a6eb-bb97-4c32-bbbd-672c76f38893 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}cfee068ae1b44bd7e6e6a7166b2f7c726952dc06" _http_log_request /usr/lib/python2.7/site-packages/keystoneclient/session.py:195
2016-01-06 08:42:26.563 20224 DEBUG keystoneclient.session [req-af6806ad-864d-4e46-ac72-ef61d1a9a9aa - - - - -] RESP: _http_log_response /usr/lib/python2.7/site-packages/keystoneclient/session.py:224
2016-01-06 08:42:26.563 20224 DEBUG neutronclient.v2_0.client [req-af6806ad-864d-4e46-ac72-ef61d1a9a9aa - - - - -] Error message: 404 Not Found

The resource could not be found.

    _handle_fault_response /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:176


Found also a traceback in nova-api.log:
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack Traceback (most recent call last):
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/__init__.py", line 125, in __call__
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     return req.get_response(self.application)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/request.py", line 1296, in send
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     application, catch_exc_info=False)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/request.py", line 1260, in call_application
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     app_iter = application(self.environ, start_response)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     return resp(environ, start_response)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py", line 634, in __call__
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     return self._call_app(env, start_response)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py", line 554, in _call_app
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     return self._app(env, _fake_start_response)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     return resp(environ, start_response)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     return resp(environ, start_response)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/routes/middleware.py", line 131, in __call__
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     response = self.app(environ, start_response)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     return resp(environ, start_response)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 130, in __call__
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     resp = self.call_func(req, *args, **self.kwargs)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 195, in call_func
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     return self.func(req, *args, **kwargs)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 756, in __call__
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     content_type, body, accept)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 821, in _process_stack
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     action_result = self.dispatch(meth, request, action_args)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 911, in dispatch
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     return method(req=request, **action_args)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/contrib/floating_ips.py", line 103, in index
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     floating_ips = self.network_api.get_floating_ips_by_project(context)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/network/neutronv2/api.py", line 1252, in get_floating_ips_by_project
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     fips = client.list_floatingips(tenant_id=project_id)['floatingips']
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 102, in with_params
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     ret = self.function(instance, *args, **kwargs)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 691, in list_floatingips
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     **_params)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 307, in list
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     for r in self._pagination(collection, path, **params):
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 320, in _pagination
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     res = self.get(path, params=params)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 293, in get
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     headers=headers, params=params)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 270, in retry_request
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     headers=headers, params=params)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 211, in do_request
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     self._handle_fault_response(status_code, replybody)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 185, in _handle_fault_response
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     exception_handler_v20(status_code, des_error_body)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 83, in exception_handler_v20
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack     message=message)
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack NeutronClientException: 404 Not Found
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack
2016-01-06 08:53:57.025 20272 TRACE nova.api.openstack The resource could not be found.


From what I gather, the IPs are like so:

192.0.2.1: Director
192.0.2.7: Overcloud
192.0.2.8: probably the node

I can login to the Overcloud but it seems to be empty, there is nothing added after the installation.

While trying to reproduce this, I hit similar timeout issue:

ERROR: deployment failed with status: CREATE_FAILED and reason: Create timed out


Action:

Actions::Fusor::Deployment::OpenStack::Deploy

Input:

{"deployment_id"=>1, "locale"=>"en"}

Output:

{"task"=>false, "poll_attempts"=>{"total"=>220, "failed"=>3}}

Exception:

RuntimeError: ERROR: deployment failed with status: CREATE_FAILED and reason: Create timed out

Backtrace:

/opt/rh/ruby193/root/usr/share/gems/gems/fusor_server-0.0.1/app/lib/actions/fusor/deployment/openstack/deploy.rb:92:in `poll_external_task'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/action/polling.rb:98:in `poll_external_task_with_rescue'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/action/polling.rb:21:in `run'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/action.rb:487:in `block (3 levels) in execute_run'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/middleware/stack.rb:26:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/middleware.rb:16:in `pass'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/action/progress.rb:30:in `with_progress_calculation'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/action/progress.rb:16:in `run'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/middleware.rb:16:in `pass'
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0.73/app/lib/actions/middleware/keep_locale.rb:23:in `block in run'
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0.73/app/lib/actions/middleware/keep_locale.rb:34:in `with_locale'
/opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0.73/app/lib/actions/middleware/keep_locale.rb:23:in `run'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/middleware/world.rb:30:in `execute'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/action.rb:486:in `block (2 levels) in execute_run'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/action.rb:485:in `catch'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/action.rb:485:in `block in execute_run'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/action.rb:402:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/action.rb:402:in `block in with_error_handling'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/action.rb:402:in `catch'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/action.rb:402:in `with_error_handling'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/action.rb:480:in `execute_run'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/action.rb:262:in `execute'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:9:in `block (2 levels) in execute'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/execution_plan/steps/abstract.rb:155:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/execution_plan/steps/abstract.rb:155:in `with_meta_calculation'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:8:in `block in execute'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:22:in `open_action'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:7:in `execute'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/executors/parallel/worker.rb:20:in `block in on_message'
/opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:859:in `block in assigns'
/opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:858:in `tap'
/opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:858:in `assigns'
/opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:138:in `match_value'
/opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:116:in `block in match'
/opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:115:in `each'
/opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:115:in `match'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/executors/parallel/worker.rb:17:in `on_message'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/micro_actor.rb:82:in `on_envelope'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/micro_actor.rb:72:in `receive'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/micro_actor.rb:99:in `block (2 levels) in run'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/micro_actor.rb:99:in `loop'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/micro_actor.rb:99:in `block in run'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/micro_actor.rb:99:in `catch'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/micro_actor.rb:99:in `run'
/opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/micro_actor.rb:13:in `block in initialize'
/opt/rh/ruby193/root/usr/share/gems/gems/logging-1.8.1/lib/logging/diagnostic_context.rb:323:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/logging-1.8.1/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context'

From nova-api.log:

2016-01-08 08:34:25.276 20566 DEBUG neutronclient.v2_0.client [req-db0211af-a545-4356-8d72-661e013ff095 e4ccb487cd7f4450ae21f34732137bd1 3898b9158ca043eca697372f33b15fc2 - - -] Error message: 404 Not Found

The resource could not be found.

    _handle_fault_response /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:176
2016-01-08 08:34:25.276 20566 ERROR nova.api.openstack [req-db0211af-a545-4356-8d72-661e013ff095 e4ccb487cd7f4450ae21f34732137bd1 3898b9158ca043eca697372f33b15fc2 - - -] Caught error: 404 Not Found

The resource could not be found.

Looking at the logs earlier on the controller it looks like you assigned a non-existent interface for public access.

Confirmed this was an issue with the interface assigned for the controller nodes to use for the external network.