[ZOOKEEPER-2530] When zookeeper started in SSL mode, set a "get" watcher on a znode from zkCli client, restart the zkCli, the "Data" watcher still present. Trying removing that watcher fails saying no watcher available

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Duplicate
• Affects Version/s: 3.5.1
• Component/s: server
• Assignee: Unassigned
• Reporter: Rakesh Kumar Singh
• Created: 25/Aug/16 06:40
• Updated: 29/Sep/24 12:37
• Resolved: 29/Sep/24 12:37

Description

When zookeeper started in SSL mode, set a "get" watcher on a znode from zkCli client, restart the zkCli, the "Data" watcher still present. Trying removing that watcher fails saying no watcher available

Steps to reproduce:-

Start Zookeeper server in ssl mode by configuring all required ssl configuration
Start zkCli and set a "Data" watcher "get -w "
Restart the zkCli client
Check the watcher. Still the Data watcher is available
Try to remove the watcher using removewachers, it fails saying no watcher available.
BLR1000007042:~ # echo wchs | netcat localhost 3181
1 connections watching 1 paths
Total watches:1
BLR1000007042:~ # echo wchs | netcat localhost 3181
1 connections watching 1 paths
Total watches:1

Client log as below:-

[zk: localhost:2181(CONNECTED) 0] get -w /test
hello1
[zk: localhost:2181(CONNECTED) 1] quit
2016-08-25 14:22:00,706 [myid:] - INFO [main:ClientCnxnSocketNetty@201] - channel is told closing
2016-08-25 14:22:00,706 [myid:] - INFO [main:ZooKeeper@1110] - Session: 0x1019f8940e20000 closed
2016-08-25 14:22:00,706 [myid:] - INFO [main-EventThread:ClientCnxn$EventThread@542] - EventThread shut down for session: 0x1019f8940e20000
2016-08-25 14:22:00,707 [myid:] - INFO [New I/O worker #1:ClientCnxnSocketNetty$ZKClientHandler@377] - channel is disconnected: [id: 0x9dab735e, /127.0.0.1:57415 :> localhost/127.0.0.1:2181]
2016-08-25 14:22:00,707 [myid:] - INFO [New I/O worker #1:ClientCnxnSocketNetty@201] - channel is told closing
BLR1000007042:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin # ./zkCli.sh
/usr/bin/java
Connecting to localhost:2181
2016-08-25 14:22:15,079 [myid:] - INFO [main:Environment@109] - Client environment:zookeeper.version=3.5.1-alpha--1, built on 08/18/2016 08:20 GMT
2016-08-25 14:22:15,083 [myid:] - INFO [main:Environment@109] - Client environment:host.name=BLR1000007042
2016-08-25 14:22:15,084 [myid:] - INFO [main:Environment@109] - Client environment:java.version=1.7.0_79
2016-08-25 14:22:15,086 [myid:] - INFO [main:Environment@109] - Client environment:java.vendor=Oracle Corporation
2016-08-25 14:22:15,086 [myid:] - INFO [main:Environment@109] - Client environment:java.home=/usr/java/jdk1.7.0_79/jre
2016-08-25 14:22:15,086 [myid:] - INFO [main:Environment@109] - Client environment:java.class.path=/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../build/classes:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../build/lib/*.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../lib/slf4j-log4j12-1.7.5.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../lib/slf4j-api-1.7.5.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../lib/servlet-api-2.5-20081211.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../lib/netty-3.7.0.Final.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../lib/log4j-1.2.16.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../lib/jline-2.11.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../lib/jetty-util-6.1.26.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../lib/jetty-6.1.26.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../lib/javacc.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../lib/jackson-mapper-asl-1.9.11.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../lib/jackson-core-asl-1.9.11.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../lib/commons-cli-1.2.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../lib/ant-eclipse-1.0-jvm1.2.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../zookeeper-3.5.1-alpha.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../src/java/lib/ant-eclipse-1.0-jvm1.2.jar:/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin/../conf:
2016-08-25 14:22:15,087 [myid:] - INFO [main:Environment@109] - Client environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
2016-08-25 14:22:15,087 [myid:] - INFO [main:Environment@109] - Client environment:java.io.tmpdir=/tmp
2016-08-25 14:22:15,087 [myid:] - INFO [main:Environment@109] - Client environment:java.compiler=
2016-08-25 14:22:15,087 [myid:] - INFO [main:Environment@109] - Client environment:os.name=Linux
2016-08-25 14:22:15,087 [myid:] - INFO [main:Environment@109] - Client environment:os.arch=amd64
2016-08-25 14:22:15,087 [myid:] - INFO [main:Environment@109] - Client environment:os.version=3.0.76-0.11-default
2016-08-25 14:22:15,087 [myid:] - INFO [main:Environment@109] - Client environment:user.name=root
2016-08-25 14:22:15,087 [myid:] - INFO [main:Environment@109] - Client environment:user.home=/root
2016-08-25 14:22:15,088 [myid:] - INFO [main:Environment@109] - Client environment:user.dir=/home/Rakesh/Zookeeper/18_Aug/zookeeper-3.5.1-alpha/bin
2016-08-25 14:22:15,088 [myid:] - INFO [main:Environment@109] - Client environment:os.memory.free=52MB
2016-08-25 14:22:15,090 [myid:] - INFO [main:Environment@109] - Client environment:os.memory.max=227MB
2016-08-25 14:22:15,090 [myid:] - INFO [main:Environment@109] - Client environment:os.memory.total=57MB
2016-08-25 14:22:15,095 [myid:] - INFO [main:ZooKeeper@716] - Initiating client connection, connectString=localhost:2181 sessionTimeout=30000 watcher=org.apache.zookeeper.ZooKeeperMain$MyWatcher@272f15b0
Welcome to ZooKeeper!
2016-08-25 14:22:15,182 [myid:] - INFO [main-SendThread(localhost:2181):ClientCnxn$SendThread@1138] - Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error)
JLine support is enabled
[INFO] Unable to bind key for unsupported operation: backward-delete-word
[INFO] Unable to bind key for unsupported operation: backward-delete-word
[INFO] Unable to bind key for unsupported operation: down-history
[INFO] Unable to bind key for unsupported operation: up-history
[INFO] Unable to bind key for unsupported operation: up-history
[INFO] Unable to bind key for unsupported operation: down-history
[INFO] Unable to bind key for unsupported operation: up-history
[INFO] Unable to bind key for unsupported operation: down-history
[INFO] Unable to bind key for unsupported operation: up-history
[INFO] Unable to bind key for unsupported operation: down-history
[INFO] Unable to bind key for unsupported operation: up-history
[INFO] Unable to bind key for unsupported operation: down-history
[zk: localhost:2181(CONNECTING) 0] 2016-08-25 14:22:15,502 [myid:] - INFO [main-SendThread(localhost:2181):ClientCnxnSocketNetty$ZKClientPipelineFactory@363] - SSL handler added for channel: null
2016-08-25 14:22:15,537 [myid:] - INFO [New I/O worker #1:ClientCnxn$SendThread@980] - Socket connection established, initiating session, client: /127.0.0.1:57420, server: localhost/127.0.0.1:2181
2016-08-25 14:22:15,540 [myid:] - INFO [New I/O worker #1:ClientCnxnSocketNetty$1@146] - channel is connected: [id: 0xfc4fe483, /127.0.0.1:57420 => localhost/127.0.0.1:2181]
2016-08-25 14:22:15,673 [myid:] - INFO [New I/O worker #1:ClientCnxn$SendThread@1400] - Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x1019f8940e20001, negotiated timeout = 30000

WATCHER::

WatchedEvent state:SyncConnected type:None path:null

[zk: localhost:2181(CONNECTED) 0] removewatches /test -a
2016-08-25 14:24:14,420 [myid:] - ERROR [New I/O worker #1:ClientCnxn@725] - Failed to find watcher!
org.apache.zookeeper.KeeperException$NoWatcherException: KeeperErrorCode = No such watcher for /test
at org.apache.zookeeper.ZooKeeper$ZKWatchManager.containsWatcher(ZooKeeper.java:377)
at org.apache.zookeeper.ZooKeeper$ZKWatchManager.removeWatcher(ZooKeeper.java:252)
at org.apache.zookeeper.WatchDeregistration.unregister(WatchDeregistration.java:58)
at org.apache.zookeeper.ClientCnxn.finishPacket(ClientCnxn.java:712)
at org.apache.zookeeper.ClientCnxn.access$1500(ClientCnxn.java:97)
at org.apache.zookeeper.ClientCnxn$SendThread.readResponse(ClientCnxn.java:948)
at org.apache.zookeeper.ClientCnxnSocketNetty$ZKClientHandler.messageReceived(ClientCnxnSocketNetty.java:419)
at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70)
at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791)
at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:296)
at org.jboss.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:462)
at org.jboss.netty.handler.codec.frame.FrameDecoder.callDecode(FrameDecoder.java:443)
at org.jboss.netty.handler.codec.frame.FrameDecoder.messageReceived(FrameDecoder.java:303)
at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70)
at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559)
at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268)
at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255)
at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88)
at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:109)
at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:312)
at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:90)
at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178)
at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
KeeperErrorCode = No such watcher for /test
[zk: localhost:2181(CONNECTED) 1]

Issue Links

• is duplicated by: ZOOKEEPER-2358 NettyServerCnxn leaks watches upon close
• is superceded by: ZOOKEEPER-3131 org.apache.zookeeper.server.WatchManager resource leak