Project

General

Profile

Actions

Bug #11199

closed

Timeout and "can't convert nil into String" error building host on OpenStack

Added by Florian Faltermeier almost 9 years ago. Updated almost 9 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
-
Category:
Compute resources - OpenStack
Target version:
-
Difficulty:
Triaged:
Fixed in Releases:
Found in Releases:

Description

Hello,

If I try to create (provision image based) a VM in openstack via foreman I get the following error.

Warning!
can't convert nil into String

TypeError
can't convert nil into String
app/models/compute_resource.rb:123:in `new_vm'
app/models/concerns/orchestration/compute.rb:24:in `compute_object'
app/views/hosts/_compute.html.erb:1:in `_app_views_hosts__compute_html_erb___4488104393375261719_92442020'
app/views/hosts/_unattended.html.erb:2:in `_app_views_hosts__unattended_html_erb__120491571739639635_87843560'
app/views/hosts/_form.html.erb:91:in `block (2 levels) in app_views_hosts_form_html_erb___3625500934001102854_90903060'
app/helpers/layout_helper.rb:273:in `form_for'
app/views/hosts/_form.html.erb:8:in `block in app_views_hosts_form_html_erb___3625500934001102854_90903060'
app/models/taxonomy.rb:61:in `block (2 levels) in as_taxonomy'
app/models/concerns/foreman/thread_session.rb:147:in `as_location'
app/models/taxonomy.rb:60:in `block in as_taxonomy'
app/models/concerns/foreman/thread_session.rb:112:in `as_org'
app/models/taxonomy.rb:59:in `as_taxonomy'
app/views/hosts/_form.html.erb:6:in `_app_views_hosts__form_html_erb___3625500934001102854_90903060'
app/views/hosts/new.html.erb:3:in `_app_views_hosts_new_html_erb___436790313474086719_69941395558060'
app/controllers/application_controller.rb:269:in `process_error'
app/controllers/hosts_controller.rb:89:in `create'
app/controllers/concerns/application_shared.rb:13:in `set_timezone'
app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
lib/middleware/catch_json_parse_errors.rb:9:in `call'

Regards,
Florian

Actions #1

Updated by Dominic Cleal almost 9 years ago

  • Category set to Compute resources - OpenStack
  • Status changed from New to Need more information
  • translation missing: en.field_release deleted (62)

Which version of Foreman are you using?

Please try enabling debugging which may give us a more precise stack trace: http://projects.theforeman.org/projects/foreman/wiki/Troubleshooting#How-do-I-enable-debugging

Actions #2

Updated by Florian Faltermeier almost 9 years ago

Hello Dominic,

version is: 1.8.2

config.log is already at debug level since the last foreman startup.

TypeError
can't convert nil into String
app/models/compute_resource.rb:124:in `new_vm'
app/models/concerns/orchestration/compute.rb:24:in `compute_object'
app/views/hosts/_compute.html.erb:1:in `_app_views_hosts__compute_html_erb___3310884315948689502_88745980'
app/views/hosts/_unattended.html.erb:2:in `_app_views_hosts__unattended_html_erb___3643589429988227325_88695220'
app/views/hosts/_form.html.erb:91:in `block (2 levels) in app_views_hosts_form_html_erb___2565851531349786364_55252420'
app/helpers/layout_helper.rb:273:in `form_for'
app/views/hosts/_form.html.erb:8:in `block in app_views_hosts_form_html_erb___2565851531349786364_55252420'
app/models/taxonomy.rb:61:in `block (2 levels) in as_taxonomy'
app/models/concerns/foreman/thread_session.rb:147:in `as_location'
app/models/taxonomy.rb:60:in `block in as_taxonomy'
app/models/concerns/foreman/thread_session.rb:112:in `as_org'
app/models/taxonomy.rb:59:in `as_taxonomy'
app/views/hosts/_form.html.erb:6:in `_app_views_hosts__form_html_erb___2565851531349786364_55252420'
app/views/hosts/new.html.erb:3:in `_app_views_hosts_new_html_erb__1592766488057532756_57680620'
app/controllers/application_controller.rb:269:in `process_error'
app/controllers/hosts_controller.rb:89:in `create'
app/controllers/concerns/application_shared.rb:13:in `set_timezone'
app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
lib/middleware/catch_json_parse_errors.rb:9:in `call'

Regards,
Florian

Actions #3

Updated by Florian Faltermeier almost 9 years ago

EXCON_DEBUG=true DEBUG=true ./script/rails s
=> Booting WEBrick
=> Rails 3.2.8 application starting in development on http://0.0.0.0:3000
=> Call with -d to detach
=> Ctrl-C to shutdown server
Exiting
/opt/rh/ruby193/root/usr/share/rubygems/rubygems/dependency.rb:247:in `to_specs': Please install the sqlite3 adapter: `gem install activerecord-sqlite3-adapter` (Could not find sqlite3 (~> 1.3.5) amongst [actionmailer-3.2.8, actionpack-3.2.8, activemodel-3.2.8, activerecord-3.2.8, activeresource-3.2.8, activesupport-3.2.8, ancestry-2.0.0, apipie-rails-0.2.6, arel-3.0.2, audited-3.0.0, audited-activerecord-3.0.0, bigdecimal-1.1.0, builder-3.0.0, bundler-1.3.5, bundler_ext-0.3.0, coffee-rails-3.2.2, coffee-script-2.2.0, coffee-script-source-1.3.3, deep_cloneable-2.0.2, deface-0.7.2, diff-lcs-1.2.5, diff-lcs-1.1.3, erubis-2.7.0, excon-0.43.0, execjs-1.4.0, fast_gettext-0.9.2, fog-1.29.0, fog-aws-0.1.0, fog-brightbox-0.0.1, fog-core-1.29.0, fog-json-1.0.0, fog-radosgw-0.0.3, fog-sakuracloud-0.1.1, fog-softlayer-0.3.9, fog-xml-0.1.1, foreigner-1.7.1, foreman_bootdisk-5.0.0, foreman_setup-2.1.1, formatador-0.2.1, friendly_id-4.0.10.1, gettext_i18n_rails-1.2.1, gettext_i18n_rails_js-0.0.8, hike-1.2.1, i18n-0.6.0, i18n_data-0.2.7, io-console-0.3, ipaddress-0.8.0, journey-1.0.4, json-1.5.5, ldap_fluff-0.3.4, mail-2.4.4, mime-types-1.19, minitest-2.5.1, multi_json-1.10.1, net-http-persistent-2.7, net-ldap-0.10.0, net-scp-1.1.0, net-ssh-2.6.7, netrc-0.7.7, nokogiri-1.5.11, oauth-0.4.7, passenger-4.0.18, pg-0.12.2, po_to_json-0.0.7, polyglot-0.3.3, rabl-0.11.4, rack-1.4.1, rack-cache-1.2, rack-jsonp-1.3.1, rack-ssl-1.3.2, rack-test-0.6.1, rails-3.2.8, railties-3.2.8, rake-0.9.2.2, rbovirt-0.0.35, rdoc-3.9.5, ref-1.0.0, rest-client-1.6.7, rspec-3.2.0, rspec-core-3.2.3, rspec-expectations-3.2.1, rspec-mocks-3.2.1, rspec-puppet-2.0.1, rspec-support-3.2.2, ruby2ruby-2.1.3, ruby_parser-3.6.3, safemode-1.2.2, scoped_search-2.7.1, secure_headers-1.4.1, sexp_processor-4.4.4, sprockets-2.12.3, therubyracer-0.11.0beta5, thor-0.18.1, tilt-1.3.3, treetop-1.4.10, turbolinks-2.5.3, tzinfo-0.3.33, unf-0.1.3, unf_ext-0.0.6, uuidtools-2.1.3, validates_lengths_from_database-0.4.0, will_paginate-3.0.2]) (LoadError)
from /opt/rh/ruby193/root/usr/share/rubygems/rubygems/dependency.rb:256:in `to_spec'
from /opt/rh/ruby193/root/usr/share/rubygems/rubygems.rb:1231:in `gem'
from /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/sqlite3_adapter.rb:3:in `<top (required)>'
from /opt/rh/ruby193/root/usr/share/rubygems/rubygems/custom_require.rb:60:in `require'
from /opt/rh/ruby193/root/usr/share/rubygems/rubygems/custom_require.rb:60:in `rescue in require'
from /opt/rh/ruby193/root/usr/share/rubygems/rubygems/custom_require.rb:35:in `require'
from /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:251:in `block in require'
from /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:236:in `load_dependency'
from /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:251:in `require'
from /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/connection_specification.rb:50:in `resolve_hash_connection'
from /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/connection_specification.rb:41:in `resolve_string_connection'
from /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/connection_specification.rb:25:in `spec'
from /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/connection_specification.rb:129:in `establish_connection'
from /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/railtie.rb:82:in `block (2 levels) in <class:Railtie>'
from /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/lazy_load_hooks.rb:36:in `instance_eval'
from /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/lazy_load_hooks.rb:36:in `execute_hook'
from /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/lazy_load_hooks.rb:26:in `block in on_load'
from /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/lazy_load_hooks.rb:25:in `each'
from /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/lazy_load_hooks.rb:25:in `on_load'
from /opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/railtie.rb:74:in `block in <class:Railtie>'
from /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/initializable.rb:30:in `instance_exec'
from /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/initializable.rb:30:in `run'
from /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/initializable.rb:55:in `block in run_initializers'
from /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/initializable.rb:54:in `each'
from /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/initializable.rb:54:in `run_initializers'
from /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:136:in `initialize!'
from /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing'
from /usr/share/foreman/config/environment.rb:12:in `<top (required)>'
from /opt/rh/ruby193/root/usr/share/rubygems/rubygems/custom_require.rb:36:in `require'
from /opt/rh/ruby193/root/usr/share/rubygems/rubygems/custom_require.rb:36:in `require'
from /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:251:in `block in require'
from /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:236:in `load_dependency'
from /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:251:in `require'
from /usr/share/foreman/config.ru:4:in `block in <main>'
from /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/builder.rb:51:in `instance_eval'
from /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/builder.rb:51:in `initialize'
from /usr/share/foreman/config.ru:1:in `new'
from /usr/share/foreman/config.ru:1:in `<main>'
from /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/builder.rb:40:in `eval'
from /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/builder.rb:40:in `parse_file'
from /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/server.rb:200:in `app'
from /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/commands/server.rb:46:in `app'
from /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/server.rb:301:in `wrapped_app'
from /opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/server.rb:252:in `start'
from /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/commands/server.rb:70:in `start'
from /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/commands.rb:55:in `block in <top (required)>'
from /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/commands.rb:50:in `tap'
from /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/commands.rb:50:in `<top (required)>'
from /opt/rh/ruby193/root/usr/share/rubygems/rubygems/custom_require.rb:60:in `require'
from /opt/rh/ruby193/root/usr/share/rubygems/rubygems/custom_require.rb:60:in `rescue in require'
from /opt/rh/ruby193/root/usr/share/rubygems/rubygems/custom_require.rb:35:in `require'
from ./script/rails:6:in `<main>'

Actions #4

Updated by Dominic Cleal almost 9 years ago

Possibly uncommenting the "remove_silencers!" line in ~foreman/config/initializers/backtrace_silencers.rb would provide a bit more info - the line shown in the backtrace isn't really indicative of where the underlying error is.

If you could include the production.log from when the host is submitted, it might show if there's an issue with any of the parameters being fed in.

If you have a 1.9 release candidate to hand, I'd recommend trying on this too in case the issue has been fixed somehow.

Actions #5

Updated by Florian Faltermeier almost 9 years ago

Hi Dominic,

this output of current production log. I will try release 1.9 too.

Started GET "/tasks/c03752f3-9fdd-471f-a8d0-108fd94d8653" for 138.232.3.34 at 2015-07-27 09:39:17 +0200
2015-07-27 09:39:17 [I] Processing by TasksController#show as */*
2015-07-27 09:39:17 [I]   Parameters: {"id"=>"c03752f3-9fdd-471f-a8d0-108fd94d8653"}
2015-07-27 09:39:17 [D]   User Load (0.6ms)  SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT 1  [["id", 3]]
2015-07-27 09:39:17 [D] Setting current user thread-local variable to admin
2015-07-27 09:39:17 [D]   AuthSource Load (0.5ms)  SELECT "auth_sources".* FROM "auth_sources" WHERE "auth_sources"."id" = 1 LIMIT 1
2015-07-27 09:39:17 [I]   Rendered tasks/_list.html.erb (0.5ms)
2015-07-27 09:39:17 [I] Completed 200 OK in 7ms (Views: 1.1ms | ActiveRecord: 1.1ms)
2015-07-27 09:39:17 [W] Failed to create a compute OpenStack (OpenStack) instance radosgw-lb3.openstacklocal: connect timeout reached
 /opt/rh/ruby193/root/usr/share/gems/gems/excon-0.43.0/lib/excon/socket.rb:200:in `rescue in block in connect'
/opt/rh/ruby193/root/usr/share/gems/gems/excon-0.43.0/lib/excon/socket.rb:172:in `block in connect'
/opt/rh/ruby193/root/usr/share/gems/gems/excon-0.43.0/lib/excon/socket.rb:168:in `each'
/opt/rh/ruby193/root/usr/share/gems/gems/excon-0.43.0/lib/excon/socket.rb:168:in `connect'
/opt/rh/ruby193/root/usr/share/gems/gems/excon-0.43.0/lib/excon/socket.rb:28:in `initialize'
/opt/rh/ruby193/root/usr/share/gems/gems/excon-0.43.0/lib/excon/connection.rb:382:in `new'
/opt/rh/ruby193/root/usr/share/gems/gems/excon-0.43.0/lib/excon/connection.rb:382:in `socket'
/opt/rh/ruby193/root/usr/share/gems/gems/excon-0.43.0/lib/excon/connection.rb:105:in `request_call'
/opt/rh/ruby193/root/usr/share/gems/gems/excon-0.43.0/lib/excon/middlewares/mock.rb:47:in `request_call'
/opt/rh/ruby193/root/usr/share/gems/gems/excon-0.43.0/lib/excon/middlewares/instrumentor.rb:22:in `request_call'
/opt/rh/ruby193/root/usr/share/gems/gems/excon-0.43.0/lib/excon/middlewares/base.rb:15:in `request_call'
/opt/rh/ruby193/root/usr/share/gems/gems/excon-0.43.0/lib/excon/middlewares/base.rb:15:in `request_call'
/opt/rh/ruby193/root/usr/share/gems/gems/excon-0.43.0/lib/excon/middlewares/base.rb:15:in `request_call'
/opt/rh/ruby193/root/usr/share/gems/gems/excon-0.43.0/lib/excon/connection.rb:232:in `request'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-core-1.29.0/lib/fog/core/connection.rb:81:in `request'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-1.29.0/lib/fog/openstack/volume.rb:156:in `request'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-1.29.0/lib/fog/openstack/requests/volume/list_volumes.rb:11:in `list_volumes'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-1.29.0/lib/fog/openstack/models/volume/volumes.rb:14:in `all'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-core-1.29.0/lib/fog/core/collection.rb:113:in `lazy_load'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-core-1.29.0/lib/fog/core/collection.rb:24:in `delete'
/usr/share/foreman/app/models/compute_resources/foreman/model/openstack.rb:92:in `rescue in create_vm'
/usr/share/foreman/app/models/compute_resources/foreman/model/openstack.rb:77:in `create_vm'
/usr/share/foreman/app/models/concerns/orchestration/compute.rb:76:in `setCompute'
/usr/share/foreman/app/models/concerns/orchestration.rb:141:in `execute'
/usr/share/foreman/app/models/concerns/orchestration.rb:86:in `block in process'
/usr/share/foreman/app/models/concerns/orchestration.rb:78:in `each'
/usr/share/foreman/app/models/concerns/orchestration.rb:78:in `process'
/usr/share/foreman/app/models/concerns/orchestration.rb:19:in `on_save'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:649:in `_run__28654676772319610__save__1496898743743993230__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_save_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/callbacks.rb:264:in `create_or_update'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/persistence.rb:84:in `save'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/validations.rb:50:in `save'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/attribute_methods/dirty.rb:22:in `save'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:241:in `block (2 levels) in save'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:295:in `block in with_transaction_returning_status'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/database_statements.rb:192:in `transaction'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:208:in `transaction'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:293:in `with_transaction_returning_status'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:241:in `block in save'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:252:in `rollback_active_record_state!'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:240:in `save'
/usr/share/foreman/app/models/concerns/foreman/sti.rb:29:in `save_with_type'
/usr/share/foreman/app/controllers/hosts_controller.rb:84:in `create'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:167:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rendering.rb:10:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:18:in `block in process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:627:in `block (4 levels) in _run__316034233501250109__process_action__1957099651361085391__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7419'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in `around'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in `_callback_around_2191'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7419'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:626:in `block (3 levels) in _run__316034233501250109__process_action__1957099651361085391__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7418'
/usr/share/foreman/app/controllers/concerns/application_shared.rb:13:in `set_timezone'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7418'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:625:in `block (2 levels) in _run__316034233501250109__process_action__1957099651361085391__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7417'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7417'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:448:in `block in _run__316034233501250109__process_action__1957099651361085391__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7416'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in `around'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in `_callback_around_13'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7416'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:414:in `_run__316034233501250109__process_action__1957099651361085391__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:17:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rescue.rb:29:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:30:in `block in process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `block in instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:29:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/params_wrapper.rb:207:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:121:in `process'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/rendering.rb:45:in `process'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:203:in `dispatch'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:246:in `block in action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `dispatch'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:36:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:68:in `block in call'
/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `each'
/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:600:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/apipie-rails-0.2.6/lib/apipie/extractor/recorder.rb:97:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/apipie-rails-0.2.6/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/etag.rb:23:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/conditionalget.rb:35:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/head.rb:14:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/params_parser.rb:21:in `call'
/usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/flash.rb:242:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:205:in `context'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:200:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/cookies.rb:339:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/query_cache.rb:64:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/connection_pool.rb:473:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `_run__3769334315777394__call__1496898743743993230__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:26:in `call_app'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:16:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/cache/strategy/local_cache.rb:72:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/lock.rb:15:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:in `pass'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in `invalidate'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:in `call!'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:223:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/builder.rb:134:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:64:in `block in call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in `each'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in `call'
/usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/rack/thread_handler_extension.rb:77:in `process_request'
/usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/request_handler/thread_handler.rb:140:in `accept_and_process_next_request'
/usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/request_handler/thread_handler.rb:108:in `main_loop'
/usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/request_handler.rb:441:in `block (3 levels) in start_threads'
2015-07-27 09:39:18 [W] Rolling back due to a problem: [Set up compute instance radosgw-lb3.openstacklocal     2     failed     [#<Host::Managed id: nil, name: "radosgw-lb3.openstacklocal", last_compile: nil, last_freshcheck: nil, last_report: nil, updated_at: nil, source_file_id: nil, created_at: nil, root_pass: "$6$LymHIPGe$Mq6QWTDkWmwlR2VCuU/Yn60dVTHd85DAAjRXhdB...", serial: nil, puppet_status: 0, architecture_id: 1, operatingsystem_id: 1, environment_id: 3, ptable_id: nil, medium_id: nil, build: true, comment: "", disk: "", installed_at: nil, model_id: nil, hostgroup_id: nil, owner_id: 3, owner_type: "User", enabled: true, puppet_ca_proxy_id: 1, managed: true, use_image: nil, image_file: nil, uuid: nil, compute_resource_id: 2, puppet_proxy_id: 1, certname: nil, image_id: 2, organization_id: nil, location_id: nil, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 2, provision_method: "image", grub_pass: "$1$sLoRDTy6$j5kM13Yl5pvZK5L/EexE/.">, :setCompute]]
2015-07-27 09:39:18 [I] Remove puppet certificate for radosgw-lb3.openstacklocal
2015-07-27 09:39:19 [I] 

Started GET "/tasks/c03752f3-9fdd-471f-a8d0-108fd94d8653" for 138.232.3.34 at 2015-07-27 09:39:19 +0200
2015-07-27 09:39:19 [I] Processing by TasksController#show as */*
2015-07-27 09:39:19 [I]   Parameters: {"id"=>"c03752f3-9fdd-471f-a8d0-108fd94d8653"}
2015-07-27 09:39:19 [D]   User Load (0.2ms)  SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT 1  [["id", 3]]
2015-07-27 09:39:19 [D] Setting current user thread-local variable to admin
2015-07-27 09:39:19 [D]   AuthSource Load (0.3ms)  SELECT "auth_sources".* FROM "auth_sources" WHERE "auth_sources"."id" = 1 LIMIT 1
2015-07-27 09:39:19 [I]   Rendered tasks/_list.html.erb (0.4ms)
2015-07-27 09:39:19 [I] Completed 200 OK in 5ms (Views: 0.8ms | ActiveRecord: 0.6ms)
2015-07-27 09:39:19 [I] Delete the autosign entry for radosgw-lb3.openstacklocal
2015-07-27 09:39:19 [D]    (0.9ms)  ROLLBACK
2015-07-27 09:39:19 [D]   Organization Load (1.0ms)  SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Organization') AND "taxonomies"."id" IS NULL ORDER BY title LIMIT 1
2015-07-27 09:39:19 [D]   Location Load (0.3ms)  SELECT "taxonomies".* FROM "taxonomies" WHERE "taxonomies"."type" IN ('Location') AND "taxonomies"."id" IS NULL ORDER BY title LIMIT 1
2015-07-27 09:39:19 [D]   Architecture Load (0.4ms)  SELECT "architectures".* FROM "architectures" WHERE "architectures"."id" = 1 LIMIT 1
2015-07-27 09:39:19 [I] Failed to save: Failed to create a compute OpenStack (OpenStack) instance radosgw-lb3.openstacklocal: connect timeout reached

2015-07-27 09:39:20 [I]   Rendered hosts/_progress.html.erb (0.5ms)
2015-07-27 09:39:20 [D] Setting current organization thread-local variable to none
2015-07-27 09:39:20 [D] Setting current location thread-local variable to none
2015-07-27 09:39:20 [D]    (0.9ms)  SELECT COUNT(*) FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet')
2015-07-27 09:39:20 [D]   Hostgroup Load (0.7ms)  SELECT "hostgroups".* FROM "hostgroups" WHERE (1=1)
2015-07-27 09:39:20 [D]   ComputeResource Load (0.6ms)  SELECT "compute_resources".* FROM "compute_resources" WHERE (1=1) ORDER BY name
2015-07-27 09:39:20 [D]    (0.8ms)  SELECT COUNT(DISTINCT "compute_profiles"."id") FROM "compute_profiles" LEFT OUTER JOIN "compute_attributes" ON "compute_attributes"."compute_profile_id" = "compute_profiles"."id" WHERE (compute_attributes.id > 0)
2015-07-27 09:39:20 [D]   SQL (0.5ms)  SELECT "compute_profiles"."id" AS t0_r0, "compute_profiles"."name" AS t0_r1, "compute_profiles"."created_at" AS t0_r2, "compute_profiles"."updated_at" AS t0_r3, "compute_attributes"."id" AS t1_r0, "compute_attributes"."compute_profile_id" AS t1_r1, "compute_attributes"."compute_resource_id" AS t1_r2, "compute_attributes"."name" AS t1_r3, "compute_attributes"."vm_attrs" AS t1_r4, "compute_attributes"."created_at" AS t1_r5, "compute_attributes"."updated_at" AS t1_r6 FROM "compute_profiles" LEFT OUTER JOIN "compute_attributes" ON "compute_attributes"."compute_profile_id" = "compute_profiles"."id" WHERE (compute_attributes.id > 0) ORDER BY compute_profiles.name
2015-07-27 09:39:20 [D]   Environment Load (0.4ms)  SELECT "environments".* FROM "environments" WHERE (1=1) ORDER BY name
2015-07-27 09:39:20 [D]    (0.5ms)  SELECT COUNT(*) FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet CA') AND (1=1)
2015-07-27 09:39:20 [D]   SmartProxy Load (0.5ms)  SELECT "smart_proxies".* FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet CA') AND (1=1)
2015-07-27 09:39:20 [D]    (0.5ms)  SELECT COUNT(*) FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet') AND (1=1)
2015-07-27 09:39:20 [D]   SmartProxy Load (0.4ms)  SELECT "smart_proxies".* FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet') AND (1=1)
2015-07-27 09:39:20 [D]    (0.4ms)  SELECT COUNT(*) FROM "realms" 
2015-07-27 09:39:20 [D]    (0.3ms)  SELECT COUNT(*) FROM "config_groups" 
2015-07-27 09:39:20 [D]    (0.3ms)  SELECT "config_groups".id FROM "config_groups" INNER JOIN "host_config_groups" ON "config_groups"."id" = "host_config_groups"."config_group_id" WHERE "host_config_groups"."host_id" IS NULL AND "host_config_groups"."host_type" = 'Host::Base' ORDER BY config_groups.name
2015-07-27 09:39:20 [D]    (0.3ms)  SELECT puppetclass_id FROM "config_group_classes" WHERE "config_group_classes"."config_group_id" IN (NULL)
2015-07-27 09:39:20 [D]   Puppetclass Load (0.6ms)  SELECT DISTINCT "puppetclasses".* FROM "puppetclasses" INNER JOIN "environment_classes" ON "puppetclasses"."id" = "environment_classes"."puppetclass_id" WHERE "environment_classes"."environment_id" = 3 AND "puppetclasses"."id" IN (NULL) ORDER BY puppetclasses.name
2015-07-27 09:39:20 [I]   Rendered puppetclasses/_selectedClasses.html.erb (0.0ms)
2015-07-27 09:39:20 [D]   CACHE (0.0ms)  SELECT "config_groups".id FROM "config_groups" INNER JOIN "host_config_groups" ON "config_groups"."id" = "host_config_groups"."config_group_id" WHERE "host_config_groups"."host_id" IS NULL AND "host_config_groups"."host_type" = 'Host::Base' ORDER BY config_groups.name
2015-07-27 09:39:20 [D]   CACHE (0.0ms)  SELECT puppetclass_id FROM "config_group_classes" WHERE "config_group_classes"."config_group_id" IN (NULL)
2015-07-27 09:39:20 [D]   CACHE (0.0ms)  SELECT DISTINCT "puppetclasses".* FROM "puppetclasses" INNER JOIN "environment_classes" ON "puppetclasses"."id" = "environment_classes"."puppetclass_id" WHERE "environment_classes"."environment_id" = 3 AND "puppetclasses"."id" IN (NULL) ORDER BY puppetclasses.name
2015-07-27 09:39:20 [I]   Rendered puppetclasses/_classes_in_groups.html.erb (0.0ms)
2015-07-27 09:39:20 [D]   Puppetclass Load (5.5ms)  SELECT DISTINCT "puppetclasses".* FROM "puppetclasses" INNER JOIN "environment_classes" ON "puppetclasses"."id" = "environment_classes"."puppetclass_id" WHERE "environment_classes"."environment_id" = 3 ORDER BY puppetclasses.name
2015-07-27 09:39:20 [D]   CACHE (0.0ms)  SELECT "config_groups".id FROM "config_groups" INNER JOIN "host_config_groups" ON "config_groups"."id" = "host_config_groups"."config_group_id" WHERE "host_config_groups"."host_id" IS NULL AND "host_config_groups"."host_type" = 'Host::Base' ORDER BY config_groups.name
2015-07-27 09:39:20 [D]   CACHE (0.0ms)  SELECT puppetclass_id FROM "config_group_classes" WHERE "config_group_classes"."config_group_id" IN (NULL)
2015-07-27 09:39:20 [D]    (0.7ms)  SELECT puppetclass_id FROM "hostgroup_classes" WHERE "hostgroup_classes"."hostgroup_id" IS NULL
2015-07-27 09:39:20 [D]    (0.3ms)  SELECT puppetclass_id FROM "host_classes" WHERE "host_classes"."host_id" IS NULL
2015-07-27 09:39:20 [D]   CACHE (0.0ms)  SELECT DISTINCT "puppetclasses".* FROM "puppetclasses" INNER JOIN "environment_classes" ON "puppetclasses"."id" = "environment_classes"."puppetclass_id" WHERE "environment_classes"."environment_id" = 3 AND "puppetclasses"."id" IN (NULL) ORDER BY puppetclasses.name
2015-07-27 09:39:21 [I] 

Started GET "/tasks/c03752f3-9fdd-471f-a8d0-108fd94d8653" for 138.232.3.34 at 2015-07-27 09:39:21 +0200
2015-07-27 09:39:21 [I] Processing by TasksController#show as */*
2015-07-27 09:39:21 [I]   Parameters: {"id"=>"c03752f3-9fdd-471f-a8d0-108fd94d8653"}
2015-07-27 09:39:21 [D]   User Load (0.5ms)  SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT 1  [["id", 3]]
2015-07-27 09:39:21 [D] Setting current user thread-local variable to admin
2015-07-27 09:39:21 [D]   AuthSource Load (0.6ms)  SELECT "auth_sources".* FROM "auth_sources" WHERE "auth_sources"."id" = 1 LIMIT 1
2015-07-27 09:39:21 [I]   Rendered tasks/_list.html.erb (0.6ms)
2015-07-27 09:39:21 [I] Completed 200 OK in 7ms (Views: 1.2ms | ActiveRecord: 1.1ms)
2015-07-27 09:39:21 [I]   Rendered puppetclasses/_classes.html.erb (618.0ms)
2015-07-27 09:39:21 [I]   Rendered puppetclasses/_class_selection.html.erb (673.0ms)
2015-07-27 09:39:21 [D]    (0.6ms)  SELECT COUNT(*) FROM "domains" WHERE (1=1)
2015-07-27 09:39:21 [D]   CACHE (0.0ms)  SELECT COUNT(*) FROM "domains" WHERE (1=1)
2015-07-27 09:39:21 [D]   Domain Load (0.3ms)  SELECT "domains".* FROM "domains" WHERE (1=1) ORDER BY name
2015-07-27 09:39:21 [D]    (0.2ms)  SELECT COUNT(*) FROM "subnets" WHERE (1=1)
2015-07-27 09:39:21 [D]   CACHE (0.0ms)  SELECT COUNT(*) FROM "subnets" WHERE (1=1)
2015-07-27 09:39:21 [D]   Subnet Load (0.3ms)  SELECT "subnets".* FROM "subnets" WHERE (1=1) ORDER BY name
2015-07-27 09:39:21 [I]   Rendered nic/_base_form.html.erb (134.8ms)
2015-07-27 09:39:21 [I]   Rendered nic/_virtual_form.html.erb (2.0ms)
2015-07-27 09:39:21 [I]   Rendered nic/_provider_specific_form.html.erb (0.9ms)
2015-07-27 09:39:21 [I]   Rendered nic/manageds/_managed.html.erb (142.5ms)
2015-07-27 09:39:21 [D]   CACHE (0.0ms)  SELECT COUNT(*) FROM "domains" WHERE (1=1)
2015-07-27 09:39:21 [D]   CACHE (0.0ms)  SELECT COUNT(*) FROM "domains" WHERE (1=1)
2015-07-27 09:39:21 [D]   CACHE (0.0ms)  SELECT "domains".* FROM "domains" WHERE (1=1) ORDER BY name
2015-07-27 09:39:21 [D]   CACHE (0.0ms)  SELECT COUNT(*) FROM "subnets" WHERE (1=1)
2015-07-27 09:39:21 [D]   CACHE (0.0ms)  SELECT COUNT(*) FROM "subnets" WHERE (1=1)
2015-07-27 09:39:21 [D]   CACHE (0.0ms)  SELECT "subnets".* FROM "subnets" WHERE (1=1) ORDER BY name
2015-07-27 09:39:21 [I]   Rendered nic/_base_form.html.erb (11.5ms)
2015-07-27 09:39:21 [I]   Rendered nic/_virtual_form.html.erb (1.1ms)
2015-07-27 09:39:21 [I]   Rendered nic/_provider_specific_form.html.erb (0.2ms)
2015-07-27 09:39:21 [I]   Rendered nic/manageds/_managed.html.erb (16.0ms)
2015-07-27 09:39:21 [I]   Rendered hosts/_interfaces.html.erb (162.9ms)
2015-07-27 09:39:21 [D]   ComputeResource Exists (0.7ms)  SELECT 1 AS one FROM "compute_resources" WHERE ("compute_resources"."name" = 'OpenStack' AND "compute_resources"."id" != 2) LIMIT 1
2015-07-27 09:39:21 [I] Successfully decrypted field for Foreman::Model::Openstack OpenStack
2015-07-27 09:39:21 [D] New VM with the following options: {"flavor_ref"=>"3", "tenant_id"=>"0606e088016842678209a62850229f94", "security_groups"=>"default", "nics"=>["", "404a859e-2023-4cf8-8434-ee845f972fcd"], "network"=>"", "boot_from_volume"=>"false", "size_gb"=>"", "image_ref"=>"ab90aca7-c0ce-46f6-abaa-7280acbffd9b", "user_data"=>nil, "interfaces_attributes"=>{"0"=>{}}}
2015-07-27 09:39:21 [D]   KeyPair Load (0.5ms)  SELECT "key_pairs".* FROM "key_pairs" WHERE "key_pairs"."compute_resource_id" = 2 LIMIT 1
2015-07-27 09:39:21 [I]   Rendered hosts/_compute.html.erb (23.0ms)
2015-07-27 09:39:21 [I]   Rendered hosts/_unattended.html.erb (24.2ms)
2015-07-27 09:39:21 [D] Setting current location thread-local variable to none
2015-07-27 09:39:21 [D] Setting current organization thread-local variable to none
2015-07-27 09:39:21 [I]   Rendered hosts/_form.html.erb (1076.3ms)
2015-07-27 09:39:21 [I]   Rendered hosts/new.html.erb within layouts/application (1077.6ms)
2015-07-27 09:39:21 [W] Operation FAILED: can't convert nil into String
2015-07-27 09:39:21 [D] /opt/rh/ruby193/root/usr/share/gems/gems/fog-1.29.0/lib/fog/openstack/models/compute/server.rb:87:in `pack'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-1.29.0/lib/fog/openstack/models/compute/server.rb:87:in `user_data='
/opt/rh/ruby193/root/usr/share/gems/gems/fog-core-1.29.0/lib/fog/core/attributes.rb:118:in `block in merge_attributes'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-core-1.29.0/lib/fog/core/attributes.rb:113:in `each_pair'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-core-1.29.0/lib/fog/core/attributes.rb:113:in `merge_attributes'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-core-1.29.0/lib/fog/core/model.rb:20:in `initialize'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-1.29.0/lib/fog/openstack/models/compute/server.rb:67:in `initialize'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-core-1.29.0/lib/fog/core/collection.rb:89:in `new'
/opt/rh/ruby193/root/usr/share/gems/gems/fog-core-1.29.0/lib/fog/core/collection.rb:89:in `new'
/usr/share/foreman/app/models/compute_resource.rb:124:in `new_vm'
/usr/share/foreman/app/models/concerns/orchestration/compute.rb:24:in `compute_object'
/usr/share/foreman/app/views/hosts/_compute.html.erb:1:in `_app_views_hosts__compute_html_erb__300945704773656828_92831360'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/template.rb:145:in `block in render'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:125:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/template.rb:143:in `render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/partial_renderer.rb:265:in `render_partial'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/partial_renderer.rb:238:in `block in render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/abstract_renderer.rb:38:in `block in instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `block in instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/abstract_renderer.rb:38:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/partial_renderer.rb:237:in `render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/renderer.rb:41:in `render_partial'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/helpers/rendering_helper.rb:27:in `render'
/usr/share/foreman/app/views/hosts/_unattended.html.erb:2:in `_app_views_hosts__unattended_html_erb___3906473893301382264_92778600'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/template.rb:145:in `block in render'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:125:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/template.rb:143:in `render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/partial_renderer.rb:265:in `render_partial'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/partial_renderer.rb:238:in `block in render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/abstract_renderer.rb:38:in `block in instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `block in instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/abstract_renderer.rb:38:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/partial_renderer.rb:237:in `render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/renderer.rb:41:in `render_partial'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/helpers/rendering_helper.rb:27:in `render'
/usr/share/foreman/app/views/hosts/_form.html.erb:91:in `block (2 levels) in _app_views_hosts__form_html_erb__96513950804296097_61142580'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/helpers/capture_helper.rb:40:in `block in capture'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/helpers/capture_helper.rb:187:in `with_output_buffer'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/helpers/capture_helper.rb:40:in `capture'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/helpers/form_helper.rb:607:in `fields_for'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/helpers/form_helper.rb:378:in `form_for'
/usr/share/foreman/app/helpers/layout_helper.rb:273:in `form_for'
/usr/share/foreman/app/views/hosts/_form.html.erb:8:in `block in _app_views_hosts__form_html_erb__96513950804296097_61142580'
/usr/share/foreman/app/models/taxonomy.rb:61:in `block (2 levels) in as_taxonomy'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:147:in `as_location'
/usr/share/foreman/app/models/taxonomy.rb:60:in `block in as_taxonomy'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:112:in `as_org'
/usr/share/foreman/app/models/taxonomy.rb:59:in `as_taxonomy'
/usr/share/foreman/app/views/hosts/_form.html.erb:6:in `_app_views_hosts__form_html_erb__96513950804296097_61142580'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/template.rb:145:in `block in render'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:125:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/template.rb:143:in `render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/partial_renderer.rb:265:in `render_partial'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/partial_renderer.rb:238:in `block in render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/abstract_renderer.rb:38:in `block in instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `block in instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/abstract_renderer.rb:38:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/partial_renderer.rb:237:in `render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/renderer.rb:41:in `render_partial'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/renderer.rb:15:in `render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/helpers/rendering_helper.rb:24:in `render'
/usr/share/foreman/app/views/hosts/new.html.erb:3:in `_app_views_hosts_new_html_erb___3155044301548901448_61084920'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/template.rb:145:in `block in render'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:125:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/template.rb:143:in `render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/template_renderer.rb:47:in `block (2 levels) in render_template'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/abstract_renderer.rb:38:in `block in instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `block in instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/abstract_renderer.rb:38:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/template_renderer.rb:46:in `block in render_template'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/template_renderer.rb:54:in `render_with_layout'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/template_renderer.rb:45:in `render_template'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/template_renderer.rb:18:in `render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/renderer.rb:36:in `render_template'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_view/renderer/renderer.rb:17:in `render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/rendering.rb:110:in `_render_template'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/streaming.rb:225:in `_render_template'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/rendering.rb:103:in `render_to_body'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/renderers.rb:28:in `render_to_body'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/compatibility.rb:50:in `render_to_body'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/rendering.rb:88:in `render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rendering.rb:16:in `render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:40:in `block (2 levels) in render'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/core_ext/benchmark.rb:5:in `block in ms'
/opt/rh/ruby193/root/usr/share/ruby/benchmark.rb:295:in `realtime'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/core_ext/benchmark.rb:5:in `ms'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:40:in `block in render'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:83:in `cleanup_view_runtime'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/railties/controller_runtime.rb:24:in `cleanup_view_runtime'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:39:in `render'
/usr/share/foreman/app/controllers/application_controller.rb:269:in `process_error'
/usr/share/foreman/app/controllers/hosts_controller.rb:89:in `create'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:167:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rendering.rb:10:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:18:in `block in process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:627:in `block (4 levels) in _run__316034233501250109__process_action__1957099651361085391__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7419'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in `around'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in `_callback_around_2191'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7419'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:626:in `block (3 levels) in _run__316034233501250109__process_action__1957099651361085391__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7418'
/usr/share/foreman/app/controllers/concerns/application_shared.rb:13:in `set_timezone'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7418'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:625:in `block (2 levels) in _run__316034233501250109__process_action__1957099651361085391__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7417'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7417'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:448:in `block in _run__316034233501250109__process_action__1957099651361085391__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:215:in `block in _conditional_callback_around_7416'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:326:in `around'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:310:in `_callback_around_13'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_7416'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:414:in `_run__316034233501250109__process_action__1957099651361085391__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/callbacks.rb:17:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rescue.rb:29:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:30:in `block in process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `block in instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/notifications.rb:123:in `instrument'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/instrumentation.rb:29:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/params_wrapper.rb:207:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/base.rb:121:in `process'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/abstract_controller/rendering.rb:45:in `process'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:203:in `dispatch'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_controller/metal.rb:246:in `block in action'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:73:in `dispatch'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:36:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:68:in `block in call'
/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `each'
/opt/rh/ruby193/root/usr/share/gems/gems/journey-1.0.4/lib/journey/router.rb:56:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/routing/route_set.rb:600:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/apipie-rails-0.2.6/lib/apipie/extractor/recorder.rb:97:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/apipie-rails-0.2.6/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/etag.rb:23:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/conditionalget.rb:35:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/head.rb:14:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/params_parser.rb:21:in `call'
/usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/flash.rb:242:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:205:in `context'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:200:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/cookies.rb:339:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/query_cache.rb:64:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/connection_pool.rb:473:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `_run__3769334315777394__call__1496898743743993230__callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:26:in `call_app'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/rack/logger.rb:16:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/request_id.rb:22:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/methodoverride.rb:21:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/runtime.rb:17:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/cache/strategy/local_cache.rb:72:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/lock.rb:15:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/actionpack-3.2.8/lib/action_dispatch/middleware/static.rb:62:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:in `pass'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in `invalidate'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:in `call!'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/engine.rb:479:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:223:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in `method_missing'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/builder.rb:134:in `call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:64:in `block in call'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in `each'
/opt/rh/ruby193/root/usr/share/gems/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in `call'
/usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/rack/thread_handler_extension.rb:77:in `process_request'
/usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/request_handler/thread_handler.rb:140:in `accept_and_process_next_request'
/usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/request_handler/thread_handler.rb:108:in `main_loop'
/usr/share/gems/gems/passenger-4.0.18/lib/phusion_passenger/request_handler.rb:441:in `block (3 levels) in start_threads'
2015-07-27 09:39:21 [I]   Rendered common/500.html.erb (9.7ms)
2015-07-27 09:39:21 [I] Completed 500 Internal Server Error in 128737ms (Views: 10.8ms | ActiveRecord: 22.0ms)
2015-07-27 09:39:22 [I] 

Started GET "/hosts/new" for 138.232.3.34 at 2015-07-27 09:39:22 +0200
2015-07-27 09:39:22 [I] Processing by HostsController#new as */*
2015-07-27 09:39:22 [D]   User Load (0.4ms)  SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT 1  [["id", 3]]
2015-07-27 09:39:22 [D] Setting current user thread-local variable to admin
2015-07-27 09:39:22 [D]   AuthSource Load (0.5ms)  SELECT "auth_sources".* FROM "auth_sources" WHERE "auth_sources"."id" = 1 LIMIT 1
2015-07-27 09:39:22 [I]   Rendered hosts/_progress.html.erb (0.1ms)
2015-07-27 09:39:22 [D] Setting current organization thread-local variable to none
2015-07-27 09:39:22 [D] Setting current location thread-local variable to none
2015-07-27 09:39:22 [D]    (0.5ms)  SELECT COUNT(*) FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet')
2015-07-27 09:39:22 [D]   Hostgroup Load (0.3ms)  SELECT "hostgroups".* FROM "hostgroups" WHERE (1=1)
2015-07-27 09:39:22 [D]   ComputeResource Load (0.3ms)  SELECT "compute_resources".* FROM "compute_resources" WHERE (1=1) ORDER BY name
2015-07-27 09:39:22 [D]    (0.5ms)  SELECT COUNT(DISTINCT "compute_profiles"."id") FROM "compute_profiles" LEFT OUTER JOIN "compute_attributes" ON "compute_attributes"."compute_profile_id" = "compute_profiles"."id" WHERE (compute_attributes.id > 0)
2015-07-27 09:39:22 [D]   SQL (0.4ms)  SELECT "compute_profiles"."id" AS t0_r0, "compute_profiles"."name" AS t0_r1, "compute_profiles"."created_at" AS t0_r2, "compute_profiles"."updated_at" AS t0_r3, "compute_attributes"."id" AS t1_r0, "compute_attributes"."compute_profile_id" AS t1_r1, "compute_attributes"."compute_resource_id" AS t1_r2, "compute_attributes"."name" AS t1_r3, "compute_attributes"."vm_attrs" AS t1_r4, "compute_attributes"."created_at" AS t1_r5, "compute_attributes"."updated_at" AS t1_r6 FROM "compute_profiles" LEFT OUTER JOIN "compute_attributes" ON "compute_attributes"."compute_profile_id" = "compute_profiles"."id" WHERE (compute_attributes.id > 0) ORDER BY compute_profiles.name
2015-07-27 09:39:22 [D]   Environment Load (0.3ms)  SELECT "environments".* FROM "environments" WHERE (1=1) ORDER BY name
2015-07-27 09:39:22 [D]    (0.5ms)  SELECT COUNT(*) FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet CA') AND (1=1)
2015-07-27 09:39:22 [D]   SmartProxy Load (0.5ms)  SELECT "smart_proxies".* FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet CA') AND (1=1)
2015-07-27 09:39:22 [D]    (1.0ms)  SELECT COUNT(*) FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet') AND (1=1)
2015-07-27 09:39:22 [D]   SmartProxy Load (0.4ms)  SELECT "smart_proxies".* FROM "smart_proxies" INNER JOIN "features_smart_proxies" ON "features_smart_proxies"."smart_proxy_id" = "smart_proxies"."id" INNER JOIN "features" ON "features"."id" = "features_smart_proxies"."feature_id" WHERE "features"."name" IN ('Puppet') AND (1=1)
2015-07-27 09:39:22 [D]    (0.3ms)  SELECT COUNT(*) FROM "realms" 
2015-07-27 09:39:22 [D]    (0.3ms)  SELECT COUNT(*) FROM "domains" WHERE (1=1)
2015-07-27 09:39:22 [D]   CACHE (0.0ms)  SELECT COUNT(*) FROM "domains" WHERE (1=1)
2015-07-27 09:39:22 [D]   Domain Load (0.3ms)  SELECT "domains".* FROM "domains" WHERE (1=1) ORDER BY name
2015-07-27 09:39:22 [D]    (0.3ms)  SELECT COUNT(*) FROM "subnets" WHERE (1=1)
2015-07-27 09:39:22 [D]   CACHE (0.0ms)  SELECT COUNT(*) FROM "subnets" WHERE (1=1)
2015-07-27 09:39:22 [D]   Subnet Load (0.3ms)  SELECT "subnets".* FROM "subnets" WHERE (1=1) ORDER BY name
2015-07-27 09:39:22 [I]   Rendered nic/_base_form.html.erb (12.3ms)
2015-07-27 09:39:22 [I]   Rendered nic/_virtual_form.html.erb (1.1ms)
2015-07-27 09:39:22 [I]   Rendered nic/_provider_specific_form.html.erb (0.1ms)
2015-07-27 09:39:22 [I]   Rendered nic/manageds/_managed.html.erb (15.3ms)
2015-07-27 09:39:22 [D]   CACHE (0.0ms)  SELECT COUNT(*) FROM "domains" WHERE (1=1)
2015-07-27 09:39:22 [D]   CACHE (0.0ms)  SELECT COUNT(*) FROM "domains" WHERE (1=1)
2015-07-27 09:39:22 [D]   CACHE (0.0ms)  SELECT "domains".* FROM "domains" WHERE (1=1) ORDER BY name
2015-07-27 09:39:22 [D]   CACHE (0.0ms)  SELECT COUNT(*) FROM "subnets" WHERE (1=1)
2015-07-27 09:39:22 [D]   CACHE (0.0ms)  SELECT COUNT(*) FROM "subnets" WHERE (1=1)
2015-07-27 09:39:22 [D]   CACHE (0.0ms)  SELECT "subnets".* FROM "subnets" WHERE (1=1) ORDER BY name
2015-07-27 09:39:22 [I]   Rendered nic/_base_form.html.erb (9.7ms)
2015-07-27 09:39:22 [I]   Rendered nic/_virtual_form.html.erb (1.1ms)
2015-07-27 09:39:22 [I]   Rendered nic/_provider_specific_form.html.erb (0.1ms)
2015-07-27 09:39:22 [I]   Rendered nic/manageds/_managed.html.erb (12.4ms)
2015-07-27 09:39:22 [I]   Rendered hosts/_interfaces.html.erb (29.7ms)
2015-07-27 09:39:22 [D]   Architecture Load (0.3ms)  SELECT "architectures".* FROM "architectures" 
2015-07-27 09:39:22 [I]   Rendered common/os_selection/_architecture.html.erb (2.4ms)
2015-07-27 09:39:22 [I]   Rendered common/os_selection/_operatingsystem.html.erb (2.8ms)
2015-07-27 09:39:22 [I]   Rendered hosts/_operating_system.html.erb (14.1ms)
2015-07-27 09:39:22 [I]   Rendered hosts/_unattended.html.erb (14.9ms)
2015-07-27 09:39:22 [D]    (0.5ms)  SELECT "config_groups".id FROM "config_groups" INNER JOIN "host_config_groups" ON "config_groups"."id" = "host_config_groups"."config_group_id" WHERE "host_config_groups"."host_id" IS NULL AND "host_config_groups"."host_type" = 'Host::Base' ORDER BY config_groups.name
2015-07-27 09:39:22 [D]    (0.2ms)  SELECT puppetclass_id FROM "config_group_classes" WHERE "config_group_classes"."config_group_id" IN (NULL)
2015-07-27 09:39:22 [D]    (0.2ms)  SELECT puppetclass_id FROM "hostgroup_classes" WHERE "hostgroup_classes"."hostgroup_id" IS NULL
2015-07-27 09:39:22 [D]    (0.2ms)  SELECT puppetclass_id FROM "host_classes" WHERE "host_classes"."host_id" IS NULL
2015-07-27 09:39:22 [D]   Puppetclass Load (0.3ms)  SELECT "puppetclasses".* FROM "puppetclasses" WHERE "puppetclasses"."id" IN (NULL) ORDER BY puppetclasses.name
2015-07-27 09:39:22 [D]    (0.3ms)  SELECT COUNT(*) AS count_all, puppetclass_id AS puppetclass_id FROM "lookup_keys" WHERE "lookup_keys"."puppetclass_id" IN (NULL) GROUP BY puppetclass_id
2015-07-27 09:39:22 [D]    (0.3ms)  SELECT COUNT(*) AS count_all, environment_classes.puppetclass_id AS environment_classes_puppetclass_id FROM "lookup_keys" INNER JOIN "environment_classes" ON "environment_classes"."lookup_key_id" = "lookup_keys"."id" WHERE "environment_classes"."puppetclass_id" IN (NULL) GROUP BY environment_classes.puppetclass_id
2015-07-27 09:39:22 [I]   Rendered puppetclasses/_class_parameters.html.erb (0.0ms)
2015-07-27 09:39:22 [I]   Rendered puppetclasses/_classes_parameters.html.erb (9.5ms)
2015-07-27 09:39:22 [D]   CommonParameter Load (0.3ms)  SELECT "parameters".* FROM "parameters" WHERE "parameters"."type" IN ('CommonParameter') ORDER BY parameters.name
2015-07-27 09:39:22 [I]   Rendered common_parameters/_inherited_parameters.html.erb (1.0ms)
2015-07-27 09:39:23 [I]   Rendered common_parameters/_puppetclass_parameter.html.erb (3.5ms)
2015-07-27 09:39:23 [I]   Rendered common_parameters/_puppetclasses_parameters.html.erb (16.9ms)
2015-07-27 09:39:23 [I]   Rendered common_parameters/_parameter.html.erb (3.0ms)
2015-07-27 09:39:23 [I]   Rendered common_parameters/_parameters.html.erb (28.2ms)
2015-07-27 09:39:23 [D]   AuthSourceHidden Load (0.5ms)  SELECT "auth_sources".* FROM "auth_sources" WHERE "auth_sources"."type" IN ('AuthSourceHidden')
2015-07-27 09:39:23 [D]   User Load (0.6ms)  SELECT "users".* FROM "users" WHERE (users.auth_source_id <> 2) ORDER BY firstname
2015-07-27 09:39:23 [D]   Usergroup Load (0.3ms)  SELECT "usergroups".* FROM "usergroups" ORDER BY usergroups.name
2015-07-27 09:39:23 [D]   Model Load (0.4ms)  SELECT "models".* FROM "models" ORDER BY models.name
2015-07-27 09:39:23 [D] Setting current location thread-local variable to none
2015-07-27 09:39:23 [D] Setting current organization thread-local variable to none
2015-07-27 09:39:23 [I]   Rendered hosts/_form.html.erb (311.0ms)
2015-07-27 09:39:23 [I]   Rendered hosts/new.html.erb within layouts/application (426.3ms)
2015-07-27 09:39:23 [I]   Rendered home/_user_dropdown.html.erb (2.4ms)
2015-07-27 09:39:23 [I] Read fragment views/tabs_and_title_records-3 (0.1ms)
2015-07-27 09:39:23 [I]   Rendered home/_topbar.html.erb (4.7ms)
2015-07-27 09:39:23 [I]   Rendered layouts/base.html.erb (7.5ms)
2015-07-27 09:39:23 [I] Completed 200 OK in 447ms (Views: 424.7ms | ActiveRecord: 13.7ms)

Regards,
Florian

Actions #6

Updated by Dominic Cleal almost 9 years ago

  • Subject changed from Unable to build new VM in openstack to Timeout and "can't convert nil into String" error building host on OpenStack
  • Status changed from Need more information to New

Thanks, that's much more useful data.

There seem to be two errors - the "nil" related error is perhaps an artefact of the first.

The first error at the top of the log is a timeout while requesting volumes from OpenStack. I don't know anything about it, but I'd perhaps check the volume service is up? Maybe there's a connectivity issue between Foreman and that service?

Actions #7

Updated by Florian Faltermeier almost 9 years ago

Hello Dominic,

with Foreman 1.9 the error doesn't occur.
I can create an instance without any errors.

Thank you.

Regards,
Florian

Actions #8

Updated by Dominic Cleal almost 9 years ago

  • Status changed from New to Resolved

Hmm okay. I'm afraid I don't know why that would be, but it's likely to have been fixed in Fog somewhere and the newer version we're shipping in 1.9 has resolved it. I'll mark the ticket as resolved in 1.9 for now - thanks very much for testing it.

Actions

Also available in: Atom PDF