zookeeper-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "mostolog@gmail.com" <mosto...@gmail.com>
Subject My first ensemble...crash!
Date Thu, 19 Jan 2017 12:33:20 GMT
Hi, Zookeeper newbie here!

Just downloaded 
http://www-us.apache.org/dist/zookeeper/zookeeper-3.5.2-alpha/zookeeper-3.5.2-alpha.tar.gz

and trying to make my first cluster. My intention is to deploy a single 
server and add more instances to the ensemble. According to 
https://zookeeper.apache.org/doc/trunk/zookeeperReconfig.html having a 
static config file + dynamic + reconfig should be enough.

*This is my static zoo.cfg*

    tickTime=2000
    dataDir=/tmp/zookeeper
    autopurge.purgeInterval=1
    initLimit=5
    syncLimit=2
    maxClientCnxns=60

    standaloneEnabled=false
    dynamicConfigFile=/zk/conf/dynamic.conf

*And this is my server #1 dynamic.conf*

    server.3 = 10.0.0.3:2181:2888;

IIUC, it doesn't matter what /id/ is (ie: it doesn't have to start with 
1), but it should match /datadir myid/ file content.

This is what I got:

    ZooKeeper JMX enabled by default
    Using config: /zk/bin/../conf/zoo.cfg
    2017-01-19 12:25:33,825 [myid:] - INFO [main:QuorumPeerConfig@116] -
    Reading configuration from: /zk/bin/../conf/zoo.cfg
    2017-01-19 12:25:33,828 [myid:] - INFO [main:QuorumPeerConfig@308] -
    clientPort is not set
    2017-01-19 12:25:33,828 [myid:] - INFO [main:QuorumPeerConfig@322] -
    secureClientPort is not set
    2017-01-19 12:25:33,831 [myid:] - WARN [main:QuorumPeerConfig@581] -
    No server failure will be tolerated. You need at least 3 servers.
    2017-01-19 12:25:33,833 [myid:3] - INFO
    [main:DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3
    2017-01-19 12:25:33,834 [myid:3] - INFO
    [main:DatadirCleanupManager@79] - autopurge.purgeInterval set to 1
    2017-01-19 12:25:33,834 [myid:3] - INFO
    [PurgeTask:DatadirCleanupManager$PurgeTask@138] - Purge task started.
    2017-01-19 12:25:33,835 [myid:3] - INFO [main:ManagedUtil@46] -
    Log4j found with jmx enabled.
    2017-01-19 12:25:33,839 [myid:3] - INFO
    [PurgeTask:DatadirCleanupManager$PurgeTask@144] - Purge task completed.
    2017-01-19 12:25:33,843 [myid:3] - INFO [main:QuorumPeerMain@136] -
    Starting quorum peer
    2017-01-19 12:25:33,863 [myid:3] - INFO [main:Slf4jLog@67] - Logging
    to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via
    org.mortbay.log.Slf4jLog
    2017-01-19 12:25:33,878 [myid:3] - INFO [main:QuorumPeer@1327] -
    Local sessions disabled
    2017-01-19 12:25:33,878 [myid:3] - INFO [main:QuorumPeer@1338] -
    Local session upgrading disabled
    2017-01-19 12:25:33,878 [myid:3] - INFO [main:QuorumPeer@1305] -
    tickTime set to 2000
    2017-01-19 12:25:33,878 [myid:3] - INFO [main:QuorumPeer@1349] -
    minSessionTimeout set to 4000
    2017-01-19 12:25:33,878 [myid:3] - INFO [main:QuorumPeer@1360] -
    maxSessionTimeout set to 40000
    2017-01-19 12:25:33,879 [myid:3] - INFO [main:QuorumPeer@1375] -
    initLimit set to 5
    2017-01-19 12:25:33,888 [myid:3] - INFO [main:QuorumPeer@776] -
    currentEpoch not found! Creating with a reasonable default of 0.
    This should only happen when you are upgrading your installation
    2017-01-19 12:25:33,933 [myid:3] - INFO [main:QuorumPeer@791] -
    acceptedEpoch not found! Creating with a reasonable default of 0.
    This should only happen when you are upgrading your installation
    2017-01-19 12:25:33,978 [myid:3] - INFO [main:Slf4jLog@67] -
    jetty-6.1.26
    2017-01-19 12:25:34,001 [myid:3] - INFO [main:Slf4jLog@67] - Started
    SelectChannelConnector@0.0.0.0:8080
    2017-01-19 12:25:34,002 [myid:3] - INFO [main:JettyAdminServer@105]
    - Started AdminServer on address 0.0.0.0, port 8080 and command URL
    /commands
    2017-01-19 12:25:34,007 [myid:3] - INFO
    [QuorumPeerListener:QuorumCnxManager$Listener@631] - My election
    bind port: /10.0.0.3:2888
    2017-01-19 12:25:34,010 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):QuorumPeer@1033]
    - LOOKING
    2017-01-19 12:25:34,010 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):FastLeaderElection@894]
    - New election. My id =  3, proposed zxid=0x0
    2017-01-19 12:25:34,012 [myid:3] - INFO
    [WorkerReceiver[myid=3]:FastLeaderElection@688] - Notification: 2
    (message format version), 3 (n.leader), 0x0 (n.zxid), 0x1 (n.round),
    LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0
    (n.config version)
    2017-01-19 12:25:34,213 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):MBeanRegistry@128]
    - Unregister MBean
    [org.apache.ZooKeeperService:name0=ReplicatedServer_id3,name1=replica.3,name2=LeaderElection]
    2017-01-19 12:25:34,213 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):QuorumPeer@1121]
    - LEADING
    2017-01-19 12:25:34,215 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Leader@63] -
    TCP NoDelay set to: true
    2017-01-19 12:25:34,215 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Leader@83] -
    zookeeper.leader.maxConcurrentSnapshots = 10
    2017-01-19 12:25:34,216 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Leader@85] -
    zookeeper.leader.maxConcurrentSnapshotTimeout = 5
    2017-01-19 12:25:34,220 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:zookeeper.version=3.5.2-alpha-1750793, built on
    06/30/2016 13:15 GMT
    2017-01-19 12:25:34,220 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:host.name=81bff920052d
    2017-01-19 12:25:34,220 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:java.version=1.8.0_111
    2017-01-19 12:25:34,220 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:java.vendor=Oracle Corporation
    2017-01-19 12:25:34,220 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:java.home=/usr/lib/jvm/java-8-openjdk-amd64/jre
    2017-01-19 12:25:34,220 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server
    environment:java.class.path=/zk/bin/../build/classes:/zk/bin/../build/lib/*.jar:/zk/bin/../lib/slf4j-log4j12-1.7.5.jar:/zk/bin/../lib/slf4j-api-1.7.5.jar:/zk/bin/../lib/servlet-api-2.5-20081211.jar:/zk/bin/../lib/netty-3.10.5.Final.jar:/zk/bin/../lib/log4j-1.2.17.jar:/zk/bin/../lib/jline-2.11.jar:/zk/bin/../lib/jetty-util-6.1.26.jar:/zk/bin/../lib/jetty-6.1.26.jar:/zk/bin/../lib/javacc.jar:/zk/bin/../lib/jackson-mapper-asl-1.9.11.jar:/zk/bin/../lib/jackson-core-asl-1.9.11.jar:/zk/bin/../lib/commons-cli-1.2.jar:/zk/bin/../zookeeper-3.5.2-alpha.jar:/zk/bin/../src/java/lib/*.jar:/zk/bin/../conf:
    2017-01-19 12:25:34,220 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server
    environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
    2017-01-19 12:25:34,220 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:java.io.tmpdir=/tmp
    2017-01-19 12:25:34,220 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:java.compiler=<NA>
    2017-01-19 12:25:34,220 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:os.name=Linux
    2017-01-19 12:25:34,220 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:os.arch=amd64
    2017-01-19 12:25:34,220 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:os.version=3.16.0-4-amd64
    2017-01-19 12:25:34,220 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:user.name=root
    2017-01-19 12:25:34,220 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:user.home=/root
    2017-01-19 12:25:34,221 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:user.dir=/
    2017-01-19 12:25:34,221 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:os.memory.free=102MB
    2017-01-19 12:25:34,221 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:os.memory.max=889MB
    2017-01-19 12:25:34,221 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Environment@109]
    - Server environment:os.memory.total=119MB
    2017-01-19 12:25:34,221 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):ZooKeeperServer@858]
    - minSessionTimeout set to 4000
    2017-01-19 12:25:34,222 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):ZooKeeperServer@867]
    - maxSessionTimeout set to 40000
    2017-01-19 12:25:34,222 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):ZooKeeperServer@156]
    - Created server with tickTime 2000 minSessionTimeout 4000
    maxSessionTimeout 40000 datadir /tmp/zookeeper/version-2 snapdir
    /tmp/zookeeper/version-2
    2017-01-19 12:25:34,223 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Leader@412] -
    LEADING - LEADER ELECTION TOOK - 10 MS
    2017-01-19 12:25:34,224 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):FileTxnSnapLog@298]
    - Snapshotting: 0x0 to /tmp/zookeeper/version-2/snapshot.0
    2017-01-19 12:25:34,323 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):Leader@1249] -
    Have quorum of supporters, sids: [ [3],[3] ]; starting up and
    setting last processed zxid: 0x100000000
    2017-01-19 12:25:34,387 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):CommitProcessor@254]
    - Configuring CommitProcessor with 4 worker threads.
    2017-01-19 12:25:34,393 [myid:3] - INFO
    [QuorumPeer[myid=3](plain=disabled)(secure=disabled):ContainerManager@64]
    - Using checkIntervalMs=60000 maxPerMinute=10000

*Does this mean the server is running?*

 From the same machine or another, whenever I try to get current config, 
this is what I get:

    $ /zk/bin/zkCli.sh -server 10.0.0.3
    Connecting to 10.0.0.3
    2017-01-19 12:28:44,775 [myid:] - INFO  [main:Environment@109] -
    Client environment:zookeeper.version=3.5.2-alpha-1750793, built on
    06/30/2016 13:15 GMT
    2017-01-19 12:28:44,778 [myid:] - INFO  [main:Environment@109] -
    Client environment:host.name=81bff920052d
    2017-01-19 12:28:44,778 [myid:] - INFO  [main:Environment@109] -
    Client environment:java.version=1.8.0_111
    2017-01-19 12:28:44,779 [myid:] - INFO  [main:Environment@109] -
    Client environment:java.vendor=Oracle Corporation
    2017-01-19 12:28:44,779 [myid:] - INFO  [main:Environment@109] -
    Client environment:java.home=/usr/lib/jvm/java-8-openjdk-amd64/jre
    2017-01-19 12:28:44,779 [myid:] - INFO  [main:Environment@109] -
    Client
    environment:java.class.path=/zk/bin/../build/classes:/zk/bin/../build/lib/*.jar:/zk/bin/../lib/slf4j-log4j12-1.7.5.jar:/zk/bin/../lib/slf4j-api-1.7.5.jar:/zk/bin/../lib/servlet-api-2.5-20081211.jar:/zk/bin/../lib/netty-3.10.5.Final.jar:/zk/bin/../lib/log4j-1.2.17.jar:/zk/bin/../lib/jline-2.11.jar:/zk/bin/../lib/jetty-util-6.1.26.jar:/zk/bin/../lib/jetty-6.1.26.jar:/zk/bin/../lib/javacc.jar:/zk/bin/../lib/jackson-mapper-asl-1.9.11.jar:/zk/bin/../lib/jackson-core-asl-1.9.11.jar:/zk/bin/../lib/commons-cli-1.2.jar:/zk/bin/../zookeeper-3.5.2-alpha.jar:/zk/bin/../src/java/lib/*.jar:/zk/bin/../conf:
    2017-01-19 12:28:44,780 [myid:] - INFO  [main:Environment@109] -
    Client
    environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
    2017-01-19 12:28:44,780 [myid:] - INFO  [main:Environment@109] -
    Client environment:java.io.tmpdir=/tmp
    2017-01-19 12:28:44,780 [myid:] - INFO  [main:Environment@109] -
    Client environment:java.compiler=<NA>
    2017-01-19 12:28:44,780 [myid:] - INFO  [main:Environment@109] -
    Client environment:os.name=Linux
    2017-01-19 12:28:44,780 [myid:] - INFO  [main:Environment@109] -
    Client environment:os.arch=amd64
    2017-01-19 12:28:44,780 [myid:] - INFO  [main:Environment@109] -
    Client environment:os.version=3.16.0-4-amd64
    2017-01-19 12:28:44,780 [myid:] - INFO  [main:Environment@109] -
    Client environment:user.name=root
    2017-01-19 12:28:44,780 [myid:] - INFO  [main:Environment@109] -
    Client environment:user.home=/root
    2017-01-19 12:28:44,780 [myid:] - INFO  [main:Environment@109] -
    Client environment:user.dir=/
    2017-01-19 12:28:44,780 [myid:] - INFO  [main:Environment@109] -
    Client environment:os.memory.free=114MB
    2017-01-19 12:28:44,781 [myid:] - INFO  [main:Environment@109] -
    Client environment:os.memory.max=228MB
    2017-01-19 12:28:44,781 [myid:] - INFO  [main:Environment@109] -
    Client environment:os.memory.total=119MB
    2017-01-19 12:28:44,783 [myid:] - INFO  [main:ZooKeeper@855] -
    Initiating client connection, connectString=10.0.0.3
    sessionTimeout=30000
    watcher=org.apache.zookeeper.ZooKeeperMain$MyWatcher@7e0b37bc
    Welcome to ZooKeeper!
    2017-01-19 12:28:44,798 [myid:10.0.0.3:2181] - INFO
    [main-SendThread(10.0.0.3:2181):ClientCnxn$SendThread@1113] -
    Opening socket connection to server 10.0.0.3/10.0.0.3:2181. Will not
    attempt to authenticate using SASL (unknown error)
    JLine support is enabled
    2017-01-19 12:28:44,847 [myid:10.0.0.3:2181] - INFO
    [main-SendThread(10.0.0.3:2181):ClientCnxn$SendThread@948] - Socket
    connection established, initiating session, client: /10.0.0.3:39105,
    server: 10.0.0.3/10.0.0.3:2181

    [zk: 10.0.0.3(CONNECTING) 0] config

    2017-01-19 12:28:54,867 [myid:10.0.0.3:2181] - INFO
    [main-SendThread(10.0.0.3:2181):ClientCnxn$SendThread@1231] - Unable
    to read additional data from server sessionid 0x0, likely server has
    closed socket, closing socket connection and attempting reconnect
    Exception in thread "main"
    org.apache.zookeeper.KeeperException$ConnectionLossException:
    KeeperErrorCode = ConnectionLoss for /zookeeper/config
         at
    org.apache.zookeeper.KeeperException.create(KeeperException.java:99)
         at
    org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
         at org.apache.zookeeper.ZooKeeper.getConfig(ZooKeeper.java:2062)
         at org.apache.zookeeper.ZooKeeper.getConfig(ZooKeeper.java:2117)
         at
    org.apache.zookeeper.cli.GetConfigCommand.exec(GetConfigCommand.java:61)
         at
    org.apache.zookeeper.ZooKeeperMain.processZKCmd(ZooKeeperMain.java:684)
         at
    org.apache.zookeeper.ZooKeeperMain.processCmd(ZooKeeperMain.java:587)
         at
    org.apache.zookeeper.ZooKeeperMain.executeLine(ZooKeeperMain.java:370)
         at org.apache.zookeeper.ZooKeeperMain.run(ZooKeeperMain.java:330)
         at org.apache.zookeeper.ZooKeeperMain.main(ZooKeeperMain.java:290)

*Why zkCli is not able to get current config from server?*

On the server, some logs are dumped:

    2017-01-19 12:28:54,863 [myid:3] - ERROR
    [LearnerHandler-/10.0.0.3:39105:LearnerHandler@604] - Unexpected
    exception causing shutdown while sock still open
    java.net.SocketTimeoutException: Read timed out
         at java.net.SocketInputStream.socketRead0(Native Method)
         at
    java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
         at java.net.SocketInputStream.read(SocketInputStream.java:170)
         at java.net.SocketInputStream.read(SocketInputStream.java:141)
         at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
         at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
         at java.io.DataInputStream.readInt(DataInputStream.java:388)
         at
    org.apache.jute.BinaryInputArchive.readString(BinaryInputArchive.java:79)
         at org.apache.zookeeper.data.Id.deserialize(Id.java:55)
         at
    org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
         at
    org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:92)
         at
    org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
         at
    org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:355)
    2017-01-19 12:28:54,867 [myid:3] - WARN
    [LearnerHandler-/10.0.0.3:39105:LearnerHandler@619] - *******
    GOODBYE /10.0.0.3:39105 ********

Could anyone help me? Thanks.

Regards


Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message