gistfile1.txt

 DEBUG -- DirectorJobRunner: SENT: agent.fdf5ffbf-8eda-4ee1-83e5-086ece4568c7 {"protocol":2,"method":"get_state","arguments":[],"reply_to":"director.0123c698-3aeb-48da-b98c-8aede0f4345e.df9b228d-aea8-4f53-ba14-f04f27f45833"}
D, [2015-11-13 05:37:13 #1265] [] DEBUG -- DirectorJobRunner: RECEIVED: director.0123c698-3aeb-48da-b98c-8aede0f4345e.df9b228d-aea8-4f53-ba14-f04f27f45833 {"value":{"properties":{"logging":{"max_log_file_size":""}},"job":{"name":"consul_z1","release":"","template":"consul_agent","version":"df7504712a02bb465a917f100ff40c51a0da32cf","sha1":"3ba66eeda24320ca91e300cc40a33144bdd2e6cd","blobstore_id":"f3a1ad65-edca-40c4-bb06-ad1640d2274f","templates":[{"name":"consul_agent","version":"df7504712a02bb465a917f100ff40c51a0da32cf","sha1":"3ba66eeda24320ca91e300cc40a33144bdd2e6cd","blobstore_id":"f3a1ad65-edca-40c4-bb06-ad1640d2274f"},{"name":"metron_agent","version":"3f92d6be36137309415738d193350de0647d4c4b","sha1":"913fabc06bec31bc8ad15e12630cb7522c86704f","blobstore_id":"9046670d-533c-447c-9ac1-50aacbaa7ff3"}]},"packages":{"common":{"name":"common","version":"e401816a4748292163679fafcbd8f818ed8154a5.1","sha1":"3fea720dd2d65b3fc5fcc284d3c3d63bab056645","blobstore_id":"08e28c85-8ca5-4f77-6b2a-1c16b9138aa2"},"consul":{"name":"consul","version":"14b83378b30a2b55a25e641e835af3e5c87a0d41.1","sha1":"926a0bdfa5a7c8c9cc7046cf4afde9b77e143096","blobstore_id":"a8b45752-0d3a-42b7-5166-3306758ef053"},"consul-common":{"name":"consul-common","version":"ffab9ae7bea8a053aacca8816681e241b0fab30b.1","sha1":"7310388bde790e8b89d1350d49b4ff58708dc245","blobstore_id":"86f80eb3-3836-44bf-4fba-92848741b95a"},"metron_agent":{"name":"metron_agent","version":"c524aa5ea6588ae77c4af566604295320404cdcb.1","sha1":"f0ef78947d0df8cbcec7fe4cb1ae471446dff369","blobstore_id":"b9457c70-9c48-44cf-7b42-c1a447820eb4"}},"configuration_hash":"205e30a13ab137b5175ec921d4d861293a1a4f6f","networks":{"cf1":{"cloud_properties":{"net_id":"d1e9b104-d23f-43ff-999d-2f9d9ca2a7f7","security_groups":["default","ssh","bosh","cf-private","cf-public"]},"default":["dns","gateway"],"dns":["8.8.8.8","10.0.0.30"],"dns_record_name":"0.consul-z1.cf1.cf-runtime-bb-1.microbosh","gateway":"10.0.0.1","ip":"10.0.0.172","netmask":"255.255.255.0"}},"resource_pool":{"cloud_properties":{"instance_type":"m1.small"},"name":"small_z1","stemcell":{"name":"bosh-openstack-kvm-ubuntu-trusty-go_agent","version":"3120"}},"deployment":"cf-runtime-bb-1","index":0,"id":"","persistent_disk":1024,"rendered_templates_archive":{"sha1":"4e1f893a10a4e171fa4da0aa5485a41af9159477","blobstore_id":"329e40d1-5730-4b51-880f-8bc02febca43"},"agent_id":"fdf5ffbf-8eda-4ee1-83e5-086ece4568c7","bosh_protocol":"1","job_state":"failing","processes":[{"name":"consul_agent","state":"unknown"},{"name":"metron_agent","state":"running"}],"vm":{"name":"vm-53807b7f-6173-434c-8057-28f4abbb8f08"},"ntp":{"offset":"0.029194","timestamp":"13 Nov 05:30:10"}}}
E, [2015-11-13 05:37:13 #1265] [canary_update(consul_z1/0)] ERROR -- DirectorJobRunner: Error updating canary instance: #<Bosh::Director::AgentJobNotRunning: `consul_z1/0' is not running after update>
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/instance_updater.rb:93:in `update'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/job_updater.rb:74:in `block (2 levels) in update_canary_instance'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_formatter.rb:49:in `with_thread_name'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/job_updater.rb:72:in `block in update_canary_instance'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/event_log.rb:97:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/event_log.rb:97:in `advance_and_track'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/job_updater.rb:71:in `update_canary_instance'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/job_updater.rb:65:in `block (2 levels) in update_canaries'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_pool.rb:77:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_pool.rb:77:in `block (2 levels) in create_thread'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_pool.rb:63:in `loop'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_pool.rb:63:in `block in create_thread'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context'
D, [2015-11-13 05:37:13 #1265] [] DEBUG -- DirectorJobRunner: Worker thread raised exception: `consul_z1/0' is not running after update - /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/instance_updater.rb:93:in `update'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/job_updater.rb:74:in `block (2 levels) in update_canary_instance'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_formatter.rb:49:in `with_thread_name'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/job_updater.rb:72:in `block in update_canary_instance'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/event_log.rb:97:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/event_log.rb:97:in `advance_and_track'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/job_updater.rb:71:in `update_canary_instance'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/job_updater.rb:65:in `block (2 levels) in update_canaries'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_pool.rb:77:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_pool.rb:77:in `block (2 levels) in create_thread'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_pool.rb:63:in `loop'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_pool.rb:63:in `block in create_thread'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context'
D, [2015-11-13 05:37:13 #1265] [] DEBUG -- DirectorJobRunner: Thread is no longer needed, cleaning up
D, [2015-11-13 05:37:13 #1265] [task:24] DEBUG -- DirectorJobRunner: Shutting down pool
D, [2015-11-13 05:37:13 #1265] [task:24] DEBUG -- DirectorJobRunner: (0.001537s) SELECT NULL
D, [2015-11-13 05:37:13 #1265] [task:24] DEBUG -- DirectorJobRunner: (0.000957s) SELECT "stemcells".* FROM "stemcells" INNER JOIN "deployments_stemcells" ON (("deployments_stemcells"."stemcell_id" = "stemcells"."id") AND ("deployments_stemcells"."deployment_id" = 2))
D, [2015-11-13 05:37:13 #1265] [task:24] DEBUG -- DirectorJobRunner: Deleting lock: lock:deployment:cf-runtime-bb-1
D, [2015-11-13 05:37:13 #1265] [task:24] DEBUG -- DirectorJobRunner: Deleted lock: lock:deployment:cf-runtime-bb-1
I, [2015-11-13 05:37:13 #1265] [task:24]  INFO -- DirectorJobRunner: sending update deployment error event
D, [2015-11-13 05:37:13 #1265] [task:24] DEBUG -- DirectorJobRunner: SENT: hm.director.alert {"id":"ae9d550e-efda-4eb4-bc97-b675dc35a525","severity":3,"title":"director - error during update deployment","summary":"Error during update deployment for 'cf-runtime-bb-1' against Director 'e25c9abb-6d0c-4e70-aa52-652bada00507': #<Bosh::Director::AgentJobNotRunning: `consul_z1/0' is not running after update>","created_at":1447393033}
E, [2015-11-13 05:37:13 #1265] [task:24] ERROR -- DirectorJobRunner: `consul_z1/0' is not running after update
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/instance_updater.rb:93:in `update'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/job_updater.rb:74:in `block (2 levels) in update_canary_instance'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_formatter.rb:49:in `with_thread_name'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/job_updater.rb:72:in `block in update_canary_instance'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/event_log.rb:97:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/event_log.rb:97:in `advance_and_track'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/job_updater.rb:71:in `update_canary_instance'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3120.0/lib/bosh/director/job_updater.rb:65:in `block (2 levels) in update_canaries'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_pool.rb:77:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_pool.rb:77:in `block (2 levels) in create_thread'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_pool.rb:63:in `loop'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3120.0/lib/common/thread_pool.rb:63:in `block in create_thread'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context'
D, [2015-11-13 05:37:13 #1265] [task:24] DEBUG -- DirectorJobRunner: (0.000102s) SELECT NULL
D, [2015-11-13 05:37:13 #1265] [task:24] DEBUG -- DirectorJobRunner: (0.000030s) BEGIN
D, [2015-11-13 05:37:13 #1265] [task:24] DEBUG -- DirectorJobRunner: (0.000222s) UPDATE "tasks" SET "state" = 'error', "timestamp" = '2015-11-13 05:37:13.712173+0000', "description" = 'create deployment', "result" = '`consul_z1/0'' is not running after update', "output" = '/var/vcap/store/director/tasks/24', "checkpoint_time" = '2015-11-13 05:36:51.364887+0000', "type" = 'update_deployment', "username" = 'admin' WHERE ("id" = 24)
D, [2015-11-13 05:37:13 #1265] [] DEBUG -- DirectorJobRunner: Lock renewal thread exiting
D, [2015-11-13 05:37:13 #1265] [task:24] DEBUG -- DirectorJobRunner: (0.072870s) COMMIT
I, [2015-11-13 05:37:13 #1265] []  INFO -- DirectorJobRunner: Task took 20 minutes 57.73201547100007 seconds to process.