Started updating job api_z1 > api_z1/0 (canary). Failed: `api_z1/0' is not running after update

[Enya Yin Lee]

Hi all,

I tried to deploy cloudfoundry on openstack via BOSH using cf-release-194 generate by spiff

get this error
Started updating job api_z1 > api_z1/0 (canary). Failed: `api_z1/0' is not running after update

vms status:
 api_worker_z1/0                    | running
 api_z1/0                           | starting
 clock_global/0                     | running
 etcd_z1/0                          | running
 ha_proxy_z1/0                      | running
 hm9000_z1/0                        | running
 loggregator_trafficcontroller_z1/0 | running
 loggregator_z1/0                   | running
 login_z1/0                         | running
 nats_z1/0                          | running
 nfs_z1/0                           | running
 postgres_z1/0                      | running
 router_z1/0                        | running
 runner_z1/0                        | running
 stats_z1/0                         | running
 uaa_z1/0                           | running

deployment for api_z1:
- instances: 1
  name: api_z1
  networks:
  - name: cf1
  persistent_disk: 0
  properties:
    metron_agent:
      zone: z1
    networks:
      apps: cf1
    nfs_server:
      address: 192.168.112.178
      allow_from_entries:
      - 192.168.112.0/24
      - 192.168.112.0/24
      share: null
  resource_pool: small_z1
  templates:
  - name: cloud_controller_ng
    release: cf
  - name: metron_agent
    release: cf
  - name: nfs_mounter
    release: cf
app_domain: 172.16.10.109.xip.io

monit summary for api_z1/0:
Process 'cloud_controller_ng'       initializing
Process 'cloud_controller_worker_local_1' initializing
Process 'cloud_controller_worker_local_2' initializing
Process 'nginx_cc'                  not monitored
Process 'metron_agent'              running

vcap/sys/log/cloud_controller_ng_ctl.err.log:
chown: changing ownership of `/var/vcap/nfs/shared': Operation not permitted

vcap/sys/log/cloud_controller_ng_ctl.log:
Preparing local package directory
Preparing local resource_pool directory
Preparing local droplet directory
{"timestamp":1418896461.8780618,"message":"PG::UndefinedTable: ERROR:  relation \"schema_migrations\" does not exist\nLINE 1: SELECT NULL AS \"nil\" FROM \"schema_migrations\" LIMIT 1\n                                  ^: SELECT NULL AS \"nil\" FROM \"schema_migrations\" LIMIT 1","log_level":"error","source":"cc.db.migrations","data":{},"thread_id":70356986794980,"fiber_id":70357011539580,"process_id":1567,"file":"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.1.0/gems/sequel-4.15.0/lib/sequel/database/logging.rb","lineno":70,"method":"block in log_each"}
...
{"timestamp":1418896462.227733,"message":"Begin applying migration 20130131184954_new_initial_schema.rb, direction: up","log_level":"info","source":"cc.db.migrations","data":{},"thread_id":70356986794980,"fiber_id":70357011539580,"process_id":1567,"file":"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.1.0/gems/sequel-4.15.0/lib/sequel/database/logging.rb","lineno":70,"method":"block in log_each"}
{"timestamp":1418896466.97979,"message":"Finished applying migration 20130131184954_new_initial_schema.rb, direction: up, took 4.751948 seconds","log_level":"info","source":"cc.db.migrations","data":{},"thread_id":70356986794980,"fiber_id":70357011539580,"process_id":1567,"file":"/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.1.0/gems/sequel-4.15.0/lib/sequel/database/logging.rb","lineno":70,"method":"block in log_each"}
...
Preparing local package directory
Preparing local resource_pool directory
Preparing local droplet directory
Deprecated: Use -s or --insert-seed flag
Killing /var/vcap/sys/run/cloud_controller_ng/cloud_controller_ng.pid: 2130
.Stopped

[James Bayer]

did you make sure that you checked out and used the spiff templates from v194 tag instead of from master?

To unsubscribe from this group and stop receiving emails from it, send an email to bosh-users+...@cloudfoundry.org.

--

Thank you,

James Bayer

[Enya Yin Lee]

Hi,
I am not sure what you mean by v194 tag and master...very new to bosh and cloudfoundry
I follow steps from http://docs.cloudfoundry.org/deploying/openstack/install_cf_openstack.html
after bosh create release, I got cf-194+dev.yml

jbayer於 2014年12月19日星期五UTC+8下午4時22分05秒寫道：

[James Bayer]

ok, when you deploy a particular cf-release version, you should checkout the right git tag of cf-release. eg. from the cf-release root directory.

git checkout v194

this way the templates that generate your yaml files are aligned with the version of the code you are using.

To unsubscribe from this group and stop receiving emails from it, send an email to bosh-users+...@cloudfoundry.org.

[Enya Yin Lee]

I use tag v194, but the problem still exist...

jbayer於 2014年12月19日星期五UTC+8下午11時22分02秒寫道：

[Dmitriy Kalinin]

If you run bosh vms after your deploy finishes, does it show it as starting or failing?

Also it seems that nginx related process is failing. Could you include those logs (should be in the same directory but probably will have nginx in the name)?

[Enya Yin Lee]

Can anyone help me about this...
still not working
here is my manifest


Enya Yin Lee於 2014年12月25日星期四UTC+8上午10時38分19秒寫道：

it shows starting

now my monit summary appears like this:
Process 'cloud_controller_ng'       Connection failed
Process 'cloud_controller_worker_local_1' not monitored
Process 'cloud_controller_worker_local_2' initializing
Process 'nginx_cc'                  initializing
Process 'metron_agent'              running
File 'nfs_mounter'                  accessible

as for logs

cloudcontroller_ng_ctl.log:

Preparing local package directory
Preparing local resource_pool directory
Preparing local droplet directory
Deprecated: Use -s or --insert-seed flag

Killing /var/vcap/sys/run/cloud_controller_ng/cloud_controller_ng.pid: 24984
.Stopped

cloudcontroller_ng_ctl.err.log:

chown: changing ownership of `/var/vcap/nfs/shared': Operation not permitted
chown: changing ownership of `/var/vcap/nfs/shared': Operation not permitted
chown: changing ownership of `/var/vcap/nfs/shared': Operation not permitted

nginx_ctl.err.log:
nginx: [emerg] duplicate location "/password/" in /var/vcap/jobs/cloud_controller_ng/config/nginx.conf:86

nginx_ctl.log:
Removing stale pidfile...


Dmitriy Kalinin於 2014年12月25日星期四UTC+8上午3時14分11秒寫道：

[Dmitriy Kalinin]

I'm not familiar enough with why cloud controller fails, but you could try `bosh recreate api_z1/0` to blow away and recreate cloud controller vm.

[Arunava Basu]

Getting exactly same issue when I am trying to deploy CF v202.

$ bosh ssh api_z1

The Monit daemon 5.2.4 uptime: 17h 1m

Process 'cloud_controller_ng'       initializing

Process 'cloud_controller_worker_local_1' initializing

Process 'cloud_controller_worker_local_2' initializing

Process 'nginx_cc'                  not monitored

Process 'metron_agent'              running

File 'nfs_mounter'                  accessible

System 'system_b27465fc-d14a-4bc6-9b02-7433dfa6b8ec' running

==> cloud_controller_worker_ctl.err.log <==

[2015-04-14 08:33:11+0000] ------------ STARTING cloud_controller_worker_ctl at Tue Apr 14 08:32:21 UTC 2015 --------------

==> cloud_controller_worker_ctl.log <==

[2015-04-14 08:33:11+0000] ------------ STARTING cloud_controller_worker_ctl at Tue Apr 14 08:32:21 UTC 2015 --------------

[2015-04-14 08:33:11+0000] [Worker(cc_api_worker.api_z1.0.1)] Starting job worker

[2015-04-14 08:33:11+0000] [Worker(cc_api_worker.api_z1.0.1)] Job VCAP::CloudController::Jobs::ExceptionCatchingJob (id=4247) RUNNING

[2015-04-14 08:33:11+0000] [Worker(cc_api_worker.api_z1.0.1)] Job VCAP::CloudController::Jobs::ExceptionCatchingJob (id=4247) COMPLETE

D after 6.5344

[2015-04-14 08:33:11+0000] [Worker(cc_api_worker.api_z1.0.1)] Job VCAP::CloudController::Jobs::ExceptionCatchingJob (id=4248) RUNNING

[2015-04-14 08:33:11+0000] [Worker(cc_api_worker.api_z1.0.1)] Job VCAP::CloudController::Jobs::ExceptionCatchingJob (id=4248) COMPLETE

D after 9.6285

[2015-04-14 08:33:11+0000] [Worker(cc_api_worker.api_z1.0.1)] Job VCAP::CloudController::Jobs::ExceptionCatchingJob (id=4251) RUNNING

[2015-04-14 08:33:11+0000] [Worker(cc_api_worker.api_z1.0.1)] Exiting...

[2015-04-14 08:33:11+0000] [Worker(cc_api_worker.api_z1.0.1)] Job VCAP::CloudController::Jobs::ExceptionCatchingJob (id=4251) COMPLETE

D after 8.7643

[2015-04-14 08:33:11+0000] [Worker(cc_api_worker.api_z1.0.1)] 3 jobs processed at 0.1199 j/s, 0 failed

[2015-04-14 08:33:11+0000] Killing /var/vcap/sys/run/cloud_controller_ng/cloud_controller_worker_1.pid: 1829

[2015-04-14 08:33:11+0000] ........Stopped

==> cloud_controller_worker_ctl.err.log <==

[2015-04-14 08:33:12+0000] ------------ STARTING cloud_controller_worker_ctl at Tue Apr 14 08:32:22 UTC 2015 --------------

==> cloud_controller_worker_ctl.log <==

[2015-04-14 08:33:12+0000] ------------ STARTING cloud_controller_worker_ctl at Tue Apr 14 08:32:22 UTC 2015 --------------

[2015-04-14 08:33:12+0000] [Worker(cc_api_worker.api_z1.0.2)] Starting job worker

[2015-04-14 08:33:12+0000] [Worker(cc_api_worker.api_z1.0.2)] Job VCAP::CloudController::Jobs::ExceptionCatchingJob (id=4246) RUNNING

[2015-04-14 08:33:12+0000] [Worker(cc_api_worker.api_z1.0.2)] Job VCAP::CloudController::Jobs::ExceptionCatchingJob (id=4246) COMPLETE

D after 17.9655

[2015-04-14 08:33:12+0000] [Worker(cc_api_worker.api_z1.0.2)] Job VCAP::CloudController::Jobs::ExceptionCatchingJob (id=4249) RUNNING

[2015-04-14 08:33:12+0000] [Worker(cc_api_worker.api_z1.0.2)] Job VCAP::CloudController::Jobs::ExceptionCatchingJob (id=4249) COMPLETE

D after 0.0360

[2015-04-14 08:33:12+0000] [Worker(cc_api_worker.api_z1.0.2)] Job VCAP::CloudController::Jobs::ExceptionCatchingJob (id=4250) RUNNING

[2015-04-14 08:33:12+0000] [Worker(cc_api_worker.api_z1.0.2)] Exiting...

[2015-04-14 08:33:12+0000] [Worker(cc_api_worker.api_z1.0.2)] Job VCAP::CloudController::Jobs::ExceptionCatchingJob (id=4250) COMPLETE

D after 16.9416

[2015-04-14 08:33:13+0000] [Worker(cc_api_worker.api_z1.0.2)] 3 jobs processed at 0.0858 j/s, 0 failed

[2015-04-14 08:33:13+0000] Killing /var/vcap/sys/run/cloud_controller_ng/cloud_controller_worker_2.pid: 1861

[2015-04-14 08:33:13+0000] ..Stopped

==> cloud_controller_ng_ctl.err.log <==

[2015-04-14 08:33:13+0000] ------------ STARTING cloud_controller_ng_ctl at Tue Apr 14 08:32:08 UTC 2015 --------------

[2015-04-14 08:33:13+0000] chown: changing ownership of â/var/vcap/nfs/sharedâ: Operation not permitted

[2015-04-14 08:33:13+0000] chown: changing ownership of â/var/vcap/nfs/sharedâ: Operation not permitted

[2015-04-14 08:33:13+0000] chown: changing ownership of â/var/vcap/nfs/sharedâ: Operation not permitted

==> cloud_controller_ng_ctl.log <==

[2015-04-14 08:33:13+0000] ------------ STARTING cloud_controller_ng_ctl at Tue Apr 14 08:32:08 UTC 2015 --------------

[2015-04-14 08:33:13+0000] Preparing local package directory

[2015-04-14 08:33:13+0000] Preparing local resource_pool directory

[2015-04-14 08:33:13+0000] Preparing local droplet directory

[2015-04-14 08:33:13+0000] Deprecated: Use -s or --insert-seed flag

[2015-04-14 08:33:14+0000] Killing /var/vcap/sys/run/cloud_controller_ng/cloud_controller_ng.pid: 1571

[2015-04-14 08:33:14+0000] .Stopped

==> nginx_ctl.err.log <==

[2015-04-14 08:35:51+0000] ------------ STARTING nginx_ctl at Tue Apr 14 08:35:50 UTC 2015 --------------

[2015-04-14 08:35:51+0000] nginx: [emerg] duplicate location /admin/ in /var/vcap/jobs/cloud_controller_ng/config/nginx.conf:88

[2015-04-14 08:36:49+0000] ------------ STARTING nginx_ctl at Tue Apr 14 08:36:49 UTC 2015 --------------

[2015-04-14 08:36:49+0000] nginx: [emerg] duplicate location /admin/ in /var/vcap/jobs/cloud_controller_ng/config/nginx.conf:88

[2015-04-14 08:38:06+0000] ------------ STARTING nginx_ctl at Tue Apr 14 08:38:06 UTC 2015 --------------

[2015-04-14 08:38:06+0000] nginx: [emerg] duplicate location /admin/ in /var/vcap/jobs/cloud_controller_ng/config/nginx.conf:88

[2015-04-14 08:39:29+0000] ------------ STARTING nginx_ctl at Tue Apr 14 08:39:28 UTC 2015 --------------

[2015-04-14 08:39:29+0000] nginx: [emerg] duplicate location /admin/ in /var/vcap/jobs/cloud_controller_ng/config/nginx.conf:88

[2015-04-14 08:40:29+0000] ------------ STARTING nginx_ctl at Tue Apr 14 08:40:29 UTC 2015 --------------

[2015-04-14 08:40:29+0000] nginx: [emerg] duplicate location /admin/ in /var/vcap/jobs/cloud_controller_ng/config/nginx.conf:88

tail -f nginx_ctl*

==> nginx_ctl.log <==

[2015-04-14 08:35:51+0000] ------------ STARTING nginx_ctl at Tue Apr 14 08:35:50 UTC 2015 --------------

[2015-04-14 08:35:51+0000] Removing stale pidfile...

[2015-04-14 08:36:49+0000] ------------ STARTING nginx_ctl at Tue Apr 14 08:36:49 UTC 2015 --------------

[2015-04-14 08:36:49+0000] Removing stale pidfile...

[2015-04-14 08:38:06+0000] ------------ STARTING nginx_ctl at Tue Apr 14 08:38:06 UTC 2015 --------------

[2015-04-14 08:38:06+0000] Removing stale pidfile...

[2015-04-14 08:39:29+0000] ------------ STARTING nginx_ctl at Tue Apr 14 08:39:28 UTC 2015 --------------

[2015-04-14 08:39:29+0000] Removing stale pidfile...

[2015-04-14 08:40:29+0000] ------------ STARTING nginx_ctl at Tue Apr 14 08:40:29 UTC 2015 --------------

[2015-04-14 08:40:29+0000] Removing stale pidfile...

$  tail -f nfs_mounter*

==> nfs_mounter <==

tail: error reading ânfs_mounterâ: Is a directory

tail: nfs_mounter: cannot follow end of this type of file; giving up on this name

==> nfs_mounter_ctl.err.log <==

[2015-04-14 08:40:14+0000] mount.nfs: trying 192.168.0.17 prog 100003 vers 3 prot TCP port 2049

[2015-04-14 08:40:14+0000] mount.nfs: trying 192.168.0.17 prog 100005 vers 3 prot UDP port 42180

[2015-04-14 08:41:19+0000] stop: Unknown instance:

[2015-04-14 08:41:19+0000] mount.nfs: mount(2): No such file or directory

[2015-04-14 08:41:19+0000] mount.nfs: trying 192.168.0.17 prog 100003 vers 3 prot TCP port 2049

[2015-04-14 08:41:19+0000] mount.nfs: trying 192.168.0.17 prog 100005 vers 3 prot UDP port 42180

[2015-04-14 08:42:42+0000] stop: Unknown instance:

[2015-04-14 08:42:42+0000] mount.nfs: mount(2): No such file or directory

[2015-04-14 08:42:42+0000] mount.nfs: trying 192.168.0.17 prog 100003 vers 3 prot TCP port 2049

[2015-04-14 08:42:42+0000] mount.nfs: trying 192.168.0.17 prog 100005 vers 3 prot UDP port 42180

==> nfs_mounter_ctl.log <==

[2015-04-14 08:42:42+0000] idmapd start/post-stop, process 8738

[2015-04-14 08:42:42+0000] Found NFS mount, unmounting...

[2015-04-14 08:42:42+0000] NFS unmounted

[2015-04-14 08:42:42+0000] Mounting NFS...

[2015-04-14 08:42:42+0000] mount.nfs: timeout set for Tue Apr 14 08:44:42 2015

[2015-04-14 08:42:42+0000] mount.nfs: trying text-based options 'timeo=10,intr,lookupcache=positive,vers=4,addr=192.168.0.17,clientaddr=192.168.0.86'

[2015-04-14 08:42:42+0000] mount.nfs: trying text-based options 'timeo=10,intr,lookupcache=positive,addr=192.168.0.17'

[2015-04-14 08:42:42+0000] mount.nfs: prog 100003, trying vers=3, prot=6

[2015-04-14 08:42:42+0000] mount.nfs: prog 100005, trying vers=3, prot=17

[2015-04-14 08:42:42+0000] NFS mounted

Any help guys????

[zaue...@pivotal.io]

Hi Arunava,

In your manifest, what's the value of properties.cc.jobs.buildpacks.buildpack_directory_key?

Thanks,

Zak

CF Runtime Team