search

GunSik2 / cf-deployment

0 stars 0 forks source link

cf-v226 on openstack kilo #4

Closed GunSik2 closed 8 years ago

GunSik2 commented 8 years ago 
ubuntu@op-v226:~/workspace/cf-release$ bosh upload release /home/ubuntu/workspace/cf-release/releases/cf-226.tgz
Acting as user 'admin' on 'bosh-director'

Verifying manifest...
Extract manifest                                             OK
Manifest exists                                              OK
Release name/version                                         OK

File exists and readable                                     OK
Read package 'acceptance-tests' (1 of 47)                    OK
Package 'acceptance-tests' checksum                          OK
Read package 'buildpack_binary' (2 of 47)                    OK
Package 'buildpack_binary' checksum                          OK
Read package 'buildpack_go' (3 of 47)                        OK
Package 'buildpack_go' checksum                              OK
Read package 'buildpack_java' (4 of 47)                      OK
Package 'buildpack_java' checksum                            OK
Read package 'buildpack_java_offline' (5 of 47)              OK
Package 'buildpack_java_offline' checksum                    OK
Read package 'buildpack_nodejs' (6 of 47)                    OK
Package 'buildpack_nodejs' checksum                          OK
Read package 'buildpack_php' (7 of 47)                       OK
Package 'buildpack_php' checksum                             OK
Read package 'buildpack_python' (8 of 47)                    OK
....

Uploading release
cf-226.tgz:    100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo|   2.0GB  24.4MB/s Time: 00:01:23

Director task 15
  Started extracting release > Extracting release. Done (00:00:24)

  Started verifying manifest > Verifying manifest. Done (00:00:00)

  Started resolving package dependencies > Resolving package dependencies. Done (00:00:00)

  Started creating new packages
  Started creating new packages > acceptance-tests/89aa1e4331ba32e04571e3681d215e484c7e0a2a. Done (00:00:01)
  Started creating new packages > buildpack_binary/e0c8736b073d83c2459519851b5736c288311d92. Done (00:00:00)
  Started creating new packages > buildpack_go/1045349b8adb8980e5b3048e69a7ea43804a096b. Done (00:00:04)
  Started creating new packages > buildpack_java/9dfade356c5a28e46d56823f262ef41775fe1d9a. Done (00:00:00)
  Started creating new packages > buildpack_java_offline/5a9ce8f1dc116e19b9defd173b795eeb0734a5cb. Done (00:00:04)
  Started creating new packages > buildpack_nodejs/651422654e2e681e9aa4c08e4b9e9afa540aeb56. Done (00:00:01)
  Started creating new packages > buildpack_php/f56676fa04128ef97ece1639a7f12a067247296d. Failed: Could not create object, 500/<html>
<head><title>500 Internal Server Error</title></head>
<body bgcolor="white">
<center><h1>500 Internal Server Error</h1></center>
<hr><center>nginx</center>
</body>
</html>
 (00:00:07)

Error 100: Could not create object, 500/<html>
<head><title>500 Internal Server Error</title></head>
<body bgcolor="white">
<center><h1>500 Internal Server Error</h1></center>
<hr><center>nginx</center>
</body>
</html>

Task 15 error
ubuntu@op-v226:~/workspace/cf-release$ bosh task 15 --debug
Acting as user 'admin' on 'bosh-director'

Director task 15
I, [2015-12-15T02:18:15.345918 #25634] [0x3fc261cb3334]  INFO -- TaskHelper: Director Version: 1.3063.0
I, [2015-12-15T02:18:15.345995 #25634] [0x3fc261cb3334]  INFO -- TaskHelper: Enqueuing task: 15
I, [2015-12-15 02:18:16 #13846] []  INFO -- DirectorJobRunner: Looking for task with task id 15
D, [2015-12-15 02:18:16 #13846] [] DEBUG -- DirectorJobRunner: (0.000283s) SELECT NULL
D, [2015-12-15 02:18:16 #13846] [] DEBUG -- DirectorJobRunner: (0.000268s) SELECT * FROM "tasks" WHERE "id" = 15
I, [2015-12-15 02:18:16 #13846] []  INFO -- DirectorJobRunner: Starting task: 15
I, [2015-12-15 02:18:16 #13846] [task:15]  INFO -- DirectorJobRunner: Creating job
D, [2015-12-15 02:18:16 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000108s) SELECT NULL
D, [2015-12-15 02:18:16 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000173s) SELECT * FROM "tasks" WHERE "id" = 15
I, [2015-12-15 02:18:16 #13846] [task:15]  INFO -- DirectorJobRunner: Performing task: 15
D, [2015-12-15 02:18:16 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000105s) SELECT NULL
D, [2015-12-15 02:18:16 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000068s) BEGIN
D, [2015-12-15 02:18:16 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000291s) UPDATE "tasks" SET "state" = 'processing', "timestamp" = '2015-12-15 02:18:16.297653+0000', "description" = 'create release', "result" = NULL, "output" = '/var/vcap/store/director/tasks/15', "checkpoint_time" = '2015-12-15 02:18:16.297739+0000', "type" = 'update_release', "username" = 'admin' WHERE ("id" = 15)
D, [2015-12-15 02:18:16 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000983s) COMMIT
I, [2015-12-15 02:18:16 #13846] [task:15]  INFO -- DirectorJobRunner: Processing update release
I, [2015-12-15 02:18:16 #13846] [task:15]  INFO -- DirectorJobRunner: Extracting release
I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Verifying manifest
I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Formatted version '226' => '226'
I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Acquiring release lock: cf
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: Acquiring lock: lock:release:cf
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: Acquired lock: lock:release:cf
D, [2015-12-15 02:18:40 #13846] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:release:cf
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000526s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000315s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000327s) SELECT * FROM "releases" WHERE ("name" = 'cf') LIMIT 1
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000103s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000097s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000206s) SELECT COUNT(*) AS "count" FROM "releases" WHERE ("name" = 'cf') LIMIT 1
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000138s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000069s) BEGIN
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000216s) INSERT INTO "releases" ("name") VALUES ('cf') RETURNING *
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.001998s) COMMIT
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000108s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000100s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000096s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000218s) SELECT * FROM "release_versions" WHERE (("release_versions"."release_id" = 3) AND ("version" = '226') AND ("uncommitted_changes" IS TRUE) AND ("commit_hash" = '5ac6aacd')) LIMIT 1
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000105s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000097s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000214s) SELECT COUNT(*) AS "count" FROM "release_versions" WHERE (("release_id" = 3) AND ("version" = '226')) LIMIT 1
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000097s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000065s) BEGIN
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000253s) INSERT INTO "release_versions" ("release_id", "version", "uncommitted_changes", "commit_hash") VALUES (3, '226', true, '5ac6aacd') RETURNING *
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.001001s) COMMIT
I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolving package dependencies
I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolving package dependencies for ["acceptance-tests", "buildpack_binary", "buildpack_go", "buildpack_java", "buildpack_java_offline", "buildpack_nodejs", "buildpack_php", "buildpack_python", "buildpack_ruby", "buildpack_staticfile", "cli", "cloud_controller_ng", "collector", "common", "consul", "consul-common", "dea_logging_agent", "dea_next", "debian_nfs_server", "doppler", "etcd", "etcd-common", "etcd_metrics_server", "gnatsd", "golang1.4", "gorouter", "haproxy", "hm9000", "libpq", "loggregator_trafficcontroller", "metron_agent", "mysqlclient-5.5", "nats", "nginx", "nginx_newrelic_plugin", "postgres-9.4.5", "rootfs_cflinuxfs2", "route_registrar", "routing-api", "rtr", "ruby-2.1.7", "ruby-2.2.3", "smoke-tests", "statsd-injector", "syslog_drain_binder", "uaa", "warden"]
I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `acceptance-tests': ["cli", "golang1.4", "rtr"]
 => ["cli", "golang1.4", "rtr"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `buildpack_binary': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `buildpack_go': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `buildpack_java': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `buildpack_java_offline': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `buildpack_nodejs': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `buildpack_php': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `buildpack_python': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `buildpack_ruby': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `buildpack_staticfile': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `cli': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `cloud_controller_ng': ["libpq", "mysqlclient-5.5", "ruby-2.2.3"]
 => ["libpq", "mysqlclient-5.5", "ruby-2.2.3"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `collector': ["ruby-2.1.7"]
 => ["ruby-2.1.7"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `common': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `consul': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `consul-common': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `dea_logging_agent': ["golang1.4"]
 => ["golang1.4"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `dea_next': ["golang1.4", "ruby-2.1.7"]
 => ["golang1.4", "ruby-2.1.7"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `debian_nfs_server': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `doppler': ["golang1.4"]
 => ["golang1.4"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `etcd': ["golang1.4"]
 => ["golang1.4"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `etcd-common': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `etcd_metrics_server': ["golang1.4"]
 => ["golang1.4"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `gnatsd': ["golang1.4"]
 => ["golang1.4"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `golang1.4': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `gorouter': ["golang1.4"]
 => ["golang1.4"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `haproxy': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `hm9000': ["golang1.4"]
 => ["golang1.4"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `libpq': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `loggregator_trafficcontroller': ["golang1.4"]
 => ["golang1.4"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `metron_agent': ["golang1.4"]
 => ["golang1.4"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `mysqlclient-5.5': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `nats': ["ruby-2.1.7"]
 => ["ruby-2.1.7"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `nginx': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `nginx_newrelic_plugin': ["ruby-2.2.3"]
 => ["ruby-2.2.3"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `postgres-9.4.5': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `rootfs_cflinuxfs2': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `route_registrar': ["ruby-2.1.7"]
 => ["ruby-2.1.7"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `routing-api': ["golang1.4"]
 => ["golang1.4"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `rtr': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `ruby-2.1.7': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `ruby-2.2.3': []
 => []

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `smoke-tests': ["cli"]
 => ["cli"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `statsd-injector': ["golang1.4"]
 => ["golang1.4"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `syslog_drain_binder': ["golang1.4"]
 => ["golang1.4"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `uaa': ["ruby-2.1.7"]
 => ["ruby-2.1.7"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Resolved package dependencies for `warden': ["ruby-2.1.7"]
 => ["ruby-2.1.7"]

I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Checking for new packages in release
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000110s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000108s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000195s) SELECT * FROM "packages" WHERE ("fingerprint" = '89aa1e4331ba32e04571e3681d215e484c7e0a2a')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000100s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000098s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000184s) SELECT * FROM "packages" WHERE ("fingerprint" = 'e0c8736b073d83c2459519851b5736c288311d92')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000105s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000100s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000194s) SELECT * FROM "packages" WHERE ("fingerprint" = '1045349b8adb8980e5b3048e69a7ea43804a096b')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000098s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000095s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000194s) SELECT * FROM "packages" WHERE ("fingerprint" = '9dfade356c5a28e46d56823f262ef41775fe1d9a')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000104s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000092s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000194s) SELECT * FROM "packages" WHERE ("fingerprint" = '5a9ce8f1dc116e19b9defd173b795eeb0734a5cb')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000097s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000091s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000173s) SELECT * FROM "packages" WHERE ("fingerprint" = '651422654e2e681e9aa4c08e4b9e9afa540aeb56')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000099s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000091s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000162s) SELECT * FROM "packages" WHERE ("fingerprint" = 'f56676fa04128ef97ece1639a7f12a067247296d')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000096s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000090s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000162s) SELECT * FROM "packages" WHERE ("fingerprint" = '4c83a11d2012d0a846f283a6e27e00b245dbd845')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000109s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000091s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000167s) SELECT * FROM "packages" WHERE ("fingerprint" = '9c2dbfb8e63da1ee5c8da008d84fb28f80944f37')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000099s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000091s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000161s) SELECT * FROM "packages" WHERE ("fingerprint" = 'ac1a56c13b8e90a3bf466db7fc1ac03c71107648')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000094s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000102s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000162s) SELECT * FROM "packages" WHERE ("fingerprint" = '6fb52c578aad523ba3c78bc350313d4aa4db7da9')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000096s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000089s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000174s) SELECT * FROM "packages" WHERE ("fingerprint" = 'fa50627862bae85bbbb0cb4d0bed7676008abfa1')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000094s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000091s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000163s) SELECT * FROM "packages" WHERE ("fingerprint" = '158398837665181c70bd786b46e6f4d772523017')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000101s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000091s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000162s) SELECT * FROM "packages" WHERE ("fingerprint" = 'e401816a4748292163679fafcbd8f818ed8154a5')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000095s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000090s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000160s) SELECT * FROM "packages" WHERE ("fingerprint" = '14b83378b30a2b55a25e641e835af3e5c87a0d41')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000096s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000093s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000244s) SELECT * FROM "packages" WHERE ("fingerprint" = 'ffab9ae7bea8a053aacca8816681e241b0fab30b')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000115s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000095s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000167s) SELECT * FROM "packages" WHERE ("fingerprint" = '0ad70ab12e5bdf94ee1d6d8ded0e461f3cca9770')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000096s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000090s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000161s) SELECT * FROM "packages" WHERE ("fingerprint" = '3059aac8a5f57982c35709cc7ce1585d64510858')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000094s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000117s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000167s) SELECT * FROM "packages" WHERE ("fingerprint" = 'aac05f22582b2f9faa6840da056084ed15772594')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000094s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000089s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000170s) SELECT * FROM "packages" WHERE ("fingerprint" = 'e8538c5e9d52ec8770337aa1c84bd917a4662802')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000093s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000089s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000159s) SELECT * FROM "packages" WHERE ("fingerprint" = 'd43feb5cdad0809d109df0afe6cd3c315dc94a61')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000096s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000089s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000187s) SELECT * FROM "packages" WHERE ("fingerprint" = 'a5492fb0ad41a80d2fa083172c0430073213a296')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000095s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000089s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000160s) SELECT * FROM "packages" WHERE ("fingerprint" = '5404a5025600d6922b92beb2c7815a63ee5430aa')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000105s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000091s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000159s) SELECT * FROM "packages" WHERE ("fingerprint" = '0242557ff8fc93c42ff54aa642c524b17ce203eb')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000093s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000109s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000160s) SELECT * FROM "packages" WHERE ("fingerprint" = '714698bc352d2a1dbe321376f0676037568147bb')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000093s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000088s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000172s) SELECT * FROM "packages" WHERE ("fingerprint" = '28fc53092fd9a473995aa3a36b5f4d609690f7ed')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000102s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000113s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000171s) SELECT * FROM "packages" WHERE ("fingerprint" = 'f5d89b125a66892628a8cd61d23be7f9b0d31171')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000094s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000088s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000160s) SELECT * FROM "packages" WHERE ("fingerprint" = '6a52baa96d06b4c7090d7923e1fe36f0c4e0dd33')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000093s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000089s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000160s) SELECT * FROM "packages" WHERE ("fingerprint" = '14d0b1290ea238243d04dd46d1a9635e6e9812bb')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000096s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000089s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000160s) SELECT * FROM "packages" WHERE ("fingerprint" = '6224f7a220924182b376e43b791ceda9750adff8')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000094s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000090s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000160s) SELECT * FROM "packages" WHERE ("fingerprint" = 'e50a1584f6163481e1627ec3a7a05d2950dbcc5f')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000117s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000105s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000176s) SELECT * FROM "packages" WHERE ("fingerprint" = 'c97be6846302ac67d8ad54ef08de4f741f8253ea')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000093s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000095s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000161s) SELECT * FROM "packages" WHERE ("fingerprint" = '560f582d348325a562493056b973bf49a9a78d33')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000093s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000089s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000173s) SELECT * FROM "packages" WHERE ("fingerprint" = 'bf3af6163e13887aacd230bbbc5eff90213ac6af')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000100s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000089s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000159s) SELECT * FROM "packages" WHERE ("fingerprint" = '72422b91a6eff1b172e3a3628946c722109da8ab')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000092s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000089s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000190s) SELECT * FROM "packages" WHERE ("fingerprint" = '06a51985e0701707b27d45c7a5757171b5cefb8c')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000094s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000091s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000161s) SELECT * FROM "packages" WHERE ("fingerprint" = '0c7713cbd01f9f8337f1f586f35f5e2eabd0cbc1')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000093s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000089s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000159s) SELECT * FROM "packages" WHERE ("fingerprint" = '5755494567906878c83a04bcdb0b8119a288bf39')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000093s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000090s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000160s) SELECT * FROM "packages" WHERE ("fingerprint" = 'b4a3e7034c4a925aa42d45419b46ad6b128d92b1')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000094s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000100s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000159s) SELECT * FROM "packages" WHERE ("fingerprint" = '2d7de4f6fc25938c21c5be87174f95583feb14b5')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000093s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000091s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000172s) SELECT * FROM "packages" WHERE ("fingerprint" = 'c977026b967eab6fad2b03a820dca6f84a900f92')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000096s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000089s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000159s) SELECT * FROM "packages" WHERE ("fingerprint" = 'b1320e11c7ad997a68103042d3d1c38270309387')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000108s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000090s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000165s) SELECT * FROM "packages" WHERE ("fingerprint" = '2c5dc1cbd1e6c91a3397d55234d168de08b4482c')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000093s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000090s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000159s) SELECT * FROM "packages" WHERE ("fingerprint" = '8c2166f3d82ffb8759d6eb409947121aca5123a1')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000104s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000090s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000159s) SELECT * FROM "packages" WHERE ("fingerprint" = '3c9c0b02c11c8dba10d059fe07e6d2ee641ec053')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000094s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000102s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000162s) SELECT * FROM "packages" WHERE ("fingerprint" = '47eaf41951557322f634eb5dbe613683bdbf275a')
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000093s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000089s) SELECT NULL
D, [2015-12-15 02:18:40 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000172s) SELECT * FROM "packages" WHERE ("fingerprint" = '000c3bf32806f123841970c293f44860c87efb44')
I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Creating new package `acceptance-tests/89aa1e4331ba32e04571e3681d215e484c7e0a2a'
I, [2015-12-15 02:18:40 #13846] [task:15]  INFO -- DirectorJobRunner: Creating package 'acceptance-tests/89aa1e4331ba32e04571e3681d215e484c7e0a2a' from provided bits
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000353s) SELECT NULL
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000099s) SELECT NULL
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000092s) SELECT NULL
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000352s) SELECT COUNT(*) AS "count" FROM "packages" WHERE (("release_id" = 3) AND ("name" = 'acceptance-tests') AND ("version" = '89aa1e4331ba32e04571e3681d215e484c7e0a2a')) LIMIT 1
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000094s) SELECT NULL
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000070s) BEGIN
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000405s) INSERT INTO "packages" ("release_id", "name", "sha1", "blobstore_id", "fingerprint", "version", "dependency_set_json") VALUES (3, 'acceptance-tests', '7a570ee3d8852b653b351b6be48b65d553bdbb17', 'f02827fa-2206-4c3a-a639-d86050f81b3a', '89aa1e4331ba32e04571e3681d215e484c7e0a2a', '89aa1e4331ba32e04571e3681d215e484c7e0a2a', '["cli","golang1.4","rtr"]') RETURNING *
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.017562s) COMMIT
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000112s) SELECT NULL
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000110s) SELECT NULL
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.025656s) SELECT pg_attribute.attname AS pk FROM pg_class, pg_attribute, pg_index, pg_namespace WHERE pg_class.oid = pg_attribute.attrelid AND pg_class.relnamespace = pg_namespace.oid AND pg_class.oid = pg_index.indrelid AND pg_index.indkey[0] = pg_attribute.attnum AND pg_index.indisprimary = 't' AND pg_class.relname = 'packages_release_versions'
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000139s) SELECT NULL
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.005069s) INSERT INTO "packages_release_versions" ("release_version_id", "package_id") VALUES (4, 13) RETURNING "id"
I, [2015-12-15 02:18:41 #13846] [task:15]  INFO -- DirectorJobRunner: Creating new package `buildpack_binary/e0c8736b073d83c2459519851b5736c288311d92'
I, [2015-12-15 02:18:41 #13846] [task:15]  INFO -- DirectorJobRunner: Creating package 'buildpack_binary/e0c8736b073d83c2459519851b5736c288311d92' from provided bits
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000180s) SELECT NULL
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000098s) SELECT NULL
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000095s) SELECT NULL
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000333s) SELECT COUNT(*) AS "count" FROM "packages" WHERE (("release_id" = 3) AND ("name" = 'buildpack_binary') AND ("version" = 'e0c8736b073d83c2459519851b5736c288311d92')) LIMIT 1
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000117s) SELECT NULL
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000087s) BEGIN
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000326s) INSERT INTO "packages" ("release_id", "name", "sha1", "blobstore_id", "fingerprint", "version", "dependency_set_json") VALUES (3, 'buildpack_binary', '720142bc1f4df421095b356ba90cea8172be83a5', '14bb367c-3e3c-4af0-833f-312e0d3b50ac', 'e0c8736b073d83c2459519851b5736c288311d92', 'e0c8736b073d83c2459519851b5736c288311d92', '[]') RETURNING *
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.001004s) COMMIT
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000119s) SELECT NULL
D, [2015-12-15 02:18:41 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.001336s) INSERT INTO "packages_release_versions" ("release_version_id", "package_id") VALUES (4, 14) RETURNING "id"
I, [2015-12-15 02:18:41 #13846] [task:15]  INFO -- DirectorJobRunner: Creating new package `buildpack_go/1045349b8adb8980e5b3048e69a7ea43804a096b'
I, [2015-12-15 02:18:41 #13846] [task:15]  INFO -- DirectorJobRunner: Creating package 'buildpack_go/1045349b8adb8980e5b3048e69a7ea43804a096b' from provided bits
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000424s) SELECT NULL
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000126s) SELECT NULL
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000104s) SELECT NULL
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000448s) SELECT COUNT(*) AS "count" FROM "packages" WHERE (("release_id" = 3) AND ("name" = 'buildpack_go') AND ("version" = '1045349b8adb8980e5b3048e69a7ea43804a096b')) LIMIT 1
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000104s) SELECT NULL
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000073s) BEGIN
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000360s) INSERT INTO "packages" ("release_id", "name", "sha1", "blobstore_id", "fingerprint", "version", "dependency_set_json") VALUES (3, 'buildpack_go', '3cbb82501e8f0f0434d964fe7e4ccd6411c50e0f', '8085b465-21a0-4a14-924f-2beb17d99933', '1045349b8adb8980e5b3048e69a7ea43804a096b', '1045349b8adb8980e5b3048e69a7ea43804a096b', '[]') RETURNING *
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.148457s) COMMIT
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000123s) SELECT NULL
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.010390s) INSERT INTO "packages_release_versions" ("release_version_id", "package_id") VALUES (4, 15) RETURNING "id"
I, [2015-12-15 02:18:45 #13846] [task:15]  INFO -- DirectorJobRunner: Creating new package `buildpack_java/9dfade356c5a28e46d56823f262ef41775fe1d9a'
I, [2015-12-15 02:18:45 #13846] [task:15]  INFO -- DirectorJobRunner: Creating package 'buildpack_java/9dfade356c5a28e46d56823f262ef41775fe1d9a' from provided bits
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000279s) SELECT NULL
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000103s) SELECT NULL
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000102s) SELECT NULL
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000329s) SELECT COUNT(*) AS "count" FROM "packages" WHERE (("release_id" = 3) AND ("name" = 'buildpack_java') AND ("version" = '9dfade356c5a28e46d56823f262ef41775fe1d9a')) LIMIT 1
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000103s) SELECT NULL
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000074s) BEGIN
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000366s) INSERT INTO "packages" ("release_id", "name", "sha1", "blobstore_id", "fingerprint", "version", "dependency_set_json") VALUES (3, 'buildpack_java', '1dbe1ff62880b013a928f087f4b918919158640f', '0bc1b473-d175-44b0-a6b9-44e4792324d0', '9dfade356c5a28e46d56823f262ef41775fe1d9a', '9dfade356c5a28e46d56823f262ef41775fe1d9a', '[]') RETURNING *
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000697s) COMMIT
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000105s) SELECT NULL
D, [2015-12-15 02:18:45 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000964s) INSERT INTO "packages_release_versions" ("release_version_id", "package_id") VALUES (4, 16) RETURNING "id"
I, [2015-12-15 02:18:45 #13846] [task:15]  INFO -- DirectorJobRunner: Creating new package `buildpack_java_offline/5a9ce8f1dc116e19b9defd173b795eeb0734a5cb'
I, [2015-12-15 02:18:45 #13846] [task:15]  INFO -- DirectorJobRunner: Creating package 'buildpack_java_offline/5a9ce8f1dc116e19b9defd173b795eeb0734a5cb' from provided bits
D, [2015-12-15 02:18:45 #13846] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:release:cf
D, [2015-12-15 02:18:46 #13846] [task:15-checkpoint] DEBUG -- DirectorJobRunner: (0.000284s) SELECT NULL
D, [2015-12-15 02:18:46 #13846] [task:15-checkpoint] DEBUG -- DirectorJobRunner: (0.000076s) BEGIN
D, [2015-12-15 02:18:46 #13846] [task:15-checkpoint] DEBUG -- DirectorJobRunner: (0.000533s) UPDATE "tasks" SET "checkpoint_time" = '2015-12-15 02:18:46.297624+0000' WHERE ("id" = 15)
D, [2015-12-15 02:18:46 #13846] [task:15-checkpoint] DEBUG -- DirectorJobRunner: (0.000922s) COMMIT
D, [2015-12-15 02:18:49 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000348s) SELECT NULL
D, [2015-12-15 02:18:49 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000104s) SELECT NULL
D, [2015-12-15 02:18:49 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000094s) SELECT NULL
D, [2015-12-15 02:18:49 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000331s) SELECT COUNT(*) AS "count" FROM "packages" WHERE (("release_id" = 3) AND ("name" = 'buildpack_java_offline') AND ("version" = '5a9ce8f1dc116e19b9defd173b795eeb0734a5cb')) LIMIT 1
D, [2015-12-15 02:18:49 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000098s) SELECT NULL
D, [2015-12-15 02:18:49 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000067s) BEGIN
D, [2015-12-15 02:18:49 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000314s) INSERT INTO "packages" ("release_id", "name", "sha1", "blobstore_id", "fingerprint", "version", "dependency_set_json") VALUES (3, 'buildpack_java_offline', '5384b670df224ef526e2f66d6b64532a2d15155b', 'b726a3b2-87d4-402f-9e3b-b0a481733822', '5a9ce8f1dc116e19b9defd173b795eeb0734a5cb', '5a9ce8f1dc116e19b9defd173b795eeb0734a5cb', '[]') RETURNING *
D, [2015-12-15 02:18:49 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.308354s) COMMIT
D, [2015-12-15 02:18:49 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000122s) SELECT NULL
D, [2015-12-15 02:18:49 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.402780s) INSERT INTO "packages_release_versions" ("release_version_id", "package_id") VALUES (4, 17) RETURNING "id"
I, [2015-12-15 02:18:49 #13846] [task:15]  INFO -- DirectorJobRunner: Creating new package `buildpack_nodejs/651422654e2e681e9aa4c08e4b9e9afa540aeb56'
I, [2015-12-15 02:18:49 #13846] [task:15]  INFO -- DirectorJobRunner: Creating package 'buildpack_nodejs/651422654e2e681e9aa4c08e4b9e9afa540aeb56' from provided bits
D, [2015-12-15 02:18:50 #13846] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:release:cf
D, [2015-12-15 02:18:50 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000484s) SELECT NULL
D, [2015-12-15 02:18:50 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000105s) SELECT NULL
D, [2015-12-15 02:18:50 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000097s) SELECT NULL
D, [2015-12-15 02:18:50 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000369s) SELECT COUNT(*) AS "count" FROM "packages" WHERE (("release_id" = 3) AND ("name" = 'buildpack_nodejs') AND ("version" = '651422654e2e681e9aa4c08e4b9e9afa540aeb56')) LIMIT 1
D, [2015-12-15 02:18:50 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000098s) SELECT NULL
D, [2015-12-15 02:18:50 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000077s) BEGIN
D, [2015-12-15 02:18:50 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000349s) INSERT INTO "packages" ("release_id", "name", "sha1", "blobstore_id", "fingerprint", "version", "dependency_set_json") VALUES (3, 'buildpack_nodejs', '54a9177103352cebd6742f35597b2ce25fbd48e3', '1c50e370-dd03-4339-b5af-351e5a5037f9', '651422654e2e681e9aa4c08e4b9e9afa540aeb56', '651422654e2e681e9aa4c08e4b9e9afa540aeb56', '[]') RETURNING *
D, [2015-12-15 02:18:50 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.001185s) COMMIT
D, [2015-12-15 02:18:50 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000108s) SELECT NULL
D, [2015-12-15 02:18:50 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.001025s) INSERT INTO "packages_release_versions" ("release_version_id", "package_id") VALUES (4, 18) RETURNING "id"
I, [2015-12-15 02:18:50 #13846] [task:15]  INFO -- DirectorJobRunner: Creating new package `buildpack_php/f56676fa04128ef97ece1639a7f12a067247296d'
I, [2015-12-15 02:18:50 #13846] [task:15]  INFO -- DirectorJobRunner: Creating package 'buildpack_php/f56676fa04128ef97ece1639a7f12a067247296d' from provided bits
D, [2015-12-15 02:18:55 #13846] [] DEBUG -- DirectorJobRunner: Renewing lock: lock:release:cf
D, [2015-12-15 02:18:57 #13846] [task:15] DEBUG -- DirectorJobRunner: Deleting lock: lock:release:cf
D, [2015-12-15 02:18:57 #13846] [task:15] DEBUG -- DirectorJobRunner: Deleted lock: lock:release:cf
D, [2015-12-15 02:18:57 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000335s) SELECT NULL
D, [2015-12-15 02:18:57 #13846] [] DEBUG -- DirectorJobRunner: Lock renewal thread exiting
D, [2015-12-15 02:18:57 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.002132s) DELETE FROM "packages_release_versions" WHERE ("release_version_id" = 4)
D, [2015-12-15 02:18:57 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000107s) SELECT NULL
D, [2015-12-15 02:18:57 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000163s) DELETE FROM "release_versions_templates" WHERE ("release_version_id" = 4)
D, [2015-12-15 02:18:57 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000108s) SELECT NULL
D, [2015-12-15 02:18:57 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000071s) BEGIN
D, [2015-12-15 02:18:57 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000322s) DELETE FROM "release_versions" WHERE "id" = 4
D, [2015-12-15 02:18:57 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000735s) COMMIT
E, [2015-12-15 02:18:57 #13846] [task:15] ERROR -- DirectorJobRunner: Could not create object, 500/<html>
<head><title>500 Internal Server Error</title></head>
<body bgcolor="white">
<center><h1>500 Internal Server Error</h1></center>
<hr><center>nginx</center>
</body>
</html>

/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/blobstore_client-1.3063.0/lib/blobstore_client/dav_blobstore_client.rb:41:in `create_file'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/blobstore_client-1.3063.0/lib/blobstore_client/base.rb:27:in `create'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/blob_util.rb:8:in `block in create_blob'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/blob_util.rb:8:in `open'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/blob_util.rb:8:in `create_blob'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/jobs/update_release.rb:468:in `save_package_source_blob'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/jobs/update_release.rb:444:in `create_package'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/jobs/update_release.rb:344:in `block (2 levels) in create_packages'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/event_log.rb:97:in `call'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.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.3063.0/lib/bosh/director/event_log.rb:50:in `track'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/jobs/update_release.rb:342:in `block in create_packages'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/jobs/update_release.rb:339:in `each'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/jobs/update_release.rb:339:in `create_packages'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/jobs/update_release.rb:251:in `process_packages'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/jobs/update_release.rb:150:in `process_release'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/jobs/update_release.rb:55:in `block in perform'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/lock_helper.rb:24:in `block in with_release_lock'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/lock_helper.rb:36:in `with_release_locks'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/lock_helper.rb:24:in `with_release_lock'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/jobs/update_release.rb:54:in `perform'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/job_runner.rb:108:in `perform_job'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/job_runner.rb:31:in `block in run'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh_common-1.3063.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.3063.0/lib/bosh/director/job_runner.rb:31:in `run'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/lib/bosh/director/jobs/base_job.rb:10:in `perform'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/resque-1.25.2/lib/resque/job.rb:227:in `perform'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/resque-1.25.2/lib/resque/worker.rb:250:in `perform'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/resque-1.25.2/lib/resque/worker.rb:189:in `block in work'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/resque-1.25.2/lib/resque/worker.rb:166:in `loop'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/resque-1.25.2/lib/resque/worker.rb:166:in `work'
/var/vcap/packages/director/gem_home/ruby/2.1.0/gems/bosh-director-1.3063.0/bin/bosh-director-worker:75:in `<top (required)>'
/var/vcap/packages/director/bin/bosh-director-worker:16:in `load'
/var/vcap/packages/director/bin/bosh-director-worker:16:in `<main>'
D, [2015-12-15 02:18:57 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000556s) SELECT NULL
D, [2015-12-15 02:18:57 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000102s) BEGIN
D, [2015-12-15 02:18:57 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000444s) UPDATE "tasks" SET "state" = 'error', "timestamp" = '2015-12-15 02:18:57.552629+0000', "description" = 'create release', "result" = 'Could not create object, 500/<html>
<head><title>500 Internal Server Error</title></head>
<body bgcolor="white">...', "output" = '/var/vcap/store/director/tasks/15', "checkpoint_time" = '2015-12-15 02:18:46.297624+0000', "type" = 'update_release', "username" = 'admin' WHERE ("id" = 15)
D, [2015-12-15 02:18:57 #13846] [task:15] DEBUG -- DirectorJobRunner: (0.000989s) COMMIT
I, [2015-12-15 02:18:57 #13846] []  INFO -- DirectorJobRunner: Task took 41.260504891 seconds to process.

Task 15 error
GunSik2 commented 8 years ago

The RCA was cinder volume wasn't created properly.