I have been trying to get ec2 host provisioning to work, but it is pretty consistently failing to ssh to new hosts. It seems to work maybe 20% of the time. I am using ami-cc5af9a5, which is a generic RHEL 6.3 AMI, set to use the user root.

I can dump the db, pull the key and do ssh -i foremankey.pem root@<host> and it works fine after the host is provisioned, but most of the time the finish script never runs and I see the output below in the logs.

I also verified that 56:4a:3d:ab:7d:9d:48:c0:b2:fc:20:a6:04:9c:ea:ef is the right fingerprint for the public key it's trying to use, but something is going wrong with the process:

SSH connection established to 54.224.51.49 - executing template
about to upload /usr/share/foreman/tmp/1120130317-26757-asxo1f-0 to remote system at /tmp/bootstrap-i-01cf076e
establishing connection to 54.224.51.49:22
connection established
negotiating protocol version
remote is `SSH-2.0-OpenSSH_5.3'
local is `SSH-2.0-Ruby/Net::SSH_2.3.0 x86_64-linux'
read 784 bytes
received packet nr 0 type 20 len 780
got KEXINIT from server
sending KEXINIT
queueing packet nr 0 type 20 len 716
sent 720 bytes
negotiating algorithms
negotiated:

• kex: diffie-hellman-group-exchange-sha1
• host_key: ssh-rsa
• encryption_server: aes128-cbc
• encryption_client: aes128-cbc
• hmac_client: hmac-sha1
• hmac_server: hmac-sha1
• compression_client: none
• compression_server: none
• language_client:
• language_server:
  exchanging keys
  queueing packet nr 1 type 34 len 20
  sent 24 bytes
  read 152 bytes
  received packet nr 1 type 31 len 148
  queueing packet nr 2 type 32 len 140
  sent 144 bytes
  read 720 bytes
  received packet nr 2 type 33 len 700
  queueing packet nr 3 type 21 len 20
  sent 24 bytes
  received packet nr 3 type 21 len 12
  beginning authentication of `root'
  queueing packet nr 4 type 5 len 28
  sent 52 bytes
  read 52 bytes
  received packet nr 4 type 6 len 28
  trying publickey
  connecting to ssh-agent
  could not connect to ssh-agent
  trying publickey (56:4a:3d:ab:7d:9d:48:c0:b2:fc:20:a6:04:9c:ea:ef)
  queueing packet nr 5 type 50 len 348
  sent 372 bytes
  read 84 bytes
  received packet nr 5 type 51 len 60
  allowed methods: publickey,gssapi-keyex,gssapi-with-mic
  all authorization methods failed (tried publickey)
  Failed to launch script on test6.montleon.intra: root/usr/lib/ruby/gems/1.8/gems/net-ssh-2.3.0/lib/net/ssh.rb:200:in `start'
  /usr/lib/ruby/gems/1.8/gems/net-scp-1.0.4/lib/net/scp.rb:197:in `start'
  /usr/lib/ruby/gems/1.8/gems/fog-1.9.0/lib/fog/core/scp.rb:70:in `upload'
  /usr/share/foreman/lib/foreman/provision/ssh.rb:19:in `deploy!'
  /usr/share/foreman/app/models/orchestration/ssh_provision.rb:80:in `setSSHProvision'
  /usr/share/foreman/app/models/orchestration.rb:151:in `send'
  /usr/share/foreman/app/models/orchestration.rb:151:in `execute'
  /usr/share/foreman/app/models/orchestration.rb:91:in `process'
  /usr/share/foreman/app/models/orchestration.rb:83:in `each'
  /usr/share/foreman/app/models/orchestration.rb:83:in `process'
  /usr/share/foreman/app/models/orchestration.rb:25:in `post_commit'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:415:in `_run_commit_callbacks'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/transactions.rb:261:in `committed!'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/connection_adapters/abstract/database_statements.rb:324:in `commit_transaction_records'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/connection_adapters/abstract/database_statements.rb:322:in `each'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/connection_adapters/abstract/database_statements.rb:322:in `commit_transaction_records'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/connection_adapters/abstract/database_statements.rb:165:in `transaction'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/transactions.rb:207:in `transaction'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/transactions.rb:290:in `with_transaction_returning_status'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/transactions.rb:240:in `save'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/transactions.rb:251:in `rollback_active_record_state!'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/transactions.rb:239:in `save'
  /usr/share/foreman/app/controllers/hosts_controller.rb:89:in `create'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/abstract_controller/base.rb:150:in `process_action'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_controller/metal/rendering.rb:11:in `process_action'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/abstract_controller/callbacks.rb:18:in `process_action'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:483:in `_run__1961535849__process_action__1159442860__callbacks'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:221:in `_conditional_callback_around_4556'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:331:in `around'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:315:in `send'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:315:in `_callback_around_1470'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:220:in `_conditional_callback_around_4556'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:482:in `_run__1961535849__process_action__1159442860__callbacks'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:221:in `_conditional_callback_around_4555'
  /usr/share/foreman/lib/foreman/thread_session.rb:31:in `clear_thread'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:220:in `_conditional_callback_around_4555'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:437:in `_run__1961535849__process_action__1159442860__callbacks'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:221:in `_conditional_callback_around_4554'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:331:in `around'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:315:in `send'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:315:in `_callback_around_13'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:220:in `_conditional_callback_around_4554'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:436:in `_run__1961535849__process_action__1159442860__callbacks'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:410:in `send'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:410:in `_run_process_action_callbacks'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:94:in `send'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:94:in `run_callbacks'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/abstract_controller/callbacks.rb:17:in `process_action'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_controller/metal/rescue.rb:17:in `process_action'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/notifications.rb:52:in `instrument'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/notifications.rb:52:in `instrument'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_controller/metal/instrumentation.rb:29:in `process_action'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/abstract_controller/base.rb:119:in `process'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/abstract_controller/rendering.rb:41:in `process'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_controller/metal.rb:138:in `dispatch'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_controller/metal.rb:178:in `action'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/routing/route_set.rb:68:in `call'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/routing/route_set.rb:68:in `dispatch'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/routing/route_set.rb:33:in `call'
  /usr/lib/ruby/gems/1.8/gems/rack-mount-0.6.14/lib/rack/mount/route_set.rb:148:in `call'
  /usr/lib/ruby/gems/1.8/gems/rack-mount-0.6.14/lib/rack/mount/code_generation.rb:93:in `recognize'
  /usr/lib/ruby/gems/1.8/gems/rack-mount-0.6.14/lib/rack/mount/code_generation.rb:229:in `optimized_each'
  /usr/lib/ruby/gems/1.8/gems/rack-mount-0.6.14/lib/rack/mount/code_generation.rb:92:in `recognize'
  /usr/lib/ruby/gems/1.8/gems/rack-mount-0.6.14/lib/rack/mount/route_set.rb:139:in `call'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/routing/route_set.rb:499:in `call'
  /usr/lib/ruby/gems/1.8/gems/apipie-rails-0.0.13/lib/apipie/static_dispatcher.rb:57:in `call'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/middleware/head.rb:14:in `call'
  /usr/lib/ruby/gems/1.8/gems/rack-1.2.5/lib/rack/methodoverride.rb:24:in `call'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/middleware/params_parser.rb:21:in `call'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/middleware/flash.rb:182:in `call'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/middleware/session/abstract_store.rb:149:in `call'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/middleware/cookies.rb:302:in `call'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/query_cache.rb:32:in `call'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/connection_adapters/abstract/query_cache.rb:28:in `cache'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/query_cache.rb:12:in `cache'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/query_cache.rb:31:in `call'
  /usr/lib/ruby/gems/1.8/gems/activerecord-3.0.20/lib/active_record/connection_adapters/abstract/connection_pool.rb:354:in `call'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/middleware/callbacks.rb:46:in `call'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/callbacks.rb:416:in `_run_call_callbacks'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/middleware/callbacks.rb:44:in `call'
  /usr/lib/ruby/gems/1.8/gems/rack-1.2.5/lib/rack/sendfile.rb:106:in `call'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/middleware/remote_ip.rb:48:in `call'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/middleware/show_exceptions.rb:47:in `call'
  /usr/lib/ruby/gems/1.8/gems/railties-3.0.20/lib/rails/rack/logger.rb:13:in `call'
  /usr/lib/ruby/gems/1.8/gems/rack-1.2.5/lib/rack/runtime.rb:17:in `call'
  /usr/lib/ruby/gems/1.8/gems/activesupport-3.0.20/lib/active_support/cache/strategy/local_cache.rb:72:in `call'
  /usr/lib/ruby/gems/1.8/gems/rack-1.2.5/lib/rack/lock.rb:13:in `call'
  /usr/lib/ruby/gems/1.8/gems/rack-1.2.5/lib/rack/lock.rb:13:in `synchronize'
  /usr/lib/ruby/gems/1.8/gems/rack-1.2.5/lib/rack/lock.rb:13:in `call'
  /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.20/lib/action_dispatch/middleware/static.rb:30:in `call'
  /usr/lib/ruby/gems/1.8/gems/railties-3.0.20/lib/rails/application.rb:168:in `call'
  /usr/lib/ruby/gems/1.8/gems/railties-3.0.20/lib/rails/application.rb:77:in `send'
  /usr/lib/ruby/gems/1.8/gems/railties-3.0.20/lib/rails/application.rb:77:in `method_missing'
  /usr/lib/ruby/gems/1.8/gems/rack-1.2.5/lib/rack/urlmap.rb:47:in `call'
  /usr/lib/ruby/gems/1.8/gems/rack-1.2.5/lib/rack/urlmap.rb:41:in `each'
  /usr/lib/ruby/gems/1.8/gems/rack-1.2.5/lib/rack/urlmap.rb:41:in `call'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/rack/request_handler.rb:96:in `process_request'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_request_handler.rb:517:in `accept_and_process_next_request'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_request_handler.rb:274:in `main_loop'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/rack/application_spawner.rb:206:in `start_request_handler'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/rack/application_spawner.rb:171:in `send'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/rack/application_spawner.rb:171:in `handle_spawn_application'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/utils.rb:470:in `safe_fork'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/rack/application_spawner.rb:166:in `handle_spawn_application'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server.rb:357:in `__send__'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server.rb:180:in `start'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/rack/application_spawner.rb:129:in `start'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/spawn_manager.rb:253:in `spawn_rack_application'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server_collection.rb:132:in `lookup_or_add'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/spawn_manager.rb:246:in `spawn_rack_application'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server_collection.rb:82:in `synchronize'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server_collection.rb:79:in `synchronize'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/spawn_manager.rb:244:in `spawn_rack_application'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/spawn_manager.rb:137:in `spawn_application'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/spawn_manager.rb:275:in `handle_spawn_application'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server.rb:357:in `__send__'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server.rb:357:in `server_main_loop'
  /usr/share/rubygems/gems/passenger-3.0.17/lib/phusion_passenger/abstract_server.rb:206:in `start_synchronously'
  /usr/share/rubygems/gems/passenger-3.0.17/helper-scripts/passenger-spawn-server:102
  Rolling back due to a problem: Configuring instance test6.montleon.intra via SSH 2003 failed test6.montleon.intrasetSSHProvision
  Remove puppet certificate for test6.montleon.intra
  Delete the autosign entry for test6.montleon.intra
  ActiveRecord::Rollback
  Completed 200 OK in 128429ms (Views: 7.5ms | ActiveRecord: 100.7ms)