Task 1

I, [2017-10-13T19:09:54.116359 #12721] [0x2adfd5fc9114]  INFO -- TaskHelper: Director Version: 263.2.0
I, [2017-10-13T19:09:54.116436 #12721] [0x2adfd5fc9114]  INFO -- TaskHelper: Enqueuing task: 1
I, [2017-10-13 19:09:54 #13840] []  INFO -- DirectorJobRunner: Looking for task with task id 1
D, [2017-10-13 19:09:54 #13840] [] DEBUG -- DirectorJobRunner: (0.000460s) SELECT NULL
D, [2017-10-13 19:09:54 #13840] [] DEBUG -- DirectorJobRunner: (0.000408s) SELECT * FROM "tasks" WHERE "id" = 1
I, [2017-10-13 19:09:54 #13840] []  INFO -- DirectorJobRunner: Found task #<Bosh::Director::Models::Task @values={:id=>1, :state=>"processing", :timestamp=>2017-10-13 19:09:54 UTC, :description=>"create release", :result=>nil, :output=>"/var/vcap/store/director/tasks/1", :checkpoint_time=>2017-10-13 19:09:54 UTC, :type=>"update_release", :username=>"bosh_admin", :deployment_name=>nil, :started_at=>nil, :event_output=>"", :result_output=>"", :context_id=>""}>
I, [2017-10-13 19:09:54 #13840] []  INFO -- DirectorJobRunner: Running from worker 'worker_3' on director/7181df5c-1743-46d9-4365-acacd0945e0d (127.0.0.1)
I, [2017-10-13 19:09:54 #13840] []  INFO -- DirectorJobRunner: Starting task: 1
I, [2017-10-13 19:09:54 #13840] [task:1]  INFO -- DirectorJobRunner: Creating job
D, [2017-10-13 19:09:54 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000178s) SELECT NULL
D, [2017-10-13 19:09:54 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000485s) SELECT * FROM "tasks" WHERE "id" = 1
D, [2017-10-13 19:09:54 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000157s) SELECT NULL
D, [2017-10-13 19:09:54 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000217s) SELECT * FROM "tasks" WHERE "id" = 1
I, [2017-10-13 19:09:54 #13840] [task:1]  INFO -- DirectorJobRunner: Performing task: #<Bosh::Director::Models::Task @values={:id=>1, :state=>"processing", :timestamp=>2017-10-13 19:09:54 UTC, :description=>"create release", :result=>nil, :output=>"/var/vcap/store/director/tasks/1", :checkpoint_time=>2017-10-13 19:09:54 UTC, :type=>"update_release", :username=>"bosh_admin", :deployment_name=>nil, :started_at=>nil, :event_output=>"", :result_output=>"", :context_id=>""}>
D, [2017-10-13 19:09:54 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000182s) SELECT NULL
D, [2017-10-13 19:09:54 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000120s) BEGIN
D, [2017-10-13 19:09:54 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000430s) UPDATE "tasks" SET "state" = 'processing', "timestamp" = '2017-10-13 19:09:54.400527+0000', "description" = 'create release', "result" = NULL, "output" = '/var/vcap/store/director/tasks/1', "checkpoint_time" = '2017-10-13 19:09:54.403179+0000', "type" = 'update_release', "username" = 'bosh_admin', "deployment_name" = NULL, "started_at" = '2017-10-13 19:09:54.402985+0000', "event_output" = '', "result_output" = '', "context_id" = '' WHERE ("id" = 1)
D, [2017-10-13 19:09:54 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.003171s) COMMIT
I, [2017-10-13 19:09:54 #13840] [task:1]  INFO -- DirectorJobRunner: Processing update release
I, [2017-10-13 19:09:54 #13840] [task:1]  INFO -- DirectorJobRunner: Downloading remote release
D, [2017-10-13 19:09:54 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000202s) SELECT NULL
D, [2017-10-13 19:09:54 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000129s) BEGIN
D, [2017-10-13 19:09:54 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000534s) UPDATE "tasks" SET "event_output" = ("event_output" || '{"time":1507921794,"stage":"Downloading remote release","tags":[],"total":1,"task":"Downloading remote release","index":1,"state":"started","progress":0}
') WHERE ("id" = 1)
D, [2017-10-13 19:09:54 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.002432s) COMMIT
I, [2017-10-13 19:09:54 #13840] [task:1]  INFO -- DirectorJobRunner: Downloading remote release from https://bosh.io/d/github.com/cloudfoundry/dns-release?v=0.0.7
E, [2017-10-13 19:10:14 #13840] [task:1] ERROR -- DirectorJobRunner: Downloading remote release from https://bosh.io/d/github.com/cloudfoundry/dns-release?v=0.0.7 failed: #<SocketError: Failed to open TCP connection to bosh.io:443 (getaddrinfo: Name or service not known)>
D, [2017-10-13 19:10:14 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000445s) SELECT NULL
D, [2017-10-13 19:10:14 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000136s) BEGIN
D, [2017-10-13 19:10:14 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000414s) UPDATE "tasks" SET "event_output" = ("event_output" || '{"time":1507921814,"stage":"Downloading remote release","tags":[],"total":1,"task":"Downloading remote release","index":1,"state":"failed","progress":100,"data":{"error":"Downloading remote release failed. Check task debug log for details."}}
') WHERE ("id" = 1)
D, [2017-10-13 19:10:14 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.002720s) COMMIT
D, [2017-10-13 19:10:14 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000292s) SELECT NULL
D, [2017-10-13 19:10:14 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000134s) BEGIN
D, [2017-10-13 19:10:14 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000493s) UPDATE "tasks" SET "event_output" = ("event_output" || '{"time":1507921814,"error":{"code":100001,"message":"Downloading remote release failed. Check task debug log for details."}}
') WHERE ("id" = 1)
D, [2017-10-13 19:10:14 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.002970s) COMMIT
E, [2017-10-13 19:10:14 #13840] [task:1] ERROR -- DirectorJobRunner: Downloading remote release failed. Check task debug log for details.
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/download_helper.rb:54:in `rescue in download_remote_file'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/download_helper.rb:14:in `download_remote_file'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/jobs/update_release.rb:67:in `download_remote_release'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/jobs/update_release.rb:45:in `block in perform'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/jobs/base_job.rb:62:in `block in single_step_stage'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/jobs/base_job.rb:56:in `block in track_and_log'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/event_log.rb:105:in `advance_and_track'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/jobs/base_job.rb:54:in `track_and_log'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/jobs/base_job.rb:62:in `single_step_stage'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/jobs/update_release.rb:45:in `perform'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/job_runner.rb:96:in `perform_job'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/job_runner.rb:32:in `block in run'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh_common-0.0.0/lib/common/thread_formatter.rb:49:in `with_thread_name'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/job_runner.rb:32:in `run'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/jobs/base_job.rb:10:in `perform'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/jobs/db_job.rb:36:in `block in perform'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/bosh-director-0.0.0/lib/bosh/director/jobs/db_job.rb:85:in `block (3 levels) in run'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/eventmachine-1.0.4/lib/eventmachine.rb:1046:in `block in spawn_threadpool'
/var/vcap/packages/director/gem_home/ruby/2.3.0/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context'
D, [2017-10-13 19:10:14 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000240s) SELECT NULL
D, [2017-10-13 19:10:14 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000401s) SELECT * FROM "tasks" WHERE ("id" = 1) LIMIT 1
D, [2017-10-13 19:10:14 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000231s) SELECT NULL
D, [2017-10-13 19:10:14 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000140s) BEGIN
D, [2017-10-13 19:10:14 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.000508s) UPDATE "tasks" SET "state" = 'error', "timestamp" = '2017-10-13 19:10:14.455320+0000', "description" = 'create release', "result" = 'Downloading remote release failed. Check task debug log for details.', "output" = '/var/vcap/store/director/tasks/1', "checkpoint_time" = '2017-10-13 19:09:54.403179+0000', "type" = 'update_release', "username" = 'bosh_admin', "deployment_name" = NULL, "started_at" = '2017-10-13 19:09:54.402985+0000', "event_output" = '{"time":1507921794,"stage":"Downloading remote release","tags":[],"total":1,"task":"Downloading remote release","index":1,"state":"started","progress":0}
{"time":1507921814,"stage":"Downloading remote release","tags":[],"total":1,"task":"Downloading remote release","index":1,"state":"failed","progress":100,"data":{"error":"Downloading remote release failed. Check task debug log for details."}}
{"time":1507921814,"error":{"code":100001,"message":"Downloading remote release failed. Check task debug log for details."}}
', "result_output" = '', "context_id" = '' WHERE ("id" = 1)
D, [2017-10-13 19:10:14 #13840] [task:1] DEBUG -- DirectorJobRunner: (0.003034s) COMMIT
I, [2017-10-13 19:10:14 #13840] []  INFO -- DirectorJobRunner: Task took 20.063635373 seconds to process.

Task 1 error

Capturing task '1' output:
  Expected task '1' to succeed but state is 'error'

Exit code 1