[Fuel 9.1]: redeployment failed at workloads_collector_add/20

[Jianghua Wang]

How to reproduce:
 Initial state: a deployment env which has 1 controller node + 4 compute nodes

 Action: added two compute nodes into this env and click on redeployment.

 Issue: Deployment failed with the following errors:
Error
Deployment has failed. All nodes are finished. Failed tasks: Task[workloads_collector_add/20] Stopping the deployment process!

Looks like failed to change project's description from 'Tenant for the openstack services' to '':

2017-01-16 09:32:55 +0000 /Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]/description (notice): description changed 'Tenant for the openstack services' to ''

  2017-01-16 09:32:55 +0000 Puppet (debug): Executing '/usr/local/bin/openstack project set cd10359f076a4e138f80d8427a13cb30 --description='
2017-01-16 09:32:56 +0000 Puppet::Type::Keystone_tenant::ProviderOpenstack (debug): Non-fatal error: 'Execution of '/usr/local/bin/openstack project set cd10359f076a4e138f80d8427a13cb30 --description=' returned 1: {} does not have enough properties (HTTP 400) (Request-ID: req-5a568120-2f59-4081-abdd-a8e834a71c79)'. Retrying for 169 more seconds
....
2017-01-16 09:35:46 +0000 Puppet (debug): Executing '/usr/local/bin/openstack project set cd10359f076a4e138f80d8427a13cb30 --description='
2017-01-16 09:35:47 +0000 /Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services] (err): Could not evaluate: Execution of '/usr/local/bin/openstack project set cd10359f076a4e138f80d8427a13cb30 --description=' returned 1: {} does not have enough properties (HTTP 400) (Request-ID: req-b5f6cfcd-da12-49b0-affc-c201f96d68ff) (tried 41, for a total of 170 seconds)

===
The traceback:

2017-01-16T09:38:50.741815+00:00 debug: Executing '/usr/local/bin/openstack project set cd10359f076a4e138f80d8427a13cb30 --description='
2017-01-16T09:38:51.908587+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) Could not evaluate: Execution of '/usr/local/bin/openstack project set cd10359f076a4e138f80d8427a13cb30 --description=' returned 1: {} does not have enough properties (HTTP 400) (Request-ID: req-932deda4-cc44-4679-b3dd-dcaa1db03197) (tried 41, for a total of 170 seconds)
2017-01-16T09:38:51.908587+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /etc/puppet/modules/openstacklib/lib/puppet/provider/openstack.rb:125:in `rescue in block (2 levels) in request'
2017-01-16T09:38:51.908587+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /etc/puppet/modules/openstacklib/lib/puppet/provider/openstack.rb:87:in `block (2 levels) in request'
2017-01-16T09:38:51.908587+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /etc/puppet/modules/openstacklib/lib/puppet/provider/openstack.rb:86:in `loop'
2017-01-16T09:38:51.908587+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /etc/puppet/modules/openstacklib/lib/puppet/provider/openstack.rb:86:in `block in request'
2017-01-16T09:38:51.908587+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/util.rb:43:in `withenv'
2017-01-16T09:38:51.908848+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /etc/puppet/modules/openstacklib/lib/puppet/provider/openstack.rb:81:in `request'
2017-01-16T09:38:51.908848+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /etc/puppet/modules/openstacklib/lib/puppet/provider/openstack/auth.rb:42:in `request'
2017-01-16T09:38:51.908848+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /etc/puppet/modules/keystone/lib/puppet/provider/keystone.rb:241:in `request'
2017-01-16T09:38:51.908848+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /etc/puppet/modules/keystone/lib/puppet/provider/keystone_tenant/openstack.rb:128:in `flush'
2017-01-16T09:38:51.908848+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/type.rb:990:in `flush'
2017-01-16T09:38:51.908848+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:24:in `evaluate'
2017-01-16T09:38:51.908848+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:204:in `apply'
2017-01-16T09:38:51.908848+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:217:in `eval_resource'
2017-01-16T09:38:51.908848+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:147:in `call'
2017-01-16T09:38:51.908848+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:147:in `block (2 levels) in evaluate'
2017-01-16T09:38:51.908848+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/util.rb:335:in `block in thinmark'
2017-01-16T09:38:51.909166+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/1.9.1/benchmark.rb:295:in `realtime'
2017-01-16T09:38:51.909166+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/util.rb:334:in `thinmark'
2017-01-16T09:38:51.909166+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:147:in `block in evaluate'
2017-01-16T09:38:51.909166+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/graph/relationship_graph.rb:118:in `traverse'
2017-01-16T09:38:51.909166+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:138:in `evaluate'
2017-01-16T09:38:51.909166+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:169:in `block in apply'
2017-01-16T09:38:51.909166+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/util/log.rb:149:in `with_destination'
2017-01-16T09:38:51.909191+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/transaction/report.rb:112:in `as_logging_destination'
2017-01-16T09:38:51.909191+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:168:in `apply'
2017-01-16T09:38:51.909191+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:120:in `block in apply_catalog'
2017-01-16T09:38:51.909191+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/util.rb:161:in `block in benchmark'
2017-01-16T09:38:51.909191+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/1.9.1/benchmark.rb:295:in `realtime'
2017-01-16T09:38:51.909191+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/util.rb:160:in `benchmark'
2017-01-16T09:38:51.909498+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:119:in `apply_catalog'
2017-01-16T09:38:51.909498+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:227:in `run_internal'
2017-01-16T09:38:51.909498+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:134:in `block in run'
2017-01-16T09:38:51.909498+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/context.rb:64:in `override'
2017-01-16T09:38:51.909498+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet.rb:246:in `override'
2017-01-16T09:38:51.909498+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:133:in `run'
2017-01-16T09:38:51.909498+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:302:in `apply_catalog'
2017-01-16T09:38:51.909559+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:236:in `block in main'
2017-01-16T09:38:51.909559+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/context.rb:64:in `override'
2017-01-16T09:38:51.909559+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet.rb:246:in `override'
2017-01-16T09:38:51.909559+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:198:in `main'
2017-01-16T09:38:51.909559+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:159:in `run_command'
2017-01-16T09:38:51.909559+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/application.rb:381:in `block (2 levels) in run'
2017-01-16T09:38:51.909559+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/application.rb:507:in `plugin_hook'
2017-01-16T09:38:51.909559+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/application.rb:381:in `block in run'
2017-01-16T09:38:51.909559+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/util.rb:496:in `exit_on_fail'
2017-01-16T09:38:51.910004+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/application.rb:381:in `run'
2017-01-16T09:38:51.910004+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/util/command_line.rb:146:in `run'
2017-01-16T09:38:51.910004+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/lib/ruby/vendor_ruby/puppet/util/command_line.rb:92:in `execute'
2017-01-16T09:38:51.910004+00:00 err: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) /usr/bin/puppet:8:in `<main>'
2017-01-16T09:38:51.910448+00:00 info: (/Stage[main]/Openstack::Workloads_collector/Keystone_tenant[services]) Evaluated in 171.99 seconds

[Oleksiy Molchanov (omolchanov)]

Please attach diagnostic snapshot, marking as Incomplete.

[Jianghua Wang (wjh-fresh)]

Oleksiy, I'm not able to upload the diagnostic snapshot. Always timeout near to finish uploading. So I uploaded the file at here:
https://citrix.sharefile.com/d-sdce25ba52da4ba59

Please help to check. Please note: i've removed the logs for several compute nodes due to the large size. If need more log, just let me know. thanks.

[Jianghua Wang (wjh-fresh)]

It looks like puppet gets the description for the tenant of "services" is empty. And the existing value in the environment is "Tenant for the openstack services"; So when it tries to ensure the resources, it will try to change it to empty, but which seems be treated as failure.

Some questions at here: how does fuel/puppet get the description value for the tenant of "services". Where is it configured?

[Jianghua Wang (wjh-fresh)]

When the description is empty, it shouldn't use the command:
"openstack project set cd10359f076a4e138f80d8427a13cb30 --description="
to set this property. The result is that it will keep the previous value. I think that's why ensuring resource failed.
root@node-20:/var/log# openstack project show services
+-------------+-----------------------------------+
| Field | Value |
+-------------+-----------------------------------+
| description | Tenant for the openstack services |
| enabled | True |
| id | cd10359f076a4e138f80d8427a13cb30 |
| name | services |
| properties | |
+-------------+-----------------------------------+
root@node-20:/var/log# openstack project set cd10359f076a4e138f80d8427a13cb30 --description=""
root@node-20:/var/log# openstack project show services
+-------------+-----------------------------------+
| Field | Value |
+-------------+-----------------------------------+
| description | Tenant for the openstack services |
| enabled | True |
| id | cd10359f076a4e138f80d8427a13cb30 |
| name | services |
| properties | |
+-------------+-----------------------------------+
root@node-20:/var/log#

[Jianghua Wang (wjh-fresh)]

I verified the following workaround:
  If I empty the description before the redeployment, it will be ok. As it won't try to update this property due to no change.

[Jianghua Wang (wjh-fresh)]

Per the source code, it's true that the OSC will use the existing "description" if the value passed from command line is empty.
https://github.com/openstack/python-openstackclient/blob/master/openstackclient/identity/v2_0/project.py#L219

So this field shouldn't be empty.

[Oleksiy Molchanov (omolchanov)]

Hi Jianghua,

Please try 9.2

[Tarik Riley (laceth)]

This has happend to me on [root@fuel network-scripts]# fuel2 --fuel-version
api: '1'
auth_required: true
feature_groups: []
openstack_version: mitaka-9.0
release: '9.2'

What is the fix for this issue ?