{"action":"created","issue":{"url":"https://api.github.com/repos/cloudfoundry/cf-release/issues/991","repository_url":"https://api.github.com/repos/cloudfoundry/cf-release","labels_url":"https://api.github.com/repos/cloudfoundry/cf-release/issues/991/labels{/name}","comments_url":"https://api.github.com/repos/cloudfoundry/cf-release/issues/991/comments","events_url":"https://api.github.com/repos/cloudfoundry/cf-release/issues/991/events","html_url":"https://github.com/cloudfoundry/cf-release/issues/991","id":162392937,"number":991,"title":"CF v237/3232.8 OpenStack DEA Staging Error \"cflinuxfs2: No such file or directory\"","user":{"login":"gkenaley","id":9956577,"avatar_url":"https://avatars.githubusercontent.com/u/9956577?v=3","gravatar_id":"","url":"https://api.github.com/users/gkenaley","html_url":"https://github.com/gkenaley","followers_url":"https://api.github.com/users/gkenaley/followers","following_url":"https://api.github.com/users/gkenaley/following{/other_user}","gists_url":"https://api.github.com/users/gkenaley/gists{/gist_id}","starred_url":"https://api.github.com/users/gkenaley/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/gkenaley/subscriptions","organizations_url":"https://api.github.com/users/gkenaley/orgs","repos_url":"https://api.github.com/users/gkenaley/repos","events_url":"https://api.github.com/users/gkenaley/events{/privacy}","received_events_url":"https://api.github.com/users/gkenaley/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/cloudfoundry/cf-release/labels/in%20progress","name":"in progress","color":"3461AD"}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":9,"created_at":"2016-06-27T07:52:21Z","updated_at":"2016-07-08T22:23:56Z","closed_at":null,"body":"I have setup my first Cloud Foundry cluster, using 5 OpenStack compute nodes with 1TB RAM and 8TB SSD storage. I am following the CF setup documentation, but have increased the size of the VMs to avoid memory issues. I am using the `cf-rails` and `fib` sample applications, _but have never gotten an application to successfully stage._\r\n\r\nI have attached my [latest deployment manifest](https://github.com/cloudfoundry/cf-release/files/334308/cf-deployment.yml.036.txt). It attempts to stay as close as possible to the templates shipped with v237 and the documentation. All SSL is turned off to the degree possible, although I believe I have all the needed keys, certs, and secrets deployed.\r\n\r\nI am using a Ubuntu 14.04 PC as a combined Internet gateway, DNS server, and bosh development system. I had to upgrade the Ubuntu PC to Ruby 2.0.0p648 in order to get all of the needed components to install and build. The bind9 DNS server setup sends traffic to the CF-related domains through ha_proxy_z1 floating IP 128.224.250.10:\r\n\r\n```\r\n/etc/bind/db.cf-domain.com:cf-domain.com. IN A 128.224.29.34 # Ubuntu PC IP address\r\n/etc/bind/db.system.cf.cf-domain.com:@ IN SOA ubuntu-pc.cf-domain.com. admin ( ...\r\n/etc/bind/db.system.cf.cf-domain.com:  IN NS  ubuntu-pc.cf-domain.com.\r\n/etc/bind/db.system.cf.cf-domain.com  *.system.cf.cf-domain.com. IN\tA 128.224.250.10\r\n/etc/bind/db.app.cf.cf-domain.com:    *.app.cf.cf-domain.com.    IN\tA 128.224.250.10\r\n/etc/bind/db.cf.cf-domain.com:        *.cf.cf-domain.com.\t     IN\tA 128.224.250.10\r\n```\r\n\r\nThere is no load balancer VM or any other physical equipment external to the Openstack system. The external public network 128.224.250.0/24 connects the Ubuntu PC to the OpenStack system. The OpenStack system has an internal private network 192.168.240.0/24 connected to all 18 VMs. In between the public and private network is an OpenStack virtual router with SNAT disabled. The OpenStack security group \"cf-bosh\" is relaxed well beyond what the documentation for CF and bosh calls for.\r\n\r\nThe system seems to have the proper buildpacks and stemcell/stack:\r\n\r\n```\r\ndemo@ubuntu-pc:~/cf-release$ cf buildpacks\r\nGetting buildpacks...\r\nbuildpack              position   enabled   locked   filename\r\nstaticfile_buildpack   1          true      false    staticfile_buildpack-cached-v1.3.8.zip\r\nruby_buildpack         2          true      false    ruby_buildpack-cached-v1.6.17.zip\r\nnodejs_buildpack       3          true      false    nodejs_buildpack-cached-v1.5.14.zip\r\ngo_buildpack           4          true      false    go_buildpack-cached-v1.7.8.zip\r\npython_buildpack       5          true      false    python_buildpack-cached-v1.5.5.zip\r\nphp_buildpack          6          true      false    php_buildpack-cached-v4.3.12.zip\r\nbinary_buildpack       7          true      false    binary_buildpack-cached-v1.0.2.zip\r\n\r\ndemo@gamer-linux:~/cf-release$ cf stacks\r\nGetting stacks in org tis-org / space qa as admin...\r\nOK\r\nname         description\r\ncflinuxfs2   Cloud Foundry Linux-based filesystem\r\n```\r\n\r\nTo debug this staging problem I turn up the log level on all jobs and then purge all the logs just before deploying. I also monitor the push and staging process from another window using `$ cf logs cf-rails --recent` and see good progress. The push of `cf-rails` proceeds smoothly through over 50 steps and gets to `bundle complete` in 54 seconds.\r\n\r\nIt finally reaches the tenth write to `/tmp/staged/app` and stops at `Uploading droplet (35M)`:\r\n\r\n```\r\nBundle completed (54.09s)\r\nCleaning up the bundler cache.\r\nDownloaded [file:///var/vcap/data/dea_next/admin_buildpacks/327ee28d-4b61-4ecc-b7da-b3fa9ba2938d_f5446238d598246474e97f7aea1e8389b26b6a58/dependencies/https___pivotal-buildpacks.s3.amazonaws.com_node_beta-binaries_node-0.12.7-linux-x64.tar.gz]\r\n-----> Preparing app for Rails asset pipeline\r\nRunning: rake assets:precompile\r\n    (...snip...)\r\nI, [2016-06-27T04:41:34.827525 #1692]  INFO -- : Writing /tmp/staged/app/public/assets/application-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css.gz\r\nAsset precompilation completed (4.30s)\r\nCleaning assets\r\nRunning: rake assets:clean\r\n-----> Uploading droplet (35M) [at this instant \"$ cf logs cf-rails --recent\" immediately shows an error]\r\n```\r\n\r\nAll apps hang at this point and never fully stage. They have been requested to start, but have not started.\r\n\r\n```\r\n$ cf apps\r\nGetting apps in org tis-org / space qa as admin...\r\nOK\r\nname       requested state   instances   memory   disk   urls\r\ncf-rails   started           0/1         512M     1G     cf-rails-meliorative-clamorist.app.cf.cf-domain.com\r\n```\r\n\r\nI logged into blobstore_z1 and found that the 35MB droplet had actually been uploaded and was present until the program was terminated.\r\n\r\nAt that point I bosh sshed to all 17 Vms and grep all the logs for errors. Here are the hits (the other VMs may be unusually quiet):\r\n\r\n**ON blobstore_z1 vm: (one error message - looks fatal)**\r\n\r\n```\r\nblobstore/internal_access.log:192.168.240.104 - blobstore-username [27/Jun/2016:04:40:30 +0000] \"HEAD /admin/system.cf.cf-domain.com-cc-droplets/buildpack_cache/f3/06/f3060397-9ba4-4c4b-b077-9e501ba7a6e8/cflinuxfs2 HTTP/1.1\" 404 0 \"-\" \"HTTPClient/1.0 (2.7.1, ruby 2.3.1 (2016-04-26))\"\r\n\r\nblobstore/internal_error.log:**2016/06/27 04:40:30 [error] 20444#0: *26514 open() \"/var/vcap/store/shared/system.cf.cf-domain.com-cc-droplets/buildpack_cache/f3/06/f3060397-9ba4-4c4b-b077-9e501ba7a6e8/cflinuxfs2\" failed (2: No such file or directory)**, client: 192.168.240.104, server: blobstore.service.cf.internal, request: \"HEAD /admin/system.cf.cf-domain.com-cc-droplets/buildpack_cache/f3/06/f3060397-9ba4-4c4b-b077-9e501ba7a6e8/cflinuxfs2 HTTP/1.1\", host: \"blobstore.service.cf.internal\"\r\n```\r\n\r\n**ON runner_z1 VM: (100+ of dea messages/1 warden message)**\r\n\r\n```\r\n(100+)dea_next/dea_next.log:{\"timestamp\":1467003546.6744301,\"message\":\"em-upload.error\",\"log_level\":\"warn\",\"source\":\"Staging\",\"data\":{\"app_guid\":\"f3060397-9ba4-4c4b-b077-9e501ba7a6e8\",\"task_id\":\"5f512e35592e4e9d9044a8fdb2c42e7b\",\"destination\":\"http://cloud-controller-ng.service.cf.internal:9022/staging/droplets/f3060397-9ba4-4c4b-b077-9e501ba7a6e8/upload\",\"connection_count\":10,\"message\":\"Error uploading: (Polling failed - status 0; error: Errno::ETIMEDOUT)\",\"http_error\":\"Errno::ETIMEDOUT\",\"http_status\":0,\"http_response\":\"\"},\"thread_id\":46918340106640,\"fiber_id\":46918349548220,\"process_id\":19230,\"file\":\"/var/vcap/packages/dea_next/lib/dea/utils/upload.rb\",\"lineno\":58,\"method\":\"handle_error\"}\r\n\r\n(1)warden/warden.log: {\"timestamp\":1467004303.4935195,\"message\":\"Exited with status 0 (1871.971s): [[\\\"/var/vcap/data/packages/warden/45feaaafb1ed6e77fd1ddd067b2577b8d13c03c7.1-2f5cb2695e36cc8f850e42384684d10854b036b0/warden/src/closefds/closefds\\\", \\\"/var/vcap/data/packages/warden/45feaaafb1ed6e77fd1ddd067b2577b8d13c03c7.1-2f5cb2695e36cc8f850e42384684d10854b036b0/warden/src/closefds/closefds\\\"], \\\"/var/vcap/data/packages/warden/45feaaafb1ed6e77fd1ddd067b2577b8d13c03c7.1-2f5cb2695e36cc8f850e42384684d10854b036b0/warden/src/oom/oom\\\", \\\"/tmp/warden/cgroup/memory/instance-19m567sv61q\\\"]\",\"log_level\":\"warn\",\"source\":\"Warden::Container::Features::MemLimit::OomNotifier\",\"data\":{\"stdout\":\"\",\"stderr\":\"\"},\"thread_id\":46982206896520,\"fiber_id\":46982217237180,\"process_id\":18887,\"file\":\"/var/vcap/data/packages/warden/45feaaafb1ed6e77fd1ddd067b2577b8d13c03c7.1-2f5cb2695e36cc8f850e42384684d10854b036b0/warden/lib/warden/container/spawn.rb\",\"lineno\":135,\"method\":\"set_deferred_success\"}\r\n```\r\n\r\n**ON doppler_z1 VM: (4 of these messages)**\r\n\r\n```\r\nsyslog_drain_binder/syslog_drain_binder.stdout.log:{\"timestamp\":1467002776.742815018,\"process_id\":4323,\"source\":\"syslog_drain_binder\",\"log_level\":\"error\",\"message\":\"Error when polling cloud controller: Get http://api.system.cf.cf-domain.com/v2/syslog_drain_urls?batch_size=1000: dial tcp 128.224.250.10:80: getsockopt: connection timed out\",\"data\":null,\"file\":\"/var/vcap/data/compile/syslog_drain_binder/loggregator/src/syslog_drain_binder/main.go\",\"line\":87,\"method\":\"main.main\"}\r\n```\r\n\r\n**ON hm9000_z1 VM: (10 of these messages)**\r\n\r\n```\r\nhm9000/hm9000_analyzer.log:{\"timestamp\":\"1467002402.283330202\",\"source\":\"fetcher\",\"message\":\"fetcher.HTTP request failed with error\",\"log_level\":2,\"data\":{\"error\":\"Get http://api.system.cf.cf-domain.com/bulk/apps?batch_size=5000\\u0026bulk_token={}: dial tcp 128.224.250.10:80: i/o timeout (Client.Timeout exceeded while awaiting headers)\"}}\r\n```\r\n\r\n**ON loggregator_z1 VM: (5 of these messages)**\r\n\r\n```\r\nsyslog_drain_binder/syslog_drain_binder.stdout.log:{\"timestamp\":1467002989.055986404,\"process_id\":4500,\"source\":\"syslog_drain_binder\",\"log_level\":\"error\",\"message\":\"Error when polling cloud controller: Get http://api.system.cf.cf-domain.com/v2/syslog_drain_urls?batch_size=1000: dial tcp 128.224.250.10:80: getsockopt: connection timed out\",\"data\":null,\"file\":\"/var/vcap/data/compile/syslog_drain_binder/loggregator/src/syslog_drain_binder/main.go\",\"line\":87,\"method\":\"main.main\"}\r\n```\r\n\r\nSo am I correct in assuming that the root cause is the \"cflinuxfs2: No such file or directory\"?\r\nHow would I go about fixing this, and any other problems you might kindly see in these logs?\r\n\r\nThanks,\r\n\r\nGary"},"comment":{"url":"https://api.github.com/repos/cloudfoundry/cf-release/issues/comments/231487072","html_url":"https://github.com/cloudfoundry/cf-release/issues/991#issuecomment-231487072","issue_url":"https://api.github.com/repos/cloudfoundry/cf-release/issues/991","id":231487072,"user":{"login":"gkenaley","id":9956577,"avatar_url":"https://avatars.githubusercontent.com/u/9956577?v=3","gravatar_id":"","url":"https://api.github.com/users/gkenaley","html_url":"https://github.com/gkenaley","followers_url":"https://api.github.com/users/gkenaley/followers","following_url":"https://api.github.com/users/gkenaley/following{/other_user}","gists_url":"https://api.github.com/users/gkenaley/gists{/gist_id}","starred_url":"https://api.github.com/users/gkenaley/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/gkenaley/subscriptions","organizations_url":"https://api.github.com/users/gkenaley/orgs","repos_url":"https://api.github.com/users/gkenaley/repos","events_url":"https://api.github.com/users/gkenaley/events{/privacy}","received_events_url":"https://api.github.com/users/gkenaley/received_events","type":"User","site_admin":false},"created_at":"2016-07-08T22:23:55Z","updated_at":"2016-07-08T22:23:55Z","body":"Hi Amit,\r\n\r\nNo, I was not able to make any progress. I tried to cross-check with another version of OpenStack, but it was so difficult to install that I could not finish the deployment.\r\n\r\n(1) Are we 100% convinced that inability to access the ha_proxy floating IP from the VM is the issue?\r\n\r\n(2) Is there some other way to configure the system so that the VM access of the ha_proxy floating IP is not necessary?\r\n\r\n(3) Would you be interested in remotely accessing the system to research the issue?\r\n\r\nThanks,\r\n\r\nGary\r\n\r\n"}}
{"actor":{"display_login":"gkenaley"}}