Fails to `cf push` app after a fresh `bosh deploy` to AWS eu-west-1

tader commented 11 years ago

After a fresh deployment of cloud-foundry to AWS eu-west-1 a cf push fails with the following error:

$ cf push
Using manifest file manifest.yml

Creating cf-env... OK

1: 54.246.83.1.xip.io
2: none
Domain> 54.246.83.1.xip.io

Creating route env.54.246.83.1.xip.io... OK
Binding env.54.246.83.1.xip.io to cf-env... OK
Uploading cf-env... FAILED
Upload failed. Try again with 'cf push'.
CFoundry::BadResponse: :

Subsequent running cf start results in:

$ cf start
Using manifest file manifest.yml

Preparing to start env... FAILED
CFoundry::AppPackageInvalid: 150001: The app package is invalid: bits have not been uploaded

All the app files are available on instance api/0 in /var/vcap/shared/cc-resources.

How to reproduce:

Follow the instructions in https://github.com/cloudfoundry-community/bosh-cloudfoundry/blob/dddf86dabda355666a030307c68969cbe556c1b1/README.md to deploy CloudFoundry in AWS region eu-west-1
Switch to a new space by running bosh show cf attributes, use cf target http://api.54.246.83.1.xip.io, cf login, cf create-org admin, cf create-space testing, cf switch-space testing. To login/setup space.
Clone the cf-env project: git clone https://github.com/cloudfoundry-community/cf-env.git and cd cf-env.
Push the app using cf push.

Push Trace: https://gist.github.com/tader/7a7a073c6e70c6db373e

drnic commented 11 years ago

Thanks for the great issue summary. I'll try to investigate further soon.

tader commented 10 years ago

Thank you for your fast response!

Today I have tried deploying in us-east-1, this had the same result. Could you give me a pointer on how to debug this problem? I know how I can bosh ssh into the various instances, but I do not know which components might cause this failure or how to debug it?

antoniou commented 10 years ago

I bumped into the same issue when trying to deploy CF to AWS eu-west-1. The problem was somehow resolved after rebooting the data/0 instance, so this might help in narrowing the problem down a bit.

jarias commented 10 years ago

Confirm what @antoniou said after rebooting data/0 push works fine

mrdavidlaing commented 10 years ago

Same issue for me when deploying CF to AWS ap-southeast-2 (Sydney).

I needed to reboot api/0 and data/0 to get it to work.

I captured the following cf push -t output of the fail:

$ cf push -t
Using manifest file manifest.yml

>>>
REQUEST: GET http://api.apps-ap-southeast-2.cityindextest5.co.uk/info
REQUEST_HEADERS:
  Accept : application/json
  Authorization : [PRIVATE DATA HIDDEN]
  Content-Length : 0
RESPONSE: [200]
RESPONSE_HEADERS:
  content-length : 306
  content-type : application/json;charset=utf-8
  date : Fri, 18 Oct 2013 20:53:18 GMT
  server : nginx
  x-content-type-options : nosniff
  x-vcap-request-id : 716d8b63-a502-4de8-be6f-b7c922f9acda
RESPONSE_BODY:
{
  "name": "vcap",
  "build": "2222",
  "support": "http://support.cloudfoundry.com",
  "version": 2,
  "description": "Cloud Foundry sponsored by Pivotal",
  "authorization_endpoint": "http://uaa.apps-ap-southeast-2.cityindextest5.co.uk",
  "token_endpoint": "http://uaa.apps-ap-southeast-2.cityindextest5.co.uk",
  "allow_debug": true
}
<<<
--->
request: post http://uaa.apps-ap-southeast-2.cityindextest5.co.uk/oauth/token
headers: {"content-type"=>"application/x-www-form-urlencoded;charset=utf-8", "accept"=>"application/json;charset=utf-8", "authorization"=>"Basic Y2Y6"}
body: grant_type=refresh_token&refresh_token=ey[PRIVATE DATA HIDDEN]BD1BX_9nq3PGwCc3fxkSVm7nMCoUX5o8DwjIW4ukewRc_bTHA
<---
response: 200
headers: {"cache-control"=>"no-store", "content-type"=>"application/json;charset=UTF-8", "date"=>"Fri, 18 Oct 2013 20:53:20 GMT", "pragma"=>"no-cache", "server"=>"Apache-Coyote/1.1", "transfer-encoding"=>"chunked"}
body: {"access_token":"eyJhbGciOiJSUzI1NiJ9.eyJ[PRIVATE DATA HIDDEN]GwCc3fxkSVm7nMCoUX5o8DwjIW4ukewRc_bTHA","expires_in":7199,"scope":"scim.read cloud_controller.admin password.write scim.write openid cloud_controller.write cloud_controller.read","jti":"a4dbe599-b08a-4223-a9ee-7dc9c35ebb7c"}
>>>
REQUEST: GET http://api.apps-ap-southeast-2.cityindextest5.co.uk/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/apps?q=name%3Alogsearch-purge-bot&inline-relations-depth=1
REQUEST_HEADERS:
  Accept : application/json
  Authorization : [PRIVATE DATA HIDDEN]
  Content-Length : 0
RESPONSE: [200]
RESPONSE_HEADERS:
  content-length : 3260
  content-type : application/json;charset=utf-8
  date : Fri, 18 Oct 2013 20:53:21 GMT
  server : nginx
  x-content-type-options : nosniff
  x-vcap-request-id : f98ea206-403e-41cd-bcd7-b84e9fec7297
RESPONSE_BODY:
{
  "total_results": 1,
  "total_pages": 1,
  "prev_url": null,
  "next_url": null,
  "resources": [
    {
      "metadata": {
        "guid": "e5d4ca1a-fb5e-4a22-8b7b-640a9222159e",
        "url": "/v2/apps/e5d4ca1a-fb5e-4a22-8b7b-640a9222159e",
        "created_at": "2013-10-18T18:49:24+00:00",
        "updated_at": null
      },
      "entity": {
        "name": "logsearch-purge-bot",
        "production": false,
        "space_guid": "373ecb74-2c41-4aca-8398-180ddba0e878",
        "stack_guid": "e6e41677-478a-40f0-bb73-65944b269631",
        "buildpack": "https://github.com/cloudfoundry-community/.net-buildpack",
        "detected_buildpack": null,
        "environment_json": {
          "elasticSearchUrl": "http://ec2-79-125-57-123.eu-west-1.compute.amazonaws.com:9200",
          "daysToKeep": "30"
        },
        "memory": 256,
        "instances": 1,
        "disk_quota": 1024,
        "state": "STOPPED",
        "version": "26b79d3f-695b-4486-8d6e-ded1490d8aa7",
        "command": null,
        "console": false,
        "debug": null,
        "staging_task_id": null,
        "space_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878",
        "space": {
          "metadata": {
            "guid": "373ecb74-2c41-4aca-8398-180ddba0e878",
            "url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878",
            "created_at": "2013-10-18T18:45:18+00:00",
            "updated_at": null
          },
          "entity": {
            "name": "development",
            "organization_guid": "d6e22f76-a753-489f-9887-8fd7ae34d753",
            "organization_url": "/v2/organizations/d6e22f76-a753-489f-9887-8fd7ae34d753",
            "developers_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/developers",
            "managers_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/managers",
            "auditors_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/auditors",
            "apps_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/apps",
            "domains_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/domains",
            "service_instances_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/service_instances",
            "app_events_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/app_events",
            "events_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/events"
          }
        },
        "stack_url": "/v2/stacks/e6e41677-478a-40f0-bb73-65944b269631",
        "stack": {
          "metadata": {
            "guid": "e6e41677-478a-40f0-bb73-65944b269631",
            "url": "/v2/stacks/e6e41677-478a-40f0-bb73-65944b269631",
            "created_at": "2013-10-18T18:33:18+00:00",
            "updated_at": "2013-10-18T18:33:31+00:00"
          },
          "entity": {
            "name": "lucid64",
            "description": "Ubuntu 10.04"
          }
        },
        "service_bindings_url": "/v2/apps/e5d4ca1a-fb5e-4a22-8b7b-640a9222159e/service_bindings",
        "service_bindings": [

        ],
        "routes_url": "/v2/apps/e5d4ca1a-fb5e-4a22-8b7b-640a9222159e/routes",
        "routes": [

        ],
        "events_url": "/v2/apps/e5d4ca1a-fb5e-4a22-8b7b-640a9222159e/events",
        "events": [

        ]
      }
    }
  ]
}
<<<
>>>
REQUEST: GET http://api.apps-ap-southeast-2.cityindextest5.co.uk/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/apps?q=name%3Alogsearch-purge-bot&inline-relations-depth=1
REQUEST_HEADERS:
  Accept : application/json
  Authorization : [PRIVATE DATA HIDDEN]
  Content-Length : 0
RESPONSE: [200]
RESPONSE_HEADERS:
  content-length : 3260
  content-type : application/json;charset=utf-8
  date : Fri, 18 Oct 2013 20:53:22 GMT
  server : nginx
  x-content-type-options : nosniff
  x-vcap-request-id : d5671393-eb37-4bae-a18a-4e0aa6d29056
RESPONSE_BODY:
{
  "total_results": 1,
  "total_pages": 1,
  "prev_url": null,
  "next_url": null,
  "resources": [
    {
      "metadata": {
        "guid": "e5d4ca1a-fb5e-4a22-8b7b-640a9222159e",
        "url": "/v2/apps/e5d4ca1a-fb5e-4a22-8b7b-640a9222159e",
        "created_at": "2013-10-18T18:49:24+00:00",
        "updated_at": null
      },
      "entity": {
        "name": "logsearch-purge-bot",
        "production": false,
        "space_guid": "373ecb74-2c41-4aca-8398-180ddba0e878",
        "stack_guid": "e6e41677-478a-40f0-bb73-65944b269631",
        "buildpack": "https://github.com/cloudfoundry-community/.net-buildpack",
        "detected_buildpack": null,
        "environment_json": {
          "elasticSearchUrl": "http://ec2-79-125-57-123.eu-west-1.compute.amazonaws.com:9200",
          "daysToKeep": "30"
        },
        "memory": 256,
        "instances": 1,
        "disk_quota": 1024,
        "state": "STOPPED",
        "version": "26b79d3f-695b-4486-8d6e-ded1490d8aa7",
        "command": null,
        "console": false,
        "debug": null,
        "staging_task_id": null,
        "space_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878",
        "space": {
          "metadata": {
            "guid": "373ecb74-2c41-4aca-8398-180ddba0e878",
            "url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878",
            "created_at": "2013-10-18T18:45:18+00:00",
            "updated_at": null
          },
          "entity": {
            "name": "development",
            "organization_guid": "d6e22f76-a753-489f-9887-8fd7ae34d753",
            "organization_url": "/v2/organizations/d6e22f76-a753-489f-9887-8fd7ae34d753",
            "developers_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/developers",
            "managers_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/managers",
            "auditors_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/auditors",
            "apps_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/apps",
            "domains_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/domains",
            "service_instances_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/service_instances",
            "app_events_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/app_events",
            "events_url": "/v2/spaces/373ecb74-2c41-4aca-8398-180ddba0e878/events"
          }
        },
        "stack_url": "/v2/stacks/e6e41677-478a-40f0-bb73-65944b269631",
        "stack": {
          "metadata": {
            "guid": "e6e41677-478a-40f0-bb73-65944b269631",
            "url": "/v2/stacks/e6e41677-478a-40f0-bb73-65944b269631",
            "created_at": "2013-10-18T18:33:18+00:00",
            "updated_at": "2013-10-18T18:33:31+00:00"
          },
          "entity": {
            "name": "lucid64",
            "description": "Ubuntu 10.04"
          }
        },
        "service_bindings_url": "/v2/apps/e5d4ca1a-fb5e-4a22-8b7b-640a9222159e/service_bindings",
        "service_bindings": [

        ],
        "routes_url": "/v2/apps/e5d4ca1a-fb5e-4a22-8b7b-640a9222159e/routes",
        "routes": [

        ],
        "events_url": "/v2/apps/e5d4ca1a-fb5e-4a22-8b7b-640a9222159e/events",
        "events": [

        ]
      }
    }
  ]
}
<<<
Uploading logsearch-purge-bot.  >>>
REQUEST: PUT http://api.apps-ap-southeast-2.cityindextest5.co.uk/v2/apps/e5d4ca1a-fb5e-4a22-8b7b-640a9222159e/bits?async=true
REQUEST_HEADERS:
  Authorization : [PRIVATE DATA HIDDEN]
REQUEST_BODY: {:resources=>"[]", :application=>#<UploadIO:0x007fe3645ef2c8 @content_type="application/zip", @original_filename="e5d4ca1a-fb5e-4a22-8b7b-640a9222159e.zip", @local_path="/var/folders/db/_0_sh45x3754pgh_v8xjqnjw0000gp/T/e5d4ca1a-fb5e-4a22-8b7b-640a9222159e.zip", @io=#<File:/var/folders/db/_0_sh45x3754pgh_v8xjqnjw0000gp/T/e5d4ca1a-fb5e-4a22-8b7b-640a9222159e.zip>, @opts={}>}
...RESPONSE: [201]
RESPONSE_HEADERS:
  content-length : 230
  content-type : application/json;charset=utf-8
  date : Fri, 18 Oct 2013 20:53:28 GMT
  server : nginx
  x-content-type-options : nosniff
  x-vcap-request-id : c162e665-dafe-490a-a18f-2a8357850cee
RESPONSE_BODY:
{
  "metadata": {
    "guid": "8bad5bed-97ae-41d5-9aec-491963ce73bd",
    "created_at": "2013-10-18T20:53:28+00:00",
    "url": "/v2/jobs/8bad5bed-97ae-41d5-9aec-491963ce73bd"
  },
  "entity": {
    "guid": "8bad5bed-97ae-41d5-9aec-491963ce73bd",
    "status": "queued"
  }
}
<<<
>>>
REQUEST: GET http://api.apps-ap-southeast-2.cityindextest5.co.uk/v2/jobs/8bad5bed-97ae-41d5-9aec-491963ce73bd
REQUEST_HEADERS:
  Accept : application/json
  Authorization : [PRIVATE DATA HIDDEN]
  Content-Length : 0
...RESPONSE: [200]
RESPONSE_HEADERS:
  content-length : 230
  content-type : application/json;charset=utf-8
  date : Fri, 18 Oct 2013 20:53:30 GMT
  server : nginx
  x-content-type-options : nosniff
  x-vcap-request-id : 11a639bb-4fbf-4bc6-b4cc-b9728cb245d5
RESPONSE_BODY:
{
  "metadata": {
    "guid": "8bad5bed-97ae-41d5-9aec-491963ce73bd",
    "created_at": "2013-10-18T20:53:28+00:00",
    "url": "/v2/jobs/8bad5bed-97ae-41d5-9aec-491963ce73bd"
  },
  "entity": {
    "guid": "8bad5bed-97ae-41d5-9aec-491963ce73bd",
    "status": "queued"
  }
}
<<<
   >>>
REQUEST: GET http://api.apps-ap-southeast-2.cityindextest5.co.uk/v2/jobs/8bad5bed-97ae-41d5-9aec-491963ce73bd
REQUEST_HEADERS:
  Accept : application/json
  Authorization : [PRIVATE DATA HIDDEN]
  Content-Length : 0
...RESPONSE: [200]
RESPONSE_HEADERS:
  content-length : 230
  content-type : application/json;charset=utf-8
  date : Fri, 18 Oct 2013 20:53:31 GMT
  server : nginx
  x-content-type-options : nosniff
  x-vcap-request-id : 8eedc0de-a9ef-40a4-8911-a28a6b655b12
RESPONSE_BODY:
{
  "metadata": {
    "guid": "8bad5bed-97ae-41d5-9aec-491963ce73bd",
    "created_at": "2013-10-18T20:53:28+00:00",
    "url": "/v2/jobs/8bad5bed-97ae-41d5-9aec-491963ce73bd"
  },
  "entity": {
    "guid": "8bad5bed-97ae-41d5-9aec-491963ce73bd",
    "status": "queued"
  }
}
<<<
   >>>
REQUEST: GET http://api.apps-ap-southeast-2.cityindextest5.co.uk/v2/jobs/8bad5bed-97ae-41d5-9aec-491963ce73bd
REQUEST_HEADERS:
  Accept : application/json
  Authorization : [PRIVATE DATA HIDDEN]
  Content-Length : 0
.  RESPONSE: [200]
RESPONSE_HEADERS:
  content-length : 231
  content-type : application/json;charset=utf-8
  date : Fri, 18 Oct 2013 20:53:33 GMT
  server : nginx
  x-content-type-options : nosniff
  x-vcap-request-id : 21fa6927-515d-4ce7-b16b-898128065cca
RESPONSE_BODY:
{
  "metadata": {
    "guid": "8bad5bed-97ae-41d5-9aec-491963ce73bd",
    "created_at": "2013-10-18T20:53:28+00:00",
    "url": "/v2/jobs/8bad5bed-97ae-41d5-9aec-491963ce73bd"
  },
  "entity": {
    "guid": "8bad5bed-97ae-41d5-9aec-491963ce73bd",
    "status": "running"
  }
}
<<<
.. >>>
REQUEST: GET http://api.apps-ap-southeast-2.cityindextest5.co.uk/v2/jobs/8bad5bed-97ae-41d5-9aec-491963ce73bd
REQUEST_HEADERS:
  Accept : application/json
  Authorization : [PRIVATE DATA HIDDEN]
  Content-Length : 0
...RESPONSE: [200]
RESPONSE_HEADERS:
  content-length : 230
  content-type : application/json;charset=utf-8
  date : Fri, 18 Oct 2013 20:53:34 GMT
  server : nginx
  x-content-type-options : nosniff
  x-vcap-request-id : d7452af5-c237-4748-a0bc-a4b7d8d29545
RESPONSE_BODY:
{
  "metadata": {
    "guid": "8bad5bed-97ae-41d5-9aec-491963ce73bd",
    "created_at": "2013-10-18T20:53:28+00:00",
    "url": "/v2/jobs/8bad5bed-97ae-41d5-9aec-491963ce73bd"
  },
  "entity": {
    "guid": "8bad5bed-97ae-41d5-9aec-491963ce73bd",
    "status": "failed"
  }
}
<<<
... FAILED
Upload failed. Try again with 'cf push'.
CFoundry::BadResponse: :

The app I was trying to upload had a single text file.

My guess is that there is some kind of communication issue between the api/0 node and the data/0 node.

mrdavidlaing commented 10 years ago

A more specific "fix" - restarting the cloud_controller on api/0.

Specifically

bosh ssh api/0,
ps aux,
find the PID of ruby /var/vcap/packages/cloud_controller_ng/cloud_controller_ng/bin/cloud_controller -m -c /var/vcap/jobs/cloud_controller_ng/config/cloud_controller_ng.yml
kill <pid> (monit will automatically restart it)

arunabhaghosh commented 10 years ago

I had a similar problem and its the same as described by mrdavidlaing. The cf crash report was identical, the second last status showed the app as running then the last get to the app status shoed the app as failed.

Restarting the API controller process did not solve the issue (as suggested by the last post on the issue) but restarting the data node did.

Any ideas as to why this problem occurs ?

mrdavidlaing commented 10 years ago

No. However, I have figured out a way to trigger the issue on an existing bosh-cloudfoundry (medium) cluster.

Just run bosh change cf attributes persistent_disk=xxxx where xxxx is some new value that triggers a redeploy of the data/0 node

thisismana commented 10 years ago

We are running into the same issue. Has anyone made any progress here?

pulecp commented 10 years ago

Same issue with deploying on own Openstack.

drnic commented 10 years ago

I'll try to create time to upgrade to v166 soon.

pulecp commented 10 years ago

I'm using v141. I tried v166 and v165 but I had problem to deploy it.

Can I try another version to deploy Cloud Foundry on Openstack Grizzly?

pulecp commented 10 years ago

interesting, I solved my problem. More here: https://github.com/ravanrijn/styx/issues/13#issuecomment-40284003

adoreumua commented 10 years ago

i came to the same problem, and i check the log file,which is on the node where you deploy the cloud_controller_ng. (/var/vcap/sys/log/cloud_controller_ng/jobs_work.stdout.log),

there is error like this [Worker(host:b011166d-1b50-40ff-a5f9-af0fa2426680 pid:1075)] Job AppBitsPackerJob (id=69) FAILED (0 prior attempts) with Errno::EACCES: Permission denied - /var/vcap/nfs/shared, i change the group and owner to vcap, and it works in my situation.

drnic commented 10 years ago

I have a working EC2 v168 deployment. Hopefully porting into bosh-cf templates soon.

On Sun, Apr 20, 2014 at 8:23 AM, linxistar8023 notifications@github.com wrote:

i came to the same problem, and i check the log file,which is on the node where you deploy the cloud_controller_ng. (/var/vcap/sys/log/cloud_controller_ng/jobs_work.stdout.log),

there is error like this [Worker(host:b011166d-1b50-40ff-a5f9-af0fa2426680 pid:1075)] Job AppBitsPackerJob (id=69) FAILED (0 prior attempts) with Errno::EACCES: Permission denied - /var/vcap/nfs/shared, i change the group and owner to vcap, and it works in my situation.

Reply to this email directly or view it on GitHub: https://github.com/cloudfoundry-community/bosh-cloudfoundry/issues/246#issuecomment-40897080

cloudfoundry-community-attic / bosh-cloudfoundry

Fails to `cf push` app after a fresh `bosh deploy` to AWS eu-west-1 #246

there is error like this [Worker(host:b011166d-1b50-40ff-a5f9-af0fa2426680 pid:1075)] Job AppBitsPackerJob (id=69) FAILED (0 prior attempts) with Errno::EACCES: Permission denied - /var/vcap/nfs/shared, i change the group and owner to vcap, and it works in my situation.