search

cloudfoundry / bosh

Cloud Foundry BOSH is an open source tool chain for release engineering, deployment and lifecycle management of large scale distributed services.
https://bosh.io
Apache License 2.0
2.03k stars 658 forks source link

Fail to deploy CF with bosh(>155) #817

Closed guanglinlv closed 8 years ago

guanglinlv commented 9 years ago

Hi ,

It will be failed if i use bosh >155 to deploy CF,bosh-155 is successful.

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

  Started updating job ha_proxy_z1 > ha_proxy_z1/0 (canary). Failed: No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl (00:00:03)

Error 100: No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl

Task 3 error

powerdns is a component of bosh, right? why is it reported here?

@cppforlife

cppforlife commented 9 years ago

Can you include a stacktrace shown at the end of the bosh task 3 --debug?

guanglinlv commented 9 years ago

@cppforlife

it's too large, the part of debug log is given here:

bosh-155 is successful with the same cf(release and deployment file) and bosh(deployment file).

this failure is happened once each time when update jobs for each VM instance of CF,bosh deploy again after once failure will be successful.

{"method":"get_task","arguments":["8f11a8df-c6fd-4e58-4afa-240954c82352"],"reply_to":"director.e08d0256-4216-4584-bc68-e44f890dde40.236dd6cc-65ba-42da-afd9-f10e704fe6e4"}
D, [2015-05-05 11:48:22 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.236dd6cc-65ba-42da-afd9-f10e704fe6e4 {"value":"prepared"}
D, [2015-05-05 11:48:22 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.9fa93e6b-52cb-445d-8c88-fdb11079d82f {"method":"drain","arguments":["update",{"deployment":"cf-warden","job":{"name":"ha_proxy_z1","templates":[{"name":"haproxy","version":"7bd402abf9d8fe86c1adf649c791fed92a03653c","sha1":"88a89bd6cd01c9b1390a2f0d27443c83b3a697a9","blobstore_id":"2dc34358-7cbe-4edd-84e6-aafee04dcd66"},{"name":"metron_agent","version":"8ad734ba7952b6184ac127a45608e64ebb1c4611","sha1":"6f229f6f524dafc9ee4d46188c8cd7af1bcb8098","blobstore_id":"3ccf6ca4-ff9d-4b4a-8b91-0d30f0dd11c8"}],"template":"haproxy","version":"7bd402abf9d8fe86c1adf649c791fed92a03653c","sha1":"88a89bd6cd01c9b1390a2f0d27443c83b3a697a9","blobstore_id":"2dc34358-7cbe-4edd-84e6-aafee04dcd66"},"index":0,"networks":{"floating":{"type":"vip","ip":"9.91.39.29","cloud_properties":{},"dns_record_name":"0.ha-proxy-z1.floating.cf-warden.bosh"},"cf1":{"ip":"10.10.10.140","netmask":"255.255.255.0","cloud_properties":{"net_id":"67a8ddc7-4d5f-432f-a154-660df2e8e69c","security_groups":["default"]},"default":["dns","gateway"],"dns":["10.10.10.3","10.10.10.64"],"gateway":"10.10.10.1","dns_record_name":"0.ha-proxy-z1.cf1.cf-warden.bosh"}},"resource_pool":{"name":"router_z1","cloud_properties":{"instance_type":"m1.medium"},"stemcell":{"name":"bosh-openstack-kvm-centos-7-go_agent-raw-m","version":"2962"}},"packages":{"haproxy":{"name":"haproxy","version":"630ad6d6e1d3cab4547ce104f3019b483f354613.1","sha1":"33522a7aef69d54845e4dbb2e3706a6e19f1b87d","blobstore_id":"148473d8-c738-4dce-5dc2-1e064a502354"},"common":{"name":"common","version":"99c756b71550530632e393f5189220f170a69647.1","sha1":"f4e3d8668a5cd7bbce48a5a600936e8fd1813e2b","blobstore_id":"3f8c19b4-aaaf-4ef0-5228-688538998b59"},"metron_agent":{"name":"metron_agent","version":"27c6122c3dcabaeac758bae7cb258910a5ac1e42.1","sha1":"d50ec240046610a5a6e3493258cc269778baa82d","blobstore_id":"1e91a9bd-8bb7-4f08-68ad-186fb62afef1"}},"configuration_hash":"5ddbb2da0fc22bb3790622806d0b3ebce5e44cfc","properties":{"ha_proxy":{"ssl_pem":"-----BEGIN CERTIFICATE-----\nMIIDETCCAfmgAwIBAgIJANZuykf1uh3LMA0GCSqGSIb3DQEBBQUAMB8xHTAbBgNV\nBAMMFCouMTAuMjQ0LjAuMzQueGlwLmlvMB4XDTE0MTIyNDIzMTkxM1oXDTI0MTIy\nMTIzMTkxM1owHzEdMBsGA1UEAwwUKi4xMC4yNDQuMC4zNC54aXAuaW8wggEiMA0G\nCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQDCjq73Fgwfj2UT0/+wR9kVVsGAguMj\npoA0opLCgE0yHStAhSvqq7YpO39dH3vBMWXyr2xIfDyaeZyhV86jWu/ZKswGjNGI\nZKv/yUINe1bqukOBqd+SHVvkVhxSLJuD1MR83JQMONRjOPJp661/ABpVhnrNfBiA\nAA6aaFv4/KbyGY/E1FHoUXqEdh4WxaJdfX6SbgG05ArWxhSD7PNj4CYvJWGCdvqP\nKBsvWFDrkxBHn5h1JIDfZJB8FKP6vaHBr7MU4pIHM+qaZ1Y+8ja0wcgkHn4YHcp6\nIOhqpck7LaH5Qq2ydYFNTcG4fTbG0jXqcit2WSUxRkXzWnrgo2E0SiHBAgMBAAGj\nUDBOMB0GA1UdDgQWBBSpCtEDtEvMwaZzXN6Lvk5U7Eyn2zAfBgNVHSMEGDAWgBSp\nCtEDtEvMwaZzXN6Lvk5U7Eyn2zAMBgNVHRMEBTADAQH/MA0GCSqGSIb3DQEBBQUA\nA4IBAQB1YIHmw3gPiMn8WDR4yVxDvSVgFHY6ZE1iZb17vVs4N2/mhQZXWJ2nZV02\ngoAivtgxHOj39sK5OBWsGvrQo5H8dt1t4XmbwB1C6xRerGc25dhDRq42RqhCN0RJ\nzzjd9b8YSiwtAaZlW36l2jVDLfRapb00tWToF9qYrDrmKy2sekS7g2hbiRStcue/\nbpT4X/CHxb/lUbpL4m8BpDbkGiOJgl+SEHRx5tZ0Kob/RDQRCcN3p+71FRbDIEBj\n+8sJl/yUUUPwQ6PNYx6cjtlICWJ1G0l0hRa141VXPqSNCmxYS4dp/8ifPCSoLc+k\n9TXFkuGl+86CPTyyMJxyMhEcAGZT\n-----END CERTIFICATE-----\n-----BEGIN RSA PRIVATE KEY-----\nMIIEpAIBAAKCAQEAwo6u9xYMH49lE9P/sEfZFVbBgILjI6aANKKSwoBNMh0rQIUr\n6qu2KTt/XR97wTFl8q9sSHw8mnmcoVfOo1rv2SrMBozRiGSr/8lCDXtW6rpDganf\nkh1b5FYcUiybg9TEfNyUDDjUYzjyaeutfwAaVYZ6zXwYgAAOmmhb+Pym8hmPxNRR\n6FF6hHYeFsWiXX1+km4BtOQK1sYUg+zzY+AmLyVhgnb6jygbL1hQ65MQR5+YdSSA\n32SQfBSj+r2hwa+zFOKSBzPqmmdWPvI2tMHIJB5+GB3KeiDoaqXJOy2h+UKtsnWB\nTU3BuH02xtI16nIrdlklMUZF81p64KNhNEohwQIDAQABAoIBAC1U3YOIyY5Y9O4n\nyT2jn/sO2cs9s/rMgrbA4n0bM+FnVnqUDOWC2NDGoihqe4VKIzzmjs5c1CoSB+K3\n+NerCpOJGzyzdubWvhS9KfzGLjxG5g/CKut6l7yeK78h0aJn4thM9NncK/BqhmET\nnrsmpPwkd1yFe5fna3+irTtYcvWZgxp8DK4JxIRB0QpJvEwbs9fUFE1E0DVw/uBV\nCytTIrik2O+n1m8S5xzsFXHXDjXT/TVNi3jtN12Oaj1avYZRP2q45RmcODhtHQIy\n4o0vqjyAmZb3jOcYysyXVwfyNreIH3Qn0/waflPkyaljMpa1OHVOCJFjh2Xl+aIc\ndQsME3kCgYEA4aXU2xb9SHew84/3ow6ZmBeYLm+7B8GUjDTe7HqLldtTUhlrJSdB\nSHZHZ/BXEQ126FnbfZ0IISkBjqVCQBw8MgjZAlaEIInDA1DRTLuOfrcyUD6PeSLi\ngVZHNYbR9MDnmJ3/So5HXiRy2rBWtLKwPlciqbwY+l3xYr2kP/QdCisCgYEA3LpB\nTBDTqp9j8QVvB/YjCakS+z+kgtO5HyMZO/uh6o9PRHrFQHwZA5y/MRrx9lxJ9zOd\nfqysKfA7fXs4VzNnRSnOfBmuDHF0HhlIgAShX/RnB94p9xnsQaMae/o2nXcknQng\n3qogvHWTo16GCJRE+YTmhA0QtvSlScJlTzHfqcMCgYAPRt/rWVoajufvBX85jeJ+\nNpK6Chx6gPOirm2tSvqqUagJdekYIdk8o61f7xil8ehsALFohronLJSLaMrcdkzp\nAkpW6y6U2V7XmaAh9szF7Xc9kY67H85//SxjBlauoGTNo1zGWm2ghQ01mxyzrSlb\nfyC8pxx1zuhpy/cT0V4p8wKBgQDb+EJaq+pFf9L5v5CHPqRsXDKucR5hwt4aScA8\nJumV+HvmovMw8Ht9PhjLty6rdg3AbY/nTe3FXcPrqYDcZj3kj2VYB7+MZwRxeoDm\nE7c/CTIkhSMNPqhUQVeDdjg3dSTn25BeVu2I4yPfC7RHmHukru2La/ncWrLebvzH\nj8x2QQKBgQDevjRDDTWbBkg8HdCRxxCvhfaHBntoSJdTHlr14Gce48NXGaXRJPQT\n9dMsPsSHkFxEra7G2clGnhpe+pK9V+WTrD9Qnoc+tK808hX1YQ6mBlnR6w99jlaR\nHVTi2pRhEhbWUkBv2kooXvD6ANb15PbPSF1FK7YyW1KHqcbm+lF22g==\n-----END RSA PRIVATE KEY-----\n","disable_http":false,"ssl_ciphers":"ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256:DHE-DSS-AES128-GCM-SHA256:kEDH+AESGCM:ECDHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA384:ECDHE-RSA-AES256-SHA:ECDHE-ECDSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES128-SHA:DHE-DSS-AES128-SHA256:DHE-RSA-AES256-SHA256:DHE-DSS-AES256-SHA:DHE-RSA-AES256-SHA:AES128-GCM-SHA256:AES256-GCM-SHA384:ECDHE-RSA-RC4-SHA:ECDHE-ECDSA-RC4-SHA:AES128:AES256:RC4-SHA:HIGH:!aNULL:!eNULL:!EXPORT:!DES:!3DES:!MD5:!PSK"},"request_timeout_in_seconds":900,"router":{"servers":{"z1":["10.10.10.141"],"z2":[]},"port":80},"networks":{"apps":"cf1"},"syslog_daemon_config":{"address":null,"port":null,"transport":"tcp"},"metron_agent":{"incoming_port":3456,"dropsonde_incoming_port":3457,"statsd_incoming_port":8125,"debug":false,"status":{"user":"","password":"","port":0},"zone":"z1","etcd_query_interval_milliseconds":5000,"collector_registrar_interval_milliseconds":60000},"loggregator":{"incoming_port":3456,"dropsonde_incoming_port":3457},"loggregator_endpoint":{"shared_secret":"loggregator-secret"},"nats":{"user":"nats","password":"nats","machines":["10.10.10.142"],"port":4222},"etcd":{"machines":["10.10.10.143"],"maxconcurrentrequests":10}},"dns_domain_name":"bosh","persistent_disk":0,"template_hashes":{"haproxy":"66baf4bb051487714f5b6886a8fa27b645f783f2","metron_agent":"aa6290cab96fd7e456be9c34299a42c1aa90a104"},"rendered_templates_archive":{"blobstore_id":"d7018513-3179-436d-85a3-b12f719f3528","sha1":"0f48d34d5a0976dd906915472bbd8ffa3c9bb716"}}],"reply_to":"director.e08d0256-4216-4584-bc68-e44f890dde40.461607b8-e838-4540-a337-362ad963492a"}
D, [2015-05-05 11:48:22 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.461607b8-e838-4540-a337-362ad963492a {"value":{"agent_task_id":"366d36d2-3f2f-4f51-4e51-e16f4a5e47f4","state":"running"}}
D, [2015-05-05 11:48:22 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.9fa93e6b-52cb-445d-8c88-fdb11079d82f {"method":"get_task","arguments":["366d36d2-3f2f-4f51-4e51-e16f4a5e47f4"],"reply_to":"director.e08d0256-4216-4584-bc68-e44f890dde40.9474347c-5bd4-4c6f-9049-7436b19c25fe"}
D, [2015-05-05 11:48:22 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.9474347c-5bd4-4c6f-9049-7436b19c25fe {"value":{"agent_task_id":"366d36d2-3f2f-4f51-4e51-e16f4a5e47f4","state":"running"}}
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.9fa93e6b-52cb-445d-8c88-fdb11079d82f {"method":"get_task","arguments":["366d36d2-3f2f-4f51-4e51-e16f4a5e47f4"],"reply_to":"director.e08d0256-4216-4584-bc68-e44f890dde40.456a41fb-0e12-46f6-ad9c-41bd526ca258"}
D, [2015-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.456a41fb-0e12-46f6-ad9c-41bd526ca258 {"value":0}
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000893s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000891s) SELECT * FROM "tasks" WHERE "id" = 43
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.9fa93e6b-52cb-445d-8c88-fdb11079d82f {"method":"stop","arguments":[],"reply_to":"director.e08d0256-4216-4584-bc68-e44f890dde40.31622716-e832-4e67-9dbb-ebb27830a8af"}
D, [2015-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.31622716-e832-4e67-9dbb-ebb27830a8af {"value":{"agent_task_id":"3d66d0dd-07dc-455b-64e5-29f8f7249525","state":"running"}}
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.9fa93e6b-52cb-445d-8c88-fdb11079d82f {"method":"get_task","arguments":["3d66d0dd-07dc-455b-64e5-29f8f7249525"],"reply_to":"director.e08d0256-4216-4584-bc68-e44f890dde40.ed386159-0e39-4616-92a7-c0feb863f38e"}
D, [2015-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.ed386159-0e39-4616-92a7-c0feb863f38e {"value":"stopped"}
I, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)]  INFO -- DirectorJobRunner: Snapshots are disabled; skipping
I, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)]  INFO -- DirectorJobRunner: Skipping VM update
I, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)]  INFO -- DirectorJobRunner: Skipping network re-configuration
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000803s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000555s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000515s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000464s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000735s) SELECT * FROM "records" WHERE (("name" = '0.ha-proxy-z1.floating.cf-warden.bosh') AND ("type" = 'A') AND ("content" = '9.91.39.29')) LIMIT 1
I, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)]  INFO -- DirectorJobRunner: Updating DNS for: 0.ha-proxy-z1.floating.cf-warden.bosh to 9.91.39.29
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000345s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000256s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000472s) SELECT * FROM "records" WHERE (("domain_id" = 1) AND ("name" = '0.ha-proxy-z1.floating.cf-warden.bosh')) LIMIT 1
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000330s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000347s) BEGIN
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000942s) INSERT INTO "records" ("domain_id", "name", "type", "ttl", "content", "change_date") VALUES (1, '0.ha-proxy-z1.floating.cf-warden.bosh', 'A', 300, '9.91.39.29', 1430826503) RETURNING *
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001686s) COMMIT
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000352s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000369s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000311s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000448s) SELECT * FROM "domains" WHERE (("name" = '39.91.9.in-addr.arpa') AND ("type" = 'NATIVE')) LIMIT 1
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000285s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000247s) BEGIN
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000429s) INSERT INTO "domains" ("name", "type") VALUES ('39.91.9.in-addr.arpa', 'NATIVE') RETURNING *
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001353s) COMMIT
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000301s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000409s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000339s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000337s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000490s) SELECT * FROM "records" WHERE (("domain_id" = 6) AND ("name" = '39.91.9.in-addr.arpa') AND ("type" = 'SOA') AND ("content" = 'localhost hostmaster@localhost 0 10800 604800 30') AND ("ttl" = 14400)) LIMIT 1
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000416s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000266s) BEGIN
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000497s) INSERT INTO "records" ("domain_id", "name", "type", "content", "ttl") VALUES (6, '39.91.9.in-addr.arpa', 'SOA', 'localhost hostmaster@localhost 0 10800 604800 30', 14400) RETURNING *
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001004s) COMMIT
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000338s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000329s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000329s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000391s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000492s) SELECT * FROM "records" WHERE (("domain_id" = 6) AND ("name" = '39.91.9.in-addr.arpa') AND ("type" = 'NS') AND ("ttl" = 14400) AND ("content" = 'ns.bosh')) LIMIT 1
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000363s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000323s) BEGIN
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000817s) INSERT INTO "records" ("domain_id", "name", "type", "ttl", "content") VALUES (6, '39.91.9.in-addr.arpa', 'NS', 14400, 'ns.bosh') RETURNING *
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001443s) COMMIT
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000370s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000291s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000262s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000375s) SELECT * FROM "records" WHERE (("content" = '0.ha-proxy-z1.floating.cf-warden.bosh') AND ("type" = 'PTR')) LIMIT 1
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000408s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000441s) BEGIN
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000789s) INSERT INTO "records" ("domain_id", "name", "type", "ttl", "content", "change_date") VALUES (6, '29.39.91.9.in-addr.arpa', 'PTR', 300, '0.ha-proxy-z1.floating.cf-warden.bosh', 1430826503) RETURNING *
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001202s) COMMIT
I, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)]  INFO -- DirectorJobRunner: Updating DNS for: 0.ha-proxy-z1.cf1.cf-warden.bosh to 10.10.10.140
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000457s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000428s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000680s) SELECT * FROM "records" WHERE (("domain_id" = 1) AND ("name" = '0.ha-proxy-z1.cf1.cf-warden.bosh')) LIMIT 1
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000499s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000375s) BEGIN
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000586s) INSERT INTO "records" ("domain_id", "name", "type", "ttl", "content", "change_date") VALUES (1, '0.ha-proxy-z1.cf1.cf-warden.bosh', 'A', 300, '10.10.10.140', 1430826503) RETURNING *
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000957s) COMMIT
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000289s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000244s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000297s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000391s) SELECT * FROM "domains" WHERE (("name" = '10.10.10.in-addr.arpa') AND ("type" = 'NATIVE')) LIMIT 1
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000256s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000223s) BEGIN
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000430s) INSERT INTO "domains" ("name", "type") VALUES ('10.10.10.in-addr.arpa', 'NATIVE') RETURNING *
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001081s) COMMIT
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000357s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000336s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000324s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000320s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000488s) SELECT * FROM "records" WHERE (("domain_id" = 7) AND ("name" = '10.10.10.in-addr.arpa') AND ("type" = 'SOA') AND ("content" = 'localhost hostmaster@localhost 0 10800 604800 30') AND ("ttl" = 14400)) LIMIT 1
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000361s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000287s) BEGIN
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000509s) INSERT INTO "records" ("domain_id", "name", "type", "content", "ttl") VALUES (7, '10.10.10.in-addr.arpa', 'SOA', 'localhost hostmaster@localhost 0 10800 604800 30', 14400) RETURNING *
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001014s) COMMIT
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000338s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000287s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000331s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000289s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000463s) SELECT * FROM "records" WHERE (("domain_id" = 7) AND ("name" = '10.10.10.in-addr.arpa') AND ("type" = 'NS') AND ("ttl" = 14400) AND ("content" = 'ns.bosh')) LIMIT 1
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000330s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000473s) BEGIN
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000892s) INSERT INTO "records" ("domain_id", "name", "type", "ttl", "content") VALUES (7, '10.10.10.in-addr.arpa', 'NS', 14400, 'ns.bosh') RETURNING *
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001340s) COMMIT
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000479s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000447s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000382s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000606s) SELECT * FROM "records" WHERE (("content" = '0.ha-proxy-z1.cf1.cf-warden.bosh') AND ("type" = 'PTR')) LIMIT 1
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000499s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000337s) BEGIN
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000801s) INSERT INTO "records" ("domain_id", "name", "type", "ttl", "content", "change_date") VALUES (7, '140.10.10.10.in-addr.arpa', 'PTR', 300, '0.ha-proxy-z1.cf1.cf-warden.bosh', 1430826503) RETURNING *
D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001254s) COMMIT
E, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] ERROR -- DirectorJobRunner: Error updating canary instance: #<Errno::ENOENT: No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl>
/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:in `spawn'
/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:in `popen_run'
/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:93:in `popen3'
/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:252:in `capture3'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/dns_helper.rb:207:in `flush_dns_cache'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:215:in `update_dns'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:71:in `block in update'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:37:in `step'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:71:in `update'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.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.2962.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.2962.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.2962.0/lib/bosh/director/event_log.rb:97:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.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.2962.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.2962.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.2962.0/lib/common/thread_pool.rb:77:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.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.2962.0/lib/common/thread_pool.rb:63:in `loop'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.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-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: Worker thread raised exception: No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl - /var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:in `spawn'
/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:in `popen_run'
/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:93:in `popen3'
/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:252:in `capture3'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/dns_helper.rb:207:in `flush_dns_cache'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:215:in `update_dns'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:71:in `block in update'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:37:in `step'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:71:in `update'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.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.2962.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.2962.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.2962.0/lib/bosh/director/event_log.rb:97:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.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.2962.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.2962.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.2962.0/lib/common/thread_pool.rb:77:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.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.2962.0/lib/common/thread_pool.rb:63:in `loop'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.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-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: Thread is no longer needed, cleaning up
D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: Shutting down pool
D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.005891s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.001478s) SELECT "stemcells".* FROM "stemcells" INNER JOIN "deployments_stemcells" ON (("deployments_stemcells"."stemcell_id" = "stemcells"."id") AND ("deployments_stemcells"."deployment_id" = 3))
D, [2015-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: Lock renewal thread exiting
D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: Deleting lock: lock:deployment:cf-warden
D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: Deleted lock: lock:deployment:cf-warden
I, [2015-05-05 11:48:23 #20891] [task:43]  INFO -- DirectorJobRunner: sending update deployment error event
D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: SENT: hm.director.alert {"id":"2f9236d9-aa9a-464f-be68-2173793a47d4","severity":3,"title":"director - error during update deployment","summary":"Error during update deployment for 'cf-warden' against Director '609afeed-cd42-48dd-a3a6-08e5bf044992': #<Errno::ENOENT: No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl>","created_at":1430826503}
E, [2015-05-05 11:48:23 #20891] [task:43] ERROR -- DirectorJobRunner: No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl
/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:in `spawn'
/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:in `popen_run'
/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:93:in `popen3'
/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:252:in `capture3'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/dns_helper.rb:207:in `flush_dns_cache'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:215:in `update_dns'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:71:in `block in update'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:37:in `step'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:71:in `update'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.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.2962.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.2962.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.2962.0/lib/bosh/director/event_log.rb:97:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.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.2962.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.2962.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.2962.0/lib/common/thread_pool.rb:77:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.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.2962.0/lib/common/thread_pool.rb:63:in `loop'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.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-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.000320s) SELECT NULL
D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.000293s) BEGIN
D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.000943s) UPDATE "tasks" SET "state" = 'error', "timestamp" = '2015-05-05 11:48:23.258668+0000', "description" = 'create deployment', "result" = 'No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl', "output" = '/var/vcap/store/director/tasks/43', "checkpoint_time" = '2015-05-05 11:48:20.863669+0000', "type" = 'update_deployment', "username" = 'admin' WHERE ("id" = 43)
D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.002082s) COMMIT
I, [2015-05-05 11:48:23 #20891] []  INFO -- DirectorJobRunner: Task took 1 minute 32.420035999999996 seconds to process.

Task 43 error
ghost commented 9 years ago

Is your Director collocated with PowerDNS?

On Mon, May 4, 2015 at 5:43 PM, guanglinlv notifications@github.com wrote:

@cppforlife https://github.com/cppforlife

it's too large, the part of debug log is given here:

bosh-155 is successful with the same cf(release and deployment file) and bosh(deployment file).

this failure is happened once each time when update jobs for each VM instance of CF,bosh deploy again after once failure will be successful.

{"method":"get_task","arguments":["8f11a8df-c6fd-4e58-4afa-240954c82352"],"reply_to":"director.e08d0256-4216-4584-bc68-e44f890dde40.236dd6cc-65ba-42da-afd9-f10e704fe6e4"} D, [2015-05-05 11:48:22 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.236dd6cc-65ba-42da-afd9-f10e704fe6e4 {"value":"prepared"} D, [2015-05-05 11:48:22 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.9fa93e6b-52cb-445d-8c88-fdb11079d82f {"method":"drain","arguments":["update",{"deployment":"cf-warden","job":{"name":"ha_proxy_z1","templates":[{"name":"haproxy","version":"7bd402abf9d8fe86c1adf649c791fed92a03653c","sha1":"88a89bd6cd01c9b1390a2f0d27443c83b3a697a9","blobstore_id":"2dc34358-7cbe-4edd-84e6-aafee04dcd66"},{"name":"metron_agent","version":"8ad734ba7952b6184ac127a45608e64ebb1c4611","sha1":"6f229f6f524dafc9ee4d46188c8cd7af1bcb8098","blobstore_id":"3ccf6ca4-ff9d-4b4a-8b91-0d30f0dd11c8"}],"template":"haproxy","version":"7bd402abf9d8fe86c1adf649c791fed92a03653c","sha1":"88a89bd6cd01c9b1390a2f0d27443c83b3a697a9","blobstore_id":"2dc34358-7cbe-4edd-84e6-aafee04dcd66"},"index":0,"networks":{"floating":{"type":"vip","ip":"9.91.39.29","cloud_properties":{},"dns_record_name":"0.ha-proxy-z1.floating.cf-warden.bosh"},"cf1":{"ip":"10.10.10.140","netmask":"255.255.255.0","cloud_properti es":{"net_id":"67a8ddc7-4d5f-432f-a154-660df2e8e69c","security_groups":["default"]},"default":["dns","gateway"],"dns":["10.10.10.3","10.10.10.64"],"gateway":"10.10.10.1","dns_record_name":"0.ha-proxy-z1.cf1.cf-warden.bosh"}},"resource_pool":{"name":"router_z1","cloud_properties":{"instance_type":"m1.medium"},"stemcell":{"name":"bosh-openstack-kvm-centos-7-go_agent-raw-m","version":"2962"}},"packages":{"haproxy":{"name":"haproxy","version":"630ad6d6e1d3cab4547ce104f3019b483f354613.1","sha1":"33522a7aef69d54845e4dbb2e3706a6e19f1b87d","blobstore_id":"148473d8-c738-4dce-5dc2-1e064a502354"},"common":{"name":"common","version":"99c756b71550530632e393f5189220f170a69647.1","sha1":"f4e3d8668a5cd7bbce48a5a600936e8fd1813e2b","blobstore_id":"3f8c19b4-aaaf-4ef0-5228-688538998b59"},"metron_agent":{"name":"metron_agent","version":"27c6122c3dcabaeac758bae7cb258910a5ac1e42.1","sha1":"d50ec240046610a5a6e3493258cc269778baa82d","blobstore_id":"1e91a9bd-8bb7-4f08-68ad-186fb62afef1"}},"configuration_hash ":"5ddbb2da0fc22bb3790622806d0b3ebce5e44cfc","properties":{"ha_proxy":{"ssl_pem":"-----BEGIN CERTIFICATE-----\nMIIDETCCAfmgAwIBAgIJANZuykf1uh3LMA0GCSqGSIb3DQEBBQUAMB8xHTAbBgNV\nBAMMFCouMTAuMjQ0LjAuMzQueGlwLmlvMB4XDTE0MTIyNDIzMTkxM1oXDTI0MTIy\nMTIzMTkxM1owHzEdMBsGA1UEAwwUKi4xMC4yNDQuMC4zNC54aXAuaW8wggEiMA0G\nCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQDCjq73Fgwfj2UT0/+wR9kVVsGAguMj\npoA0opLCgE0yHStAhSvqq7YpO39dH3vBMWXyr2xIfDyaeZyhV86jWu/ZKswGjNGI\nZKv/yUINe1bqukOBqd+SHVvkVhxSLJuD1MR83JQMONRjOPJp661/ABpVhnrNfBiA\nAA6aaFv4/KbyGY/E1FHoUXqEdh4WxaJdfX6SbgG05ArWxhSD7PNj4CYvJWGCdvqP\nKBsvWFDrkxBHn5h1JIDfZJB8FKP6vaHBr7MU4pIHM+qaZ1Y+8ja0wcgkHn4YHcp6\nIOhqpck7LaH5Qq2ydYFNTcG4fTbG0jXqcit2WSUxRkXzWnrgo2E0SiHBAgMBAAGj\nUDBOMB0GA1UdDgQWBBSpCtEDtEvMwaZzXN6Lvk5U7Eyn2zAfBgNVHSMEGDAWgBSp\nCtEDtEvMwaZzXN6Lvk5U7Eyn2zAMBgNVHRMEBTADAQH/MA0GCSqGSIb3DQEBBQUA\nA4IBAQB1YIHmw3gPiMn8WDR4yVxDvSVgFHY6ZE1iZb17vVs4N2/mhQZXWJ2nZV02\ngoAivtgxHOj39sK5OBWsGvrQo5H8dt1t4XmbwB1C6xRerGc25dhDRq42RqhCN0RJ\nzzjd9b8YSiwtAaZlW36l2jVDLfRa pb00tWToF9qYrDrmKy2sekS7g2hbiRStcue/\nbpT4X/CHxb/lUbpL4m8BpDbkGiOJgl+SEHRx5tZ0Kob/RDQRCcN3p+71FRbDIEBj\n+8sJl/yUUUPwQ6PNYx6cjtlICWJ1G0l0hRa141VXPqSNCmxYS4dp/8ifPCSoLc+k\n9TXFkuGl+86CPTyyMJxyMhEcAGZT\n-----END CERTIFICATE-----\n-----BEGIN RSA PRIVATE KEY-----\nMIIEpAIBAAKCAQEAwo6u9xYMH49lE9P/sEfZFVbBgILjI6aANKKSwoBNMh0rQIUr\n6qu2KTt/XR97wTFl8q9sSHw8mnmcoVfOo1rv2SrMBozRiGSr/8lCDXtW6rpDganf\nkh1b5FYcUiybg9TEfNyUDDjUYzjyaeutfwAaVYZ6zXwYgAAOmmhb+Pym8hmPxNRR\n6FF6hHYeFsWiXX1+km4BtOQK1sYUg+zzY+AmLyVhgnb6jygbL1hQ65MQR5+YdSSA\n32SQfBSj+r2hwa+zFOKSBzPqmmdWPvI2tMHIJB5+GB3KeiDoaqXJOy2h+UKtsnWB\nTU3BuH02xtI16nIrdlklMUZF81p64KNhNEohwQIDAQABAoIBAC1U3YOIyY5Y9O4n\nyT2jn/sO2cs9s/rMgrbA4n0bM+FnVnqUDOWC2NDGoihqe4VKIzzmjs5c1CoSB+K3\n+NerCpOJGzyzdubWvhS9KfzGLjxG5g/CKut6l7yeK78h0aJn4thM9NncK/BqhmET\nnrsmpPwkd1yFe5fna3+irTtYcvWZgxp8DK4JxIRB0QpJvEwbs9fUFE1E0DVw/uBV\nCytTIrik2O+n1m8S5xzsFXHXDjXT/TVNi3jtN12Oaj1avYZRP2q45RmcODhtHQIy\n4o0vqjyAmZb3jOcYysyXVwfyNreIH3Qn0/waflPkyaljMpa1OHVOCJFjh2Xl+aIc\ndQsME3kCgYE A4aXU2xb9SHew84/3ow6ZmBeYLm+7B8GUjDTe7HqLldtTUhlrJSdB\nSHZHZ/BXEQ126FnbfZ0IISkBjqVCQBw8MgjZAlaEIInDA1DRTLuOfrcyUD6PeSLi\ngVZHNYbR9MDnmJ3/So5HXiRy2rBWtLKwPlciqbwY+l3xYr2kP/QdCisCgYEA3LpB\nTBDTqp9j8QVvB/YjCakS+z+kgtO5HyMZO/uh6o9PRHrFQHwZA5y/MRrx9lxJ9zOd\nfqysKfA7fXs4VzNnRSnOfBmuDHF0HhlIgAShX/RnB94p9xnsQaMae/o2nXcknQng\n3qogvHWTo16GCJRE+YTmhA0QtvSlScJlTzHfqcMCgYAPRt/rWVoajufvBX85jeJ+\nNpK6Chx6gPOirm2tSvqqUagJdekYIdk8o61f7xil8ehsALFohronLJSLaMrcdkzp\nAkpW6y6U2V7XmaAh9szF7Xc9kY67H85//SxjBlauoGTNo1zGWm2ghQ01mxyzrSlb\nfyC8pxx1zuhpy/cT0V4p8wKBgQDb+EJaq+pFf9L5v5CHPqRsXDKucR5hwt4aScA8\nJumV+HvmovMw8Ht9PhjLty6rdg3AbY/nTe3FXcPrqYDcZj3kj2VYB7+MZwRxeoDm\nE7c/CTIkhSMNPqhUQVeDdjg3dSTn25BeVu2I4yPfC7RHmHukru2La/ncWrLebvzH\nj8x2QQKBgQDevjRDDTWbBkg8HdCRxxCvhfaHBntoSJdTHlr14Gce48NXGaXRJPQT\n9dMsPsSHkFxEra7G2clGnhpe+pK9V+WTrD9Qnoc+tK808hX1YQ6mBlnR6w99jlaR\nHVTi2pRhEhbWUkBv2kooXvD6ANb15PbPSF1FK7YyW1KHqcbm+lF22g==\n-----END RSA PRIVATE KEY-----\n","disable_http":false,"ssl_ciphers":"ECDHE-RSA-AES128-GCM-SH A256:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256:DHE-DSS-AES128-GCM-SHA256:kEDH+AESGCM:ECDHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA384:ECDHE-RSA-AES256-SHA:ECDHE-ECDSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES128-SHA:DHE-DSS-AES128-SHA256:DHE-RSA-AES256-SHA256:DHE-DSS-AES256-SHA:DHE-RSA-AES256-SHA:AES128-GCM-SHA256:AES256-GCM-SHA384:ECDHE-RSA-RC4-SHA:ECDHE-ECDSA-RC4-SHA:AES128:AES256:RC4-SHA:HIGH:!aNULL:!eNULL:!EXPORT:!DES:!3DES:!MD5:!PSK"},"request_timeout_in_seconds":900,"router":{"servers":{"z1":["10.10.10.141"],"z2":[]},"port":80},"networks":{"apps":"cf1"},"syslog_daemon_config":{"address":null,"port":null,"transport":"tcp"},"metron_agent":{"incoming_port":3456,"dropsonde_incoming_port":3457,"statsd_incoming_port":8125,"debug":false,"status":{"user":"","password":"","port":0},"zone":"z1","etcd_query_interval_mill iseconds":5000,"collector_registrar_interval_milliseconds":60000},"loggregator":{"incoming_port":3456,"dropsonde_incoming_port":3457},"loggregator_endpoint":{"shared_secret":"loggregator-secret"},"nats":{"user":"nats","password":"nats","machines":["10.10.10.142"],"port":4222},"etcd":{"machines":["10.10.10.143"],"maxconcurrentrequests":10}},"dns_domain_name":"bosh","persistent_disk":0,"template_hashes":{"haproxy":"66baf4bb051487714f5b6886a8fa27b645f783f2","metron_agent":"aa6290cab96fd7e456be9c34299a42c1aa90a104"},"rendered_templates_archive":{"blobstore_id":"d7018513-3179-436d-85a3-b12f719f3528","sha1":"0f48d34d5a0976dd906915472bbd8ffa3c9bb716"}}],"reply_to":"director.e08d0256-4216-4584-bc68-e44f890dde40.461607b8-e838-4540-a337-362ad963492a"} D, [2015-05-05 11:48:22 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.461607b8-e838-4540-a337-362ad963492a {"value":{"agent_task_id":"366d36d2-3f2f-4f51-4e51-e16f4a5e47f4","state":"running"}} D, [2015-05-05 11:48:22 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.9fa93e6b-52cb-445d-8c88-fdb11079d82f {"method":"get_task","arguments":["366d36d2-3f2f-4f51-4e51-e16f4a5e47f4"],"reply_to":"director.e08d0256-4216-4584-bc68-e44f890dde40.9474347c-5bd4-4c6f-9049-7436b19c25fe"} D, [2015-05-05 11:48:22 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.9474347c-5bd4-4c6f-9049-7436b19c25fe {"value":{"agent_task_id":"366d36d2-3f2f-4f51-4e51-e16f4a5e47f4","state":"running"}} D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.9fa93e6b-52cb-445d-8c88-fdb11079d82f {"method":"get_task","arguments":["366d36d2-3f2f-4f51-4e51-e16f4a5e47f4"],"reply_to":"director.e08d0256-4216-4584-bc68-e44f890dde40.456a41fb-0e12-46f6-ad9c-41bd526ca258"} D, [2015-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.456a41fb-0e12-46f6-ad9c-41bd526ca258 {"value":0} D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000893s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000891s) SELECT * FROM "tasks" WHERE "id" = 43 D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.9fa93e6b-52cb-445d-8c88-fdb11079d82f {"method":"stop","arguments":[],"reply_to":"director.e08d0256-4216-4584-bc68-e44f890dde40.31622716-e832-4e67-9dbb-ebb27830a8af"} D, [2015-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.31622716-e832-4e67-9dbb-ebb27830a8af {"value":{"agent_task_id":"3d66d0dd-07dc-455b-64e5-29f8f7249525","state":"running"}} D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: SENT: agent.9fa93e6b-52cb-445d-8c88-fdb11079d82f {"method":"get_task","arguments":["3d66d0dd-07dc-455b-64e5-29f8f7249525"],"reply_to":"director.e08d0256-4216-4584-bc68-e44f890dde40.ed386159-0e39-4616-92a7-c0feb863f38e"} D, [2015-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.ed386159-0e39-4616-92a7-c0feb863f38e {"value":"stopped"} I, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] INFO -- DirectorJobRunner: Snapshots are disabled; skipping I, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] INFO -- DirectorJobRunner: Skipping VM update I, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] INFO -- DirectorJobRunner: Skipping network re-configuration D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000803s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000555s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000515s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000464s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000735s) SELECT * FROM "records" WHERE (("name" = '0.ha-proxy-z1.floating.cf-warden.bosh') AND ("type" = 'A') AND ("content" = '9.91.39.29')) LIMIT 1 I, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] INFO -- DirectorJobRunner: Updating DNS for: 0.ha-proxy-z1.floating.cf-warden.bosh to 9.91.39.29 D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000345s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000256s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000472s) SELECT * FROM "records" WHERE (("domain_id" = 1) AND ("name" = '0.ha-proxy-z1.floating.cf-warden.bosh')) LIMIT 1 D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000330s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000347s) BEGIN D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000942s) INSERT INTO "records" ("domain_id", "name", "type", "ttl", "content", "change_date") VALUES (1, '0.ha-proxy-z1.floating.cf-warden.bosh', 'A', 300, '9.91.39.29', 1430826503) RETURNING D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001686s) COMMIT D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000352s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000369s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000311s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000448s) SELECT * FROM "domains" WHERE (("name" = '39.91.9.in-addr.arpa') AND ("type" = 'NATIVE')) LIMIT 1 D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000285s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000247s) BEGIN D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000429s) INSERT INTO "domains" ("name", "type") VALUES ('39.91.9.in-addr.arpa', 'NATIVE') RETURNING D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001353s) COMMIT D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000301s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000409s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000339s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000337s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000490s) SELECT * FROM "records" WHERE (("domain_id" = 6) AND ("name" = '39.91.9.in-addr.arpa') AND ("type" = 'SOA') AND ("content" = 'localhost hostmaster@localhost 0 10800 604800 30') AND ("ttl" = 14400)) LIMIT 1 D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000416s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000266s) BEGIN D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000497s) INSERT INTO "records" ("domain_id", "name", "type", "content", "ttl") VALUES (6, '39.91.9.in-addr.arpa', 'SOA', 'localhost hostmaster@localhost 0 10800 604800 30', 14400) RETURNING D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001004s) COMMIT D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000338s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000329s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000329s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000391s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000492s) SELECT * FROM "records" WHERE (("domain_id" = 6) AND ("name" = '39.91.9.in-addr.arpa') AND ("type" = 'NS') AND ("ttl" = 14400) AND ("content" = 'ns.bosh')) LIMIT 1 D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000363s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000323s) BEGIN D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000817s) INSERT INTO "records" ("domain_id", "name", "type", "ttl", "content") VALUES (6, '39.91.9.in-addr.arpa', 'NS', 14400, 'ns.bosh') RETURNING D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001443s) COMMIT D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000370s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000291s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000262s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000375s) SELECT * FROM "records" WHERE (("content" = '0.ha-proxy-z1.floating.cf-warden.bosh') AND ("type" = 'PTR')) LIMIT 1 D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000408s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000441s) BEGIN D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000789s) INSERT INTO "records" ("domain_id", "name", "type", "ttl", "content", "change_date") VALUES (6, '29.39.91.9.in-addr.arpa', 'PTR', 300, '0.ha-proxy-z1.floating.cf-warden.bosh', 1430826503) RETURNING D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001202s) COMMIT I, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] INFO -- DirectorJobRunner: Updating DNS for: 0.ha-proxy-z1.cf1.cf-warden.bosh to 10.10.10.140 D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000457s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000428s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000680s) SELECT * FROM "records" WHERE (("domain_id" = 1) AND ("name" = '0.ha-proxy-z1.cf1.cf-warden.bosh')) LIMIT 1 D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000499s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000375s) BEGIN D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000586s) INSERT INTO "records" ("domain_id", "name", "type", "ttl", "content", "change_date") VALUES (1, '0.ha-proxy-z1.cf1.cf-warden.bosh', 'A', 300, '10.10.10.140', 1430826503) RETURNING D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000957s) COMMIT D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000289s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000244s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000297s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000391s) SELECT * FROM "domains" WHERE (("name" = '10.10.10.in-addr.arpa') AND ("type" = 'NATIVE')) LIMIT 1 D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000256s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000223s) BEGIN D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000430s) INSERT INTO "domains" ("name", "type") VALUES ('10.10.10.in-addr.arpa', 'NATIVE') RETURNING D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001081s) COMMIT D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000357s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000336s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000324s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000320s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000488s) SELECT * FROM "records" WHERE (("domain_id" = 7) AND ("name" = '10.10.10.in-addr.arpa') AND ("type" = 'SOA') AND ("content" = 'localhost hostmaster@localhost 0 10800 604800 30') AND ("ttl" = 14400)) LIMIT 1 D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000361s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000287s) BEGIN D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000509s) INSERT INTO "records" ("domain_id", "name", "type", "content", "ttl") VALUES (7, '10.10.10.in-addr.arpa', 'SOA', 'localhost hostmaster@localhost 0 10800 604800 30', 14400) RETURNING D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001014s) COMMIT D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000338s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000287s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000331s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000289s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000463s) SELECT * FROM "records" WHERE (("domain_id" = 7) AND ("name" = '10.10.10.in-addr.arpa') AND ("type" = 'NS') AND ("ttl" = 14400) AND ("content" = 'ns.bosh')) LIMIT 1 D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000330s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000473s) BEGIN D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000892s) INSERT INTO "records" ("domain_id", "name", "type", "ttl", "content") VALUES (7, '10.10.10.in-addr.arpa', 'NS', 14400, 'ns.bosh') RETURNING D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001340s) COMMIT D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000479s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000447s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000382s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000606s) SELECT * FROM "records" WHERE (("content" = '0.ha-proxy-z1.cf1.cf-warden.bosh') AND ("type" = 'PTR')) LIMIT 1 D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000499s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000337s) BEGIN D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000801s) INSERT INTO "records" ("domain_id", "name", "type", "ttl", "content", "change_date") VALUES (7, '140.10.10.10.in-addr.arpa', 'PTR', 300, '0.ha-proxy-z1.cf1.cf-warden.bosh', 1430826503) RETURNING D, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001254s) COMMIT E, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] ERROR -- DirectorJobRunner: Error updating canary instance: #<Errno::ENOENT: No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl> /var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:in spawn' /var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:inpopen_run' /var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:93:in popen3' /var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:252:incapture3' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/dns_helper.rb:207:in flush_dns_cache' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:215:inupdate_dns' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:71:in block in update' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:37:instep' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:71:in update' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/job_updater.rb:74:inblock (2 levels) in update_canary_instance' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.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.2962.0/lib/bosh/director/job_updater.rb:72:inblock in update_canary_instance' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/event_log.rb:97:in call' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/event_log.rb:97:inadvance_and_track' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.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.2962.0/lib/bosh/director/job_updater.rb:65:inblock (2 levels) in update_canaries' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:77:in call' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:77:inblock (2 levels) in create_thread' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:63:in loop' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:63:inblock 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:inblock in create_with_logging_context' D, [2015-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: Worker thread raised exception: No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl - /var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:in spawn' /var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:inpopen_run' /var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:93:in popen3' /var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:252:incapture3' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/dns_helper.rb:207:in flush_dns_cache' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:215:inupdate_dns' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:71:in block in update' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:37:instep' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:71:in update' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/job_updater.rb:74:inblock (2 levels) in update_canary_instance' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.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.2962.0/lib/bosh/director/job_updater.rb:72:inblock in update_canary_instance' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/event_log.rb:97:in call' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/event_log.rb:97:inadvance_and_track' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.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.2962.0/lib/bosh/director/job_updater.rb:65:inblock (2 levels) in update_canaries' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:77:in call' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:77:inblock (2 levels) in create_thread' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:63:in loop' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:63:inblock 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:inblock in create_with_logging_context' D, [2015-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: Thread is no longer needed, cleaning up D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: Shutting down pool D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.005891s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.001478s) SELECT "stemcells".* FROM "stemcells" INNER JOIN "deployments_stemcells" ON (("deployments_stemcells"."stemcell_id" = "stemcells"."id") AND ("deployments_stemcells"."deployment_id" = 3)) D, [2015-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: Lock renewal thread exiting D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: Deleting lock: lock:deployment:cf-warden D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: Deleted lock: lock:deployment:cf-warden I, [2015-05-05 11:48:23 #20891] [task:43] INFO -- DirectorJobRunner: sending update deployment error event D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: SENT: hm.director.alert {"id":"2f9236d9-aa9a-464f-be68-2173793a47d4","severity":3,"title":"director - error during update deployment","summary":"Error during update deployment for 'cf-warden' against Director '609afeed-cd42-48dd-a3a6-08e5bf044992': #<Errno::ENOENT: No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl>","created_at":1430826503} E, [2015-05-05 11:48:23 #20891] [task:43] ERROR -- DirectorJobRunner: No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl /var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:in spawn' /var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:inpopen_run' /var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:93:in popen3' /var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:252:incapture3' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/dns_helper.rb:207:in flush_dns_cache' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:215:inupdate_dns' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:71:in block in update' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:37:instep' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/instance_updater.rb:71:in update' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/job_updater.rb:74:inblock (2 levels) in update_canary_instance' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.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.2962.0/lib/bosh/director/job_updater.rb:72:inblock in update_canary_instance' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/event_log.rb:97:in call' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.0/lib/bosh/director/event_log.rb:97:inadvance_and_track' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.2962.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.2962.0/lib/bosh/director/job_updater.rb:65:inblock (2 levels) in update_canaries' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:77:in call' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:77:inblock (2 levels) in create_thread' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:63:in loop' /var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:63:inblock 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:inblock in create_with_logging_context' D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.000320s) SELECT NULL D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.000293s) BEGIN D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.000943s) UPDATE "tasks" SET "state" = 'error', "timestamp" = '2015-05-05 11:48:23.258668+0000', "description" = 'create deployment', "result" = 'No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl', "output" = '/var/vcap/store/director/tasks/43', "checkpoint_time" = '2015-05-05 11:48:20.863669+0000', "type" = 'update_deployment', "username" = 'admin' WHERE ("id" = 43) D, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.002082s) COMMIT I, [2015-05-05 11:48:23 #20891] [] INFO -- DirectorJobRunner: Task took 1 minute 32.420035999999996 seconds to process.

Task 43 error

— Reply to this email directly or view it on GitHub https://github.com/cloudfoundry/bosh/issues/817#issuecomment-98893974.

guanglinlv commented 9 years ago

@bosh-ci @cppforlife ,

I use microbosh to deploy bosh. then, i use bosh to deploy CF.

so, the bosh director is collocated with powerDNS, is there some difference between bosh-155 and later version on the deployment file?

here is my deployment file:

---
name: bosh
director_uuid: 11a6c6ab-8419-4db9-9730-7e15a9f42ed0 # CHANGE

release:
  name: bosh
  version: latest

compilation:
  workers: 3
  network: default
  reuse_compilation_vms: true 
  cloud_properties:
    instance_type: m1.medium # CHANGE
#    availability_zone: szxts01-az

update:
  canaries: 1
  canary_watch_time: 3000-120000
  update_watch_time: 3000-120000
  max_in_flight: 50
  max_errors: 1
#  serial: true

networks:
  - name: floating
    type: vip
    cloud_properties: {}
  - name: default
    type: manual
    subnets:
      - name: private
        range: 10.10.10.0/24 # CHANGE
        gateway: 10.10.10.1 # CHANGE
        dns: [10.10.10.3] #CHANGE
        reserved:
          - 10.10.10.2 - 10.10.10.60 # CHANGE,100-110 larger than resource_pools["size"]
        static:
          - 10.10.10.61 - 10.10.10.70 # CHANGE
        cloud_properties:
          net_id: 67a8ddc7-4d5f-432f-a154-660df2e8e69c # CHANGE

resource_pools:
  - name: common
    network: default
    size: 8
    stemcell:
      name: bosh-openstack-kvm-centos-7-go_agent-raw-m
      version: latest
    cloud_properties:
      instance_type: m1.medium # CHANGE
#      availability_zone: szxts01-az

jobs:
  - name: nats
    template: nats
    instances: 1
    resource_pool: common
    networks:
      - name: default
        default: [dns, gateway]
        static_ips:
          - 10.10.10.61 # CHANGE

  - name: redis
    template: redis
    instances: 1
    resource_pool: common
    networks:
      - name: default
        default: [dns, gateway]
        static_ips:
          - 10.10.10.62 # CHANGE

  - name: postgres
    template: postgres
    instances: 1
    resource_pool: common
    persistent_disk: 16384
    networks:
      - name: default
        default: [dns, gateway]
        static_ips:
          - 10.10.10.63 # CHANGE

  - name: powerdns
    template: powerdns
    instances: 1
    resource_pool: common
    networks:
      - name: default
        default: [dns, gateway]
        static_ips:
          - 10.10.10.64 # CHANGE
      - name: floating
        static_ips:
          - 9.91.39.27 # CHANGE

  - name: blobstore
    template: blobstore
    instances: 1
    resource_pool: common
    persistent_disk: 51200
    networks:
      - name: default
        default: [dns, gateway]
        static_ips:
          - 10.10.10.65 # CHANGE

  - name: director
    template: director
    instances: 1
    resource_pool: common
    persistent_disk: 16384
    networks:
      - name: default
        default: [dns, gateway]
        static_ips:
          - 10.10.10.66 # CHANGE
      - name: floating
        static_ips:
          - 9.91.39.28 # CHANGE

  - name: registry
    template: registry
    instances: 1
    resource_pool: common
    networks:
      - name: default
        default: [dns, gateway]
        static_ips:
          - 10.10.10.67 # CHANGE

  - name: health_monitor
    template: health_monitor
    instances: 1
    resource_pool: common
    networks:
      - name: default
        default: [dns, gateway]
        static_ips:
          - 10.10.10.68 # CHANGE

properties:
  nats:
    address: 10.10.10.61 # CHANGE
    user: nats
    password: nats

  redis:
    address: 10.10.10.62 # CHANGE
    password: redis

  postgres: &bosh_db
    host: 10.10.10.63 # CHANGE
    user: postgres
    password: postgres
    database: bosh

  dns:
    address: 10.10.10.64 # CHANGE
    db: *bosh_db
    recursor: 9.91.39.27 # CHANGE

  blobstore:
    address: 10.10.10.65 # CHANGE
    agent:
      user: agent
      password: agent
    director:
      user: director
      password: director

  director:
    name: bosh
    address: 10.10.10.66 # CHANGE
    db: *bosh_db

  registry:
    address: 10.10.10.67 # CHANGE
    db: *bosh_db
    http:
      user: registry
      password: registry

  hm:
    http:
      user: hm
      password: hm
    director_account:
      user: admin
      password: admin
    resurrector_enabled: true

  ntp:
    - 0.north-america.pool.ntp.org
    - 1.north-america.pool.ntp.org

  openstack:
    auth_url: http://9.91.17.18:5000/v2.0 # CHANGE
    username: admin # CHANGE
    api_key: Huawei # CHANGE
    tenant: admin # CHANGE
#    region: RegionOne # CHANGE
    default_security_groups: ["default", "default"] # CHANGE
    default_key_name: lv_microbosh # CHANGE
#    ignore_server_availability_zone: true
ghost commented 9 years ago

Your Director is not collocated with the PowerDNS since they are on the different VMs. Collocated = on the same VM. Recently Director was changed to correctly flush DNS entries via /var/vcap/jobs/powerdns/bin/powerdns_ctl flush ( https://github.com/cloudfoundry/bosh/commit/2137b55d5405ee8af59474d0764934777dd75006). It looks like it does not properly account for the case when Director is on a separate VM from the PowerDNS. Not sure what can be done in that case...

On Mon, May 4, 2015 at 7:20 PM, guanglinlv notifications@github.com wrote:

@bosh-ci https://github.com/bosh-ci @cppforlife https://github.com/cppforlife ,

I use microbosh to deploy bosh. then, i use bosh to deploy CF.

so, the bosh director is collocated with powerDNS, is there some difference between bosh-155 and later version on the deployment file?

here is my deployment file:

---name: boshdirector_uuid: 11a6c6ab-8419-4db9-9730-7e15a9f42ed0 # CHANGE release: name: bosh version: latest compilation: workers: 3 network: default reuse_compilation_vms: true cloud_properties: instance_type: m1.medium # CHANGE# availability_zone: szxts01-az update: canaries: 1 canary_watch_time: 3000-120000 update_watch_time: 3000-120000 max_in_flight: 50 max_errors: 1# serial: true networks:

  • name: floating type: vip cloud_properties: {}
  • name: default type: manual subnets:
    • name: private range: 10.10.10.0/24 # CHANGE gateway: 10.10.10.1 # CHANGE dns: [10.10.10.3] #CHANGE reserved:
    • 10.10.10.2 - 10.10.10.60 # CHANGE,100-110 larger than resource_pools["size"] static:
    • 10.10.10.61 - 10.10.10.70 # CHANGE cloud_properties: net_id: 67a8ddc7-4d5f-432f-a154-660df2e8e69c # CHANGE resource_pools:
  • name: common network: default size: 8 stemcell: name: bosh-openstack-kvm-centos-7-go_agent-raw-m version: latest cloud_properties: instance_type: m1.medium # CHANGE# availability_zone: szxts01-az jobs:
  • name: nats template: nats instances: 1 resource_pool: common networks:
    • name: default default: [dns, gateway] static_ips:
    • 10.10.10.61 # CHANGE
  • name: redis template: redis instances: 1 resource_pool: common networks:
    • name: default default: [dns, gateway] static_ips:
    • 10.10.10.62 # CHANGE
  • name: postgres template: postgres instances: 1 resource_pool: common persistent_disk: 16384 networks:
    • name: default default: [dns, gateway] static_ips:
    • 10.10.10.63 # CHANGE
  • name: powerdns template: powerdns instances: 1 resource_pool: common networks:
    • name: default default: [dns, gateway] static_ips:
    • 10.10.10.64 # CHANGE
    • name: floating static_ips:
    • 9.91.39.27 # CHANGE
  • name: blobstore template: blobstore instances: 1 resource_pool: common persistent_disk: 51200 networks:
    • name: default default: [dns, gateway] static_ips:
    • 10.10.10.65 # CHANGE
  • name: director template: director instances: 1 resource_pool: common persistent_disk: 16384 networks:
    • name: default default: [dns, gateway] static_ips:
    • 10.10.10.66 # CHANGE
    • name: floating static_ips:
    • 9.91.39.28 # CHANGE
  • name: registry template: registry instances: 1 resource_pool: common networks:
    • name: default default: [dns, gateway] static_ips:
    • 10.10.10.67 # CHANGE

  • name: health_monitor template: health_monitor instances: 1 resource_pool: common networks:

    • name: default default: [dns, gateway] static_ips:
    • 10.10.10.68 # CHANGE properties: nats: address: 10.10.10.61 # CHANGE user: nats password: nats

    redis: address: 10.10.10.62 # CHANGE password: redis

    postgres: &bosh_db host: 10.10.10.63 # CHANGE user: postgres password: postgres database: bosh

    dns: address: 10.10.10.64 # CHANGE db: *bosh_db recursor: 9.91.39.27 # CHANGE

    blobstore: address: 10.10.10.65 # CHANGE agent: user: agent password: agent director: user: director password: director

    director: name: bosh address: 10.10.10.66 # CHANGE db: *bosh_db

    registry: address: 10.10.10.67 # CHANGE db: *bosh_db http: user: registry password: registry

    hm: http: user: hm password: hm director_account: user: admin password: admin resurrector_enabled: true

    ntp:

- 0.north-america.pool.ntp.org
- 1.north-america.pool.ntp.org

openstack: auth_url: http://9.91.17.18:5000/v2.0 # CHANGE username: admin # CHANGE api_key: Huawei # CHANGE tenant: admin # CHANGE# region: RegionOne # CHANGE default_security_groups: ["default", "default"] # CHANGE default_key_name: lv_microbosh # CHANGE# ignore_server_availability_zone: true

— Reply to this email directly or view it on GitHub https://github.com/cloudfoundry/bosh/issues/817#issuecomment-98908827.

guanglinlv commented 9 years ago

@bosh-ci ,thanks your help,i will try to deploy bosh director and powerDNS on the same VM.

also @mariash , can you help me to find out the scenario that bosh director is on a separate VM from the PowerDNS? thanks.

cppforlife commented 9 years ago

@guanglinlv What do you mean by "can you help me to find out the scenario that bosh director is on a separate VM from the PowerDNS?" You have your deployment set to do that.

guanglinlv commented 9 years ago

hi @cppforlife ,

if i deploy bosh director and powerDNS to a separate VM,just like my deployment said, i will get a error when i deploy CF with bosh.

Hi ,

It will be failed if i use bosh >155 to deploy CF,bosh-155 is successful.

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

Started updating job ha_proxy_z1 > ha_proxy_z1/0 (canary). Failed: No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl (00:00:03)

Error 100: No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl

Task 3 error powerdns is a component of bosh, right? why is it reported here?

however, if i let bosh director and powerDNS reside in the same VM, there is no this error.

cppforlife commented 9 years ago

That's correct. You should place your PowerDNS job on the same VM as Director after the changes we have made to properly flush the PowerDNS entries.

guanglinlv commented 9 years ago

@cppforlife

oh,it means that i cant deploy bosh director and powerDNS to different VM,right? it looks like a new limitation.if it is yes, i think the example of deployment would better update.

thanks.

dpb587-pivotal commented 8 years ago

Closing - original issue was resolved and [now bosh-init-managed] example manifests are maintained on bosh.io.