/sbin/start zookeeper failed to start job

[hodiapa]

I got following error when starting the zookeeper.

2016-02-16 01:46:56 +0000 Puppet (debug): Executing: '/sbin/status zookeeper'
2016-02-16 01:46:56 +0000 Puppet (debug): Executing: '/sbin/initctl --version'
2016-02-16 01:46:56 +0000 Puppet (debug): Executing: '/sbin/start zookeeper'
2016-02-16 01:46:56 +0000 Puppet (err): Could not start Service[zookeeper]: Execution of '/sbin/start zookeeper' returned 1: start: Job failed to start
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/util/execution.rb:232:in `execute'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/provider.rb:102:in `execute'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/provider/service/service.rb:25:in `texecute'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/provider/service/init.rb:172:in `texecute'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/provider/service/service.rb:39:in `ucommand'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/provider/service/base.rb:80:in `start'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/type/service.rb:92:in `block (3 levels) in <module:Puppet>'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/property.rb:427:in `set'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/property.rb:501:in `sync'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/type/service.rb:103:in `sync'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/transaction/resource_harness.rb:214:in `sync'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/transaction/resource_harness.rb:139:in `sync_if_needed'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/transaction/resource_harness.rb:81:in `perform_changes'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/transaction/resource_harness.rb:20:in `evaluate'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/transaction.rb:207:in `apply'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/transaction.rb:223:in `eval_resource'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/transaction.rb:150:in `call'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/transaction.rb:150:in `block (2 levels) in evaluate'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/util.rb:292:in `block in thinmark'
/usr/lib/ruby/2.0.0/benchmark.rb:296:in `realtime'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/util.rb:291:in `thinmark'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/transaction.rb:150:in `block in evaluate'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/graph/relationship_graph.rb:118:in `traverse'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/transaction.rb:141:in `evaluate'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/resource/catalog.rb:202:in `block in apply'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/util/log.rb:153:in `with_destination'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/transaction/report.rb:107:in `as_logging_destination'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/resource/catalog.rb:201:in `apply'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/configurer.rb:119:in `block in apply_catalog'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/util.rb:129:in `block in benchmark'
/usr/lib/ruby/2.0.0/benchmark.rb:296:in `realtime'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/util.rb:128:in `benchmark'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/configurer.rb:118:in `apply_catalog'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/configurer.rb:232:in `run_internal'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/configurer.rb:134:in `block in run'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/context.rb:65:in `override'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet.rb:240:in `override'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/configurer.rb:133:in `run'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/application/apply.rb:347:in `apply_catalog'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/application/apply.rb:274:in `block in main'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/context.rb:65:in `override'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet.rb:240:in `override'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/application/apply.rb:225:in `main'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/application/apply.rb:170:in `run_command'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/application.rb:344:in `block in run'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/util.rb:446:in `exit_on_fail'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/application.rb:344:in `run'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/util/command_line.rb:128:in `run'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/lib/puppet/util/command_line.rb:72:in `execute'
/var/lib/gems/2.0.0/gems/puppet-4.3.2/bin/puppet:5:in `<top (required)>'
/usr/local/bin/puppet:23:in `load'
/usr/local/bin/puppet:23:in `<main>'
2016-02-16 01:46:56 +0000 /Stage[main]/Zookeeper::Service/Service[zookeeper]/ensure (err): change from stopped to running failed: Could not start Service[zookeeper]: Execution of '/sbin/start zookeeper' returned 1: start: Job failed to start

[deric]

Which distribution do you use? Could you check system logs or ZooKeeper logs? It might be either problem with writing to datastore or the way how Puppet tries to start service is not supported on your distribution.

[hodiapa]

I do not see any logs being created in the /var/log/zookeeper folder. I am including the syslog here
https://gist.github.com/hodiapa/e409ccdbbfea233834b8#file-syslog

Here is the puppetprovisioning log showing the zookeeper error
https://gist.github.com/hodiapa/241ac0d696cc099f9e76#file-puppetlog

The distribution I am using ubuntu 14.04.

Here is the link to the code repo which I am trying:
https://github.com/hodiapa/puppet-mesos-example

[deric]

I'd be worried most about this syslog line:

 kernel: [    4.890118] init: zookeeper pre-start process (1032) terminated with status 127

Exit code 127 means command not found. So, either is something wrong with your $PATH or some ENV variable setting.

Ubuntu's pre-start script might look like this (correct me if I'm wrong):

pre-start script
    [ -r "/usr/share/java/zookeeper.jar" ] || exit 0
    [ -r "/etc/zookeeper/conf/environment" ] || exit 0
    . /etc/zookeeper/conf/environment
    [ -d $ZOO_LOG_DIR ] || mkdir -p $ZOO_LOG_DIR
    chown $USER:$GROUP $ZOO_LOG_DIR
end script

It's quite strange that it would end up in this block. Could you check your /etc/zookeeper/conf/environment and verify that both zookeeper user and group exist. Other probable cause is that /usr/bin/java was not found.

[hodiapa]

I did verify both the environment variables and the /usr/bin/java and they are set.snapshot

Path

I do however see that for "echo $CLASSPATH", I do not see any output.

PS: I am using oracle-java8

[hodiapa]

Hi. I also tested it with the latest puppet-zookeeper v0.5.1 and I am still getting the same error.

[deric]

There seems to be a problem with mixing different service start mechanisms. There's a certain level of schizophrenia in Ubuntu services. zookeeperd package is distributed with both /etc/init.d/zookeeper and upstart /etc/init/zookeeper.conf scripts.

On a clean install:

service zookeeper status
zookeeper start/running, process 353

and at the same time init.d is not aware of the service:

/etc/init.d/zookeeper status
 * zookeeper is not running

So, the process was started by upstart and it's running:

ps aux | grep zoo
zookeep+   353  0.1  0.0 6253016 138516 ?      Ssl   2015 392:11 /usr/bin/java -cp /etc/zookeeper/conf:/usr/share/java/jline.jar:/usr/share/java/log4j-1.2.jar:/usr/share/java/xercesImpl.jar:/usr/share/java/xmlParserAPIs.jar:/usr/share/java/netty.jar:/usr/share/java/slf4j-api.jar:/usr/share/java/slf4j-log4j12.jar:/usr/share/java/zookeeper.jar -Xmx2048m -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.local.only=false -Dzookeeper.log.dir=/var/log/zookeeper -Dzookeeper.root.logger=INFO,ROLLINGFILE org.apache.zookeeper.server.quorum.QuorumPeerMain /etc/zookeeper/conf/zoo.cfg

Anyway the real problem is here tail /var/log/zookeeper/zookeeper.log:

ERROR [main:QuorumPeerConfig@178] - ninja:2888:3888:2888:3888 does not have the form host:port or host:port:port  or host:port:port:type
ERROR [main:QuorumPeerConfig@178] - ninja:2888:3888:2888:3888 does not have the form host:port or host:port:port  or host:port:port:type

[deric]

So, the problem is in hiera config, instead of using:

zookeeper::servers: ['ninja:2888:3888', 'nova:2888:3888', 'nuclear:2888:3888']

so it should be just (or preferably just IP addresses):

zookeeper::servers: ['ninja', 'nova', 'nuclear']

The listing of all servers is complicated. But currently I'm not aware of any mechanism in Puppet that would make this easier and reliable (see #18). At least we can try to strip server name before :.

[hodiapa]

Hi @deric thanks for looking into this. So hiera configuration is the one that is causing the zookeeper service to not start in this case?

[deric]

Yes, but with current config ZooKeeper will probably start in read-only mode. I'm still not sure whether Puppet manages ZooKeeper service reliably on Ubuntu.

As far as your Vagrant file is concerned, you should enable all 3 servers in order to have fully functional ZooKeeper cluster. Make sure that ninja hostname is correctly resolved on all hosts.