{"action":"created","issue":{"url":"https://api.github.com/repos/cloudfoundry/bosh/issues/817","labels_url":"https://api.github.com/repos/cloudfoundry/bosh/issues/817/labels{/name}","comments_url":"https://api.github.com/repos/cloudfoundry/bosh/issues/817/comments","events_url":"https://api.github.com/repos/cloudfoundry/bosh/issues/817/events","html_url":"https://github.com/cloudfoundry/bosh/issues/817","id":72941457,"number":817,"title":"Fail to deploy CF with bosh(>155)","user":{"login":"guanglinlv","id":10666676,"avatar_url":"https://avatars.githubusercontent.com/u/10666676?v=3","gravatar_id":"","url":"https://api.github.com/users/guanglinlv","html_url":"https://github.com/guanglinlv","followers_url":"https://api.github.com/users/guanglinlv/followers","following_url":"https://api.github.com/users/guanglinlv/following{/other_user}","gists_url":"https://api.github.com/users/guanglinlv/gists{/gist_id}","starred_url":"https://api.github.com/users/guanglinlv/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/guanglinlv/subscriptions","organizations_url":"https://api.github.com/users/guanglinlv/orgs","repos_url":"https://api.github.com/users/guanglinlv/repos","events_url":"https://api.github.com/users/guanglinlv/events{/privacy}","received_events_url":"https://api.github.com/users/guanglinlv/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":2,"created_at":"2015-05-04T07:16:06Z","updated_at":"2015-05-05T00:43:03Z","closed_at":null,"body":"Hi ,\r\n\r\nIt will be failed if i use `bosh >155` to deploy CF,`bosh-155` is successful.\r\n\r\n```log\r\n  Started preparing configuration > Binding configuration. Done (00:00:04)\r\n\r\n  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)\r\n\r\nError 100: No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl\r\n\r\nTask 3 error\r\n```\r\n\r\npowerdns is a component of bosh, right? why is it reported here?\r\n\r\n@cppforlife \r\n\r\n"},"comment":{"url":"https://api.github.com/repos/cloudfoundry/bosh/issues/comments/98893974","html_url":"https://github.com/cloudfoundry/bosh/issues/817#issuecomment-98893974","issue_url":"https://api.github.com/repos/cloudfoundry/bosh/issues/817","id":98893974,"user":{"login":"guanglinlv","id":10666676,"avatar_url":"https://avatars.githubusercontent.com/u/10666676?v=3","gravatar_id":"","url":"https://api.github.com/users/guanglinlv","html_url":"https://github.com/guanglinlv","followers_url":"https://api.github.com/users/guanglinlv/followers","following_url":"https://api.github.com/users/guanglinlv/following{/other_user}","gists_url":"https://api.github.com/users/guanglinlv/gists{/gist_id}","starred_url":"https://api.github.com/users/guanglinlv/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/guanglinlv/subscriptions","organizations_url":"https://api.github.com/users/guanglinlv/orgs","repos_url":"https://api.github.com/users/guanglinlv/repos","events_url":"https://api.github.com/users/guanglinlv/events{/privacy}","received_events_url":"https://api.github.com/users/guanglinlv/received_events","type":"User","site_admin":false},"created_at":"2015-05-05T00:43:03Z","updated_at":"2015-05-05T00:43:03Z","body":"@cppforlife \r\n\r\nit's too large, the part of debug log is given here:\r\n\r\n`bosh-155` is successful with the same cf(release and deployment file) and bosh(deployment file).\r\n\r\nthis failure is happened once each time when update jobs for each VM instance of CF,`bosh deploy` again after once failure will be successful.\r\n\r\n```log\r\n{\"method\":\"get_task\",\"arguments\":[\"8f11a8df-c6fd-4e58-4afa-240954c82352\"],\"reply_to\":\"director.e08d0256-4216-4584-bc68-e44f890dde40.236dd6cc-65ba-42da-afd9-f10e704fe6e4\"}\r\nD, [2015-05-05 11:48:22 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.236dd6cc-65ba-42da-afd9-f10e704fe6e4 {\"value\":\"prepared\"}\r\nD, [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\"}\r\nD, [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\"}}\r\nD, [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\"}\r\nD, [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\"}}\r\nD, [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\"}\r\nD, [2015-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.456a41fb-0e12-46f6-ad9c-41bd526ca258 {\"value\":0}\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000893s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000891s) SELECT * FROM \"tasks\" WHERE \"id\" = 43\r\nD, [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\"}\r\nD, [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\"}}\r\nD, [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\"}\r\nD, [2015-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: RECEIVED: director.e08d0256-4216-4584-bc68-e44f890dde40.ed386159-0e39-4616-92a7-c0feb863f38e {\"value\":\"stopped\"}\r\nI, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)]  INFO -- DirectorJobRunner: Snapshots are disabled; skipping\r\nI, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)]  INFO -- DirectorJobRunner: Skipping VM update\r\nI, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)]  INFO -- DirectorJobRunner: Skipping network re-configuration\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000803s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000555s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000515s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000464s) SELECT NULL\r\nD, [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\r\nI, [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\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000345s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000256s) SELECT NULL\r\nD, [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\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000330s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000347s) BEGIN\r\nD, [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 *\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001686s) COMMIT\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000352s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000369s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000311s) SELECT NULL\r\nD, [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\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000285s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000247s) BEGIN\r\nD, [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 *\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001353s) COMMIT\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000301s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000409s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000339s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000337s) SELECT NULL\r\nD, [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\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000416s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000266s) BEGIN\r\nD, [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 *\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001004s) COMMIT\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000338s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000329s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000329s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000391s) SELECT NULL\r\nD, [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\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000363s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000323s) BEGIN\r\nD, [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 *\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001443s) COMMIT\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000370s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000291s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000262s) SELECT NULL\r\nD, [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\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000408s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000441s) BEGIN\r\nD, [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 *\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001202s) COMMIT\r\nI, [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\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000457s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000428s) SELECT NULL\r\nD, [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\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000499s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000375s) BEGIN\r\nD, [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 *\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000957s) COMMIT\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000289s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000244s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000297s) SELECT NULL\r\nD, [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\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000256s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000223s) BEGIN\r\nD, [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 *\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001081s) COMMIT\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000357s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000336s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000324s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000320s) SELECT NULL\r\nD, [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\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000361s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000287s) BEGIN\r\nD, [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 *\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001014s) COMMIT\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000338s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000287s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000331s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000289s) SELECT NULL\r\nD, [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\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000330s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000473s) BEGIN\r\nD, [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 *\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001340s) COMMIT\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000479s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000447s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000382s) SELECT NULL\r\nD, [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\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000499s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.000337s) BEGIN\r\nD, [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 *\r\nD, [2015-05-05 11:48:23 #20891] [canary_update(ha_proxy_z1/0)] DEBUG -- DirectorJobRunner: (0.001254s) COMMIT\r\nE, [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>\r\n/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:in `spawn'\r\n/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:in `popen_run'\r\n/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:93:in `popen3'\r\n/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:252:in `capture3'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:77:in `call'\r\n/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'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:63:in `loop'\r\n/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'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `call'\r\n/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'\r\nD, [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'\r\n/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:in `popen_run'\r\n/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:93:in `popen3'\r\n/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:252:in `capture3'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:77:in `call'\r\n/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'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:63:in `loop'\r\n/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'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `call'\r\n/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'\r\nD, [2015-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: Thread is no longer needed, cleaning up\r\nD, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: Shutting down pool\r\nD, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.005891s) SELECT NULL\r\nD, [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))\r\nD, [2015-05-05 11:48:23 #20891] [] DEBUG -- DirectorJobRunner: Lock renewal thread exiting\r\nD, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: Deleting lock: lock:deployment:cf-warden\r\nD, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: Deleted lock: lock:deployment:cf-warden\r\nI, [2015-05-05 11:48:23 #20891] [task:43]  INFO -- DirectorJobRunner: sending update deployment error event\r\nD, [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}\r\nE, [2015-05-05 11:48:23 #20891] [task:43] ERROR -- DirectorJobRunner: No such file or directory - /var/vcap/jobs/powerdns/bin/powerdns_ctl\r\n/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:in `spawn'\r\n/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:193:in `popen_run'\r\n/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:93:in `popen3'\r\n/var/vcap/packages/ruby/lib/ruby/2.1.0/open3.rb:252:in `capture3'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/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'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:77:in `call'\r\n/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'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.2962.0/lib/common/thread_pool.rb:63:in `loop'\r\n/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'\r\n/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `call'\r\n/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'\r\nD, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.000320s) SELECT NULL\r\nD, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.000293s) BEGIN\r\nD, [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)\r\nD, [2015-05-05 11:48:23 #20891] [task:43] DEBUG -- DirectorJobRunner: (0.002082s) COMMIT\r\nI, [2015-05-05 11:48:23 #20891] []  INFO -- DirectorJobRunner: Task took 1 minute 32.420035999999996 seconds to process.\r\n\r\nTask 43 error\r\n```\r\n"}}