Skip to content

Instantly share code, notes, and snippets.

@jimhorng

jimhorng/CF app cannot start

Last active December 27, 2015 08:59
Show Gist options
  • Save jimhorng/7300748 to your computer and use it in GitHub Desktop.
Save jimhorng/7300748 to your computer and use it in GitHub Desktop.
Download ZIP
CF app cannot start
Raw
CF app cannot start
-----
>cf restart hello
Stopping hello... OK
Preparing to start hello... OK
Checking status of app 'hello'...
0 of 1 instances running (1 starting)
0 of 1 instances running (1 down)
0 of 1 instances running (1 down)
-----
>cf health hello
Getting health status... OK
hello: 0%
-----
>cf events hello
Time instance index description
exit status
013-11-04 18:29:40 +0800 0 Error downloading: http://zxsfhgjg:[email protected]:8181/staging/dro
lets/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d/download (HTTP status: 400) Failure (-1)
013-11-04 18:50:44 +0800 0 Error downloading: http://zxsfhgjg:[email protected]:8181/staging/dro
lets/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d/download (HTTP status: 400) Failure (-1)
-----
>cf logs hello
Getting logs for hello #0... FAILED
CFoundry::FileError: 190001: File error: Request failed for app: hello, instance: 0 and path: logs as the instance is no
t found.
-----
>cf crashlogs hello
Getting logs for hello #a87f90f9f98ab7644309f7e1896bdb43... FAILED
CFoundry::NotFound: 404: 404 Not Found
-----
>cf app hello -t
>>>
REQUEST: GET http://api.192.168.12.34.xip.io:8181/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/apps?q=name%3Ahello&inl
ine-relations-depth=1
REQUEST_HEADERS:
Accept : application/json
Authorization : [PRIVATE DATA HIDDEN]
Content-Length : 0
RESPONSE: [200]
RESPONSE_HEADERS:
connection : keep-alive
content-length : 4603
content-type : application/json;charset=utf-8
server : thin 1.5.1 codename Straight Razor
x-frame-options : sameorigin
x-vcap-request-id : 1fcea29a-a8ee-4482-ba8b-641f916473cf
x-xss-protection : 1; mode=block
RESPONSE_BODY:
{
"total_results": 1,
"total_pages": 1,
"prev_url": null,
"next_url": null,
"resources": [
{
"metadata": {
"guid": "b7efdae5-fecf-44c9-894d-f1c37d5e9f2d",
"url": "/v2/apps/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d",
"created_at": "2013-10-31 12:15:10 +0800",
"updated_at": "2013-11-04 18:29:39 +0800"
},
"entity": {
"name": "hello",
"production": false,
"space_guid": "ccfa0e16-ec39-436d-a32e-51463e49682c",
"stack_guid": "a06d03f2-5f8d-46d7-b544-0ec77f69411c",
"buildpack": null,
"detected_buildpack": "Ruby/Rack",
"environment_json": {
},
"memory": 256,
"instances": 1,
"disk_quota": 1024,
"state": "STARTED",
"version": "88a60d81-94ad-45df-9184-42a6a61edc13",
"command": null,
"console": true,
"debug": null,
"staging_task_id": "27fe21f53ac90175eb50a8a95206d3cc",
"service_bindings_url": "/v2/apps/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d/service_bindings",
"service_bindings": [
],
"routes_url": "/v2/apps/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d/routes",
"routes": [
{
"metadata": {
"guid": "a6557a99-2769-4cad-baa0-5ee8a2f1affe",
"url": "/v2/routes/a6557a99-2769-4cad-baa0-5ee8a2f1affe",
"created_at": "2013-10-30 17:39:02 +0800",
"updated_at": null
},
"entity": {
"host": "hello",
"domain_guid": "e9100cf7-f463-4897-aa95-1227c1f5b126",
"space_guid": "ccfa0e16-ec39-436d-a32e-51463e49682c",
"apps_url": "/v2/routes/a6557a99-2769-4cad-baa0-5ee8a2f1affe/apps",
"domain_url": "/v2/domains/e9100cf7-f463-4897-aa95-1227c1f5b126",
"space_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c"
}
}
],
"events_url": "/v2/apps/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d/events",
"events": [
{
"metadata": {
"guid": "3857ec59-b261-4fc6-a4cf-9f089d883eda",
"url": "/v2/app_events/3857ec59-b261-4fc6-a4cf-9f089d883eda",
"created_at": "2013-11-04 18:29:40 +0800",
"updated_at": null
},
"entity": {
"app_guid": "b7efdae5-fecf-44c9-894d-f1c37d5e9f2d",
"instance_guid": "a87f90f9f98ab7644309f7e1896bdb43",
"instance_index": 0,
"exit_status": -1,
"exit_description": "Error downloading: http://zxsfhgjg:[email protected]:8181/staging/droplets/b7ef
dae5-fecf-44c9-894d-f1c37d5e9f2d/download (HTTP status: 400)",
"timestamp": "2013-11-04 18:29:40 +0800",
"app_url": "/v2/apps/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d"
}
}
],
"space_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c",
"space": {
"metadata": {
"guid": "ccfa0e16-ec39-436d-a32e-51463e49682c",
"url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c",
"created_at": "2013-10-30 17:37:25 +0800",
"updated_at": null
},
"entity": {
"name": "myspace",
"organization_guid": "18dd8eb5-738e-407d-8f1c-3887f6441535",
"developers_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/developers",
"managers_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/managers",
"auditors_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/auditors",
"apps_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/apps",
"domains_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/domains",
"service_instances_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/service_instances",
"app_events_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/app_events",
"organization_url": "/v2/organizations/18dd8eb5-738e-407d-8f1c-3887f6441535"
}
},
"stack_url": "/v2/stacks/a06d03f2-5f8d-46d7-b544-0ec77f69411c",
"stack": {
"metadata": {
"guid": "a06d03f2-5f8d-46d7-b544-0ec77f69411c",
"url": "/v2/stacks/a06d03f2-5f8d-46d7-b544-0ec77f69411c",
"created_at": "2013-10-30 17:00:17 +0800",
"updated_at": null
},
"entity": {
"name": "lucid64",
"description": "Ubuntu 10.04 on x86-64"
}
}
}
}
]
}
<<<
>>>
REQUEST: GET http://api.192.168.12.34.xip.io:8181/v2/apps/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d/instances
REQUEST_HEADERS:
Accept : application/json
Authorization : [PRIVATE DATA HIDDEN]
Content-Length : 0
RESPONSE: [200]
RESPONSE_HEADERS:
connection : keep-alive
content-length : 41
content-type : application/json;charset=utf-8
server : thin 1.5.1 codename Straight Razor
x-frame-options : sameorigin
x-vcap-request-id : 860458a8-5870-4b42-8b81-1145f42d7111
x-xss-protection : 1; mode=block
RESPONSE_BODY:
{
"0": {
"state": "DOWN",
"since": 1383561145
}
}
<<<
hello: 0%
usage: 256M x 1 instance
>>>
REQUEST: GET http://api.192.168.12.34.xip.io:8181/v2/domains/e9100cf7-f463-4897-aa95-1227c1f5b126?inline-relations-depth
=1
REQUEST_HEADERS:
Accept : application/json
Authorization : [PRIVATE DATA HIDDEN]
Content-Length : 0
RESPONSE: [200]
RESPONSE_HEADERS:
connection : keep-alive
content-length : 1514
content-type : application/json;charset=utf-8
server : thin 1.5.1 codename Straight Razor
x-frame-options : sameorigin
x-vcap-request-id : 47e1a818-b446-499c-8fcf-f470fdd8c7f2
x-xss-protection : 1; mode=block
RESPONSE_BODY:
{
"metadata": {
"guid": "e9100cf7-f463-4897-aa95-1227c1f5b126",
"url": "/v2/domains/e9100cf7-f463-4897-aa95-1227c1f5b126",
"created_at": "2013-10-30 17:28:44 +0800",
"updated_at": null
},
"entity": {
"name": "192.168.12.34.xip.io",
"owning_organization_guid": null,
"wildcard": true,
"spaces_url": "/v2/domains/e9100cf7-f463-4897-aa95-1227c1f5b126/spaces",
"spaces": [
{
"metadata": {
"guid": "ccfa0e16-ec39-436d-a32e-51463e49682c",
"url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c",
"created_at": "2013-10-30 17:37:25 +0800",
"updated_at": null
},
"entity": {
"name": "myspace",
"organization_guid": "18dd8eb5-738e-407d-8f1c-3887f6441535",
"developers_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/developers",
"managers_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/managers",
"auditors_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/auditors",
"apps_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/apps",
"domains_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/domains",
"service_instances_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/service_instances",
"app_events_url": "/v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/app_events",
"organization_url": "/v2/organizations/18dd8eb5-738e-407d-8f1c-3887f6441535"
}
}
]
}
}
<<<
urls: hello.192.168.12.34.xip.io
-----
vagrant@cf:/vagrant$ sudo tail /var/log/upstart/cf-*.log
==> /var/log/upstart/cf-cloud_controller.log <==
192.168.12.1 - - [04/Nov/2013 18:31:00] "GET /v2/apps/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d/instances HTTP/1.1" 200 41 2.2396
192.168.12.1 - - [04/Nov/2013 18:31:03] "GET /v2/apps/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d/instances HTTP/1.1" 200 41 2.2025
192.168.12.1 - - [04/Nov/2013 18:31:07] "GET /v2/apps/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d/instances HTTP/1.1" 200 41 2.2256
192.168.12.1 - - [04/Nov/2013 18:31:10] "GET /v2/apps/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d/instances HTTP/1.1" 200 41 2.2418
192.168.12.1 - - [04/Nov/2013 18:31:52] "GET /v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/apps?q=name%3Ahello&inline-relations-depth=1 HTTP/1.1" 20
0 4603 0.2513
192.168.12.1 - - [04/Nov/2013 18:31:52] "GET /v2/apps/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d/crashes HTTP/1.1" 200 76 0.2215
192.168.12.1 - - [04/Nov/2013 18:31:52] "GET /v2/apps/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d/instances/a87f90f9f98ab7644309f7e1896bdb43/files/logs HTTP/
1.1" 302 - 0.1919
192.168.12.1 - - [04/Nov/2013 18:32:23] "GET /v2/spaces/ccfa0e16-ec39-436d-a32e-51463e49682c/apps?q=name%3Ahello&inline-relations-depth=1 HTTP/1.1" 20
0 4603 0.2087
192.168.12.1 - - [04/Nov/2013 18:32:25] "GET /v2/apps/b7efdae5-fecf-44c9-894d-f1c37d5e9f2d/instances HTTP/1.1" 200 41 2.2035
192.168.12.1 - - [04/Nov/2013 18:32:25] "GET /v2/domains/e9100cf7-f463-4897-aa95-1227c1f5b126?inline-relations-depth=1 HTTP/1.1" 200 1514 0.2575
==> /var/log/upstart/cf-dea.log <==
Session terminated, terminating shell...DEBUG:route: 192.168.12.34.xip.io
==> /var/log/upstart/cf-dir_server.log <==
Session terminated, terminating shell...{"Timestamp":1.38356060775999e+09,"Message":"Starting HTTP server at host: 192.168.12.34 on port: 5678","Level
":"info","Data":null,"File":"","Method":"","Line":0}
==> /var/log/upstart/cf-file_server.log <==
Session terminated, terminating shell...>> Thin web server (v1.5.1 codename Straight Razor)
>> Maximum connections set to 1024
>> Listening on 0.0.0.0:9999, CTRL+C to stop
==> /var/log/upstart/cf-health_manager.log <==
Session terminated, terminating shell...DEBUG:route: 127.0.0.1
==> /var/log/upstart/cf-nats-server.log <==
Session terminated, terminating shell...
==> /var/log/upstart/cf-router.log <==
Session terminated, terminating shell...
==> /var/log/upstart/cf-uaa.log <==
Nov 4, 2013 6:24:53 PM org.apache.catalina.core.ApplicationContext log
INFO: Testing for YAML resources at: file:/vagrant/custom_config_files/uaa//uaa.yml
Nov 4, 2013 6:24:53 PM org.apache.catalina.core.ApplicationContext log
INFO: Loading YAML environment properties from location: URL [file:/vagrant/custom_config_files/uaa//uaa.yml]
Nov 4, 2013 6:24:54 PM org.apache.catalina.core.ApplicationContext log
INFO: Loading log4j config from location: classpath:log4j.properties
Nov 4, 2013 6:25:38 PM org.apache.coyote.http11.Http11Protocol init
INFO: Initializing Coyote HTTP/1.1 on http-8080
Nov 4, 2013 6:25:38 PM org.apache.coyote.http11.Http11Protocol start
INFO: Starting Coyote HTTP/1.1 on http-8080
==> /var/log/upstart/cf-warden.log <==
Session terminated, terminating shell... ...terminated.
-----
$ tail logs/*.log
==> logs/cf_bootstrap.log <==
- Push a very simple ruby sinatra app:
$ cd test/fixture/apps/sinatra
$ cf push
- Test it:
$ curl -v hello.192.168.12.34.xip.io
<h3>Sinatra Test app for CF Vagrant Installer</h3>
Hello from 0.0.0.0:61007! <br/>
==> logs/cf-nats-server.log <==
["Starting nats-server version 0.4.26 on port 4222"]
["Server exiting.."]
["Starting nats-server version 0.4.26 on port 4222"]
["Server exiting.."]
["Starting nats-server version 0.4.26 on port 4222"]
["Server exiting.."]
["Starting nats-server version 0.4.26 on port 4222"]
==> logs/cloud_controller.log <==
{"timestamp":1383561145.6371024,"message":"found: read e9100cf7-f463-4897-aa95-1227c1f5b126","log_level":"debug","source":"cc.api","data":{"request_gu
id":"47e1a818-b446-499c-8fcf-f470fdd8c7f2"},"thread_id":28182580,"fiber_id":69992733268280,"process_id":2821,"file":"/vagrant/cloud_controller_ng/lib/
cloud_controller/rest_controller/model_controller.rb","lineno":178,"method":"find_id_and_validate_access"}
{"timestamp":1383561145.637471,"message":"validate access: read e9100cf7-f463-4897-aa95-1227c1f5b126","log_level":"debug","source":"cc.api","data":{"r
equest_guid":"47e1a818-b446-499c-8fcf-f470fdd8c7f2"},"thread_id":28182580,"fiber_id":69992733268280,"process_id":2821,"file":"/vagrant/cloud_controlle
r_ng/lib/cloud_controller/rest_controller/model_controller.rb","lineno":202,"method":"validate_access"}
{"timestamp":1383561145.641012,"message":"(0.001346s) SELECT COUNT(*) AS 'count' FROM `spaces` INNER JOIN `domains_spaces` ON ((`domains_spaces`.`spac
e_id` = `spaces`.`id`) AND (`domains_spaces`.`domain_id` = 1)) WHERE (`spaces`.`id` IN (SELECT `spaces_auditors`.`space_id` FROM `spaces_auditors` WHE
RE ((`spaces_auditors`.`user_id` IN (3)) AND (`spaces_auditors`.`space_id` IS NOT NULL)))) LIMIT 1","log_level":"debug2","source":"cc.db","data":{"req
uest_guid":"47e1a818-b446-499c-8fcf-f470fdd8c7f2"},"thread_id":28182580,"fiber_id":69992733268280,"process_id":2821,"file":"/home/vagrant/.rbenv/versi
ons/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sequel-3.45.0/lib/sequel/database/logging.rb","lineno":70,"method":"block in log_each"}
{"timestamp":1383561145.6433344,"message":"(0.001216s) SELECT COUNT(*) AS 'count' FROM `spaces` INNER JOIN `domains_spaces` ON ((`domains_spaces`.`spa
ce_id` = `spaces`.`id`) AND (`domains_spaces`.`domain_id` = 1)) WHERE (`spaces`.`id` IN (SELECT `spaces_developers`.`space_id` FROM `spaces_developers
` WHERE ((`spaces_developers`.`user_id` IN (3)) AND (`spaces_developers`.`space_id` IS NOT NULL)))) LIMIT 1","log_level":"debug2","source":"cc.db","da
ta":{"request_guid":"47e1a818-b446-499c-8fcf-f470fdd8c7f2"},"thread_id":28182580,"fiber_id":69992733268280,"process_id":2821,"file":"/home/vagrant/.rb
env/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sequel-3.45.0/lib/sequel/database/logging.rb","lineno":70,"method":"block in log_each"}
{"timestamp":1383561145.6462998,"message":"(0.001873s) SELECT COUNT(*) AS 'count' FROM `spaces` INNER JOIN `domains_spaces` ON ((`domains_spaces`.`spa
ce_id` = `spaces`.`id`) AND (`domains_spaces`.`domain_id` = 1)) WHERE (`spaces`.`id` IN (SELECT `spaces_managers`.`space_id` FROM `spaces_managers` WH
ERE ((`spaces_managers`.`user_id` IN (3)) AND (`spaces_managers`.`space_id` IS NOT NULL)))) LIMIT 1","log_level":"debug2","source":"cc.db","data":{"re
quest_guid":"47e1a818-b446-499c-8fcf-f470fdd8c7f2"},"thread_id":28182580,"fiber_id":69992733268280,"process_id":2821,"file":"/home/vagrant/.rbenv/vers
ions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sequel-3.45.0/lib/sequel/database/logging.rb","lineno":70,"method":"block in log_each"}
{"timestamp":1383561145.6468122,"message":"validate access OK: read e9100cf7-f463-4897-aa95-1227c1f5b126","log_level":"debug","source":"cc.api","data"
:{"request_guid":"47e1a818-b446-499c-8fcf-f470fdd8c7f2"},"thread_id":28182580,"fiber_id":69992733268280,"process_id":2821,"file":"/vagrant/cloud_contr
oller_ng/lib/cloud_controller/rest_controller/model_controller.rb","lineno":208,"method":"validate_access"}
{"timestamp":1383561145.6470919,"message":"find_id_and_validate_access OK: read e9100cf7-f463-4897-aa95-1227c1f5b126","log_level":"debug","source":"cc
.api","data":{"request_guid":"47e1a818-b446-499c-8fcf-f470fdd8c7f2"},"thread_id":28182580,"fiber_id":69992733268280,"process_id":2821,"file":"/vagrant
/cloud_controller_ng/lib/cloud_controller/rest_controller/model_controller.rb","lineno":184,"method":"find_id_and_validate_access"}
{"timestamp":1383561145.650617,"message":"(0.001735s) SELECT COUNT(*) AS 'count' FROM `spaces` INNER JOIN `domains_spaces` ON ((`domains_spaces`.`spac
e_id` = `spaces`.`id`) AND (`domains_spaces`.`domain_id` = 1)) WHERE (`id` IS NOT NULL) LIMIT 1","log_level":"debug2","source":"cc.db","data":{"reques
t_guid":"47e1a818-b446-499c-8fcf-f470fdd8c7f2"},"thread_id":28182580,"fiber_id":69992733268280,"process_id":2821,"file":"/home/vagrant/.rbenv/versions
/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sequel-3.45.0/lib/sequel/database/logging.rb","lineno":70,"method":"block in log_each"}
{"timestamp":1383561145.6543424,"message":"(0.000383s) SELECT * FROM `organizations` WHERE (`organizations`.`id` = 2) LIMIT 1","log_level":"debug2","s
ource":"cc.db","data":{"request_guid":"47e1a818-b446-499c-8fcf-f470fdd8c7f2"},"thread_id":28182580,"fiber_id":69992733268280,"process_id":2821,"file":
"/home/vagrant/.rbenv/versions/1.9.3-p392/lib/ruby/gems/1.9.1/gems/sequel-3.45.0/lib/sequel/database/logging.rb","lineno":70,"method":"block in log_ea
ch"}
{"timestamp":1383561145.6548827,"message":"(0.003560s) SELECT `spaces`.* FROM `spaces` INNER JOIN `domains_spaces` ON ((`domains_spaces`.`space_id` =
`spaces`.`id`) AND (`domains_spaces`.`domain_id` = 1)) WHERE (`id` IS NOT NULL)","log_level":"debug2","source":"cc.db","data":{"request_guid":"47e1a81
8-b446-499c-8fcf-f470fdd8c7f2"},"thread_id":28182580,"fiber_id":69992733268280,"process_id":2821,"file":"/home/vagrant/.rbenv/versions/1.9.3-p392/lib/
ruby/gems/1.9.1/gems/sequel-3.45.0/lib/sequel/database/logging.rb","lineno":70,"method":"block in log_each"}
==> logs/dea_ng.log <==
{"timestamp":1383561368.308101,"message":"Reaping orphaned crashes","log_level":"debug2","source":"Dea::InstanceRegistry","data":{},"thread_id":515070
0,"fiber_id":13205780,"process_id":2648,"file":"/vagrant/dea_ng/lib/dea/instance_registry.rb","lineno":104,"method":"reap_orphaned_crashes"}
{"timestamp":1383561368.30854,"message":"Reaping crashes","log_level":"debug2","source":"Dea::InstanceRegistry","data":{},"thread_id":5150700,"fiber_i
d":13205780,"process_id":2648,"file":"/vagrant/dea_ng/lib/dea/instance_registry.rb","lineno":123,"method":"reap_crashes"}
{"timestamp":1383561368.3087988,"message":"Reaping crashes under disk pressure","log_level":"debug2","source":"Dea::InstanceRegistry","data":{},"threa
d_id":5150700,"fiber_id":13205780,"process_id":2648,"file":"/vagrant/dea_ng/lib/dea/instance_registry.rb","lineno":147,"method":"reap_crashes_under_di
sk_pressure"}
{"timestamp":1383561378.3702219,"message":"Reaping orphaned crashes","log_level":"debug2","source":"Dea::InstanceRegistry","data":{},"thread_id":51507
00,"fiber_id":13205780,"process_id":2648,"file":"/vagrant/dea_ng/lib/dea/instance_registry.rb","lineno":104,"method":"reap_orphaned_crashes"}
{"timestamp":1383561378.3705807,"message":"Reaping crashes","log_level":"debug2","source":"Dea::InstanceRegistry","data":{},"thread_id":5150700,"fiber
_id":13205780,"process_id":2648,"file":"/vagrant/dea_ng/lib/dea/instance_registry.rb","lineno":123,"method":"reap_crashes"}
{"timestamp":1383561378.3708005,"message":"Reaping crashes under disk pressure","log_level":"debug2","source":"Dea::InstanceRegistry","data":{},"threa
d_id":5150700,"fiber_id":13205780,"process_id":2648,"file":"/vagrant/dea_ng/lib/dea/instance_registry.rb","lineno":147,"method":"reap_crashes_under_di
sk_pressure"}
{"timestamp":1383561388.4350572,"message":"Reaping orphaned crashes","log_level":"debug2","source":"Dea::InstanceRegistry","data":{},"thread_id":51507
00,"fiber_id":13205780,"process_id":2648,"file":"/vagrant/dea_ng/lib/dea/instance_registry.rb","lineno":104,"method":"reap_orphaned_crashes"}
{"timestamp":1383561388.435576,"message":"Reaping crashes","log_level":"debug2","source":"Dea::InstanceRegistry","data":{},"thread_id":5150700,"fiber_
id":13205780,"process_id":2648,"file":"/vagrant/dea_ng/lib/dea/instance_registry.rb","lineno":123,"method":"reap_crashes"}
{"timestamp":1383561388.4361362,"message":"Reaping crashes under disk pressure","log_level":"debug2","source":"Dea::InstanceRegistry","data":{},"threa
d_id":5150700,"fiber_id":13205780,"process_id":2648,"file":"/vagrant/dea_ng/lib/dea/instance_registry.rb","lineno":147,"method":"reap_crashes_under_di
sk_pressure"}
{"timestamp":1383561396.9721968,"message":"Received on \"router.start\": {\"id\"=>\"d16bf945ef1162a93a18d3f2a6ee3dae\", \"hosts\"=>[\"10.0.2.15\"]}","
log_level":"debug","source":"Dea::Nats","data":{},"thread_id":5150700,"fiber_id":13205780,"process_id":2648,"file":"/vagrant/dea_ng/lib/dea/nats.rb","
lineno":75,"method":"block in subscribe"}
==> logs/gorouter.log <==
{"timestamp":1383561277.863410950,"process_id":2646,"source":"router.proxy","log_level":"warn","message":"404 Not Found","data":{"Host":"api.192.168.1
2.34.xip.io","RemoteAddr":"192.168.12.34:60093","X-Forwarded-For":null,"X-Forwarded-Proto":null}}
{"timestamp":1383561277.863795996,"process_id":2646,"source":"router.proxy","log_level":"warn","message":"404 Not Found","data":{"Host":"api.192.168.1
2.34.xip.io","RemoteAddr":"192.168.12.34:60094","X-Forwarded-For":null,"X-Forwarded-Proto":null}}
{"timestamp":1383561298.027720928,"process_id":2646,"source":"router.global","log_level":"debug","message":"Start to check and prune stale droplets","
data":null}
{"timestamp":1383561328.027508974,"process_id":2646,"source":"router.global","log_level":"debug","message":"Start to check and prune stale droplets","
data":null}
{"timestamp":1383561337.941131115,"process_id":2646,"source":"router.proxy","log_level":"warn","message":"404 Not Found","data":{"Host":"api.192.168.1
2.34.xip.io","RemoteAddr":"192.168.12.34:60095","X-Forwarded-For":null,"X-Forwarded-Proto":null}}
{"timestamp":1383561337.941147804,"process_id":2646,"source":"router.proxy","log_level":"warn","message":"404 Not Found","data":{"Host":"api.192.168.1
2.34.xip.io","RemoteAddr":"192.168.12.34:60096","X-Forwarded-For":null,"X-Forwarded-Proto":null}}
{"timestamp":1383561358.028477907,"process_id":2646,"source":"router.global","log_level":"debug","message":"Start to check and prune stale droplets","
data":null}
{"timestamp":1383561388.027759075,"process_id":2646,"source":"router.global","log_level":"debug","message":"Start to check and prune stale droplets","
data":null}
{"timestamp":1383561397.972682953,"process_id":2646,"source":"router.proxy","log_level":"warn","message":"404 Not Found","data":{"Host":"api.192.168.1
2.34.xip.io","RemoteAddr":"192.168.12.34:60097","X-Forwarded-For":null,"X-Forwarded-Proto":null}}
{"timestamp":1383561397.972695112,"process_id":2646,"source":"router.proxy","log_level":"warn","message":"404 Not Found","data":{"Host":"api.192.168.1
2.34.xip.io","RemoteAddr":"192.168.12.34:60098","X-Forwarded-For":null,"X-Forwarded-Proto":null}}
==> logs/health_manager.log <==
{"timestamp":1383561378.916955,"message":"Droplet analysis interrupted. Desired state is not available","log_level":"warn","source":"hm","data":{},"th
read_id":19619820,"fiber_id":25480160,"process_id":2642,"file":"/vagrant/health_manager/lib/health_manager/harmonizer.rb","lineno":216,"method":"analy
ze_apps"}
{"timestamp":1383561388.4381983,"message":"Actual: #process_heartbeat: {\"droplets\":[{\"cc_partition\":\"ng\",\"droplet\":\"b7efdae5-fecf-44c9-894d-f
1c37d5e9f2d\",\"version\":\"88a60d81-94ad-45df-9184-42a6a61edc13\",\"instance\":\"a87f90f9f98ab7644309f7e1896bdb43\",\"index\":0,\"state\":\"CRASHED\"
,\"state_timestamp\":1383560980.7285554}],\"dea\":\"0-69f95cbe8902d573d6520ef7c898a09e\",\"prod\":false}","log_level":"debug","source":"hm","data":{},
"thread_id":19619820,"fiber_id":25480160,"process_id":2642,"file":"/vagrant/health_manager/lib/health_manager/actual_state.rb","lineno":86,"method":"p
rocess_heartbeat"}
{"timestamp":1383561397.9648168,"message":"bulk: requesting API credentials over NATS...","log_level":"info","source":"hm","data":{},"thread_id":19619
820,"fiber_id":25480160,"process_id":2642,"file":"/vagrant/health_manager/lib/health_manager/desired_state.rb","lineno":148,"method":"with_credentials
"}
{"timestamp":1383561397.9652169,"message":"config: nats_request_timeout: 5","log_level":"debug","source":"hm","data":{},"thread_id":19619820,"fiber_id
":25480160,"process_id":2642,"file":"/vagrant/health_manager/lib/health_manager/common.rb","lineno":23,"method":"get_param_from_config_or_default"}
{"timestamp":1383561397.9654274,"message":"bulk: requesting API credentials over NATS...","log_level":"info","source":"hm","data":{},"thread_id":19619
820,"fiber_id":25480160,"process_id":2642,"file":"/vagrant/health_manager/lib/health_manager/desired_state.rb","lineno":148,"method":"with_credentials
"}
{"timestamp":1383561397.9656186,"message":"config: nats_request_timeout: 5","log_level":"debug","source":"hm","data":{},"thread_id":19619820,"fiber_id
":25480160,"process_id":2642,"file":"/vagrant/health_manager/lib/health_manager/common.rb","lineno":23,"method":"get_param_from_config_or_default"}
{"timestamp":1383561397.968271,"message":"bulk: API credentials received.","log_level":"info","source":"hm","data":{},"thread_id":19619820,"fiber_id":
25480160,"process_id":2642,"file":"/vagrant/health_manager/lib/health_manager/desired_state.rb","lineno":150,"method":"block in with_credentials"}
{"timestamp":1383561397.9700148,"message":"bulk: API credentials received.","log_level":"info","source":"hm","data":{},"thread_id":19619820,"fiber_id"
:25480160,"process_id":2642,"file":"/vagrant/health_manager/lib/health_manager/desired_state.rb","lineno":150,"method":"block in with_credentials"}
{"timestamp":1383561397.9738724,"message":"bulk: request problem. Response: {\"CONTENT_TYPE\"=>\"text/plain; charset=utf-8\", \"DATE\"=>\"Mon, 04 Nov
2013 10:36:37 GMT\", \"TRANSFER_ENCODING\"=>\"chunked\"} 404 Not Found\n","log_level":"error","source":"hm","data":{},"thread_id":19619820,"fiber_id":
25480160,"process_id":2642,"file":"/vagrant/health_manager/lib/health_manager/desired_state.rb","lineno":31,"method":"block (2 levels) in update_user_
counts"}
{"timestamp":1383561397.9746153,"message":"bulk: request problem. Response status: 404","log_level":"error","source":"hm","data":{},"thread_id":196198
20,"fiber_id":25480160,"process_id":2642,"file":"/vagrant/health_manager/lib/health_manager/desired_state.rb","lineno":72,"method":"block (2 levels) i
n process_next_batch"}
==> logs/uaa.log <==
[2013-11-04 18:26:06.949] uaa/uaa - ???? [http-8080-1] .... DEBUG --- RequestMappingHandlerMapping: Returning handler method [public org.springframewo
rk.http.ResponseEntity<org.springframework.security.oauth2.common.OAuth2AccessToken> org.springframework.security.oauth2.provider.endpoint.TokenEndpoi
nt.getAccessToken(java.security.Principal,java.lang.String,java.util.Map<java.lang.String, java.lang.String>)]
[2013-11-04 18:26:06.963] uaa/uaa - ???? [http-8080-1] .... DEBUG --- ResourceOwnerPasswordTokenGranter: Getting access token for: cf
[2013-11-04 18:26:06.964] uaa/uaa - ???? [http-8080-1] .... DEBUG --- AuthzAuthenticationManager: Processing authentication request for admin
[2013-11-04 18:26:07.065] uaa/uaa - ???? [http-8080-1] .... DEBUG --- AuthzAuthenticationManager: Password successfully matched
[2013-11-04 18:26:07.066] uaa/uaa - ???? [http-8080-1] .... INFO --- Audit: UserAuthenticationSuccess ('admin'): principal=c43cdd5d-ad85-4265-9053-9b
57fb3ac3c7, origin=[unknown]
[2013-11-04 18:26:07.120] uaa/uaa - ???? [http-8080-1] .... DEBUG --- HttpEntityMethodProcessor: Written [eyJhbGciOiJIUzI1NiJ9.eyJqdGkiOiJkYzRjYWFiYS0
4YzhhLTQ1ZDQtOTYzMi01ZjMxNGQ4NjcyZjEiLCJzdWIiOiJjNDNjZGQ1ZC1hZDg1LTQyNjUtOTA1My05YjU3ZmIzYWMzYzciLCJzY29wZSI6WyJjbG91ZF9jb250cm9sbGVyLmFkbWluIiwiY2xvd
WRfY29udHJvbGxlci5yZWFkIiwiY2xvdWRfY29udHJvbGxlci53cml0ZSIsIm9wZW5pZCIsInBhc3N3b3JkLndyaXRlIiwic2NpbS5yZWFkIiwic2NpbS51c2VyaWRzIiwic2NpbS53cml0ZSJdLCJ
jbGllbnRfaWQiOiJjZiIsImNpZCI6ImNmIiwiZ3JhbnRfdHlwZSI6InBhc3N3b3JkIiwidXNlcl9pZCI6ImM0M2NkZDVkLWFkODUtNDI2NS05MDUzLTliNTdmYjNhYzNjNyIsInVzZXJfbmFtZSI6I
mFkbWluIiwiZW1haWwiOiJhZG1pbiIsImlhdCI6MTM4MzU2MDc2NywiZXhwIjoxMzgzNjAzOTY3LCJpc3MiOiJodHRwOi8vbG9jYWxob3N0OjgwODAvdWFhL29hdXRoL3Rva2VuIiwiYXVkIjpbInN
jaW0iLCJvcGVuaWQiLCJjbG91ZF9jb250cm9sbGVyIiwicGFzc3dvcmQiXX0.Q6B79jnxskdrJWP7OLe3ECHmUsHkZgl0Bn9zuXKrhP4] as "application/json;charset=UTF-8" using [o
rg.springframework.http.converter.json.MappingJacksonHttpMessageConverter@27aed7c1]
[2013-11-04 18:26:07.121] uaa/uaa - ???? [http-8080-1] .... DEBUG --- DispatcherServlet: Null ModelAndView returned to DispatcherServlet with name 'sp
ring': assuming HandlerAdapter completed request handling
[2013-11-04 18:26:07.121] uaa/uaa - ???? [http-8080-1] .... DEBUG --- DispatcherServlet: Successfully completed request
[2013-11-04 18:26:07.121] uaa/uaa - ???? [http-8080-1] .... DEBUG --- ExceptionTranslationFilter: Chain processed normally
[2013-11-04 18:26:07.122] uaa/uaa - ???? [http-8080-1] .... DEBUG --- SecurityContextPersistenceFilter: SecurityContextHolder now cleared, as request
processing completed
==> logs/warden.log <==
{"timestamp":1383561312.338442,"message":"Exited with status 0 (0.004s): [[\"/vagrant/warden/warden/src/closefds/closefds\", \"/vagrant/warden/warden/
src/closefds/closefds\"], \"/vagrant/warden/warden/src/repquota/repquota\", \"/\", \"10000\"]","log_level":"debug2","source":"Warden::Container::Linux
","data":{"stdout":"10000 20480 0 1048576 0 5 0 0 0\n","stderr":""},"thread_id":19132400,"fiber_id":23503360,"process_id":2735,"file":"/vagrant/warden
/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
{"timestamp":1383561312.3388057,"message":"info (took 0.059208)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"17aatib82ho"
,"request":{"handle":"17aatib82ho"},"response":{"state":"active","events":[],"host_ip":"10.254.0.1","container_ip":"10.254.0.2","container_path":"/tmp
/warden/containers/17aatib82ho","memory_stat":"#<Warden::Protocol::InfoResponse::MemoryStat:0x00000002c79280>","cpu_stat":"#<Warden::Protocol::InfoRes
ponse::CpuStat:0x00000002c7be18>","disk_stat":"#<Warden::Protocol::InfoResponse::DiskStat:0x000000035416b0>","bandwidth_stat":"#<Warden::Protocol::Inf
oResponse::BandwidthStat:0x0000000353ced0>","job_ids":[]}},"thread_id":19132400,"fiber_id":23005420,"process_id":2735,"file":"/vagrant/warden/warden/l
ib/warden/container/base.rb","lineno":319,"method":"dispatch"}
{"timestamp":1383561312.3897994,"message":"Exited with status 0 (0.049s): [[\"/vagrant/warden/warden/src/closefds/closefds\", \"/vagrant/warden/warden
/src/closefds/closefds\"], \"/tmp/warden/containers/17aatib82ho/stop.sh\"]","log_level":"debug2","source":"Warden::Container::Linux","data":{"handle":
"17aatib82ho","stdout":"","stderr":""},"thread_id":19132400,"fiber_id":23503360,"process_id":2735,"file":"/vagrant/warden/warden/lib/warden/container/
spawn.rb","lineno":136,"method":"set_deferred_success"}
{"timestamp":1383561312.390696,"message":"Wrote snapshot in 0.000387","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"17aati
b82ho"},"thread_id":19132400,"fiber_id":23005420,"process_id":2735,"file":"/vagrant/warden/warden/lib/warden/container/base.rb","lineno":353,"method":
"write_snapshot"}
{"timestamp":1383561312.390905,"message":"Killing oom-notifier process","log_level":"debug","source":"Warden::Container::Features::MemLimit::OomNotifi
er","data":{},"thread_id":19132400,"fiber_id":23005420,"process_id":2735,"file":"/vagrant/warden/warden/lib/warden/container/features/mem_limit.rb","l
ineno":51,"method":"kill"}
{"timestamp":1383561312.491473,"message":"stop (took 0.152143)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"17aatib82ho",
"request":{},"response":{}},"thread_id":19132400,"fiber_id":23005420,"process_id":2735,"file":"/vagrant/warden/warden/lib/warden/container/base.rb","l
ineno":319,"method":"dispatch"}
{"timestamp":1383561312.496387,"message":"Exited with status 0 (330.712s): [[\"/vagrant/warden/warden/src/closefds/closefds\", \"/vagrant/warden/warde
n/src/closefds/closefds\"], \"/vagrant/warden/warden/src/oom/oom\", \"/tmp/warden/cgroup/memory/instance-17aatib82ho\"]","log_level":"warn","source":"
Warden::Container::Features::MemLimit::OomNotifier","data":{"stdout":"","stderr":""},"thread_id":19132400,"fiber_id":23503360,"process_id":2735,"file"
:"/vagrant/warden/warden/lib/warden/container/spawn.rb","lineno":134,"method":"set_deferred_success"}
{"timestamp":1383561312.7265418,"message":"Exited with status 0 (0.231s): [[\"/vagrant/warden/warden/src/closefds/closefds\", \"/vagrant/warden/warden
/src/closefds/closefds\"], \"/vagrant/warden/warden/root/linux/destroy.sh\", \"/tmp/warden/containers/17aatib82ho\"]","log_level":"debug2","source":"W
arden::Container::Linux","data":{"handle":"17aatib82ho","stdout":"","stderr":""},"thread_id":19132400,"fiber_id":23503360,"process_id":2735,"file":"/v
agrant/warden/warden/lib/warden/container/spawn.rb","lineno":136,"method":"set_deferred_success"}
{"timestamp":1383561312.72687,"message":"Container destroyed","log_level":"debug","source":"Warden::Container::Linux","data":{"handle":"17aatib82ho"},
"thread_id":19132400,"fiber_id":23005420,"process_id":2735,"file":"/vagrant/warden/warden/lib/warden/container/linux.rb","lineno":129,"method":"do_des
troy"}
{"timestamp":1383561312.727286,"message":"destroy (took 0.447833)","log_level":"info","source":"Warden::Container::Linux","data":{"handle":"17aatib82h
o","request":{},"response":{}},"thread_id":19132400,"fiber_id":23005420,"process_id":2735,"file":"/vagrant/warden/warden/lib/warden/container/base.rb"
,"lineno":319,"method":"dispatch"}
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment