@Johannes.. FYI,
D, [2015-04-13 12:33:49 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:33:54 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:33:59 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:34:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000165s) BEGIN
D, [2015-04-13 12:34:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000287s) UPDATE "tasks" SET "checkpoint_time" = '2015-04-13 12:34:04.422992+0000' WHERE ("id" = 395)
D, [2015-04-13 12:34:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.001075s) COMMIT
D, [2015-04-13 12:34:04 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:34:09 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:34:14 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:34:19 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:34:24 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:34:29 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:34:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000201s) BEGIN
D, [2015-04-13 12:34:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000411s) UPDATE "tasks" SET "checkpoint_time" = '2015-04-13 12:34:34.425973+0000' WHERE ("id" = 395)
D, [2015-04-13 12:34:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.001259s) COMMIT
D, [2015-04-13 12:34:34 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:34:39 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:34:44 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
I, [2015-04-13 12:34:48 #31034] [canary_update(ha_proxy_z1/0)] INFO -- DirectorJobRunner: Checking if ha_proxy_z1/0 has been updated after 63.333333333333336 seconds
D, [2015-04-13 12:34:48 #31034] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.07477f12-af4d-47fc-bb2e-d3ff95f9bb5b {"method":"get_state","arguments":[],"reply_to":"director.2502dd46-ce40-4772-b10f-386482f5d7eb.8fb20b94-0776-42de-8319-fe14b8b166e1"}
D, [2015-04-13 12:34:48 #31034] [] DEBUG -- DirectorJobRunner: RECEIVED: director.2502dd46-ce40-4772-b10f-386482f5d7eb.8fb20b94-0776-42de-8319-fe14b8b166e1 {"value":{"properties":{"logging":{"max_log_file_size":""}},"job":{"name":"ha_proxy_z1","release":"","template":"haproxy","version":"7bd402abf9d8fe86c1adf649c791fed92a03653c","sha1":"88a89bd6cd01c9b1390a2f0d27443c83b3a697a9","blobstore_id":"5fed26eb-e946-4216-952a-235dc99fd0a1","templates":[{"name":"haproxy","version":"7bd402abf9d8fe86c1adf649c791fed92a03653c","sha1":"88a89bd6cd01c9b1390a2f0d27443c83b3a697a9","blobstore_id":"5fed26eb-e946-4216-952a-235dc99fd0a1"},{"name":"metron_agent","version":"4cf0a43aa50c72ea4dd4538f7289aa97f68de3cd","sha1":"304b93276d9df64042ba994bbca9601e66db2256","blobstore_id":"9b3e412b-98ce-438d-9652-4d7de52fbf67"}]},"packages":{"common":{"name":"common","version":"43595236d1ce5f9a6120198108c226c07ab17012.1","sha1":"c002fcd08d711baf15707f6e0824324ecc8d96ce","blobstore_id":"584fc8bd-c835-4b8e-7b18-98fed900c30c"},"haproxy":{"name":"haproxy","version":"630ad6d6e1d3cab4547ce104f3019b483f354613.1","sha1":"5e7b97d56c0f76ad009366fb2a2faad96e8abe25","blobstore_id":"19670058-d247-48d6-658e-26768b5823f9"},"metron_agent":{"name":"metron_agent","version":"b6b63ba2f186801009546f6d190516452b4ce7b0.1","sha1":"1021acfd05f8a6481120fd3d259900094436cd84","blobstore_id":"48a32300-6250-4bbe-6966-d360cae6e9fc"}},"configuration_hash":"2b1c3ce6fdb95d1f73348e240052833a7eaeacf9","networks":{"cf1":{"cloud_properties":{"name":"CF-33"},"default":["dns","gateway"],"dns":["10.255.232.50","10.255.237.40"],"dns_record_name":"0.ha-proxy-z1.cf1.cloudfoundry.microbosh","gateway":"192.168.33.1","ip":"192.168.33.51","netmask":"255.255.255.0"}},"resource_pool":{"cloud_properties":{"cpu":1,"disk":2048,"ram":1024},"name":"router_z1","stemcell":{"name":"bosh-vsphere-esxi-ubuntu-trusty-go_agent","version":"2865"}},"deployment":"cloudfoundry","index":0,"persistent_disk":0,"persistent_disk_pool":null,"rendered_templates_archive":{"sha1":"427abe50d93f952292b4153a8db4947322a87042","blobstore_id":"23728c62-9164-45e5-b37f-d94de04e01e9"},"agent_id":"07477f12-af4d-47fc-bb2e-d3ff95f9bb5b","bosh_protocol":"1","job_state":"failing","vm":{"name":"vm-6a77bb07-1f72-485e-b0d4-074c43a1004e"},"ntp":{"message":"bad ntp server"}}}
I, [2015-04-13 12:34:48 #31034] [canary_update(ha_proxy_z1/0)] INFO -- DirectorJobRunner: Waiting for 63.333333333333336 seconds to check ha_proxy_z1/0 status
D, [2015-04-13 12:34:49 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:34:54 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:34:59 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:35:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000194s) BEGIN
D, [2015-04-13 12:35:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000369s) UPDATE "tasks" SET "checkpoint_time" = '2015-04-13 12:35:04.429838+0000' WHERE ("id" = 395)
D, [2015-04-13 12:35:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.001314s) COMMIT
D, [2015-04-13 12:35:04 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:35:09 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:35:14 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:35:19 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:35:24 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:35:29 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:35:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000204s) BEGIN
D, [2015-04-13 12:35:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000370s) UPDATE "tasks" SET "checkpoint_time" = '2015-04-13 12:35:34.433544+0000' WHERE ("id" = 395)
D, [2015-04-13 12:35:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.001347s) COMMIT
D, [2015-04-13 12:35:34 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:35:39 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:35:44 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:35:49 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
I, [2015-04-13 12:35:52 #31034] [canary_update(ha_proxy_z1/0)] INFO -- DirectorJobRunner: Checking if ha_proxy_z1/0 has been updated after 63.333333333333336 seconds
D, [2015-04-13 12:35:52 #31034] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.07477f12-af4d-47fc-bb2e-d3ff95f9bb5b {"method":"get_state","arguments":[],"reply_to":"director.2502dd46-ce40-4772-b10f-386482f5d7eb.186653d1-6e37-44f6-af95-1a7fdc2b0b51"}
D, [2015-04-13 12:35:52 #31034] [] DEBUG -- DirectorJobRunner: RECEIVED: director.2502dd46-ce40-4772-b10f-386482f5d7eb.186653d1-6e37-44f6-af95-1a7fdc2b0b51 {"value":{"properties":{"logging":{"max_log_file_size":""}},"job":{"name":"ha_proxy_z1","release":"","template":"haproxy","version":"7bd402abf9d8fe86c1adf649c791fed92a03653c","sha1":"88a89bd6cd01c9b1390a2f0d27443c83b3a697a9","blobstore_id":"5fed26eb-e946-4216-952a-235dc99fd0a1","templates":[{"name":"haproxy","version":"7bd402abf9d8fe86c1adf649c791fed92a03653c","sha1":"88a89bd6cd01c9b1390a2f0d27443c83b3a697a9","blobstore_id":"5fed26eb-e946-4216-952a-235dc99fd0a1"},{"name":"metron_agent","version":"4cf0a43aa50c72ea4dd4538f7289aa97f68de3cd","sha1":"304b93276d9df64042ba994bbca9601e66db2256","blobstore_id":"9b3e412b-98ce-438d-9652-4d7de52fbf67"}]},"packages":{"common":{"name":"common","version":"43595236d1ce5f9a6120198108c226c07ab17012.1","sha1":"c002fcd08d711baf15707f6e0824324ecc8d96ce","blobstore_id":"584fc8bd-c835-4b8e-7b18-98fed900c30c"},"haproxy":{"name":"haproxy","version":"630ad6d6e1d3cab4547ce104f3019b483f354613.1","sha1":"5e7b97d56c0f76ad009366fb2a2faad96e8abe25","blobstore_id":"19670058-d247-48d6-658e-26768b5823f9"},"metron_agent":{"name":"metron_agent","version":"b6b63ba2f186801009546f6d190516452b4ce7b0.1","sha1":"1021acfd05f8a6481120fd3d259900094436cd84","blobstore_id":"48a32300-6250-4bbe-6966-d360cae6e9fc"}},"configuration_hash":"2b1c3ce6fdb95d1f73348e240052833a7eaeacf9","networks":{"cf1":{"cloud_properties":{"name":"CF-33"},"default":["dns","gateway"],"dns":["10.255.232.50","10.255.237.40"],"dns_record_name":"0.ha-proxy-z1.cf1.cloudfoundry.microbosh","gateway":"192.168.33.1","ip":"192.168.33.51","netmask":"255.255.255.0"}},"resource_pool":{"cloud_properties":{"cpu":1,"disk":2048,"ram":1024},"name":"router_z1","stemcell":{"name":"bosh-vsphere-esxi-ubuntu-trusty-go_agent","version":"2865"}},"deployment":"cloudfoundry","index":0,"persistent_disk":0,"persistent_disk_pool":null,"rendered_templates_archive":{"sha1":"427abe50d93f952292b4153a8db4947322a87042","blobstore_id":"23728c62-9164-45e5-b37f-d94de04e01e9"},"agent_id":"07477f12-af4d-47fc-bb2e-d3ff95f9bb5b","bosh_protocol":"1","job_state":"failing","vm":{"name":"vm-6a77bb07-1f72-485e-b0d4-074c43a1004e"},"ntp":{"message":"bad ntp server"}}}
I, [2015-04-13 12:35:52 #31034] [canary_update(ha_proxy_z1/0)] INFO -- DirectorJobRunner: Waiting for 63.333333333333336 seconds to check ha_proxy_z1/0 status
D, [2015-04-13 12:35:54 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:35:59 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:36:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000171s) BEGIN
D, [2015-04-13 12:36:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000379s) UPDATE "tasks" SET "checkpoint_time" = '2015-04-13 12:36:04.437429+0000' WHERE ("id" = 395)
D, [2015-04-13 12:36:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.001124s) COMMIT
D, [2015-04-13 12:36:04 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:36:09 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:36:14 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:36:19 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:36:24 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:36:29 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:36:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000199s) BEGIN
D, [2015-04-13 12:36:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000396s) UPDATE "tasks" SET "checkpoint_time" = '2015-04-13 12:36:34.440954+0000' WHERE ("id" = 395)
D, [2015-04-13 12:36:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000960s) COMMIT
D, [2015-04-13 12:36:34 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:36:39 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:36:44 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:36:49 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:36:54 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
I, [2015-04-13 12:36:55 #31034] [canary_update(ha_proxy_z1/0)] INFO -- DirectorJobRunner: Checking if ha_proxy_z1/0 has been updated after 63.333333333333336 seconds
D, [2015-04-13 12:36:55 #31034] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.07477f12-af4d-47fc-bb2e-d3ff95f9bb5b {"method":"get_state","arguments":[],"reply_to":"director.2502dd46-ce40-4772-b10f-386482f5d7eb.0ffa28a8-934a-464c-a039-c862fce4645d"}
D, [2015-04-13 12:36:55 #31034] [] DEBUG -- DirectorJobRunner: RECEIVED: director.2502dd46-ce40-4772-b10f-386482f5d7eb.0ffa28a8-934a-464c-a039-c862fce4645d {"value":{"properties":{"logging":{"max_log_file_size":""}},"job":{"name":"ha_proxy_z1","release":"","template":"haproxy","version":"7bd402abf9d8fe86c1adf649c791fed92a03653c","sha1":"88a89bd6cd01c9b1390a2f0d27443c83b3a697a9","blobstore_id":"5fed26eb-e946-4216-952a-235dc99fd0a1","templates":[{"name":"haproxy","version":"7bd402abf9d8fe86c1adf649c791fed92a03653c","sha1":"88a89bd6cd01c9b1390a2f0d27443c83b3a697a9","blobstore_id":"5fed26eb-e946-4216-952a-235dc99fd0a1"},{"name":"metron_agent","version":"4cf0a43aa50c72ea4dd4538f7289aa97f68de3cd","sha1":"304b93276d9df64042ba994bbca9601e66db2256","blobstore_id":"9b3e412b-98ce-438d-9652-4d7de52fbf67"}]},"packages":{"common":{"name":"common","version":"43595236d1ce5f9a6120198108c226c07ab17012.1","sha1":"c002fcd08d711baf15707f6e0824324ecc8d96ce","blobstore_id":"584fc8bd-c835-4b8e-7b18-98fed900c30c"},"haproxy":{"name":"haproxy","version":"630ad6d6e1d3cab4547ce104f3019b483f354613.1","sha1":"5e7b97d56c0f76ad009366fb2a2faad96e8abe25","blobstore_id":"19670058-d247-48d6-658e-26768b5823f9"},"metron_agent":{"name":"metron_agent","version":"b6b63ba2f186801009546f6d190516452b4ce7b0.1","sha1":"1021acfd05f8a6481120fd3d259900094436cd84","blobstore_id":"48a32300-6250-4bbe-6966-d360cae6e9fc"}},"configuration_hash":"2b1c3ce6fdb95d1f73348e240052833a7eaeacf9","networks":{"cf1":{"cloud_properties":{"name":"CF-33"},"default":["dns","gateway"],"dns":["10.255.232.50","10.255.237.40"],"dns_record_name":"0.ha-proxy-z1.cf1.cloudfoundry.microbosh","gateway":"192.168.33.1","ip":"192.168.33.51","netmask":"255.255.255.0"}},"resource_pool":{"cloud_properties":{"cpu":1,"disk":2048,"ram":1024},"name":"router_z1","stemcell":{"name":"bosh-vsphere-esxi-ubuntu-trusty-go_agent","version":"2865"}},"deployment":"cloudfoundry","index":0,"persistent_disk":0,"persistent_disk_pool":null,"rendered_templates_archive":{"sha1":"427abe50d93f952292b4153a8db4947322a87042","blobstore_id":"23728c62-9164-45e5-b37f-d94de04e01e9"},"agent_id":"07477f12-af4d-47fc-bb2e-d3ff95f9bb5b","bosh_protocol":"1","job_state":"failing","vm":{"name":"vm-6a77bb07-1f72-485e-b0d4-074c43a1004e"},"ntp":{"message":"bad ntp server"}}}
I, [2015-04-13 12:36:55 #31034] [canary_update(ha_proxy_z1/0)] INFO -- DirectorJobRunner: Waiting for 63.333333333333336 seconds to check ha_proxy_z1/0 status
D, [2015-04-13 12:36:59 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:37:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000184s) BEGIN
D, [2015-04-13 12:37:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000390s) UPDATE "tasks" SET "checkpoint_time" = '2015-04-13 12:37:04.444270+0000' WHERE ("id" = 395)
D, [2015-04-13 12:37:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.001203s) COMMIT
D, [2015-04-13 12:37:04 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:37:09 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:37:14 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:37:19 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:37:24 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:37:29 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:37:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000262s) BEGIN
D, [2015-04-13 12:37:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000397s) UPDATE "tasks" SET "checkpoint_time" = '2015-04-13 12:37:34.447769+0000' WHERE ("id" = 395)
D, [2015-04-13 12:37:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.001159s) COMMIT
D, [2015-04-13 12:37:34 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:37:39 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:37:44 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:37:49 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:37:54 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
I, [2015-04-13 12:37:58 #31034] [canary_update(ha_proxy_z1/0)] INFO -- DirectorJobRunner: Checking if ha_proxy_z1/0 has been updated after 63.333333333333336 seconds
D, [2015-04-13 12:37:58 #31034] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.07477f12-af4d-47fc-bb2e-d3ff95f9bb5b {"method":"get_state","arguments":[],"reply_to":"director.2502dd46-ce40-4772-b10f-386482f5d7eb.70951e70-8df4-48d2-8325-6c853d7c9a1e"}
D, [2015-04-13 12:37:58 #31034] [] DEBUG -- DirectorJobRunner: RECEIVED: director.2502dd46-ce40-4772-b10f-386482f5d7eb.70951e70-8df4-48d2-8325-6c853d7c9a1e {"value":{"properties":{"logging":{"max_log_file_size":""}},"job":{"name":"ha_proxy_z1","release":"","template":"haproxy","version":"7bd402abf9d8fe86c1adf649c791fed92a03653c","sha1":"88a89bd6cd01c9b1390a2f0d27443c83b3a697a9","blobstore_id":"5fed26eb-e946-4216-952a-235dc99fd0a1","templates":[{"name":"haproxy","version":"7bd402abf9d8fe86c1adf649c791fed92a03653c","sha1":"88a89bd6cd01c9b1390a2f0d27443c83b3a697a9","blobstore_id":"5fed26eb-e946-4216-952a-235dc99fd0a1"},{"name":"metron_agent","version":"4cf0a43aa50c72ea4dd4538f7289aa97f68de3cd","sha1":"304b93276d9df64042ba994bbca9601e66db2256","blobstore_id":"9b3e412b-98ce-438d-9652-4d7de52fbf67"}]},"packages":{"common":{"name":"common","version":"43595236d1ce5f9a6120198108c226c07ab17012.1","sha1":"c002fcd08d711baf15707f6e0824324ecc8d96ce","blobstore_id":"584fc8bd-c835-4b8e-7b18-98fed900c30c"},"haproxy":{"name":"haproxy","version":"630ad6d6e1d3cab4547ce104f3019b483f354613.1","sha1":"5e7b97d56c0f76ad009366fb2a2faad96e8abe25","blobstore_id":"19670058-d247-48d6-658e-26768b5823f9"},"metron_agent":{"name":"metron_agent","version":"b6b63ba2f186801009546f6d190516452b4ce7b0.1","sha1":"1021acfd05f8a6481120fd3d259900094436cd84","blobstore_id":"48a32300-6250-4bbe-6966-d360cae6e9fc"}},"configuration_hash":"2b1c3ce6fdb95d1f73348e240052833a7eaeacf9","networks":{"cf1":{"cloud_properties":{"name":"CF-33"},"default":["dns","gateway"],"dns":["10.255.232.50","10.255.237.40"],"dns_record_name":"0.ha-proxy-z1.cf1.cloudfoundry.microbosh","gateway":"192.168.33.1","ip":"192.168.33.51","netmask":"255.255.255.0"}},"resource_pool":{"cloud_properties":{"cpu":1,"disk":2048,"ram":1024},"name":"router_z1","stemcell":{"name":"bosh-vsphere-esxi-ubuntu-trusty-go_agent","version":"2865"}},"deployment":"cloudfoundry","index":0,"persistent_disk":0,"persistent_disk_pool":null,"rendered_templates_archive":{"sha1":"427abe50d93f952292b4153a8db4947322a87042","blobstore_id":"23728c62-9164-45e5-b37f-d94de04e01e9"},"agent_id":"07477f12-af4d-47fc-bb2e-d3ff95f9bb5b","bosh_protocol":"1","job_state":"failing","vm":{"name":"vm-6a77bb07-1f72-485e-b0d4-074c43a1004e"},"ntp":{"message":"bad ntp server"}}}
I, [2015-04-13 12:37:58 #31034] [canary_update(ha_proxy_z1/0)] INFO -- DirectorJobRunner: Waiting for 63.333333333333336 seconds to check ha_proxy_z1/0 status
D, [2015-04-13 12:37:59 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:38:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000192s) BEGIN
D, [2015-04-13 12:38:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000572s) UPDATE "tasks" SET "checkpoint_time" = '2015-04-13 12:38:04.451525+0000' WHERE ("id" = 395)
D, [2015-04-13 12:38:04 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000769s) COMMIT
D, [2015-04-13 12:38:04 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:38:09 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:38:14 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:38:19 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:38:24 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:38:29 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:38:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000211s) BEGIN
D, [2015-04-13 12:38:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.000395s) UPDATE "tasks" SET "checkpoint_time" = '2015-04-13 12:38:34.455148+0000' WHERE ("id" = 395)
D, [2015-04-13 12:38:34 #31034] [task:395-checkpoint] DEBUG -- DirectorJobRunner: (0.001106s) COMMIT
D, [2015-04-13 12:38:34 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:38:39 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:38:44 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:38:49 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:38:54 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:38:59 #31034] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:deployment:cloudfoundry
I, [2015-04-13 12:39:02 #31034] [canary_update(ha_proxy_z1/0)] INFO -- DirectorJobRunner: Checking if ha_proxy_z1/0 has been updated after 63.333333333333336 seconds
D, [2015-04-13 12:39:02 #31034] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.07477f12-af4d-47fc-bb2e-d3ff95f9bb5b {"method":"get_state","arguments":[],"reply_to":"director.2502dd46-ce40-4772-b10f-386482f5d7eb.7729b595-6a49-4513-94c1-ca7465166a9f"}
D, [2015-04-13 12:39:02 #31034] [] DEBUG -- DirectorJobRunner: RECEIVED: director.2502dd46-ce40-4772-b10f-386482f5d7eb.7729b595-6a49-4513-94c1-ca7465166a9f {"value":{"properties":{"logging":{"max_log_file_size":""}},"job":{"name":"ha_proxy_z1","release":"","template":"haproxy","version":"7bd402abf9d8fe86c1adf649c791fed92a03653c","sha1":"88a89bd6cd01c9b1390a2f0d27443c83b3a697a9","blobstore_id":"5fed26eb-e946-4216-952a-235dc99fd0a1","templates":[{"name":"haproxy","version":"7bd402abf9d8fe86c1adf649c791fed92a03653c","sha1":"88a89bd6cd01c9b1390a2f0d27443c83b3a697a9","blobstore_id":"5fed26eb-e946-4216-952a-235dc99fd0a1"},{"name":"metron_agent","version":"4cf0a43aa50c72ea4dd4538f7289aa97f68de3cd","sha1":"304b93276d9df64042ba994bbca9601e66db2256","blobstore_id":"9b3e412b-98ce-438d-9652-4d7de52fbf67"}]},"packages":{"common":{"name":"common","version":"43595236d1ce5f9a6120198108c226c07ab17012.1","sha1":"c002fcd08d711baf15707f6e0824324ecc8d96ce","blobstore_id":"584fc8bd-c835-4b8e-7b18-98fed900c30c"},"haproxy":{"name":"haproxy","version":"630ad6d6e1d3cab4547ce104f3019b483f354613.1","sha1":"5e7b97d56c0f76ad009366fb2a2faad96e8abe25","blobstore_id":"19670058-d247-48d6-658e-26768b5823f9"},"metron_agent":{"name":"metron_agent","version":"b6b63ba2f186801009546f6d190516452b4ce7b0.1","sha1":"1021acfd05f8a6481120fd3d259900094436cd84","blobstore_id":"48a32300-6250-4bbe-6966-d360cae6e9fc"}},"configuration_hash":"2b1c3ce6fdb95d1f73348e240052833a7eaeacf9","networks":{"cf1":{"cloud_properties":{"name":"CF-33"},"default":["dns","gateway"],"dns":["10.255.232.50","10.255.237.40"],"dns_record_name":"0.ha-proxy-z1.cf1.cloudfoundry.microbosh","gateway":"192.168.33.1","ip":"192.168.33.51","netmask":"255.255.255.0"}},"resource_pool":{"cloud_properties":{"cpu":1,"disk":2048,"ram":1024},"name":"router_z1","stemcell":{"name":"bosh-vsphere-esxi-ubuntu-trusty-go_agent","version":"2865"}},"deployment":"cloudfoundry","index":0,"persistent_disk":0,"persistent_disk_pool":null,"rendered_templates_archive":{"sha1":"427abe50d93f952292b4153a8db4947322a87042","blobstore_id":"23728c62-9164-45e5-b37f-d94de04e01e9"},"agent_id":"07477f12-af4d-47fc-bb2e-d3ff95f9bb5b","bosh_protocol":"1","job_state":"failing","vm":{"name":"vm-6a77bb07-1f72-485e-b0d4-074c43a1004e"},"ntp":{"message":"bad ntp server"}}}
E, [2015-04-13 12:39:02 #31034] [canary_update(ha_proxy_z1/0)] ERROR -- DirectorJobRunner: Error updating canary instance: #<Bosh::Director::AgentJobNotRunning: `ha_proxy_z1/0' is not running after update>
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2865.0/lib/bosh/director/instance_updater.rb:85:in `update'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2865.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.2865.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.2865.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.2865.0/lib/bosh/director/event_log.rb:97:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2865.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.2865.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.2865.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.2865.0/lib/common/thread_pool.rb:77:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2865.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.2865.0/lib/common/thread_pool.rb:63:in `loop'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2865.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-04-13 12:39:02 #31034] [] DEBUG -- DirectorJobRunner: Worker thread raised exception: `ha_proxy_z1/0' is not running after update - /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2865.0/lib/bosh/director/instance_updater.rb:85:in `update'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2865.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.2865.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.2865.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.2865.0/lib/bosh/director/event_log.rb:97:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2865.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.2865.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.2865.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.2865.0/lib/common/thread_pool.rb:77:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2865.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.2865.0/lib/common/thread_pool.rb:63:in `loop'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2865.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-04-13 12:39:02 #31034] [] DEBUG -- DirectorJobRunner: Thread is no longer needed, cleaning up
D, [2015-04-13 12:39:02 #31034] [task:395] DEBUG -- DirectorJobRunner: Shutting down pool
D, [2015-04-13 12:39:02 #31034] [task:395] DEBUG -- DirectorJobRunner: (0.000745s) SELECT "stemcells".* FROM "stemcells" INNER JOIN "deployments_stemcells" ON (("deployments_stemcells"."stemcell_id" = "stemcells"."id") AND ("deployments_stemcells"."deployment_id" = 3))
D, [2015-04-13 12:39:02 #31034] [task:395] DEBUG -- DirectorJobRunner: Deleting lock: lock:deployment:cloudfoundry
D, [2015-04-13 12:39:02 #31034] [] DEBUG -- DirectorJobRunner: Lock renewal thread exiting
D, [2015-04-13 12:39:02 #31034] [task:395] DEBUG -- DirectorJobRunner: Deleted lock: lock:deployment:cloudfoundry
I, [2015-04-13 12:39:02 #31034] [task:395] INFO -- DirectorJobRunner: sending update deployment error event
D, [2015-04-13 12:39:02 #31034] [task:395] DEBUG -- DirectorJobRunner: SENT: hm.director.alert {"id":"2116decd-a809-409c-9671-bd9fca3260e2","severity":3,"title":"director - error during update deployment","summary":"Error during update deployment for cloudfoundry against Director d88bce25-25f1-4873-9e7b-5c554e2deabe: #<Bosh::Director::AgentJobNotRunning: `ha_proxy_z1/0' is not running after update>","created_at":1428928742}
E, [2015-04-13 12:39:02 #31034] [task:395] ERROR -- DirectorJobRunner: `ha_proxy_z1/0' is not running after update
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2865.0/lib/bosh/director/instance_updater.rb:85:in `update'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2865.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.2865.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.2865.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.2865.0/lib/bosh/director/event_log.rb:97:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2865.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.2865.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.2865.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.2865.0/lib/common/thread_pool.rb:77:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2865.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.2865.0/lib/common/thread_pool.rb:63:in `loop'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2865.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-04-13 12:39:02 #31034] [task:395] DEBUG -- DirectorJobRunner: (0.000102s) BEGIN
D, [2015-04-13 12:39:02 #31034] [task:395] DEBUG -- DirectorJobRunner: (0.000457s) UPDATE "tasks" SET "state" = 'error', "timestamp" = '2015-04-13 12:39:02.309854+0000', "description" = 'create deployment', "result" = '`ha_proxy_z1/0'' is not running after update', "output" = '/var/vcap/store/director/tasks/395', "checkpoint_time" = '2015-04-13 12:38:34.455148+0000', "type" = 'update_deployment', "username" = 'admin' WHERE ("id" = 395)
D, [2015-04-13 12:39:02 #31034] [task:395] DEBUG -- DirectorJobRunner: (0.001249s) COMMIT
I, [2015-04-13 12:39:02 #31034] [] INFO -- DirectorJobRunner: Task took 10 minutes 59.805384995000054 seconds to process.
Task 395 error
Thanks..