You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@zookeeper.apache.org by "Rakesh Kumar Singh (JIRA)" <ji...@apache.org> on 2016/09/02 11:56:21 UTC
[jira] [Created] (ZOOKEEPER-2546) Started throwing "Error Path:null
Error:KeeperErrorCode = ReconfigInProgress" error when trying to change the
cluster using reconfig and the IO hangged at one node
Rakesh Kumar Singh created ZOOKEEPER-2546:
---------------------------------------------
Summary: Started throwing "Error Path:null Error:KeeperErrorCode = ReconfigInProgress" error when trying to change the cluster using reconfig and the IO hangged at one node
Key: ZOOKEEPER-2546
URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2546
Project: ZooKeeper
Issue Type: Bug
Components: server
Affects Versions: 3.5.1
Reporter: Rakesh Kumar Singh
Started throwing "Error Path:null Error:KeeperErrorCode = ReconfigInProgress" error when trying to change the cluster using reconfig and the IO hangged at one node.
Steps:-
1. Start Zookeeper in cluster mode
2. try to reconfig the cluster using "reconfig" command from one node's client (194) like
"reconfig -remove 3 -add 3=10.18.221.194:2888:3888;2181
3. make the IO busy for 5-10 secs at 194 node and then release
4. Again execute the above reconfig command
It is failing to execute even after 3-4 mins.
Server log is attached. (Complete server log is attached)
2016-09-02 18:12:05,845 [myid:2] - INFO [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):QuorumPeer@1074] - LEADING
2016-09-02 18:12:05,848 [myid:2] - INFO [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Leader@63] - TCP NoDelay set to: true
2016-09-02 18:12:05,848 [myid:2] - INFO [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Leader@83] - zookeeper.leader.maxConcurrentSnapshots = 10
2016-09-02 18:12:05,848 [myid:2] - INFO [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Leader@85] - zookeeper.leader.maxConcurrentSnapshotTimeout = 5
2016-09-02 18:12:05,849 [myid:2] - INFO [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@858] - minSessionTimeout set to 4000
2016-09-02 18:12:05,849 [myid:2] - INFO [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@867] - maxSessionTimeout set to 40000
2016-09-02 18:12:05,849 [myid:2] - INFO [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ZooKeeperServer@156] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /home/Rakesh/Zookeeper/18_Aug/cluster/zookeeper-3.5.1-alpha/data/version-2 snapdir /home/Rakesh/Zookeeper/18_Aug/cluster/zookeeper-3.5.1-alpha/data/version-2
2016-09-02 18:12:05,850 [myid:2] - INFO [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Leader@412] - LEADING - LEADER ELECTION TOOK - 5
2016-09-02 18:12:05,852 [myid:2] - INFO [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):FileTxnSnapLog@298] - Snapshotting: 0x100000001 to /home/Rakesh/Zookeeper/18_Aug/cluster/zookeeper-3.5.1-alpha/data/version-2/snapshot.100000001
2016-09-02 18:12:06,854 [myid:2] - INFO [LearnerHandler-/10.18.101.80:55632:LearnerHandler@382] - Follower sid: 1 : info : 10.18.101.80:2888:3888:participant;0.0.0.0:2181
2016-09-02 18:12:06,869 [myid:2] - INFO [LearnerHandler-/10.18.101.80:55632:LearnerHandler@683] - Synchronizing with Follower sid: 1 maxCommittedLog=0x100000001 minCommittedLog=0x100000001 lastProcessedZxid=0x100000001 peerLastZxid=0x100000001
2016-09-02 18:12:06,869 [myid:2] - INFO [LearnerHandler-/10.18.101.80:55632:LearnerHandler@727] - Sending DIFF zxid=0x100000001 for peer sid: 1
2016-09-02 18:12:06,888 [myid:2] - INFO [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):Leader@1245] - Have quorum of supporters, sids: [ [1, 2] ]; starting up and setting last processed zxid: 0x200000000
2016-09-02 18:12:06,890 [myid:2] - INFO [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):CommitProcessor@254] - Configuring CommitProcessor with 8 worker threads.
2016-09-02 18:12:06,898 [myid:2] - INFO [QuorumPeer[myid=2](plain=/0:0:0:0:0:0:0:0:2181)(secure=disabled):ContainerManager@64] - Using checkIntervalMs=60000 maxPerMinute=10000
2016-09-02 18:12:18,886 [myid:2] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@688] - Notification: 2 (message format version), 3 (n.leader), 0x0 (n.zxid), 0xffffffffffffffff (n.round), LEADING (n.state), 3 (n.sid), 0x1 (n.peerEPoch), LEADING (my state)200000028 (n.config version)
2016-09-02 18:13:47,869 [myid:2] - INFO [ProcessThread(sid:2 cport:-1)::PrepRequestProcessor@512] - Incremental reconfig
2016-09-02 18:13:47,872 [myid:2] - ERROR [ProcessThread(sid:2 cport:-1)::QuorumPeer@1383] - setLastSeenQuorumVerifier called with stale config 8589934593. Current version: 8589934632
2016-09-02 18:14:15,545 [myid:2] - INFO [ProcessThread(sid:2 cport:-1)::PrepRequestProcessor@843] - Got user-level KeeperException when processing sessionid:0x1000aa5ce650000 type:reconfig cxid:0x3 zxid:0x200000002 txntype:-1 reqpath:n/a Error Path:null Error:KeeperErrorCode = ReconfigInProgress
2016-09-02 18:14:56,442 [myid:2] - INFO [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /10.18.219.50:48388
2016-09-02 18:14:56,454 [myid:2] - INFO [NIOWorkerThread-1:NIOServerCnxn@485] - Processing srvr command from /10.18.219.50:48388
2016-09-02 18:14:56,467 [myid:2] - INFO [NIOWorkerThread-1:NIOServerCnxn@606] - Closed socket connection for client /10.18.219.50:48388 (no session established for client)
2016-09-02 18:17:18,365 [myid:2] - INFO [ProcessThread(sid:2 cport:-1)::PrepRequestProcessor@843] - Got user-level KeeperException when processing sessionid:0x1000aa5ce650000 type:reconfig cxid:0x4 zxid:0x200000003 txntype:-1 reqpath:n/a Error Path:null Error:KeeperErrorCode = ReconfigInProgress
2016-09-02 18:19:23,699 [myid:2] - INFO [ProcessThread(sid:2 cport:-1)::PrepRequestProcessor@843] - Got user-level KeeperException when processing sessionid:0x1000aa5ce650000 type:reconfig cxid:0x5 zxid:0x200000004 txntype:-1 reqpath:n/a Error Path:null Error:KeeperErrorCode = ReconfigInProgress
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)