Bug 1224212 - Migration finished with session_timeout and proxy_request_timeout set to 0 (installer fails, cannot sign in)
Summary: Migration finished with session_timeout and proxy_request_timeout set to 0 (i...
Status: CLOSED WONTFIX
Alias: None
Product: Red Hat Satellite 6
Classification: Red Hat
Component: Installer
Version: 6.1.0
Hardware: Unspecified
OS: Unspecified
unspecified
high vote
Target Milestone: Unspecified
Assignee: Katello Bug Bin
QA Contact: Sachin Ghai
URL: http://projects.theforeman.org/issues...
Whiteboard:
Keywords:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2015-05-22 10:41 UTC by Sachin Ghai
Modified: 2017-02-23 19:59 UTC (History)
3 users (show)

(edit)
Clone Of:
(edit)
Last Closed: 2015-05-29 15:44:01 UTC


Attachments (Terms of Use)
foreman-debug (256.91 KB, application/x-xz)
2015-05-22 10:45 UTC, Sachin Ghai
no flags Details


External Trackers
Tracker ID Priority Status Summary Last Updated
Foreman Issue Tracker 8657 None None None 2016-04-22 16:18 UTC

Description Sachin Ghai 2015-05-22 10:41:44 UTC
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:

Comment 1 Sachin Ghai 2015-05-22 10:42:54 UTC
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

Comment 2 Sachin Ghai 2015-05-22 10:45:58 UTC
Created attachment 1028691 [details]
foreman-debug

Comment 4 Lukas Zapletal 2015-05-22 11:40:05 UTC
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?

Comment 5 Lukas Zapletal 2015-05-22 12:13:16 UTC
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)

Comment 6 Lukas Zapletal 2015-05-22 12:30:10 UTC
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"

Comment 8 Lukas Zapletal 2015-05-22 12:40:24 UTC
WORKAROUND:

foreman-rake config -- -k idle_timeout -v 60
foreman-rake config -- -k proxy_request_timeout -v 99

Comment 9 Lukas Zapletal 2015-05-22 13:00:01 UTC
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?

Comment 10 Ivan Necas 2015-05-25 09:18:22 UTC
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 :(

Comment 11 Bryan Kearney 2015-05-29 15:44:01 UTC
Closing this now. If we see it more, and can recreate it, please open this back up or opena new one.


Note You need to log in before you can comment on or make changes to this bug.