[ZOOKEEPER-2616] ZK client fails to connect to ReadOnly server

• Type: Bug
• Status: Open
• Priority: Critical
• Resolution: Unresolved
• Affects Version/s: 3.5.2
• Assignee: Unassigned
• Reporter: Benjamin Jaton
• Created: 17/Oct/16 22:08
• Updated: 30/Jan/17 20:34

Description

Only 1 of the 3 nodes of the ensemble is started. The server successfully started in readonly ("Read-only server started").

client

System.setProperty("readonlymode.enabled", "true");

String cs = "QA-E8WIN11:2181,QA-E8WIN12:2181,QA-E8WIN13:2181";
ZooKeeper zk = new ZooKeeper(cs, 30000, null, true);
		
// wait for connection
while (!zk.getState().isConnected()) {
	Thread.sleep(1000);
	logger.error(zk.getState());
}
zk.getData("/", false, new Stat());

logger.error("DONE");

The client code above manages to acquire a connection ("CONNECTEDREADONLY") but the subsequent getData fails with ConnectionLoss:

client log

2016-10-17 14:37:43 ERROR TestCuratorReadOnly:31 - CONNECTEDREADONLY
2016-10-17 14:39:49 ERROR o.a.z.ClientCnxn:526 - Error while calling watcher 
java.lang.NullPointerException
	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:524) [zookeeper-3.5.2-alpha.jar:3.5.2-alpha--1]
	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:499) [zookeeper-3.5.2-alpha.jar:3.5.2-alpha--1]
Exception in thread "main" org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:99)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1956)
	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1985)
	at TestCuratorReadOnly.main(TestCuratorReadOnly.java:33)

Full server logs are attached, but here are the relevant parts:

server log

2016-10-17 14:37:31,375 [myid:1] - INFO  [Thread-2:ReadOnlyZooKeeperServer@73] - Read-only server started
(...)
2016-10-17 14:37:55,241 [myid:1] - INFO  [NIOServerCxnFactory.AcceptThread:/0.0.0.0:2181:NIOServerCnxnFactory$AcceptThread@296] - Accepted socket connection from /10.11.12.4:40800
2016-10-17 14:37:55,250 [myid:1] - INFO  [NIOWorkerThread-1:ZooKeeperServer@964] - Client attempting to establish new session at /10.11.12.4:40800
2016-10-17 14:37:55,255 [myid:1] - INFO  [ProcessThread(sid:1 cport:-1)::ZooKeeperServer@678] - Established session 0x100024619520000 with negotiated timeout 30000 for client /10.11.12.4:40800
(...)
 [org.apache.ZooKeeperService:name0=ReplicatedServer_id1,name1=replica.1,name2=ReadOnlyServer,name3=Connections,name4=10.11.12.4,name5=0x100024619520000]
2016-10-17 14:38:26,929 [myid:1] - INFO  [ProcessThread(sid:1 cport:-1)::NIOServerCnxn@607] - Closed socket connection for client /10.11.12.4:40800 which had sessionid 0x100024619520000

The client and server are using official 3.5.2-alpha.

zoo.cfg

autopurge.purgeInterval=3
initLimit=10
syncLimit=5
autopurge.snapRetainCount=3
snapCount=10000
minSessionTimeout=5000
maxSessionTimeout=600000
tickTime=2000
admin.commandURL=/commands
quorumListenOnAllIPs=true
dataDir=C:/workspace/zookeeper-3.5.2-alpha/data
admin.serverPort=8080
admin.enableServer=false
standaloneEnabled=false
dynamicConfigFile=C:/workspace/zookeeper-3.5.2-alpha/conf/zoo.cfg.dynamic.10000046b

zoo.cfg.dynamic.10000046b

server.1=QA-E8WIN11:2888:3888:participant;0.0.0.0:2181
server.2=QA-E8WIN12:2888:3888:participant;0.0.0.0:2181
server.3=QA-E8WIN13:2888:3888:participant;0.0.0.0:2181