Description of problem: Katello installer with sat6.1 GA snap5 compose2 failed with error: The full log is at /var/log/katello-installer/katello-installer.log [ INFO 2015-05-22 06:33:23 verbose] All hooks in group post finished [ERROR 2015-05-22 06:33:23 verbose] Repeating errors encountered during run: [ERROR 2015-05-22 06:33:23 verbose] Could not set 'present' on ensure: 422 Unprocessable Entity at 12:/usr/share/katello-installer/modules/foreman_proxy/manifests/register.pp [ERROR 2015-05-22 06:33:23 verbose] Could not set 'present' on ensure: 422 Unprocessable Entity at 12:/usr/share/katello-installer/modules/foreman_proxy/manifests/register.pp [ERROR 2015-05-22 06:33:23 verbose] /Stage[main]/Foreman_proxy::Register/Foreman_smartproxy[cloud-qe-9.idmqe.lab.eng.bos.redhat.com]/ensure: change from absent to present failed: Could not set 'present' on ensure: 422 Unprocessable Entity at 12:/usr/share/katello-installer/modules/foreman_proxy/manifests/register.pp Version-Release number of selected component (if applicable): sat6.1 GA snap5 compose2 How reproducible: tried two times Steps to Reproduce: 1. katello-installer -v -d --foreman-admin-password changeme 2. 3. Actual results: Expected results: installer should succeed Additional info:
Exception from installer.log [ERROR 2015-05-22 06:33:21 verbose] Could not set 'present' on ensure: 422 Unprocessable Entity at 12:/usr/share/katello-installer/modules/foreman_proxy/manifests/register.pp [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/abstract_response.rb:48:in `return!' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:230:in `process_result' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:178:in `block in transmit' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/net/http.rb:852:in `start' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:172:in `transmit' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:64:in `execute' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:33:in `execute' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/resource.rb:67:in `post' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/api.rb:279:in `call_client' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/api.rb:210:in `http_call' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/api.rb:160:in `call' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/resource.rb:14:in `call' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/katello-installer/modules/foreman/lib/puppet/provider/foreman_smartproxy/rest_v2.rb:44:in `create' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/property/ensure.rb:16:in `block in defaultvalues' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/property.rb:197:in `call_valuemethod' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/property.rb:498:in `set' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/property.rb:581:in `sync' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:191:in `sync' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:128:in `sync_if_needed' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:81:in `perform_changes' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:20:in `evaluate' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:174:in `apply' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:187:in `eval_resource' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:117:in `call' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:117:in `block (2 levels) in evaluate' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:327:in `block in thinmark' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/benchmark.rb:296:in `realtime' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:326:in `thinmark' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:117:in `block in evaluate' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/graph/relationship_graph.rb:118:in `traverse' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:108:in `evaluate' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/resource/catalog.rb:167:in `block in apply' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util/log.rb:149:in `with_destination' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/report.rb:112:in `as_logging_destination' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/resource/catalog.rb:166:in `apply' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/configurer.rb:117:in `block in apply_catalog' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:161:in `block in benchmark' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/benchmark.rb:296:in `realtime' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:160:in `benchmark' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/configurer.rb:116:in `apply_catalog' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/configurer.rb:191:in `run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application/apply.rb:288:in `apply_catalog' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application/apply.rb:228:in `block in main' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/context.rb:64:in `override' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet.rb:234:in `override' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application/apply.rb:190:in `main' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application/apply.rb:151:in `run_command' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application.rb:371:in `block (2 levels) in run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application.rb:477:in `plugin_hook' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application.rb:371:in `block in run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:479:in `exit_on_fail' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application.rb:371:in `run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util/command_line.rb:137:in `run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util/command_line.rb:91:in `execute' [ INFO 2015-05-22 06:33:21 verbose] /usr/bin/puppet:8:in `<main>' [ERROR 2015-05-22 06:33:21 verbose] Could not set 'present' on ensure: 422 Unprocessable Entity at 12:/usr/share/katello-installer/modules/foreman_proxy/manifests/register.pp [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/abstract_response.rb:48:in `return!' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:230:in `process_result' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:178:in `block in transmit' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/net/http.rb:852:in `start' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:172:in `transmit' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:64:in `execute' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:33:in `execute' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/resource.rb:67:in `post' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/api.rb:279:in `call_client' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/api.rb:210:in `http_call' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/api.rb:160:in `call' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/resource.rb:14:in `call' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/katello-installer/modules/foreman/lib/puppet/provider/foreman_smartproxy/rest_v2.rb:44:in `create' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/property/ensure.rb:16:in `block in defaultvalues' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/property.rb:197:in `call_valuemethod' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/property.rb:498:in `set' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/property.rb:581:in `sync' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:191:in `sync' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:128:in `sync_if_needed' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:81:in `perform_changes' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:20:in `evaluate' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:174:in `apply' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:187:in `eval_resource' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:117:in `call' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:117:in `block (2 levels) in evaluate' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:327:in `block in thinmark' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/benchmark.rb:296:in `realtime' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:326:in `thinmark' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:117:in `block in evaluate' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/graph/relationship_graph.rb:118:in `traverse' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:108:in `evaluate' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/resource/catalog.rb:167:in `block in apply' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util/log.rb:149:in `with_destination' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/report.rb:112:in `as_logging_destination' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/resource/catalog.rb:166:in `apply' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/configurer.rb:117:in `block in apply_catalog' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:161:in `block in benchmark' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/benchmark.rb:296:in `realtime' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:160:in `benchmark' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/configurer.rb:116:in `apply_catalog' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/configurer.rb:191:in `run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application/apply.rb:288:in `apply_catalog' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application/apply.rb:228:in `block in main' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/context.rb:64:in `override' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet.rb:234:in `override' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application/apply.rb:190:in `main' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application/apply.rb:151:in `run_command' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application.rb:371:in `block (2 levels) in run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application.rb:477:in `plugin_hook' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application.rb:371:in `block in run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:479:in `exit_on_fail' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application.rb:371:in `run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util/command_line.rb:137:in `run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util/command_line.rb:91:in `execute' [ INFO 2015-05-22 06:33:21 verbose] /usr/bin/puppet:8:in `<main>' [ INFO 2015-05-22 06:33:21 verbose] Wrapped exception: [ INFO 2015-05-22 06:33:21 verbose] 422 Unprocessable Entity [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/abstract_response.rb:48:in `return!' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:230:in `process_result' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:178:in `block in transmit' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/net/http.rb:852:in `start' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:172:in `transmit' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:64:in `execute' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:33:in `execute' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/resource.rb:67:in `post' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/api.rb:279:in `call_client' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/api.rb:210:in `http_call' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/api.rb:160:in `call' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/resource.rb:14:in `call' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/katello-installer/modules/foreman/lib/puppet/provider/foreman_smartproxy/rest_v2.rb:44:in `create' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/property/ensure.rb:16:in `block in defaultvalues' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/property.rb:197:in `call_valuemethod' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/property.rb:498:in `set' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/property.rb:581:in `sync' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:191:in `sync' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:128:in `sync_if_needed' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:81:in `perform_changes' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:20:in `evaluate' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:174:in `apply' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:187:in `eval_resource' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:117:in `call' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:117:in `block (2 levels) in evaluate' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:327:in `block in thinmark' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/benchmark.rb:296:in `realtime' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:326:in `thinmark' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:117:in `block in evaluate' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/graph/relationship_graph.rb:118:in `traverse' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction.rb:108:in `evaluate' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/resource/catalog.rb:167:in `block in apply' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util/log.rb:149:in `with_destination' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/transaction/report.rb:112:in `as_logging_destination' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/resource/catalog.rb:166:in `apply' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/configurer.rb:117:in `block in apply_catalog' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:161:in `block in benchmark' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/benchmark.rb:296:in `realtime' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:160:in `benchmark' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/configurer.rb:116:in `apply_catalog' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/configurer.rb:191:in `run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application/apply.rb:288:in `apply_catalog' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application/apply.rb:228:in `block in main' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/context.rb:64:in `override' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet.rb:234:in `override' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application/apply.rb:190:in `main' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application/apply.rb:151:in `run_command' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application.rb:371:in `block (2 levels) in run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application.rb:477:in `plugin_hook' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application.rb:371:in `block in run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util.rb:479:in `exit_on_fail' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/application.rb:371:in `run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util/command_line.rb:137:in `run' [ INFO 2015-05-22 06:33:21 verbose] /usr/share/ruby/vendor_ruby/puppet/util/command_line.rb:91:in `execute' [ INFO 2015-05-22 06:33:21 verbose] /usr/bin/puppet:8:in `<main>' [ERROR 2015-05-22 06:33:21 verbose] /Stage[main]/Foreman_proxy::Register/Foreman_smartproxy[cloud-qe-9.idmqe.lab.eng.bos.redhat.com]/ensure: change from absent to present failed: Could not set 'present' on ensure: 422 Unprocessable Entity at 12:/usr/share/katello-installer/modules/foreman_proxy/manifests/register.pp
Created attachment 1028691 [details] foreman-debug
2015-05-22 06:33:21 [E] Unprocessable entity SmartProxy (id: new): Unable to communicate with the proxy: ERF12-2530 [ProxyAPI::ProxyException]: Unable to detect features ([RestClient:: +RequestTimeout]: Request Timeout) for proxy https://cloud-qe-9.idmqe.lab.eng.bos.redhat.com:9090/features Please check the proxy is configured and running on the host Your proxy is not running on the capsule. Firewall problem? Can you attach foreman-debug from the Capsule server?
Weird, the communication goes okay, proxy responds 200 to features, but got Timeout error in Rails. ==> /var/log/httpd/foreman-ssl_access_ssl.log <== 10.16.96.106 - - [22/May/2015:08:11:48 -0400] "GET /api/smart_proxies?search=name%3Dcloud-qe-9.idmqe.lab.eng.bos.redhat.com HTTP/1.1" 200 192 "-" "OAuth gem v0.4.7" 10.16.96.106 - - [22/May/2015:08:11:48 -0400] "POST /api/smart_proxies HTTP/1.1" 422 643 "-" "OAuth gem v0.4.7" ==> /var/log/foreman-proxy/proxy.log <== 10.16.96.106 - - [22/May/2015 08:11:48] "GET /features HTTP/1.1" 200 40 0.0004 ==> /var/log/foreman/production.log <== 2015-05-22 08:11:48 [I] Processing by Api::V2::SmartProxiesController#index as JSON 2015-05-22 08:11:48 [I] Parameters: {"search"=>"name=cloud-qe-9.idmqe.lab.eng.bos.redhat.com", "apiv"=>"v2", "smart_proxy"=>{}} 2015-05-22 08:11:48 [I] Authorized user foreman_api_admin(API Admin) 2015-05-22 08:11:48 [I] Rendered api/v2/smart_proxies/index.json.rabl within api/v2/layouts/index_layout (4.7ms) 2015-05-22 08:11:48 [I] Completed 200 OK in 22ms (Views: 7.2ms | ActiveRecord: 2.9ms) 2015-05-22 08:11:48 [I] Processing by Api::V2::SmartProxiesController#create as JSON 2015-05-22 08:11:48 [I] Parameters: {"smart_proxy"=>{"name"=>"cloud-qe-9.idmqe.lab.eng.bos.redhat.com", "url"=>"https://cloud-qe-9.idmqe.lab.eng.bos.redhat.com:9090"}, "apiv"=>"v2"} 2015-05-22 08:11:48 [I] Authorized user foreman_api_admin(API Admin) 2015-05-22 08:11:48 [E] Unprocessable entity SmartProxy (id: new): Unable to communicate with the proxy: ERF12-2530 [ProxyAPI::ProxyException]: Unable to detect features ([RestClient::RequestTimeout]: Request Timeout) for proxy https://cloud-qe-9.idmqe.lab.eng.bos.redhat.com:9090/features Please check the proxy is configured and running on the host. 2015-05-22 08:11:48 [I] Rendered api/v2/errors/unprocessable_entity.json.rabl within api/v2/layouts/error_layout (0.6ms) 2015-05-22 08:11:48 [I] Completed 422 Unprocessable Entity in 29ms (Views: 1.3ms | ActiveRecord: 2.5ms)
Both proxy_request_timeout and session_timeout are set to 0 which leads to unexpected behaviour: 1) All proxy REST calls timeouts immediately 2) When you try to log in you are logged out immediately with "Your session has expired, please login again"
Related ? http://projects.theforeman.org/issues/7579 http://projects.theforeman.org/issues/7353 https://bugzilla.redhat.com/show_bug.cgi?id=1135989
WORKAROUND: foreman-rake config -- -k idle_timeout -v 60 foreman-rake config -- -k proxy_request_timeout -v 99
Interesting erro in the postgres log: ERROR: duplicate key value violates unique constraint "index_settings_on_name" DETAIL: Key (name)=(dynflow_enable_console) already exists. STATEMENT: INSERT INTO "settings" ("category", "created_at", "default", "description", "name", "settings_type", "updated_at", "value") VALUES ($1, $2, $3, $4, $5, $6, $7, $8) RETURNING "id" It looks like our foreman-rake config tool does something incorrectly and overwrites our settings? I wonder how this is possible since we don't touch timeouts in our installer AFAIK. What we do is we create them during first start, and we do this in the single transaction: (app/models/setting/general.rb). Ivan you were building the tool and fixing the similar issue recently. Any ideas?
So far, I was not able to find the cause of the 0 in the idle_timeout, as well as the duplicate key: it's strange it's only in the postres log, nowhere else :(
Closing this now. If we see it more, and can recreate it, please open this back up or opena new one.