bosh-lite/cloudfoundry deployment to AWS failing

[Andrew Serff]

I'm trying to deploy bosh-lite and cloudfoundry running in my own instance on AWS and the deployment of cloudfoundry is failing.  I'm using the provision_cf script to deploy and after a couple hours of it uploading the release, it gets to the end and fails doing the following:

Release `cf/180' already exists. Skipping upload.
+ bosh -n deploy
Getting deployment properties from director...
Compiling deployment manifest...


Director task 4
  Started preparing deployment
  Started preparing deployment > Binding deployment. Done (00:00:00)
  Started preparing deployment > Binding releases. Done (00:00:00)
  Started preparing deployment > Binding existing deployment. Done (00:00:00)
  Started preparing deployment > Binding resource pools. Done (00:00:00)
  Started preparing deployment > Binding stemcells. Done (00:00:00)
  Started preparing deployment > Binding templates. Done (00:00:00)
  Started preparing deployment > Binding properties. Done (00:00:00)
  Started preparing deployment > Binding unallocated VMs. Done (00:00:00)
  Started preparing deployment > Binding instance networks. Done (00:00:00)
     Done preparing deployment (00:00:00)


  Started preparing package compilation > Finding packages to compile. Done (00:00:01)


  Started preparing dns > Binding DNS. Done (00:00:00)


  Started preparing configuration > Binding configuration. Done (00:00:01)


  Started updating job etcd_z1 > etcd_z1/0. Failed: Extracting method arguments from payload: Unmarshalling action argument: json: cannot unmarshal object into Go value of type action.VMCID (00:00:01)


Error 100: Extracting method arguments from payload: Unmarshalling action argument: json: cannot unmarshal object into Go value of type action.VMCID


Task 4 error

For a more detailed error report, run: bosh task 4 --debug

The debug output shows:

D, [2014-09-02T19:52:39.117988 #12732] [task:4] DEBUG -- : Shutting down pool
D, [2014-09-02T19:52:39.119714 #12732] [task:4] DEBUG -- : (0.000354s) SELECT "stemcells".* FROM "stemcells" INNER JOIN "deployments_stemcells" ON (("deployments_stemcells"."stemcell_id" = "stemcells"."id") AND ("deployments_stemcells"."deployment_id" = 1))
D, [2014-09-02T19:52:39.120020 #12732] [task:4] DEBUG -- : Deleting lock: lock:deployment:cf-warden
D, [2014-09-02T19:52:39.120115 #12732] [0xbd2bd0] DEBUG -- : Lock renewal thread exiting
D, [2014-09-02T19:52:39.120998 #12732] [task:4] DEBUG -- : Deleted lock: lock:deployment:cf-warden
E, [2014-09-02T19:52:39.121370 #12732] [task:4] ERROR -- : Extracting method arguments from payload: Unmarshalling action argument: json: cannot unmarshal object into Go value of type action.VMCID
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh_cpi-1.2707.0/lib/cloud/external_cpi.rb:123:in `handle_error'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh_cpi-1.2707.0/lib/cloud/external_cpi.rb:90:in `block (2 levels) in <class:ExternalCpi>'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh-director-1.2707.0/lib/bosh/director/instance_updater.rb:316:in `block in create_disk'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/sequel-3.43.0/lib/sequel/database/query.rb:338:in `_transaction'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/sequel-3.43.0/lib/sequel/database/query.rb:300:in `block in transaction'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/sequel-3.43.0/lib/sequel/database/connecting.rb:236:in `block in synchronize'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/sequel-3.43.0/lib/sequel/connection_pool/threaded.rb:104:in `hold'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/sequel-3.43.0/lib/sequel/database/connecting.rb:236:in `synchronize'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/sequel-3.43.0/lib/sequel/database/query.rb:293:in `transaction'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh-director-1.2707.0/lib/bosh/director/instance_updater.rb:315:in `create_disk'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh-director-1.2707.0/lib/bosh/director/instance_updater.rb:252:in `update_persistent_disk'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh-director-1.2707.0/lib/bosh/director/instance_updater.rb:72:in `block in update'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh-director-1.2707.0/lib/bosh/director/instance_updater.rb:37:in `step'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh-director-1.2707.0/lib/bosh/director/instance_updater.rb:72:in `update'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh-director-1.2707.0/lib/bosh/director/job_updater.rb:94:in `block (2 levels) in update_instance'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh_common-1.2707.0/lib/common/thread_formatter.rb:46:in `with_thread_name'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh-director-1.2707.0/lib/bosh/director/job_updater.rb:92:in `block in update_instance'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh-director-1.2707.0/lib/bosh/director/event_log.rb:83:in `call'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh-director-1.2707.0/lib/bosh/director/event_log.rb:83:in `advance_and_track'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh-director-1.2707.0/lib/bosh/director/job_updater.rb:91:in `update_instance'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh-director-1.2707.0/lib/bosh/director/job_updater.rb:85:in `block (2 levels) in update_instances'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh_common-1.2707.0/lib/common/thread_pool.rb:77:in `call'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh_common-1.2707.0/lib/common/thread_pool.rb:77:in `block (2 levels) in create_thread'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh_common-1.2707.0/lib/common/thread_pool.rb:63:in `loop'
/var/vcap/packages/director/gem_home/ruby/1.9.1/gems/bosh_common-1.2707.0/lib/common/thread_pool.rb:63:in `block in create_thread'
D, [2014-09-02T19:52:39.121967 #12732] [task:4] DEBUG -- : (0.000087s) BEGIN
D, [2014-09-02T19:52:39.123029 #12732] [task:4] DEBUG -- : (0.000363s) UPDATE "tasks" SET "state" = 'error', "timestamp" = '2014-09-02 19:52:39.121625+0000', "description" = 'create deployment', "result" = 'Extracting method arguments from payload: Unmarshalling action argument: json: cannot unmarshal object into Go value of type...', "output" = '/var/vcap/store/director/tasks/4', "user_id" = NULL, "checkpoint_time" = '2014-09-02 19:52:36.719570+0000', "type" = 'update_deployment' WHERE ("id" = 4)
D, [2014-09-02T19:52:39.124709 #12732] [task:4] DEBUG -- : (0.001555s) COMMIT
I, [2014-09-02T19:52:39.124858 #12732] [0x642878]  INFO -- : Task took 2.749191211 seconds to process.


Task 4 error

I don't know what to start looking at to get this working.  I've tried re-running the provision_cf script and get the same result each time.  Any ideas?  

Andrew

P.S. I know I can use "TryCF", but I was trying to get my own instance running so I know what's there.