Skip to content

Instantly share code, notes, and snippets.

@grenzr

grenzr/gist:5575893

Created May 14, 2013 13:33
Show Gist options
  • Save grenzr/5575893 to your computer and use it in GitHub Desktop.
Save grenzr/5575893 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
gistfile1.txt
travis@precise64:/vagrant$ rake cf:init_cf_cli
==> Initializing cf CLI
Setting target to http://127.0.0.1:8181... OK
target: http://127.0.0.1:8181
Authenticating... OK
There are no spaces. You may want to create one with create-space.
Creating organization myorg... OK
Switching to organization myorg... OK
There are no spaces. You may want to create one with create-space.
Creating space myspace... OK
Adding you as a manager... OK
Adding you as a developer... OK
Space created! Use `cf switch-space myspace` to target it.
Switching to space myspace... OK
target: http://127.0.0.1:8181
organization: myorg
space: myspace
Now you can try to push the example app, like this:
> cd /vagrant/sinatra-test-app
> cf push
travis@precise64:/vagrant$ cd sinatra-test-app/
travis@precise64:/vagrant/sinatra-test-app$ cf push
Name> test-app
Instances> 1
Custom startup command> none
1: 64M
2: 128M
3: 256M
4: 512M
5: 1G
6: 2G
7: 4G
8: 8G
9: 16G
10: 32G
Memory Limit> 256M
Creating test-app... OK
1: test-app
2: none
Subdomain> test-app
1: vcap.me
2: none
Domain> vcap.me
Creating route test-app.vcap.me... OK
Binding test-app.vcap.me to test-app... OK
Create services for application?> n
Save configuration?> n
Uploading test-app... OK
Starting test-app... OK
-----> Downloaded app package (4.0K)
Installing ruby.
-----> Using Ruby version: ruby-1.9.2
-----> Installing dependencies using Bundler version 1.3.2
Running: bundle install --without development:test --path vendor/bundle --binstubs vendor/bundle/bin --deployment
Fetching gem metadata from http://rubygems.org/..........
Fetching gem metadata from http://rubygems.org/..
Installing rack (1.5.1)
Installing rack-protection (1.3.2)
Installing tilt (1.3.3)
Installing sinatra (1.3.4)
Using bundler (1.3.2)
Your bundle is complete! It was installed into ./vendor/bundle
Cleaning up the bundler cache.
-----> Uploading staged droplet (21M)
-----> Uploaded droplet
Checking test-app...
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 starting
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
0/1 instances: 1 down
Application failed to start.
Here are the logs from foreman:
00:14:16 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:14:16] "PUT /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/bits HTTP/1.1" 201 - 0.2745
00:14:16 dea_ng.1 | {"timestamp":1368490456.6990495,"message":"Received on \"staging.stop\": {\"app_id\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:14:16 dea_ng.1 | {"timestamp":1368490456.6994097,"message":"Received on \"staging.0-fddbbbf868db8195eaa6af3f1a8f79a9.start\": {\"app_id\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"task_id\"=>\"b73d068229756676a4613abc47727ba1\", \"properties\"=>{\"services\"=>[], \"buildpack\"=>nil, \"resources\"=>{\"memory\"=>256, \"disk\"=>1024, \"fds\"=>16384}, \"environment\"=>[], \"meta\"=>{\"console\"=>true}}, \"download_uri\"=>\"http://zxsfhgjg:[email protected]:8181/staging/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"upload_uri\"=>\"http://zxsfhgjg:[email protected]:8181/staging/droplets/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/upload\", \"buildpack_cache_download_uri\"=>\"http://zxsfhgjg:[email protected]:8181/staging/buildpack_cache/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/download\", \"buildpack_cache_upload_uri\"=>\"http://zxsfhgjg:[email protected]:8181/staging/buildpack_cache/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/upload\", \"async\"=>true}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:14:16 dea_ng.1 | {"timestamp":1368490456.6995692,"message":"Got async staging request with {\"app_id\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"task_id\"=>\"b73d068229756676a4613abc47727ba1\", \"properties\"=>{\"services\"=>[], \"buildpack\"=>nil, \"resources\"=>{\"memory\"=>256, \"disk\"=>1024, \"fds\"=>16384}, \"environment\"=>[], \"meta\"=>{\"console\"=>true}}, \"download_uri\"=>\"http://zxsfhgjg:[email protected]:8181/staging/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"upload_uri\"=>\"http://zxsfhgjg:[email protected]:8181/staging/droplets/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/upload\", \"buildpack_cache_download_uri\"=>\"http://zxsfhgjg:[email protected]:8181/staging/buildpack_cache/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/download\", \"buildpack_cache_upload_uri\"=>\"http://zxsfhgjg:[email protected]:8181/staging/buildpack_cache/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/upload\", \"async\"=>true}","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837"},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/responders/staging.rb","lineno":38,"method":"handle"}
00:14:16 dea_ng.1 | {"timestamp":1368490456.7014523,"message":"Downloading application from http://zxsfhgjg:[email protected]:8181/staging/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1"},"thread_id":15308800,"fiber_id":24973060,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/staging_task.rb","lineno":231,"method":"block in promise_app_download"}
00:14:16 dea_ng.1 | {"timestamp":1368490456.7043846,"message":"Downloading buildpack cache from http://zxsfhgjg:[email protected]:8181/staging/buildpack_cache/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/download","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1"},"thread_id":15308800,"fiber_id":24987800,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/staging_task.rb","lineno":285,"method":"block in promise_buildpack_cache_download"}
00:14:16 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:14:16] "GET /staging/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837 HTTP/1.1" 200 903 0.2700
00:14:16 dea_ng.1 | {"timestamp":1368490456.9786856,"message":"Download succeeded","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1"},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/utils/download.rb","lineno":68,"method":"block (2 levels) in download!"}
00:14:16 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:14:16] "GET /staging/buildpack_cache/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/download HTTP/1.1" 400 106 0.1287
00:14:16 dea_ng.1 | {"timestamp":1368490456.979218,"message":"Error downloading: http://zxsfhgjg:[email protected]:8181/staging/buildpack_cache/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/download (HTTP status: 400)","log_level":"warn","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1","droplet_uri":"http://zxsfhgjg:[email protected]:8181/staging/buildpack_cache/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/download","droplet_http_status":400},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/utils/download.rb","lineno":80,"method":"block (2 levels) in download!"}
00:14:16 dea_ng.1 | {"timestamp":1368490456.9793983,"message":"Failed to download buildpack cache from http://zxsfhgjg:[email protected]:8181/staging/buildpack_cache/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/download","log_level":"error","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1"},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/staging_task.rb","lineno":289,"method":"block (2 levels) in promise_buildpack_cache_download"}
00:14:17 warden.1 | {"timestamp":1368490348.888557,"message":"rlimit_nofile: 1024 => 32768","log_level":"debug2","source":"Warden::Server","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":266,"method":"run!"}
00:14:17 warden.1 | {"timestamp":1368490348.8887014,"message":"Configuration","log_level":"info","source":"Warden::Server","data":{"server":{"unix_domain_path":"/tmp/warden.sock","unix_domain_permissions":511,"container_klass":"Warden::Container::Linux","container_grace_time":300,"job_output_limit":10485760,"quota":{"disk_quota_enabled":true},"container_rootfs_path":"/var/warden/rootfs","container_depot_path":"/tmp/warden/containers","container_rlimits":{"as":4294967296,"nofile":8192,"nproc":512}},"logging":{"level":"debug2"},"network":{"pool_network":"10.254.0.0/22","deny_networks":[],"allow_networks":[]},"port":{"pool_start_port":61001,"pool_size":4000},"user":{"pool_start_uid":10000,"pool_size":256}},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":269,"method":"run!"}
00:14:17 warden.1 | {"timestamp":1368490359.1270657,"message":"Exited with status 0 (10.226s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/warden/warden/root/linux/setup.sh\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"stdout":"","stderr":"quotaon: Mountpoint (or device) / not found or has no quota enabled.\n"},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:14:17 warden.1 | {"timestamp":1368490359.1320648,"message":"Listening on /tmp/warden.sock","log_level":"info","source":"Warden::Server","data":{},"thread_id":9056240,"fiber_id":14705720,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":303,"method":"block (2 levels) in run!"}
00:14:17 warden.1 | {"timestamp":1368490456.7045093,"message":"Connection registered: #<Warden::Server::ClientConnection:0x00000001c2f348>","log_level":"debug2","source":"Warden::Server::Drainer","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":88,"method":"register_connection"}
00:14:17 warden.1 | {"timestamp":1368490456.7069416,"message":"<Warden::Protocol::CreateRequest bind_mounts: [<Warden::Protocol::CreateRequest::BindMount src_path: \"/tmp/dea_ng/staging/d20130514-1977-sr67uo\", dst_path: \"/tmp/dea_ng/staging/d20130514-1977-sr67uo\", mode: RO(0)>, <Warden::Protocol::CreateRequest::BindMount src_path: \"/vagrant/dea_ng/buildpacks\", dst_path: \"/vagrant/dea_ng/buildpacks\", mode: RO(0)>]>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:14:17 warden.1 | {"timestamp":1368490456.7159245,"message":"Exited with status 0 (0.008s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"setquota\", \"-u\", \"10000\", \"0\", \"0\", \"0\", \"0\", \"/\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:14:17 warden.1 | {"timestamp":1368490456.920128,"message":"Exited with status 0 (0.203s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/warden/warden/root/linux/create.sh\", \"/tmp/warden/containers/16ska1ops1f\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"/tmp/warden/containers/16ska1ops1f\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:14:17 warden.1 | {"timestamp":1368490456.9202209,"message":"Container created","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":14892220,"process_id":2001,"file":"/warden/warden/lib/warden/container/linux.rb","lineno":104,"method":"do_create"}
00:14:17 warden.1 | {"timestamp":1368490456.9208457,"message":"Wrote bind mount commands","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":14892220,"process_id":2001,"file":"/warden/warden/lib/warden/container/linux.rb","lineno":107,"method":"do_create"}
00:14:17 warden.1 | {"timestamp":1368490457.1810067,"message":"Exited with status 0 (0.259s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/start.sh\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:14:17 warden.1 | {"timestamp":1368490457.1811056,"message":"Container started","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":14892220,"process_id":2001,"file":"/warden/warden/lib/warden/container/linux.rb","lineno":110,"method":"do_create"}
00:14:17 warden.1 | {"timestamp":1368490457.1815512,"message":"Wrote snapshot in 0.000340","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":14892220,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:14:17 warden.1 | {"timestamp":1368490457.1816418,"message":"create (took 0.474501)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"bind_mounts":["#<Warden::Protocol::CreateRequest::BindMount:0x00000001c48cd0>","#<Warden::Protocol::CreateRequest::BindMount:0x00000001c50e80>"]},"response":{"handle":"16ska1ops1f"}},"thread_id":9056240,"fiber_id":14892220,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:14:17 warden.1 | {"timestamp":1368490457.1817255,"message":"<Warden::Protocol::CreateResponse handle: \"16ska1ops1f\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14892220,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:14:17 warden.1 | {"timestamp":1368490457.1830904,"message":"<Warden::Protocol::LimitDiskRequest handle: \"16ska1ops1f\", byte: 2147483648>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:14:17 warden.1 | {"timestamp":1368490457.1867864,"message":"Exited with status 0 (0.003s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/warden/warden/src/repquota/repquota\", \"/\", \"10000\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"stdout":"10000 16384 0 0 0 4 0 0 0\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:14:17 warden.1 | {"timestamp":1368490457.1892178,"message":"Exited with status 0 (0.002s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"setquota\", \"-u\", \"10000\", \"0\", \"2097152\", \"0\", \"0\", \"/\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:14:17 warden.1 | {"timestamp":1368490457.1913774,"message":"Exited with status 0 (0.001s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/warden/warden/src/repquota/repquota\", \"/\", \"10000\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"stdout":"10000 16384 0 2097152 0 4 0 0 0\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:14:17 dea_ng.1 | {"timestamp":1368490457.1975205,"message":"Preparing staging log: mkdir -p /tmp/staged/logs && touch /tmp/staged/logs/staging_task.log","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1","warden_handle":"16ska1ops1f"},"thread_id":15308800,"fiber_id":25925160,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/staging_task.rb","lineno":152,"method":"block in promise_prepare_staging_log"}
00:14:17 warden.1 | {"timestamp":1368490457.1920676,"message":"Wrote snapshot in 0.000539","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":15339360,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:14:17 warden.1 | {"timestamp":1368490457.1923363,"message":"limit_disk (took 0.008915)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","byte":2147483648},"response":{"block_limit":2097152,"block":2097152,"block_soft":0,"block_hard":2097152,"inode_limit":0,"inode":0,"inode_soft":0,"inode_hard":0,"byte_limit":2147483648,"byte":2147483648,"byte_soft":0,"byte_hard":2147483648}},"thread_id":9056240,"fiber_id":15339360,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:14:17 warden.1 | {"timestamp":1368490457.192616,"message":"<Warden::Protocol::LimitDiskResponse block_limit: 2097152, block: 2097152, block_soft: 0, block_hard: 2097152, inode_limit: 0, inode: 0, inode_soft: 0, inode_hard: 0, byte_limit: 2147483648, byte: 2147483648, byte_soft: 0, byte_hard: 2147483648>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":15339360,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:14:17 warden.1 | {"timestamp":1368490457.1953316,"message":"<Warden::Protocol::LimitMemoryRequest handle: \"16ska1ops1f\", limit_in_bytes: 1073741824>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:14:17 warden.1 | {"timestamp":1368490457.1969097,"message":"Wrote snapshot in 0.000364","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":15666380,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:14:17 warden.1 | {"timestamp":1368490457.196997,"message":"limit_memory (took 0.001540)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","limit_in_bytes":1073741824},"response":{"limit_in_bytes":1073741824}},"thread_id":9056240,"fiber_id":15666380,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:14:17 warden.1 | {"timestamp":1368490457.1970825,"message":"<Warden::Protocol::LimitMemoryResponse limit_in_bytes: 1073741824>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":15666380,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:14:17 warden.1 | {"timestamp":1368490457.1986759,"message":"Connection registered: #<Warden::Server::ClientConnection:0x00000001e1a7e8>","log_level":"debug2","source":"Warden::Server::Drainer","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":88,"method":"register_connection"}
00:14:17 warden.1 | {"timestamp":1368490457.198887,"message":"<Warden::Protocol::RunRequest handle: \"16ska1ops1f\", script: \"mkdir -p /tmp/staged/logs && touch /tmp/staged/logs/staging_task.log\", privileged: false>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:14:17 warden.1 | {"timestamp":1368490457.1999702,"message":"<Warden::Protocol::InfoRequest handle: \"16ska1ops1f\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:14:17 warden.1 | {"timestamp":1368490457.2056386,"message":"Wrote snapshot in 0.000697","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":15829740,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:14:17 warden.1 | {"timestamp":1368490457.205792,"message":"spawn (took 0.006692)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":"mkdir -p /tmp/staged/logs && touch /tmp/staged/logs/staging_task.log"},"response":{"job_id":1}},"thread_id":9056240,"fiber_id":15829740,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:14:17 warden.1 | {"timestamp":1368490457.222019,"message":"Exited with status 0 (0.022s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-spawn\", \"/tmp/warden/containers/16ska1ops1f/jobs/1\", \"/tmp/warden/containers/16ska1ops1f/bin/wsh\", \"--socket\", \"/tmp/warden/containers/16ska1ops1f/run/wshd.sock\", \"--user\", \"vcap\", \"/bin/bash\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"child_pid=2765\nchild active\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:14:17 warden.1 | {"timestamp":1368490457.2221572,"message":"Exited with status 0 (0.021s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/net.sh\", \"get_egress_info\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"qdisc pfifo_fast 0: root refcnt 2 bands 3 priomap 1 2 2 2 1 2 0 0 1 1 1 1 1 1 1 1\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:14:17 warden.1 | {"timestamp":1368490457.222914,"message":"Exited with status 0 (0.021s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-link\", \"-w\", \"/tmp/warden/containers/16ska1ops1f/jobs/1/cursors\", \"/tmp/warden/containers/16ska1ops1f/jobs/1\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:14:17 warden.1 | {"timestamp":1368490457.223767,"message":"Wrote snapshot in 0.000724","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:14:17 warden.1 | {"timestamp":1368490457.2410207,"message":"link (took 0.035013)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","job_id":1},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":15829740,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:14:17 warden.1 | {"timestamp":1368490457.2411454,"message":"run (took 0.042131)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":"mkdir -p /tmp/staged/logs && touch /tmp/staged/logs/staging_task.log"},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":15829740,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:14:17 warden.1 | {"timestamp":1368490457.2412388,"message":"<Warden::Protocol::RunResponse exit_status: 0, stdout: \"\", stderr: \"\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":15829740,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:14:17 warden.1 | {"timestamp":1368490457.2417128,"message":"<Warden::Protocol::RunRequest handle: \"16ska1ops1f\", script: \"mkdir -p /app && touch /app/support_heroku_buildpacks && chown -R vcap:vcap /app\", privileged: true>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:14:17 dea_ng.1 | {"timestamp":1368490457.265153,"message":"Unpacking app to /tmp/unstaged","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1","warden_handle":"16ska1ops1f"},"thread_id":15308800,"fiber_id":25143340,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/staging_task.rb","lineno":207,"method":"block in promise_unpack_app"}
00:14:17 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:14:17] "PUT /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837?stage_async=true HTTP/1.1" 201 1148 0.7306
00:14:17 warden.1 | {"timestamp":1368490457.249017,"message":"Exited with status 0 (0.026s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/net.sh\", \"get_ingress_info\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:14:17 warden.1 | {"timestamp":1368490457.2529833,"message":"Exited with status 0 (0.003s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/warden/warden/src/repquota/repquota\", \"/\", \"10000\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"stdout":"10000 24576 0 2097152 0 7 0 0 0\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:14:17 warden.1 | {"timestamp":1368490457.2531617,"message":"info (took 0.052974)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f"},"response":{"state":"active","events":[],"host_ip":"10.254.0.1","container_ip":"10.254.0.2","container_path":"/tmp/warden/containers/16ska1ops1f","memory_stat":"#<Warden::Protocol::InfoResponse::MemoryStat:0x00000001e906c8>","cpu_stat":"#<Warden::Protocol::InfoResponse::CpuStat:0x00000001e8e9e0>","disk_stat":"#<Warden::Protocol::InfoResponse::DiskStat:0x00000001587360>","bandwidth_stat":"#<Warden::Protocol::InfoResponse::BandwidthStat:0x000000014b5c98>","job_ids":[]}},"thread_id":9056240,"fiber_id":15912000,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:14:17 warden.1 | {"timestamp":1368490457.2533739,"message":"<Warden::Protocol::InfoResponse state: \"active\", events: [], host_ip: \"10.254.0.1\", container_ip: \"10.254.0.2\", container_path: \"/tmp/warden/containers/16ska1ops1f\", memory_stat: <Warden::Protocol::InfoResponse::MemoryStat cache: 1036288, rss: 20480, mapped_file: 0, pgpgin: 1000, pgpgout: 742, swap: 0, pgfault: 4273, pgmajfault: 12, inactive_anon: 0, active_anon: 20480, inactive_file: 798720, active_file: 237568, unevictable: 0, hierarchical_memory_limit: 1073741824, hierarchical_memsw_limit: 1073741824, total_cache: 1036288, total_rss: 20480, total_mapped_file: 0, total_pgpgin: 1000, total_pgpgout: 742, total_swap: 0, total_pgfault: 4273, total_pgmajfault: 12, total_inactive_anon: 0, total_active_anon: 20480, total_inactive_file: 798720, total_active_file: 237568, total_unevictable: 0>, cpu_stat: <Warden::Protocol::InfoResponse::CpuStat usage: 13932101, user: 0, system: 0>, disk_stat: <Warden::Protocol::InfoResponse::DiskStat bytes_used: 24576, inodes_used: 7>, bandwidth_stat: <Warden::Protocol::InfoResponse::BandwidthStat in_rate: 4294967295, in_burst: 4294967295, out_rate: 4294967295, out_burst: 4294967295>, job_ids: []>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":15912000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:14:17 warden.1 | {"timestamp":1368490457.2551734,"message":"Wrote snapshot in 0.000540","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":9646620,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:14:17 warden.1 | {"timestamp":1368490457.2552817,"message":"spawn (took 0.012933)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":"mkdir -p /app && touch /app/support_heroku_buildpacks && chown -R vcap:vcap /app","privileged":true},"response":{"job_id":2}},"thread_id":9056240,"fiber_id":9646620,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:14:17 warden.1 | {"timestamp":1368490457.262541,"message":"Exited with status 0 (0.015s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-spawn\", \"/tmp/warden/containers/16ska1ops1f/jobs/2\", \"/tmp/warden/containers/16ska1ops1f/bin/wsh\", \"--socket\", \"/tmp/warden/containers/16ska1ops1f/run/wshd.sock\", \"--user\", \"root\", \"/bin/bash\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"child_pid=2808\nchild active\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:14:17 warden.1 | {"timestamp":1368490457.2631612,"message":"Exited with status 0 (0.011s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-link\", \"-w\", \"/tmp/warden/containers/16ska1ops1f/jobs/2/cursors\", \"/tmp/warden/containers/16ska1ops1f/jobs/2\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:14:17 warden.1 | {"timestamp":1368490457.2636733,"message":"Wrote snapshot in 0.000393","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:14:17 warden.1 | {"timestamp":1368490457.26413,"message":"link (took 0.008391)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","job_id":2},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":9646620,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:14:17 warden.1 | {"timestamp":1368490457.2642395,"message":"run (took 0.021954)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":"mkdir -p /app && touch /app/support_heroku_buildpacks && chown -R vcap:vcap /app","privileged":true},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":9646620,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:14:17 warden.1 | {"timestamp":1368490457.2643218,"message":"<Warden::Protocol::RunResponse exit_status: 0, stdout: \"\", stderr: \"\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":9646620,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:14:17 warden.1 | {"timestamp":1368490457.2659419,"message":"<Warden::Protocol::RunRequest handle: \"16ska1ops1f\", script: \" package_size=`du -h /tmp/dea_ng/staging/d20130514-1977-sr67uo/app.zip | cut -f1`\\n echo \\\"-----> Downloaded app package ($package_size)\\\" >> /tmp/staged/logs/staging_task.log\\n unzip -q /tmp/dea_ng/staging/d20130514-1977-sr67uo/app.zip -d /tmp/unstaged\\n\", privileged: false>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:14:17 warden.1 | {"timestamp":1368490457.2724583,"message":"Wrote snapshot in 0.000235","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":12550660,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:14:17 warden.1 | {"timestamp":1368490457.2725523,"message":"spawn (took 0.006417)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":" package_size=`du -h /tmp/dea_ng/staging/d20130514-1977-sr67uo/app.zip | cut -f1`\n echo \"-----> Downloaded app package ($package_size)\" >> /tmp/staged/logs/staging_task.log\n unzip -q /tmp/dea_ng/staging/d20130514-1977-sr67uo/app.zip -d /tmp/unstaged\n"},"response":{"job_id":3}},"thread_id":9056240,"fiber_id":12550660,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:14:17 dea_ng.1 | {"timestamp":1368490457.2973747,"message":"Staging: PLATFORM_CONFIG=/tmp/dea_ng/staging/d20130514-1977-sr67uo/platform_config BUILDPACK_CACHE=/var/vcap/packages/buildpack_cache STAGING_TIMEOUT=900.0 /usr/bin/ruby /vagrant/dea_ng/buildpacks/bin/run /tmp/dea_ng/staging/d20130514-1977-sr67uo/plugin_config >> /tmp/staged/logs/staging_task.log 2>&1","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1","warden_handle":"16ska1ops1f"},"thread_id":15308800,"fiber_id":22891720,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/staging_task.rb","lineno":179,"method":"block in promise_stage"}
00:14:17 dir_server.1 | {"Timestamp":1.368490457821731e+09,"Message":"Sending HTTP request to DEA: http://127.0.0.1:1234/staging_tasks/b73d068229756676a4613abc47727ba1/file_path?hmac=8b2aea13ae204bee7c8b4a208fe10611041049d8c8be1b3f2267d8e1c363c0362bd7160ec2c5ef7e6dc681c95ef03494dbf0bdf9eb5a65500016c5b5cdae2cef&path=%2Ftmp%2Fstaged%2Flogs%2Fstaging_task.log&timestamp=1368490457&tail&tail_offset=0","Level":"info","Data":null,"File":"","Method":"","Line":0}
00:14:23 dir_server.1 | {"Timestamp":1.368490463148452e+09,"Message":"Sending HTTP request to DEA: http://127.0.0.1:1234/staging_tasks/b73d068229756676a4613abc47727ba1/file_path?hmac=8b2aea13ae204bee7c8b4a208fe10611041049d8c8be1b3f2267d8e1c363c0362bd7160ec2c5ef7e6dc681c95ef03494dbf0bdf9eb5a65500016c5b5cdae2cef&path=%2Ftmp%2Fstaged%2Flogs%2Fstaging_task.log&timestamp=1368490457&tail&tail_offset=37","Level":"info","Data":null,"File":"","Method":"","Line":0}
00:14:28 dea_ng.1 | {"timestamp":1368490468.099854,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:14:32 dir_server.1 | {"Timestamp":1.368490472445847e+09,"Message":"Sending HTTP request to DEA: http://127.0.0.1:1234/staging_tasks/b73d068229756676a4613abc47727ba1/file_path?hmac=8b2aea13ae204bee7c8b4a208fe10611041049d8c8be1b3f2267d8e1c363c0362bd7160ec2c5ef7e6dc681c95ef03494dbf0bdf9eb5a65500016c5b5cdae2cef&path=%2Ftmp%2Fstaged%2Flogs%2Fstaging_task.log&timestamp=1368490457&tail&tail_offset=54","Level":"info","Data":null,"File":"","Method":"","Line":0}
00:14:37 dir_server.1 | {"Timestamp":1.368490477648793e+09,"Message":"Sending HTTP request to DEA: http://127.0.0.1:1234/staging_tasks/b73d068229756676a4613abc47727ba1/file_path?hmac=8b2aea13ae204bee7c8b4a208fe10611041049d8c8be1b3f2267d8e1c363c0362bd7160ec2c5ef7e6dc681c95ef03494dbf0bdf9eb5a65500016c5b5cdae2cef&path=%2Ftmp%2Fstaged%2Flogs%2Fstaging_task.log&timestamp=1368490457&tail&tail_offset=54","Level":"info","Data":null,"File":"","Method":"","Line":0}
00:14:42 dir_server.1 | {"Timestamp":1.368490482852569e+09,"Message":"Sending HTTP request to DEA: http://127.0.0.1:1234/staging_tasks/b73d068229756676a4613abc47727ba1/file_path?hmac=8b2aea13ae204bee7c8b4a208fe10611041049d8c8be1b3f2267d8e1c363c0362bd7160ec2c5ef7e6dc681c95ef03494dbf0bdf9eb5a65500016c5b5cdae2cef&path=%2Ftmp%2Fstaged%2Flogs%2Fstaging_task.log&timestamp=1368490457&tail&tail_offset=54","Level":"info","Data":null,"File":"","Method":"","Line":0}
00:14:49 dir_server.1 | {"Timestamp":1.368490489115944e+09,"Message":"Sending HTTP request to DEA: http://127.0.0.1:1234/staging_tasks/b73d068229756676a4613abc47727ba1/file_path?hmac=8b2aea13ae204bee7c8b4a208fe10611041049d8c8be1b3f2267d8e1c363c0362bd7160ec2c5ef7e6dc681c95ef03494dbf0bdf9eb5a65500016c5b5cdae2cef&path=%2Ftmp%2Fstaged%2Flogs%2Fstaging_task.log&timestamp=1368490457&tail&tail_offset=54","Level":"info","Data":null,"File":"","Method":"","Line":0}
00:14:54 dir_server.1 | {"Timestamp":1.368490494327744e+09,"Message":"Sending HTTP request to DEA: http://127.0.0.1:1234/staging_tasks/b73d068229756676a4613abc47727ba1/file_path?hmac=8b2aea13ae204bee7c8b4a208fe10611041049d8c8be1b3f2267d8e1c363c0362bd7160ec2c5ef7e6dc681c95ef03494dbf0bdf9eb5a65500016c5b5cdae2cef&path=%2Ftmp%2Fstaged%2Flogs%2Fstaging_task.log&timestamp=1368490457&tail&tail_offset=54","Level":"info","Data":null,"File":"","Method":"","Line":0}
00:14:58 dea_ng.1 | {"timestamp":1368490498.1001918,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:15:06 dir_server.1 | {"Timestamp":1.3684905066268349e+09,"Message":"Sending HTTP request to DEA: http://127.0.0.1:1234/staging_tasks/b73d068229756676a4613abc47727ba1/file_path?hmac=8b2aea13ae204bee7c8b4a208fe10611041049d8c8be1b3f2267d8e1c363c0362bd7160ec2c5ef7e6dc681c95ef03494dbf0bdf9eb5a65500016c5b5cdae2cef&path=%2Ftmp%2Fstaged%2Flogs%2Fstaging_task.log&timestamp=1368490457&tail&tail_offset=272","Level":"info","Data":null,"File":"","Method":"","Line":0}
00:15:19 dir_server.1 | {"Timestamp":1.3684905193338308e+09,"Message":"Sending HTTP request to DEA: http://127.0.0.1:1234/staging_tasks/b73d068229756676a4613abc47727ba1/file_path?hmac=8b2aea13ae204bee7c8b4a208fe10611041049d8c8be1b3f2267d8e1c363c0362bd7160ec2c5ef7e6dc681c95ef03494dbf0bdf9eb5a65500016c5b5cdae2cef&path=%2Ftmp%2Fstaged%2Flogs%2Fstaging_task.log&timestamp=1368490457&tail&tail_offset=669","Level":"info","Data":null,"File":"","Method":"","Line":0}
00:15:24 dir_server.1 | {"Timestamp":1.3684905245315552e+09,"Message":"Sending HTTP request to DEA: http://127.0.0.1:1234/staging_tasks/b73d068229756676a4613abc47727ba1/file_path?hmac=8b2aea13ae204bee7c8b4a208fe10611041049d8c8be1b3f2267d8e1c363c0362bd7160ec2c5ef7e6dc681c95ef03494dbf0bdf9eb5a65500016c5b5cdae2cef&path=%2Ftmp%2Fstaged%2Flogs%2Fstaging_task.log&timestamp=1368490457&tail&tail_offset=669","Level":"info","Data":null,"File":"","Method":"","Line":0}
00:15:28 dea_ng.1 | {"timestamp":1368490528.1050208,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:15:29 dir_server.1 | {"Timestamp":1.368490529740489e+09,"Message":"Sending HTTP request to DEA: http://127.0.0.1:1234/staging_tasks/b73d068229756676a4613abc47727ba1/file_path?hmac=8b2aea13ae204bee7c8b4a208fe10611041049d8c8be1b3f2267d8e1c363c0362bd7160ec2c5ef7e6dc681c95ef03494dbf0bdf9eb5a65500016c5b5cdae2cef&path=%2Ftmp%2Fstaged%2Flogs%2Fstaging_task.log&timestamp=1368490457&tail&tail_offset=669","Level":"info","Data":null,"File":"","Method":"","Line":0}
00:15:34 dir_server.1 | {"Timestamp":1.3684905349422998e+09,"Message":"Sending HTTP request to DEA: http://127.0.0.1:1234/staging_tasks/b73d068229756676a4613abc47727ba1/file_path?hmac=8b2aea13ae204bee7c8b4a208fe10611041049d8c8be1b3f2267d8e1c363c0362bd7160ec2c5ef7e6dc681c95ef03494dbf0bdf9eb5a65500016c5b5cdae2cef&path=%2Ftmp%2Fstaged%2Flogs%2Fstaging_task.log&timestamp=1368490457&tail&tail_offset=669","Level":"info","Data":null,"File":"","Method":"","Line":0}
00:15:39 warden.1 | {"timestamp":1368490457.2952182,"message":"Exited with status 0 (0.029s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-spawn\", \"/tmp/warden/containers/16ska1ops1f/jobs/3\", \"/tmp/warden/containers/16ska1ops1f/bin/wsh\", \"--socket\", \"/tmp/warden/containers/16ska1ops1f/run/wshd.sock\", \"--user\", \"vcap\", \"/bin/bash\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"child_pid=2820\nchild active\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:39 warden.1 | {"timestamp":1368490457.2953641,"message":"Exited with status 0 (0.025s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-link\", \"-w\", \"/tmp/warden/containers/16ska1ops1f/jobs/3/cursors\", \"/tmp/warden/containers/16ska1ops1f/jobs/3\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:39 warden.1 | {"timestamp":1368490457.2960062,"message":"Wrote snapshot in 0.000432","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:39 warden.1 | {"timestamp":1368490457.296156,"message":"link (took 0.023461)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","job_id":3},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":12550660,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:39 warden.1 | {"timestamp":1368490457.296594,"message":"run (took 0.030502)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":" package_size=`du -h /tmp/dea_ng/staging/d20130514-1977-sr67uo/app.zip | cut -f1`\n echo \"-----> Downloaded app package ($package_size)\" >> /tmp/staged/logs/staging_task.log\n unzip -q /tmp/dea_ng/staging/d20130514-1977-sr67uo/app.zip -d /tmp/unstaged\n"},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":12550660,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:39 warden.1 | {"timestamp":1368490457.2966793,"message":"<Warden::Protocol::RunResponse exit_status: 0, stdout: \"\", stderr: \"\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":12550660,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:39 warden.1 | {"timestamp":1368490457.3094895,"message":"<Warden::Protocol::RunRequest handle: \"16ska1ops1f\", script: \"PLATFORM_CONFIG=/tmp/dea_ng/staging/d20130514-1977-sr67uo/platform_config BUILDPACK_CACHE=/var/vcap/packages/buildpack_cache STAGING_TIMEOUT=900.0 /usr/bin/ruby /vagrant/dea_ng/buildpacks/bin/run /tmp/dea_ng/staging/d20130514-1977-sr67uo/plugin_config >> /tmp/staged/logs/staging_task.log 2>&1\", privileged: false>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:39 warden.1 | {"timestamp":1368490457.3143091,"message":"Wrote snapshot in 0.000239","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":10886200,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:39 warden.1 | {"timestamp":1368490457.3144073,"message":"spawn (took 0.004663)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":"PLATFORM_CONFIG=/tmp/dea_ng/staging/d20130514-1977-sr67uo/platform_config BUILDPACK_CACHE=/var/vcap/packages/buildpack_cache STAGING_TIMEOUT=900.0 /usr/bin/ruby /vagrant/dea_ng/buildpacks/bin/run /tmp/dea_ng/staging/d20130514-1977-sr67uo/plugin_config >> /tmp/staged/logs/staging_task.log 2>&1"},"response":{"job_id":4}},"thread_id":9056240,"fiber_id":10886200,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:39 warden.1 | {"timestamp":1368490487.3723185,"message":"Connection unregistered: #<Warden::Server::ClientConnection:0x00000001e1a7e8>","log_level":"debug2","source":"Warden::Server::Drainer","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":95,"method":"unregister_connection"}
00:15:39 warden.1 | {"timestamp":1368490539.2365603,"message":"Exited with status 0 (81.926s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-spawn\", \"/tmp/warden/containers/16ska1ops1f/jobs/4\", \"/tmp/warden/containers/16ska1ops1f/bin/wsh\", \"--socket\", \"/tmp/warden/containers/16ska1ops1f/run/wshd.sock\", \"--user\", \"vcap\", \"/bin/bash\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"child_pid=2834\nchild active\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:39 warden.1 | {"timestamp":1368490539.2367103,"message":"Exited with status 0 (81.924s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-link\", \"-w\", \"/tmp/warden/containers/16ska1ops1f/jobs/4/cursors\", \"/tmp/warden/containers/16ska1ops1f/jobs/4\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:39 warden.1 | {"timestamp":1368490539.2371287,"message":"Wrote snapshot in 0.000304","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:39 warden.1 | {"timestamp":1368490539.2375147,"message":"link (took 81.922773)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","job_id":4},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":10886200,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:39 warden.1 | {"timestamp":1368490539.2376122,"message":"run (took 81.927930)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":"PLATFORM_CONFIG=/tmp/dea_ng/staging/d20130514-1977-sr67uo/platform_config BUILDPACK_CACHE=/var/vcap/packages/buildpack_cache STAGING_TIMEOUT=900.0 /usr/bin/ruby /vagrant/dea_ng/buildpacks/bin/run /tmp/dea_ng/staging/d20130514-1977-sr67uo/plugin_config >> /tmp/staged/logs/staging_task.log 2>&1"},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":10886200,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:39 warden.1 | {"timestamp":1368490539.2376947,"message":"<Warden::Protocol::RunResponse exit_status: 0, stdout: \"\", stderr: \"\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":10886200,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:39 warden.1 | {"timestamp":1368490539.2483397,"message":"<Warden::Protocol::RunRequest handle: \"16ska1ops1f\", script: \" cd /tmp/staged &&\\n COPYFILE_DISABLE=true tar -czf /tmp/droplet.tgz .\\n\", privileged: false>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:40 dir_server.1 | {"Timestamp":1.368490540142996e+09,"Message":"Sending HTTP request to DEA: http://127.0.0.1:1234/staging_tasks/b73d068229756676a4613abc47727ba1/file_path?hmac=8b2aea13ae204bee7c8b4a208fe10611041049d8c8be1b3f2267d8e1c363c0362bd7160ec2c5ef7e6dc681c95ef03494dbf0bdf9eb5a65500016c5b5cdae2cef&path=%2Ftmp%2Fstaged%2Flogs%2Fstaging_task.log&timestamp=1368490457&tail&tail_offset=669","Level":"info","Data":null,"File":"","Method":"","Line":0}
00:15:41 dea_ng.1 | {"timestamp":1368490541.3152535,"message":"Copying out to /tmp/dea_ng/staging/d20130514-1977-sr67uo/staged/droplet.tgz","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1","warden_handle":"16ska1ops1f"},"thread_id":15308800,"fiber_id":16992080,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/staging_task.rb","lineno":313,"method":"block in promise_copy_out"}
00:15:41 warden.1 | {"timestamp":1368490539.2542489,"message":"Wrote snapshot in 0.000249","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":10700540,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:41 warden.1 | {"timestamp":1368490539.2543485,"message":"spawn (took 0.005084)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":" cd /tmp/staged &&\n COPYFILE_DISABLE=true tar -czf /tmp/droplet.tgz .\n"},"response":{"job_id":5}},"thread_id":9056240,"fiber_id":10700540,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:41 warden.1 | {"timestamp":1368490541.3133278,"message":"Exited with status 0 (2.063s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-spawn\", \"/tmp/warden/containers/16ska1ops1f/jobs/5\", \"/tmp/warden/containers/16ska1ops1f/bin/wsh\", \"--socket\", \"/tmp/warden/containers/16ska1ops1f/run/wshd.sock\", \"--user\", \"vcap\", \"/bin/bash\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"child_pid=3422\nchild active\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:41 warden.1 | {"timestamp":1368490541.3134685,"message":"Exited with status 0 (2.061s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-link\", \"-w\", \"/tmp/warden/containers/16ska1ops1f/jobs/5/cursors\", \"/tmp/warden/containers/16ska1ops1f/jobs/5\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:41 warden.1 | {"timestamp":1368490541.3140001,"message":"Wrote snapshot in 0.000357","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:41 warden.1 | {"timestamp":1368490541.3144424,"message":"link (took 2.059666)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","job_id":5},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":10700540,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:41 warden.1 | {"timestamp":1368490541.3145397,"message":"run (took 2.065329)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":" cd /tmp/staged &&\n COPYFILE_DISABLE=true tar -czf /tmp/droplet.tgz .\n"},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":10700540,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:41 warden.1 | {"timestamp":1368490541.3146183,"message":"<Warden::Protocol::RunResponse exit_status: 0, stdout: \"\", stderr: \"\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":10700540,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:41 warden.1 | {"timestamp":1368490541.3160665,"message":"<Warden::Protocol::CopyOutRequest handle: \"16ska1ops1f\", src_path: \"/tmp/droplet.tgz\", dst_path: \"/tmp/dea_ng/staging/d20130514-1977-sr67uo/staged\", owner: \"1000\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:41 warden.1 | {"timestamp":1368490541.697615,"message":"Exited with status 0 (0.381s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"rsync\", \"-e\", \"/tmp/warden/containers/16ska1ops1f/bin/wsh --socket /tmp/warden/containers/16ska1ops1f/run/wshd.sock --rsh\", \"-r\", \"-p\", \"--links\", \"vcap@container:/tmp/droplet.tgz\", \"/tmp/dea_ng/staging/d20130514-1977-sr67uo/staged\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:41 warden.1 | {"timestamp":1368490541.7,"message":"Exited with status 0 (0.002s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"chown\", \"-R\", \"1000\", \"/tmp/dea_ng/staging/d20130514-1977-sr67uo/staged\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:41 warden.1 | {"timestamp":1368490541.7001193,"message":"copy_out (took 0.383870)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","src_path":"/tmp/droplet.tgz","dst_path":"/tmp/dea_ng/staging/d20130514-1977-sr67uo/staged","owner":"1000"},"response":{}},"thread_id":9056240,"fiber_id":14658480,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:41 warden.1 | {"timestamp":1368490541.7001894,"message":"<Warden::Protocol::CopyOutResponse >","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14658480,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:41 warden.1 | {"timestamp":1368490541.701127,"message":"<Warden::Protocol::RunRequest handle: \"16ska1ops1f\", script: \" droplet_size=`du -h /tmp/droplet.tgz | cut -f1`\\n echo \\\"-----> Uploading staged droplet ($droplet_size)\\\" >> /tmp/staged/logs/staging_task.log\\n\", privileged: false>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:41 warden.1 | {"timestamp":1368490541.7056084,"message":"Wrote snapshot in 0.000228","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":14787760,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:41 warden.1 | {"timestamp":1368490541.7056963,"message":"spawn (took 0.004399)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":" droplet_size=`du -h /tmp/droplet.tgz | cut -f1`\n echo \"-----> Uploading staged droplet ($droplet_size)\" >> /tmp/staged/logs/staging_task.log\n"},"response":{"job_id":6}},"thread_id":9056240,"fiber_id":14787760,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:41 warden.1 | {"timestamp":1368490541.7103603,"message":"Exited with status 0 (0.008s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-spawn\", \"/tmp/warden/containers/16ska1ops1f/jobs/6\", \"/tmp/warden/containers/16ska1ops1f/bin/wsh\", \"--socket\", \"/tmp/warden/containers/16ska1ops1f/run/wshd.sock\", \"--user\", \"vcap\", \"/bin/bash\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"child_pid=3439\nchild active\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:41 warden.1 | {"timestamp":1368490541.7109494,"message":"Exited with status 0 (0.008s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-link\", \"-w\", \"/tmp/warden/containers/16ska1ops1f/jobs/6/cursors\", \"/tmp/warden/containers/16ska1ops1f/jobs/6\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:42 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:15:42] "POST /staging/droplets/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/upload HTTP/1.1" 200 - 0.3296
00:15:42 dea_ng.1 | {"timestamp":1368490542.2193313,"message":"Upload succeeded","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1","warden_handle":"16ska1ops1f"},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/utils/upload.rb","lineno":39,"method":"block in upload!"}
00:15:42 dea_ng.1 | {"timestamp":1368490542.2195349,"message":"Uploaded app to http://zxsfhgjg:[email protected]:8181/staging/droplets/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/upload","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1","warden_handle":"16ska1ops1f"},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/staging_task.rb","lineno":263,"method":"block (2 levels) in promise_app_upload"}
00:15:42 dea_ng.1 | {"timestamp":1368490542.4050066,"message":"Delivered: pack buildpack cache (took 0.185)","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1","warden_handle":"16ska1ops1f"},"thread_id":15308800,"fiber_id":32181180,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/task.rb","lineno":271,"method":"block in resolve"}
00:15:42 dea_ng.1 | {"timestamp":1368490542.4051528,"message":"Copying out to /tmp/dea_ng/staging/d20130514-1977-sr67uo/staged/droplet.tgz","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1","warden_handle":"16ska1ops1f"},"thread_id":15308800,"fiber_id":21336020,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/staging_task.rb","lineno":377,"method":"block in promise_copy_out_buildpack_cache"}
00:15:42 warden.1 | {"timestamp":1368490541.7140918,"message":"Wrote snapshot in 0.002527","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:42 warden.1 | {"timestamp":1368490541.7142336,"message":"link (took 0.008422)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","job_id":6},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":14787760,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:42 warden.1 | {"timestamp":1368490541.7147312,"message":"run (took 0.013465)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":" droplet_size=`du -h /tmp/droplet.tgz | cut -f1`\n echo \"-----> Uploading staged droplet ($droplet_size)\" >> /tmp/staged/logs/staging_task.log\n"},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":14787760,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:42 warden.1 | {"timestamp":1368490541.7148104,"message":"<Warden::Protocol::RunResponse exit_status: 0, stdout: \"\", stderr: \"\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14787760,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:42 warden.1 | {"timestamp":1368490542.2206414,"message":"<Warden::Protocol::RunRequest handle: \"16ska1ops1f\", script: \" mkdir -p /tmp/cache &&\\n cd /tmp/cache &&\\n COPYFILE_DISABLE=true tar -czf /tmp/buildpack_cache.tgz .\\n\", privileged: false>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:42 warden.1 | {"timestamp":1368490542.2279124,"message":"Wrote snapshot in 0.000357","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":15196020,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:42 warden.1 | {"timestamp":1368490542.2280204,"message":"spawn (took 0.007171)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":" mkdir -p /tmp/cache &&\n cd /tmp/cache &&\n COPYFILE_DISABLE=true tar -czf /tmp/buildpack_cache.tgz .\n"},"response":{"job_id":7}},"thread_id":9056240,"fiber_id":15196020,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:42 warden.1 | {"timestamp":1368490542.4025013,"message":"Exited with status 0 (0.181s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-spawn\", \"/tmp/warden/containers/16ska1ops1f/jobs/7\", \"/tmp/warden/containers/16ska1ops1f/bin/wsh\", \"--socket\", \"/tmp/warden/containers/16ska1ops1f/run/wshd.sock\", \"--user\", \"vcap\", \"/bin/bash\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"child_pid=3453\nchild active\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:42 warden.1 | {"timestamp":1368490542.4031358,"message":"Exited with status 0 (0.179s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-link\", \"-w\", \"/tmp/warden/containers/16ska1ops1f/jobs/7/cursors\", \"/tmp/warden/containers/16ska1ops1f/jobs/7\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:42 warden.1 | {"timestamp":1368490542.403703,"message":"Wrote snapshot in 0.000355","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:42 warden.1 | {"timestamp":1368490542.4038377,"message":"link (took 0.175687)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","job_id":7},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":15196020,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:42 warden.1 | {"timestamp":1368490542.4042935,"message":"run (took 0.183495)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":" mkdir -p /tmp/cache &&\n cd /tmp/cache &&\n COPYFILE_DISABLE=true tar -czf /tmp/buildpack_cache.tgz .\n"},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":15196020,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:42 warden.1 | {"timestamp":1368490542.4043722,"message":"<Warden::Protocol::RunResponse exit_status: 0, stdout: \"\", stderr: \"\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":15196020,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:42 warden.1 | {"timestamp":1368490542.4057758,"message":"<Warden::Protocol::CopyOutRequest handle: \"16ska1ops1f\", src_path: \"/tmp/buildpack_cache.tgz\", dst_path: \"/tmp/dea_ng/staging/d20130514-1977-sr67uo/staged\", owner: \"1000\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:42 warden.1 | {"timestamp":1368490542.4682374,"message":"Exited with status 0 (0.062s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"rsync\", \"-e\", \"/tmp/warden/containers/16ska1ops1f/bin/wsh --socket /tmp/warden/containers/16ska1ops1f/run/wshd.sock --rsh\", \"-r\", \"-p\", \"--links\", \"vcap@container:/tmp/buildpack_cache.tgz\", \"/tmp/dea_ng/staging/d20130514-1977-sr67uo/staged\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:42 warden.1 | {"timestamp":1368490542.4707284,"message":"Exited with status 0 (0.002s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"chown\", \"-R\", \"1000\", \"/tmp/dea_ng/staging/d20130514-1977-sr67uo/staged\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:42 warden.1 | {"timestamp":1368490542.4708376,"message":"copy_out (took 0.064910)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","src_path":"/tmp/buildpack_cache.tgz","dst_path":"/tmp/dea_ng/staging/d20130514-1977-sr67uo/staged","owner":"1000"},"response":{}},"thread_id":9056240,"fiber_id":15523100,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:42 warden.1 | {"timestamp":1368490542.4709055,"message":"<Warden::Protocol::CopyOutResponse >","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":15523100,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:42 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:15:42] "POST /staging/buildpack_cache/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/upload HTTP/1.1" 200 - 0.1551
00:15:42 dea_ng.1 | {"timestamp":1368490542.6627953,"message":"Upload succeeded","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1","warden_handle":"16ska1ops1f"},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/utils/upload.rb","lineno":39,"method":"block in upload!"}
00:15:42 dea_ng.1 | {"timestamp":1368490542.662944,"message":"Uploaded buildpack cache to http://zxsfhgjg:[email protected]:8181/staging/buildpack_cache/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/upload","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1","warden_handle":"16ska1ops1f"},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/staging_task.rb","lineno":276,"method":"block (2 levels) in promise_buildpack_cache_upload"}
00:15:42 dea_ng.1 | {"timestamp":1368490542.7081435,"message":"Staging task info: {\"detected_buildpack\"=>\"Ruby/Rack\"}","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1","warden_handle":"16ska1ops1f"},"thread_id":15308800,"fiber_id":21362780,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/staging_task.rb","lineno":200,"method":"block in promise_staging_info"}
00:15:42 warden.1 | {"timestamp":1368490542.6639621,"message":"<Warden::Protocol::RunRequest handle: \"16ska1ops1f\", script: \" echo \\\"-----> Uploaded droplet\\\" >> /tmp/staged/logs/staging_task.log\\n\", privileged: false>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:42 warden.1 | {"timestamp":1368490542.6685905,"message":"Wrote snapshot in 0.000241","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":15648860,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:42 warden.1 | {"timestamp":1368490542.6686797,"message":"spawn (took 0.004514)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":" echo \"-----> Uploaded droplet\" >> /tmp/staged/logs/staging_task.log\n"},"response":{"job_id":8}},"thread_id":9056240,"fiber_id":15648860,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:42 warden.1 | {"timestamp":1368490542.672128,"message":"Exited with status 0 (0.007s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-spawn\", \"/tmp/warden/containers/16ska1ops1f/jobs/8\", \"/tmp/warden/containers/16ska1ops1f/bin/wsh\", \"--socket\", \"/tmp/warden/containers/16ska1ops1f/run/wshd.sock\", \"--user\", \"vcap\", \"/bin/bash\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"child_pid=3472\nchild active\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:42 warden.1 | {"timestamp":1368490542.6726663,"message":"Exited with status 0 (0.006s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/bin/iomux-link\", \"-w\", \"/tmp/warden/containers/16ska1ops1f/jobs/8/cursors\", \"/tmp/warden/containers/16ska1ops1f/jobs/8\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:42 warden.1 | {"timestamp":1368490542.673159,"message":"Wrote snapshot in 0.000296","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:42 warden.1 | {"timestamp":1368490542.6732824,"message":"link (took 0.004489)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","job_id":8},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":15648860,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:42 warden.1 | {"timestamp":1368490542.6736963,"message":"run (took 0.009254)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","script":" echo \"-----> Uploaded droplet\" >> /tmp/staged/logs/staging_task.log\n"},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":15648860,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:42 warden.1 | {"timestamp":1368490542.6737742,"message":"<Warden::Protocol::RunResponse exit_status: 0, stdout: \"\", stderr: \"\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":15648860,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:42 warden.1 | {"timestamp":1368490542.675028,"message":"<Warden::Protocol::CopyOutRequest handle: \"16ska1ops1f\", src_path: \"/tmp/staging_info.yml\", dst_path: \"/tmp/dea_ng/staging/d20130514-1977-sr67uo\", owner: \"1000\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:42 warden.1 | {"timestamp":1368490542.704684,"message":"Exited with status 0 (0.029s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"rsync\", \"-e\", \"/tmp/warden/containers/16ska1ops1f/bin/wsh --socket /tmp/warden/containers/16ska1ops1f/run/wshd.sock --rsh\", \"-r\", \"-p\", \"--links\", \"vcap@container:/tmp/staging_info.yml\", \"/tmp/dea_ng/staging/d20130514-1977-sr67uo\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:42 warden.1 | {"timestamp":1368490542.7071342,"message":"Exited with status 0 (0.002s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"chown\", \"-R\", \"1000\", \"/tmp/dea_ng/staging/d20130514-1977-sr67uo\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:42 warden.1 | {"timestamp":1368490542.7072375,"message":"copy_out (took 0.032082)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","src_path":"/tmp/staging_info.yml","dst_path":"/tmp/dea_ng/staging/d20130514-1977-sr67uo","owner":"1000"},"response":{}},"thread_id":9056240,"fiber_id":16037320,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:42 warden.1 | {"timestamp":1368490542.7073052,"message":"<Warden::Protocol::CopyOutResponse >","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":16037320,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:42 warden.1 | {"timestamp":1368490542.7092218,"message":"<Warden::Protocol::CopyOutRequest handle: \"16ska1ops1f\", src_path: \"/tmp/staged/logs/staging_task.log\", dst_path: \"/tmp/dea_ng/staging/d20130514-1977-sr67uo\", owner: \"1000\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:42 warden.1 | {"timestamp":1368490542.7366748,"message":"Exited with status 0 (0.027s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"rsync\", \"-e\", \"/tmp/warden/containers/16ska1ops1f/bin/wsh --socket /tmp/warden/containers/16ska1ops1f/run/wshd.sock --rsh\", \"-r\", \"-p\", \"--links\", \"vcap@container:/tmp/staged/logs/staging_task.log\", \"/tmp/dea_ng/staging/d20130514-1977-sr67uo\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:42 warden.1 | {"timestamp":1368490542.739067,"message":"Exited with status 0 (0.002s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"chown\", \"-R\", \"1000\", \"/tmp/dea_ng/staging/d20130514-1977-sr67uo\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:42 warden.1 | {"timestamp":1368490542.739173,"message":"copy_out (took 0.029818)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f","src_path":"/tmp/staged/logs/staging_task.log","dst_path":"/tmp/dea_ng/staging/d20130514-1977-sr67uo","owner":"1000"},"response":{}},"thread_id":9056240,"fiber_id":16083600,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:42 dea_ng.1 | {"timestamp":1368490542.7427335,"message":"Staging task log: -----> Downloaded app package (4.0K)\nInstalling ruby.\n-----> Using Ruby version: ruby-1.9.2\n-----> Installing dependencies using Bundler version 1.3.2\n Running: bundle install --without development:test --path vendor/bundle --binstubs vendor/bundle/bin --deployment\n Fetching gem metadata from http://rubygems.org/..........\n Fetching gem metadata from http://rubygems.org/..\n Installing rack (1.5.1)\n Installing rack-protection (1.3.2)\n Installing tilt (1.3.3)\n Installing sinatra (1.3.4)\n Using bundler (1.3.2)\n Your bundle is complete! It was installed into ./vendor/bundle\n Cleaning up the bundler cache.\n-----> Uploading staged droplet (21M)\n-----> Uploaded droplet\n","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1","warden_handle":"16ska1ops1f"},"thread_id":15308800,"fiber_id":21522600,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/staging_task.rb","lineno":192,"method":"block in promise_task_log"}
00:15:43 dea_ng.1 | {"timestamp":1368490543.051894,"message":"Finished staging task","log_level":"info","source":"Staging","data":{"app_guid":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","task_id":"b73d068229756676a4613abc47727ba1","warden_handle":"16ska1ops1f"},"thread_id":15308800,"fiber_id":21601940,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/staging_task.rb","lineno":55,"method":"block in start"}
00:15:43 dir_server.1 | {"Timestamp":1.368490543167099e+09,"Message":"Sending HTTP request to DEA: http://127.0.0.1:1234/staging_tasks/b73d068229756676a4613abc47727ba1/file_path?hmac=8b2aea13ae204bee7c8b4a208fe10611041049d8c8be1b3f2267d8e1c363c0362bd7160ec2c5ef7e6dc681c95ef03494dbf0bdf9eb5a65500016c5b5cdae2cef&path=%2Ftmp%2Fstaged%2Flogs%2Fstaging_task.log&timestamp=1368490457&tail&tail_offset=731","Level":"info","Data":null,"File":"","Method":"","Line":0}
00:15:43 dir_server.1 | {"Timestamp":1.368490543170837e+09,"Message":"Error in LookupPath: DEA did not respond with 200 status","Level":"warn","Data":null,"File":"","Method":"","Line":0}
00:15:43 dea_ng.1 | {"timestamp":1368490543.174832,"message":"Received on \"dea.0-fddbbbf868db8195eaa6af3f1a8f79a9.start\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"name\"=>\"test-app\", \"uris\"=>[\"test-app.vcap.me\"], \"prod\"=>false, \"sha1\"=>\"f5d7e5b8e9315ee886d78983ccf6863b8676220d\", \"executableFile\"=>\"deprecated\", \"executableUri\"=>\"http://zxsfhgjg:[email protected]:8181/staging/droplets/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/download\", \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\", \"services\"=>[], \"limits\"=>{\"mem\"=>256, \"disk\"=>1024, \"fds\"=>16384}, \"cc_partition\"=>\"ng\", \"env\"=>[], \"console\"=>true, \"debug\"=>nil, \"index\"=>0}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:15:43 dea_ng.1 | {"timestamp":1368490543.176574,"message":"Starting instance","log_level":"info","source":"Dea::Instance","data":{},"thread_id":15308800,"fiber_id":23385860,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/instance.rb","lineno":506,"method":"block in start"}
00:15:43 dea_ng.1 | {"timestamp":1368490543.1779733,"message":"New droplet: f5d7e5b8e9315ee886d78983ccf6863b8676220d","log_level":"debug","source":"Dea::DropletRegistry","data":{"droplet_sha1":"f5d7e5b8e9315ee886d78983ccf6863b8676220d"},"thread_id":15308800,"fiber_id":23397540,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/droplet_registry.rb","lineno":13,"method":"block in initialize"}
00:15:43 dea_ng.1 | {"timestamp":1368490543.1797297,"message":"Starting droplet download","log_level":"info","source":"Dea::Instance","data":{},"thread_id":15308800,"fiber_id":23397540,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/instance.rb","lineno":569,"method":"block in promise_droplet"}
00:15:43 dea_ng.1 | {"timestamp":1368490543.181012,"message":"Waiting for download to complete","log_level":"debug","source":"Dea::Droplet","data":{"droplet_sha1":"f5d7e5b8e9315ee886d78983ccf6863b8676220d"},"thread_id":15308800,"fiber_id":25918600,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/droplet.rb","lineno":44,"method":"download"}
00:15:43 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:15:43] "GET /staging/droplets/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/download HTTP/1.1" 200 21752884 0.1823
00:15:43 warden.1 | {"timestamp":1368490542.739282,"message":"<Warden::Protocol::CopyOutResponse >","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":16083600,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:43 warden.1 | {"timestamp":1368490542.7433684,"message":"<Warden::Protocol::DestroyRequest handle: \"16ska1ops1f\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:43 warden.1 | {"timestamp":1368490542.762929,"message":"Exited with status 0 (0.018s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1f/stop.sh\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490542.7633195,"message":"Wrote snapshot in 0.000272","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":16139120,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:43 warden.1 | {"timestamp":1368490542.7633991,"message":"Killing oom-notifier process","log_level":"debug","source":"Warden::Container::Features::MemLimit::OomNotifier","data":{},"thread_id":9056240,"fiber_id":16139120,"process_id":2001,"file":"/warden/warden/lib/warden/container/features/mem_limit.rb","lineno":51,"method":"kill"}
00:15:43 warden.1 | {"timestamp":1368490542.8637733,"message":"stop (took 0.119247)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{},"response":{}},"thread_id":9056240,"fiber_id":16139120,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:43 warden.1 | {"timestamp":1368490542.8649664,"message":"Exited with status 0 (85.669s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/warden/warden/src/oom/oom\", \"/sys/fs/cgroup/memory/instance-16ska1ops1f\"]","log_level":"warn","source":"Warden::Container::Features::MemLimit::OomNotifier","data":{"stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":134,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490543.050986,"message":"Exited with status 0 (0.186s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/warden/warden/root/linux/destroy.sh\", \"/tmp/warden/containers/16ska1ops1f\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490543.0510805,"message":"Container destroyed","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f"},"thread_id":9056240,"fiber_id":16139120,"process_id":2001,"file":"/warden/warden/lib/warden/container/linux.rb","lineno":129,"method":"do_destroy"}
00:15:43 warden.1 | {"timestamp":1368490543.0512867,"message":"destroy (took 0.306995)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1f","request":{"handle":"16ska1ops1f"},"response":{}},"thread_id":9056240,"fiber_id":16139120,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:43 warden.1 | {"timestamp":1368490543.0513518,"message":"<Warden::Protocol::DestroyResponse >","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":16139120,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:43 warden.1 | {"timestamp":1368490543.1848197,"message":"Connection registered: #<Warden::Server::ClientConnection:0x00000001eecdb0>","log_level":"debug2","source":"Warden::Server::Drainer","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":88,"method":"register_connection"}
00:15:43 warden.1 | {"timestamp":1368490543.18585,"message":"<Warden::Protocol::CreateRequest bind_mounts: [<Warden::Protocol::CreateRequest::BindMount src_path: \"/tmp/dea_ng/droplets/f5d7e5b8e9315ee886d78983ccf6863b8676220d\", dst_path: \"/tmp/dea_ng/droplets/f5d7e5b8e9315ee886d78983ccf6863b8676220d\", mode: RO(0)>]>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:43 warden.1 | {"timestamp":1368490543.1884987,"message":"Exited with status 0 (0.002s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"setquota\", \"-u\", \"10001\", \"0\", \"0\", \"0\", \"0\", \"/\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490543.3492572,"message":"Exited with status 0 (0.160s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/warden/warden/root/linux/create.sh\", \"/tmp/warden/containers/16ska1ops1g\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"/tmp/warden/containers/16ska1ops1g\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490543.3494608,"message":"Container created","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":19497420,"process_id":2001,"file":"/warden/warden/lib/warden/container/linux.rb","lineno":104,"method":"do_create"}
00:15:43 warden.1 | {"timestamp":1368490543.3497827,"message":"Wrote bind mount commands","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":19497420,"process_id":2001,"file":"/warden/warden/lib/warden/container/linux.rb","lineno":107,"method":"do_create"}
00:15:43 warden.1 | {"timestamp":1368490543.5645218,"message":"Exited with status 0 (0.212s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1g/start.sh\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490543.5646203,"message":"Container started","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":19497420,"process_id":2001,"file":"/warden/warden/lib/warden/container/linux.rb","lineno":110,"method":"do_create"}
00:15:43 warden.1 | {"timestamp":1368490543.5650496,"message":"Wrote snapshot in 0.000314","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":19497420,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:43 warden.1 | {"timestamp":1368490543.5651464,"message":"create (took 0.379115)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"bind_mounts":["#<Warden::Protocol::CreateRequest::BindMount:0x00000001eea5b0>"]},"response":{"handle":"16ska1ops1g"}},"thread_id":9056240,"fiber_id":19497420,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:43 warden.1 | {"timestamp":1368490543.5652387,"message":"<Warden::Protocol::CreateResponse handle: \"16ska1ops1g\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":19497420,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:43 warden.1 | {"timestamp":1368490543.5717645,"message":"<Warden::Protocol::NetInRequest handle: \"16ska1ops1g\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:43 warden.1 | {"timestamp":1368490543.585691,"message":"Exited with status 0 (0.012s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1g/net.sh\", \"in\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490543.5860775,"message":"Wrote snapshot in 0.000267","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":10294220,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:43 warden.1 | {"timestamp":1368490543.5861776,"message":"net_in (took 0.013873)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g"},"response":{"host_port":61001,"container_port":61001}},"thread_id":9056240,"fiber_id":10294220,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:43 warden.1 | {"timestamp":1368490543.5862563,"message":"<Warden::Protocol::NetInResponse host_port: 61001, container_port: 61001>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":10294220,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:43 warden.1 | {"timestamp":1368490543.5927732,"message":"<Warden::Protocol::NetInRequest handle: \"16ska1ops1g\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:43 warden.1 | {"timestamp":1368490543.6021724,"message":"Exited with status 0 (0.009s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1g/net.sh\", \"in\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490543.6025233,"message":"Wrote snapshot in 0.000223","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":12232560,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:43 warden.1 | {"timestamp":1368490543.6026156,"message":"net_in (took 0.009686)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g"},"response":{"host_port":61002,"container_port":61002}},"thread_id":9056240,"fiber_id":12232560,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:43 warden.1 | {"timestamp":1368490543.602692,"message":"<Warden::Protocol::NetInResponse host_port: 61002, container_port: 61002>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":12232560,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:43 warden.1 | {"timestamp":1368490543.605763,"message":"<Warden::Protocol::LimitDiskRequest handle: \"16ska1ops1g\", byte: 1073741824>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:43 warden.1 | {"timestamp":1368490543.607949,"message":"Exited with status 0 (0.002s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/warden/warden/src/repquota/repquota\", \"/\", \"10001\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"stdout":"10001 16384 0 0 0 4 0 0 0\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490543.6101882,"message":"Exited with status 0 (0.002s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"setquota\", \"-u\", \"10001\", \"0\", \"1048576\", \"0\", \"0\", \"/\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490543.6121693,"message":"Exited with status 0 (0.001s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/warden/warden/src/repquota/repquota\", \"/\", \"10001\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"stdout":"10001 16384 0 1048576 0 4 0 0 0\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490543.612544,"message":"Wrote snapshot in 0.000248","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":12517160,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:43 warden.1 | {"timestamp":1368490543.6126502,"message":"limit_disk (took 0.006717)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g","byte":1073741824},"response":{"block_limit":1048576,"block":1048576,"block_soft":0,"block_hard":1048576,"inode_limit":0,"inode":0,"inode_soft":0,"inode_hard":0,"byte_limit":1073741824,"byte":1073741824,"byte_soft":0,"byte_hard":1073741824}},"thread_id":9056240,"fiber_id":12517160,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:43 warden.1 | {"timestamp":1368490543.6127484,"message":"<Warden::Protocol::LimitDiskResponse block_limit: 1048576, block: 1048576, block_soft: 0, block_hard: 1048576, inode_limit: 0, inode: 0, inode_soft: 0, inode_hard: 0, byte_limit: 1073741824, byte: 1073741824, byte_soft: 0, byte_hard: 1073741824>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":12517160,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:43 warden.1 | {"timestamp":1368490543.616416,"message":"<Warden::Protocol::LimitMemoryRequest handle: \"16ska1ops1g\", limit_in_bytes: 301989888>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:43 warden.1 | {"timestamp":1368490543.6174824,"message":"Wrote snapshot in 0.000224","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":13837280,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:43 warden.1 | {"timestamp":1368490543.6175687,"message":"limit_memory (took 0.001003)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g","limit_in_bytes":301989888},"response":{"limit_in_bytes":301989888}},"thread_id":9056240,"fiber_id":13837280,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:43 warden.1 | {"timestamp":1368490543.617633,"message":"<Warden::Protocol::LimitMemoryResponse limit_in_bytes: 301989888>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":13837280,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:43 dea_ng.1 | {"timestamp":1368490543.6633615,"message":"Download succeeded","log_level":"info","source":"Download","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/utils/download.rb","lineno":68,"method":"block (2 levels) in download!"}
00:15:43 dea_ng.1 | {"timestamp":1368490543.663624,"message":"Moved droplet to /tmp/dea_ng/droplets/f5d7e5b8e9315ee886d78983ccf6863b8676220d/droplet.tgz","log_level":"debug","source":"Dea::Droplet","data":{"droplet_sha1":"f5d7e5b8e9315ee886d78983ccf6863b8676220d"},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/droplet.rb","lineno":53,"method":"block in download"}
00:15:43 warden.1 | {"timestamp":1368490543.6342402,"message":"<Warden::Protocol::RunRequest handle: \"16ska1ops1g\", script: \"cd / && mkdir -p home/vcap/app && chown vcap:vcap home/vcap/app && ln -s home/vcap/app /app\", privileged: true>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:43 warden.1 | {"timestamp":1368490543.6426888,"message":"Wrote snapshot in 0.001605","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":14746940,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:43 warden.1 | {"timestamp":1368490543.6428008,"message":"spawn (took 0.008330)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g","script":"cd / && mkdir -p home/vcap/app && chown vcap:vcap home/vcap/app && ln -s home/vcap/app /app","privileged":true},"response":{"job_id":9}},"thread_id":9056240,"fiber_id":14746940,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:43 warden.1 | {"timestamp":1368490543.6465786,"message":"Exited with status 0 (0.011s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1g/bin/iomux-spawn\", \"/tmp/warden/containers/16ska1ops1g/jobs/9\", \"/tmp/warden/containers/16ska1ops1g/bin/wsh\", \"--socket\", \"/tmp/warden/containers/16ska1ops1g/run/wshd.sock\", \"--user\", \"root\", \"/bin/bash\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"child_pid=3669\nchild active\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490543.6472492,"message":"Exited with status 0 (0.009s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1g/bin/iomux-link\", \"-w\", \"/tmp/warden/containers/16ska1ops1g/jobs/9/cursors\", \"/tmp/warden/containers/16ska1ops1g/jobs/9\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490543.64775,"message":"Wrote snapshot in 0.000388","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:43 warden.1 | {"timestamp":1368490543.6482575,"message":"link (took 0.004951)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g","job_id":9},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":14746940,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:43 warden.1 | {"timestamp":1368490543.6483672,"message":"run (took 0.013964)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g","script":"cd / && mkdir -p home/vcap/app && chown vcap:vcap home/vcap/app && ln -s home/vcap/app /app","privileged":true},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":14746940,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:43 warden.1 | {"timestamp":1368490543.6484478,"message":"<Warden::Protocol::RunResponse exit_status: 0, stdout: \"\", stderr: \"\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14746940,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:43 warden.1 | {"timestamp":1368490543.6647568,"message":"<Warden::Protocol::NetInRequest handle: \"16ska1ops1g\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:43 warden.1 | {"timestamp":1368490543.674813,"message":"Exited with status 0 (0.009s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1g/net.sh\", \"in\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490543.6752172,"message":"Wrote snapshot in 0.000291","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":15000480,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:43 warden.1 | {"timestamp":1368490543.6753094,"message":"net_in (took 0.010393)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g"},"response":{"host_port":61003,"container_port":61003}},"thread_id":9056240,"fiber_id":15000480,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:43 warden.1 | {"timestamp":1368490543.6753826,"message":"<Warden::Protocol::NetInResponse host_port: 61003, container_port: 61003>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":15000480,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:43 warden.1 | {"timestamp":1368490543.6762629,"message":"<Warden::Protocol::NetInRequest handle: \"16ska1ops1g\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:43 warden.1 | {"timestamp":1368490543.6852221,"message":"Exited with status 0 (0.008s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1g/net.sh\", \"in\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:43 warden.1 | {"timestamp":1368490543.6855562,"message":"Wrote snapshot in 0.000235","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":15452720,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:43 warden.1 | {"timestamp":1368490543.6856403,"message":"net_in (took 0.009250)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g"},"response":{"host_port":61004,"container_port":61004}},"thread_id":9056240,"fiber_id":15452720,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:43 warden.1 | {"timestamp":1368490543.6857088,"message":"<Warden::Protocol::NetInResponse host_port: 61004, container_port: 61004>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":15452720,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:43 warden.1 | {"timestamp":1368490543.686718,"message":"<Warden::Protocol::RunRequest handle: \"16ska1ops1g\", script: \"cd /home/vcap/ && tar zxf /tmp/dea_ng/droplets/f5d7e5b8e9315ee886d78983ccf6863b8676220d/droplet.tgz\", privileged: false>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:44 warden.1 | {"timestamp":1368490543.6945083,"message":"Wrote snapshot in 0.001958","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":15525620,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:44 warden.1 | {"timestamp":1368490543.6946614,"message":"spawn (took 0.007698)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g","script":"cd /home/vcap/ && tar zxf /tmp/dea_ng/droplets/f5d7e5b8e9315ee886d78983ccf6863b8676220d/droplet.tgz"},"response":{"job_id":10}},"thread_id":9056240,"fiber_id":15525620,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:44 warden.1 | {"timestamp":1368490544.037768,"message":"Exited with status 0 (0.350s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1g/bin/iomux-spawn\", \"/tmp/warden/containers/16ska1ops1g/jobs/10\", \"/tmp/warden/containers/16ska1ops1g/bin/wsh\", \"--socket\", \"/tmp/warden/containers/16ska1ops1g/run/wshd.sock\", \"--user\", \"vcap\", \"/bin/bash\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"child_pid=3693\nchild active\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:44 warden.1 | {"timestamp":1368490544.0379157,"message":"Exited with status 0 (0.348s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1g/bin/iomux-link\", \"-w\", \"/tmp/warden/containers/16ska1ops1g/jobs/10/cursors\", \"/tmp/warden/containers/16ska1ops1g/jobs/10\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:15:44 warden.1 | {"timestamp":1368490544.0383892,"message":"Wrote snapshot in 0.000357","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:44 warden.1 | {"timestamp":1368490544.0385325,"message":"link (took 0.343707)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g","job_id":10},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":15525620,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:44 warden.1 | {"timestamp":1368490544.038999,"message":"run (took 0.352106)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g","script":"cd /home/vcap/ && tar zxf /tmp/dea_ng/droplets/f5d7e5b8e9315ee886d78983ccf6863b8676220d/droplet.tgz"},"response":{"exit_status":0,"stdout":"","stderr":""}},"thread_id":9056240,"fiber_id":15525620,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:44 warden.1 | {"timestamp":1368490544.0390832,"message":"<Warden::Protocol::RunResponse exit_status: 0, stdout: \"\", stderr: \"\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":15525620,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:44 warden.1 | {"timestamp":1368490544.0408995,"message":"<Warden::Protocol::SpawnRequest handle: \"16ska1ops1g\", script: \"umask 077\\nexport VCAP_APPLICATION='{\\\"application_users\\\":[],\\\"instance_id\\\":\\\"820fd91dc440ca2da315a194a5b943e7\\\",\\\"instance_index\\\":0,\\\"application_version\\\":\\\"cab62092-f242-43e2-ae39-0ab5afae5ce5\\\",\\\"application_name\\\":\\\"test-app\\\",\\\"application_uris\\\":[\\\"test-app.vcap.me\\\"],\\\"started_at\\\":\\\"2013-05-14 00:15:43 +0000\\\",\\\"started_at_timestamp\\\":1368490543,\\\"host\\\":\\\"0.0.0.0\\\",\\\"port\\\":61003,\\\"limits\\\":{\\\"mem\\\":256,\\\"disk\\\":1024,\\\"fds\\\":16384},\\\"version\\\":\\\"cab62092-f242-43e2-ae39-0ab5afae5ce5\\\",\\\"name\\\":\\\"test-app\\\",\\\"uris\\\":[\\\"test-app.vcap.me\\\"],\\\"users\\\":[],\\\"start\\\":\\\"2013-05-14 00:15:43 +0000\\\",\\\"state_timestamp\\\":1368490543}'\\nexport VCAP_SERVICES='{}'\\nexport VCAP_APP_HOST='0.0.0.0'\\nexport VCAP_APP_PORT='61003'\\nexport VCAP_CONSOLE_IP='0.0.0.0'\\nexport VCAP_CONSOLE_PORT='61004'\\n./startup -p 61003\\nexit\", privileged: false, rlimits: <Warden::Protocol::ResourceLimits nofile: 16384, nproc: 512>>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:44 warden.1 | {"timestamp":1368490544.0459476,"message":"Wrote snapshot in 0.000222","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g"},"thread_id":9056240,"fiber_id":15827860,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":360,"method":"write_snapshot"}
00:15:44 warden.1 | {"timestamp":1368490544.0460334,"message":"spawn (took 0.005009)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g","script":"umask 077\nexport VCAP_APPLICATION='{\"application_users\":[],\"instance_id\":\"820fd91dc440ca2da315a194a5b943e7\",\"instance_index\":0,\"application_version\":\"cab62092-f242-43e2-ae39-0ab5afae5ce5\",\"application_name\":\"test-app\",\"application_uris\":[\"test-app.vcap.me\"],\"started_at\":\"2013-05-14 00:15:43 +0000\",\"started_at_timestamp\":1368490543,\"host\":\"0.0.0.0\",\"port\":61003,\"limits\":{\"mem\":256,\"disk\":1024,\"fds\":16384},\"version\":\"cab62092-f242-43e2-ae39-0ab5afae5ce5\",\"name\":\"test-app\",\"uris\":[\"test-app.vcap.me\"],\"users\":[],\"start\":\"2013-05-14 00:15:43 +0000\",\"state_timestamp\":1368490543}'\nexport VCAP_SERVICES='{}'\nexport VCAP_APP_HOST='0.0.0.0'\nexport VCAP_APP_PORT='61003'\nexport VCAP_CONSOLE_IP='0.0.0.0'\nexport VCAP_CONSOLE_PORT='61004'\n./startup -p 61003\nexit","rlimits":"#<Warden::Protocol::ResourceLimits:0x00000001e18da8>"},"response":{"job_id":11}},"thread_id":9056240,"fiber_id":15827860,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:15:44 warden.1 | {"timestamp":1368490544.0461106,"message":"<Warden::Protocol::SpawnResponse job_id: 11>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":15827860,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:15:44 warden.1 | {"timestamp":1368490544.0469084,"message":"Connection registered: #<Warden::Server::ClientConnection:0x00000001e8df90>","log_level":"debug2","source":"Warden::Server::Drainer","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":88,"method":"register_connection"}
00:15:44 warden.1 | {"timestamp":1368490544.047011,"message":"Connection registered: #<Warden::Server::ClientConnection:0x00000001e96c08>","log_level":"debug2","source":"Warden::Server::Drainer","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":88,"method":"register_connection"}
00:15:44 warden.1 | {"timestamp":1368490544.04763,"message":"<Warden::Protocol::LinkRequest handle: \"16ska1ops1g\", job_id: 11>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:44 warden.1 | {"timestamp":1368490544.047856,"message":"<Warden::Protocol::InfoRequest handle: \"16ska1ops1g\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:15:44 dea_ng.1 | {"timestamp":1368490544.0721345,"message":"Health check for 127.0.0.1:61003","log_level":"debug","source":"Dea::Instance","data":{"warden_handle":"16ska1ops1g"},"thread_id":15308800,"fiber_id":21260900,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/instance.rb","lineno":804,"method":"block in promise_port_open"}
00:15:45 dea_ng.1 | {"timestamp":1368490545.4421737,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:15:45 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:15:45] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.2691
00:15:48 dea_ng.1 | {"timestamp":1368490548.5821066,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:15:48 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:15:48] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1294
00:15:51 dea_ng.1 | {"timestamp":1368490551.7229905,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:15:51 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:15:51] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1326
00:15:54 dea_ng.1 | {"timestamp":1368490554.8587275,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:15:54 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:15:54] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1332
00:15:57 dea_ng.1 | {"timestamp":1368490557.9861495,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:15:57 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:15:57] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1243
00:15:58 dea_ng.1 | {"timestamp":1368490558.099567,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:01 dea_ng.1 | {"timestamp":1368490561.113952,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:01 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:01] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1246
00:16:04 dea_ng.1 | {"timestamp":1368490564.240922,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:04 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:04] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1235
00:16:07 dea_ng.1 | {"timestamp":1368490567.3802335,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:07 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:07] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1289
00:16:10 dea_ng.1 | {"timestamp":1368490570.5139463,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:10 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:10] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1297
00:16:13 dea_ng.1 | {"timestamp":1368490573.6441917,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:13 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:13] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1274
00:16:16 dea_ng.1 | {"timestamp":1368490576.7770205,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:16 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:16] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1290
00:16:19 dea_ng.1 | {"timestamp":1368490579.90743,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:19 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:19] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1269
00:16:23 dea_ng.1 | {"timestamp":1368490583.0460327,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:23 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:23] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1364
00:16:26 dea_ng.1 | {"timestamp":1368490586.1867783,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:26 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:26] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1377
00:16:28 dea_ng.1 | {"timestamp":1368490588.0983946,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:29 dea_ng.1 | {"timestamp":1368490589.3174732,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:29 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:29] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1283
00:16:32 dea_ng.1 | {"timestamp":1368490592.4493625,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:32 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:32] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1283
00:16:35 dea_ng.1 | {"timestamp":1368490595.5872514,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:35 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:35] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1352
00:16:38 dea_ng.1 | {"timestamp":1368490598.7362304,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:38 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:38] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1468
00:16:41 dea_ng.1 | {"timestamp":1368490601.8687348,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:41 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:41] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 132 2.1286
00:16:44 dea_ng.1 | {"timestamp":1368490604.1535413,"message":"Instance unhealthy","log_level":"warn","source":"Dea::Instance","data":{"warden_handle":"16ska1ops1g"},"thread_id":15308800,"fiber_id":23385860,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/instance.rb","lineno":537,"method":"block in start"}
00:16:44 dea_ng.1 | {"timestamp":1368490604.1537206,"message":"Failed: start instance (took 60.977)","log_level":"warn","source":"Dea::Instance","data":{"warden_handle":"16ska1ops1g"},"thread_id":15308800,"fiber_id":23385980,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/task.rb","lineno":268,"method":"block in resolve"}
00:16:44 dea_ng.1 | {"timestamp":1368490604.1537597,"message":"Caught exception: Instance unhealthy","log_level":"warn","source":"Dea::Instance","data":{"warden_handle":"16ska1ops1g","backtrace":["/vagrant/dea_ng/lib/dea/promise.rb:69:in `resolve'","/vagrant/dea_ng/lib/dea/promise.rb:14:in `block in resolve'"]},"thread_id":15308800,"fiber_id":23385980,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/task.rb","lineno":269,"method":"block in resolve"}
00:16:45 warden.1 | {"timestamp":1368490544.0608263,"message":"Exited with status 0 (0.008s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1g/net.sh\", \"get_egress_info\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"qdisc pfifo_fast 0: root refcnt 2 bands 3 priomap 1 2 2 2 1 2 0 0 1 1 1 1 1 1 1 1\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:16:45 dea_ng.1 | {"timestamp":1368490605.0088625,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:45 warden.1 | {"timestamp":1368490544.0680542,"message":"Exited with status 0 (0.007s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1g/net.sh\", \"get_ingress_info\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:16:45 dea_ng.1 | {"timestamp":1368490605.010454,"message":"Linking completed with exit status: 255","log_level":"info","source":"Dea::Instance","data":{"warden_handle":"16ska1ops1g"},"thread_id":15308800,"fiber_id":19588700,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/instance.rb","lineno":751,"method":"block in promise_link"}
00:16:45 warden.1 | {"timestamp":1368490544.070035,"message":"Exited with status 0 (0.002s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/warden/warden/src/repquota/repquota\", \"/\", \"10001\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"stdout":"10001 50802688 0 1048576 0 1565 0 0 0\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:16:45 warden.1 | {"timestamp":1368490544.070192,"message":"info (took 0.022157)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g"},"response":{"state":"active","events":[],"host_ip":"10.254.0.5","container_ip":"10.254.0.6","container_path":"/tmp/warden/containers/16ska1ops1g","memory_stat":"#<Warden::Protocol::InfoResponse::MemoryStat:0x00000001ea8ae8>","cpu_stat":"#<Warden::Protocol::InfoResponse::CpuStat:0x00000001ea7468>","disk_stat":"#<Warden::Protocol::InfoResponse::DiskStat:0x00000001ec2718>","bandwidth_stat":"#<Warden::Protocol::InfoResponse::BandwidthStat:0x00000001eb09f0>","job_ids":[11]}},"thread_id":9056240,"fiber_id":16060500,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:16:45 warden.1 | {"timestamp":1368490544.0704076,"message":"<Warden::Protocol::InfoResponse state: \"active\", events: [], host_ip: \"10.254.0.5\", container_ip: \"10.254.0.6\", container_path: \"/tmp/warden/containers/16ska1ops1g\", memory_stat: <Warden::Protocol::InfoResponse::MemoryStat cache: 49889280, rss: 208896, mapped_file: 0, pgpgin: 13404, pgpgout: 1173, swap: 0, pgfault: 7070, pgmajfault: 0, inactive_anon: 0, active_anon: 208896, inactive_file: 48771072, active_file: 1118208, unevictable: 0, hierarchical_memory_limit: 301989888, hierarchical_memsw_limit: 301989888, total_cache: 49889280, total_rss: 212992, total_mapped_file: 0, total_pgpgin: 13405, total_pgpgout: 1173, total_swap: 0, total_pgfault: 7072, total_pgmajfault: 0, total_inactive_anon: 0, total_active_anon: 208896, total_inactive_file: 48771072, total_active_file: 1118208, total_unevictable: 0>, cpu_stat: <Warden::Protocol::InfoResponse::CpuStat usage: 477170281, user: 12, system: 12>, disk_stat: <Warden::Protocol::InfoResponse::DiskStat bytes_used: 50802688, inodes_used: 1565>, bandwidth_stat: <Warden::Protocol::InfoResponse::BandwidthStat in_rate: 4294967295, in_burst: 4294967295, out_rate: 4294967295, out_burst: 4294967295>, job_ids: [11]>","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":16060500,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:16:45 warden.1 | {"timestamp":1368490573.2334948,"message":"Connection unregistered: #<Warden::Server::ClientConnection:0x00000001c2f348>","log_level":"debug2","source":"Warden::Server::Drainer","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":95,"method":"unregister_connection"}
00:16:45 warden.1 | {"timestamp":1368490574.1892548,"message":"Connection unregistered: #<Warden::Server::ClientConnection:0x00000001eecdb0>","log_level":"debug2","source":"Warden::Server::Drainer","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":95,"method":"unregister_connection"}
00:16:45 warden.1 | {"timestamp":1368490574.1893895,"message":"Connection unregistered: #<Warden::Server::ClientConnection:0x00000001e96c08>","log_level":"debug2","source":"Warden::Server::Drainer","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":95,"method":"unregister_connection"}
00:16:45 warden.1 | {"timestamp":1368490604.1556518,"message":"Connection registered: #<Warden::Server::ClientConnection:0x00000001edcc08>","log_level":"debug2","source":"Warden::Server::Drainer","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":88,"method":"register_connection"}
00:16:45 warden.1 | {"timestamp":1368490604.1561751,"message":"<Warden::Protocol::CopyOutRequest handle: \"16ska1ops1g\", src_path: \"/home/vcap/\", dst_path: \"/tmp/dea_ng/crashes/820fd91dc440ca2da315a194a5b943e7\", owner: \"1000\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:16:45 warden.1 | {"timestamp":1368490604.9838114,"message":"Exited with status 0 (0.827s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"rsync\", \"-e\", \"/tmp/warden/containers/16ska1ops1g/bin/wsh --socket /tmp/warden/containers/16ska1ops1g/run/wshd.sock --rsh\", \"-r\", \"-p\", \"--links\", \"vcap@container:/home/vcap/\", \"/tmp/dea_ng/crashes/820fd91dc440ca2da315a194a5b943e7\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:16:45 warden.1 | {"timestamp":1368490604.994734,"message":"Exited with status 0 (0.010s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"chown\", \"-R\", \"1000\", \"/tmp/dea_ng/crashes/820fd91dc440ca2da315a194a5b943e7\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:16:45 warden.1 | {"timestamp":1368490604.9948514,"message":"copy_out (took 0.838500)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","request":{"handle":"16ska1ops1g","src_path":"/home/vcap/","dst_path":"/tmp/dea_ng/crashes/820fd91dc440ca2da315a194a5b943e7","owner":"1000"},"response":{}},"thread_id":9056240,"fiber_id":16192020,"process_id":2001,"file":"/warden/warden/lib/warden/container/base.rb","lineno":318,"method":"dispatch"}
00:16:45 warden.1 | {"timestamp":1368490604.994929,"message":"<Warden::Protocol::CopyOutResponse >","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":16192020,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":366,"method":"send_response"}
00:16:45 warden.1 | {"timestamp":1368490604.9960165,"message":"<Warden::Protocol::DestroyRequest handle: \"16ska1ops1g\">","log_level":"debug2","source":"Warden::Server::ClientConnection","data":{},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/server.rb","lineno":401,"method":"receive_request"}
00:16:45 warden.1 | {"timestamp":1368490605.0088658,"message":"Exited with status 0 (60.967s): [[\"/warden/warden/src/closefds/closefds\", \"/warden/warden/src/closefds/closefds\"], \"/tmp/warden/containers/16ska1ops1g/bin/iomux-spawn\", \"/tmp/warden/containers/16ska1ops1g/jobs/11\", \"/tmp/warden/containers/16ska1ops1g/bin/wsh\", \"--socket\", \"/tmp/warden/containers/16ska1ops1g/run/wshd.sock\", \"--user\", \"vcap\", \"/bin/bash\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":"16ska1ops1g","stdout":"child_pid=3704\nchild active\n","stderr":""},"thread_id":9056240,"fiber_id":14692000,"process_id":2001,"file":"/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
00:16:47 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:47] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1342
00:16:50 dea_ng.1 | {"timestamp":1368490610.1337607,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:52 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:52] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1232
00:16:55 dea_ng.1 | {"timestamp":1368490615.2669704,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:16:57 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:16:57] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1313
00:16:58 dea_ng.1 | {"timestamp":1368490618.1000612,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:00 dea_ng.1 | {"timestamp":1368490620.396879,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:02 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:17:02] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1278
00:17:05 dea_ng.1 | {"timestamp":1368490625.5448017,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:07 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:17:07] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1336
00:17:10 dea_ng.1 | {"timestamp":1368490630.6794982,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:12 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:17:12] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1313
00:17:15 dea_ng.1 | {"timestamp":1368490635.849138,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:17 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:17:17] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1673
00:17:20 dea_ng.1 | {"timestamp":1368490640.9805005,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:22 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:17:22] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1269
00:17:26 dea_ng.1 | {"timestamp":1368490646.1157935,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:28 dea_ng.1 | {"timestamp":1368490648.1000295,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:28 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:17:28] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1314
00:17:31 dea_ng.1 | {"timestamp":1368490651.2466414,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:33 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:17:33] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1285
00:17:36 dea_ng.1 | {"timestamp":1368490656.3865273,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:38 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:17:38] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1357
00:17:41 dea_ng.1 | {"timestamp":1368490661.541181,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:43 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:17:43] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1309
cd00:17:46 dea_ng.1 | {"timestamp":1368490666.6704652,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:48 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:17:48] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1257
00:17:51 dea_ng.1 | {"timestamp":1368490671.8055716,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:53 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:17:53] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1322
00:17:56 dea_ng.1 | {"timestamp":1368490676.9413636,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:58 dea_ng.1 | {"timestamp":1368490678.099886,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:17:58 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:17:58] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1312
00:18:02 dea_ng.1 | {"timestamp":1368490682.078755,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:18:04 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:18:04] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1361
00:18:07 dea_ng.1 | {"timestamp":1368490687.2181096,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:18:09 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:18:09] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1306
00:18:12 dea_ng.1 | {"timestamp":1368490692.3522043,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:18:14 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:18:14] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1318
00:18:17 dea_ng.1 | {"timestamp":1368490697.4871676,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:18:19 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:18:19] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1313
00:18:22 dea_ng.1 | {"timestamp":1368490702.6136081,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:18:24 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:18:24] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1215
00:18:27 dea_ng.1 | {"timestamp":1368490707.741913,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:18:28 dea_ng.1 | {"timestamp":1368490708.0995135,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:18:29 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:18:29] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1263
00:18:32 dea_ng.1 | {"timestamp":1368490712.8747015,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:18:34 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:18:34] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1285
00:18:38 dea_ng.1 | {"timestamp":1368490718.0128617,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:18:40 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:18:40] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1358
00:18:43 dea_ng.1 | {"timestamp":1368490723.1477942,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:18:45 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:18:45] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1319
00:18:48 dea_ng.1 | {"timestamp":1368490728.2810133,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:18:50 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:18:50] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1287
00:18:53 dea_ng.1 | {"timestamp":1368490733.4144895,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:18:55 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:18:55] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1310
00:18:58 dea_ng.1 | {"timestamp":1368490738.0997913,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:18:58 dea_ng.1 | {"timestamp":1368490738.5727189,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:19:00 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:19:00] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1554
00:19:03 dea_ng.1 | {"timestamp":1368490743.708686,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:19:05 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:19:05] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1327
00:19:08 dea_ng.1 | {"timestamp":1368490748.8457968,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:19:10 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:19:10] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1339
00:19:13 dea_ng.1 | {"timestamp":1368490753.978373,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:19:15 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:19:15] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1289
00:19:19 dea_ng.1 | {"timestamp":1368490759.132172,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:19:21 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:19:21] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1500
00:19:24 dea_ng.1 | {"timestamp":1368490764.2796617,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:19:26 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:19:26] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1442
00:19:28 dea_ng.1 | {"timestamp":1368490768.0985253,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:19:29 dea_ng.1 | {"timestamp":1368490769.4369912,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:19:31 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:19:31] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1535
00:19:34 dea_ng.1 | {"timestamp":1368490774.5839267,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:19:36 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:19:36] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1391
00:19:39 dea_ng.1 | {"timestamp":1368490779.7556107,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:19:41 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:19:41] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1695
00:19:44 dea_ng.1 | {"timestamp":1368490784.9014108,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:19:46 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:19:46] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1423
00:19:50 dea_ng.1 | {"timestamp":1368490790.0449018,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:19:52 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:19:52] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1396
00:19:55 dea_ng.1 | {"timestamp":1368490795.1888607,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:19:57 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:19:57] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1421
00:19:58 dea_ng.1 | {"timestamp":1368490798.099573,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:20:00 dea_ng.1 | {"timestamp":1368490800.3369002,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:20:02 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:20:02] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1436
00:20:05 dea_ng.1 | {"timestamp":1368490805.4793293,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:20:07 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:20:07] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1382
00:20:10 dea_ng.1 | {"timestamp":1368490810.6208525,"message":"Received on \"dea.find.droplet\": {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"states\"=>[\"STARTING\", \"RUNNING\"], \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:20:12 cc_ng.1 | 127.0.0.1 - - [14/May/2013 00:20:12] "GET /v2/apps/6ec399db-ba71-4b2e-8fd4-bfc78f73b837/instances HTTP/1.1" 200 41 4.1397
00:20:28 dea_ng.1 | {"timestamp":1368490828.0999064,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:20:58 dea_ng.1 | {"timestamp":1368490858.0985155,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:21:28 dea_ng.1 | {"timestamp":1368490888.0998993,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:21:58 dea_ng.1 | {"timestamp":1368490918.0986404,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:22:28 dea_ng.1 | {"timestamp":1368490948.0983949,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:22:58 dea_ng.1 | {"timestamp":1368490978.0985084,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:23:28 dea_ng.1 | {"timestamp":1368491008.0984056,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:23:58 dea_ng.1 | {"timestamp":1368491038.0990694,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:24:28 dea_ng.1 | {"timestamp":1368491068.0985928,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:24:58 dea_ng.1 | {"timestamp":1368491098.0988688,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:25:28 dea_ng.1 | {"timestamp":1368491128.101157,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:25:58 dea_ng.1 | {"timestamp":1368491158.0983143,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:26:28 dea_ng.1 | {"timestamp":1368491188.0994232,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:26:58 dea_ng.1 | {"timestamp":1368491218.099353,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:27:28 dea_ng.1 | {"timestamp":1368491248.098819,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:58:27 dea_ng.1 | {"timestamp":1368493107.5353045,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:58:28 dea_ng.1 | {"timestamp":1368493108.0993042,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:58:58 dea_ng.1 | {"timestamp":1368493138.0987382,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:59:28 dea_ng.1 | {"timestamp":1368493168.0994387,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
00:59:58 dea_ng.1 | {"timestamp":1368493198.0988247,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:00:28 dea_ng.1 | {"timestamp":1368493228.0992844,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:00:58 dea_ng.1 | {"timestamp":1368493258.0993497,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:01:28 dea_ng.1 | {"timestamp":1368493288.0986285,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:01:58 dea_ng.1 | {"timestamp":1368493318.0987532,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:02:28 dea_ng.1 | {"timestamp":1368493348.1000135,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:02:58 dea_ng.1 | {"timestamp":1368493378.0999177,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:03:28 dea_ng.1 | {"timestamp":1368493408.099397,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:03:58 dea_ng.1 | {"timestamp":1368493438.0984547,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:04:28 dea_ng.1 | {"timestamp":1368493468.1050255,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:04:58 dea_ng.1 | {"timestamp":1368493498.0995061,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:05:28 dea_ng.1 | {"timestamp":1368493528.104529,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:05:58 dea_ng.1 | {"timestamp":1368493558.0984888,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:06:28 dea_ng.1 | {"timestamp":1368493588.0996406,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:06:58 dea_ng.1 | {"timestamp":1368493618.0995054,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:07:28 dea_ng.1 | {"timestamp":1368493648.0993273,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:07:58 dea_ng.1 | {"timestamp":1368493678.098857,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:08:28 dea_ng.1 | {"timestamp":1368493708.0994143,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:08:58 dea_ng.1 | {"timestamp":1368493738.0993245,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:09:28 dea_ng.1 | {"timestamp":1368493768.1001182,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:09:58 dea_ng.1 | {"timestamp":1368493798.0984821,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:10:28 dea_ng.1 | {"timestamp":1368493828.099854,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:10:58 dea_ng.1 | {"timestamp":1368493858.098478,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:11:28 dea_ng.1 | {"timestamp":1368493888.1053948,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:11:58 dea_ng.1 | {"timestamp":1368493918.1053104,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:12:28 dea_ng.1 | {"timestamp":1368493948.099592,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:12:58 dea_ng.1 | {"timestamp":1368493978.0993,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:13:28 dea_ng.1 | {"timestamp":1368494008.1015632,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:13:58 dea_ng.1 | {"timestamp":1368494038.1231546,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:14:28 dea_ng.1 | {"timestamp":1368494068.0985363,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:14:58 dea_ng.1 | {"timestamp":1368494098.1054626,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:15:28 dea_ng.1 | {"timestamp":1368494128.1046019,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:15:58 dea_ng.1 | {"timestamp":1368494158.098794,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:16:28 dea_ng.1 | {"timestamp":1368494188.0984442,"message":"Received on \"router.start\": {\"id\"=>\"b34899eceee8bd7ab7249b3da611a650\", \"hosts\"=>[\"10.0.2.15\"]}","log_level":"debug","source":"Dea::Nats","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/nats.rb","lineno":75,"method":"block in subscribe"}
01:16:53 dea_ng.1 | {"timestamp":1368494213.9168675,"message":"Removing crash 820fd91dc440ca2da315a194a5b943e7","log_level":"debug","source":"Dea::InstanceRegistry","data":{"instance_id":"820fd91dc440ca2da315a194a5b943e7","reason":"stale","application_id":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","application_version":"cab62092-f242-43e2-ae39-0ab5afae5ce5","application_name":"test-app"},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/instance_registry.rb","lineno":162,"method":"reap_crash"}
01:16:53 dea_ng.1 | {"timestamp":1368494213.9480088,"message":"Removing droplet for sha=f5d7e5b8e9315ee886d78983ccf6863b8676220d","log_level":"debug","source":"Dea::Bootstrap","data":{},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/bootstrap.rb","lineno":399,"method":"block in reap_unreferenced_droplets"}
01:16:53 dea_ng.1 | {"timestamp":1368494213.948219,"message":"Renaming /tmp/dea_ng/droplets/f5d7e5b8e9315ee886d78983ccf6863b8676220d to /tmp/dea_ng/droplets/f5d7e5b8e9315ee886d78983ccf6863b8676220d.deleted.1368494213","log_level":"debug","source":"Dea::Droplet","data":{"droplet_sha1":"f5d7e5b8e9315ee886d78983ccf6863b8676220d"},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/droplet.rb","lineno":69,"method":"destroy"}
01:16:54 dea_ng.1 | {"timestamp":1368494214.0089216,"message":"Removing /tmp/dea_ng/droplets/f5d7e5b8e9315ee886d78983ccf6863b8676220d.deleted.1368494213","log_level":"debug","source":"Dea::Droplet","data":{"droplet_sha1":"f5d7e5b8e9315ee886d78983ccf6863b8676220d"},"thread_id":31070600,"fiber_id":29662720,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/droplet.rb","lineno":73,"method":"block in destroy"}
01:16:54 dea_ng.1 | {"timestamp":1368494214.0120952,"message":"Removing crash 820fd91dc440ca2da315a194a5b943e7: took 0.095s","log_level":"debug","source":"Dea::InstanceRegistry","data":{"instance_id":"820fd91dc440ca2da315a194a5b943e7","reason":"stale","application_id":"6ec399db-ba71-4b2e-8fd4-bfc78f73b837","application_version":"cab62092-f242-43e2-ae39-0ab5afae5ce5","application_name":"test-app"},"thread_id":15308800,"fiber_id":18185620,"process_id":1977,"file":"/vagrant/dea_ng/lib/dea/instance_registry.rb","lineno":166,"method":"block in reap_crash"}
I noticed this in the Health Manager logs:
{"timestamp":1368490777.751985,"message":"reporter: status: message: {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"state\"=>\"FLAPPING\", \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"hm","data":{},"thread_id":11352060,"fiber_id":16394940,"process_id":1996,"file":"/vagrant/health_manager/lib/health_manager/reporter.rb","lineno":31,"method":"process_status_message"}
{"timestamp":1368490782.8985956,"message":"reporter: status: message: {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"state\"=>\"FLAPPING\", \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"hm","data":{},"thread_id":11352060,"fiber_id":16394940,"process_id":1996,"file":"/vagrant/health_manager/lib/health_manager/reporter.rb","lineno":31,"method":"process_status_message"}
{"timestamp":1368490788.0411336,"message":"reporter: status: message: {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"state\"=>\"FLAPPING\", \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"hm","data":{},"thread_id":11352060,"fiber_id":16394940,"process_id":1996,"file":"/vagrant/health_manager/lib/health_manager/reporter.rb","lineno":31,"method":"process_status_message"}
{"timestamp":1368490793.1850405,"message":"reporter: status: message: {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"state\"=>\"FLAPPING\", \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"hm","data":{},"thread_id":11352060,"fiber_id":16394940,"process_id":1996,"file":"/vagrant/health_manager/lib/health_manager/reporter.rb","lineno":31,"method":"process_status_message"}
{"timestamp":1368490798.3329206,"message":"reporter: status: message: {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"state\"=>\"FLAPPING\", \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"hm","data":{},"thread_id":11352060,"fiber_id":16394940,"process_id":1996,"file":"/vagrant/health_manager/lib/health_manager/reporter.rb","lineno":31,"method":"process_status_message"}
{"timestamp":1368490803.4764426,"message":"reporter: status: message: {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"state\"=>\"FLAPPING\", \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"hm","data":{},"thread_id":11352060,"fiber_id":16394940,"process_id":1996,"file":"/vagrant/health_manager/lib/health_manager/reporter.rb","lineno":31,"method":"process_status_message"}
{"timestamp":1368490808.616818,"message":"reporter: status: message: {\"droplet\"=>\"6ec399db-ba71-4b2e-8fd4-bfc78f73b837\", \"state\"=>\"FLAPPING\", \"version\"=>\"cab62092-f242-43e2-ae39-0ab5afae5ce5\"}","log_level":"debug","source":"hm","data":{},"thread_id":11352060,"fiber_id":16394940,"process_id":1996,"file":"/vagrant/health_manager/lib/health_manager/reporter.rb","lineno":31,"method":"process_status_message"}
{"timestamp":1368490828.264052,"message":"bulk: requesting API credentials over NATS...","log_level":"info","source":"hm","data":{},"thread_id":11352060,"fiber_id":16394940,"process_id":1996,"file":"/vagrant/health_manager/lib/health_manager/bulk_based_expected_state_provider.rb","lineno":152,"method":"with_credentials"}
{"timestamp":1368490828.26426,"message":"config: nats_request_timeout: 5","log_level":"debug","source":"hm","data":{},"thread_id":11352060,"fiber_id":16394940,"process_id":1996,"file":"/vagrant/health_manager/lib/health_manager/common.rb","lineno":23,"method":"get_param_from_config_or_default"}
{"timestamp":1368490828.264419,"message":"bulk: requesting API credentials over NATS...","log_level":"info","source":"hm","data":{},"thread_id":11352060,"fiber_id":16394940,"process_id":1996,"file":"/vagrant/health_manager/lib/health_manager/bulk_based_expected_state_provider.rb","lineno":152,"method":"with_credentials"}
{"timestamp":1368490828.2645192,"message":"config: nats_request_timeout: 5","log_level":"debug","source":"hm","data":{},"thread_id":11352060,"fiber_id":16394940,"process_id":1996,"file":"/vagrant/health_manager/lib/health_manager/common.rb","lineno":23,"method":"get_param_from_config_or_default"}
{"timestamp":1368490833.2651906,"message":"bulk: NATS timeout getting bulk api credentials. Request ignored.","log_level":"error","source":"hm","data":{},"thread_id":11352060,"fiber_id":16394940,"process_id":1996,"file":"/vagrant/health_manager/lib/health_manager/bulk_based_expected_state_provider.rb","lineno":162,"method":"block in with_credentials"}
{"timestamp":1368490833.265321,"message":"bulk: NATS timeout getting bulk api credentials. Request ignored.","log_level":"error","source":"hm","data":{},"thread_id":11352060,"fiber_id":16394940,"process_id":1996,"file":"/vagrant/health_manager/lib/health_manager/bulk_based_expected_state_provider.rb","lineno":162,"method":"block in with_credentials"}
@ndzj081221130
Copy link

I SAW "Killing oom-notifier process" in warden.log

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment