[
https://issues.apache.org/jira/browse/ZOOKEEPER-2848?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
prashantkumar updated ZOOKEEPER-2848:
-------------------------------------
Description:
Hi
I am seeing below error in ZK logs :
"Unexpected exception causing shutdown while sock still open
java.io.EOFException"
and then ZK server shuts down with "shutdown Leader! reason: Not sufficient
followers synced, only synced with sids: " error.
I am using zookeeper-3.5.1-alpha version.
it is ensemble of 2 servers
Could you please help me resolve this issue
Thanks
config
{code:java}
initLimit=10
syncLimit=5
maxClientCnxns=0
tickTime=2000
quorumListenOnAllIPs=true
dataDir=/var/run/zookeeper/conf/default
admin.enableServer=false
standaloneEnabled=false
{code}
zookeeper server logs
{code:java}
114829 2017-06-22 11:24:18,182 [myid:2147483652] - INFO
[ProcessThread(sid:2147483652 cport:-1)::PrepRequestProcessor@649] - Processed
session termination for sessionid: 0x40000007cef003d
114830 2017-06-22 11:24:18,182 [myid:2147483652] - INFO
[NIOWorkerThread-8:MBeanRegistry@119] - Unregister MBean
[org.apache.ZooKeeperService:name0=ReplicatedServer_id2147483652,
name1=replica.2147483652,name2=Leader,name3=Connections,name4=128.0.0.5,name5=0x40000007cef003d]
114831 2017-06-22 11:24:18,183 [myid:2147483652] - INFO
[NIOWorkerThread-8:NIOServerCnxn@606] - Closed socket connection for client
/128.0.0.5:34651 which had sessionid 0x40000007cef003d
114832 2017-06-22 11:24:18,421 [myid:2147483652] - ERROR
[LearnerHandler-/128.0.0.5:33610:LearnerHandler@604] - Unexpected exception
causing shutdown while sock still open
114833 java.io.EOFException
114834 at java.io.DataInputStream.readInt(DataInputStream.java:403)
114835 at
org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
114836 at
org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
114837 at
org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
114838 at
org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:515)
114839 2017-06-22 11:24:18,422 [myid:2147483652] - WARN
[LearnerHandler-/128.0.0.5:33610:LearnerHandler@619] - ******* GOODBYE
/128.0.0.5:33610 ********
114840 2017-06-22 11:24:18,422 [myid:2147483652] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:61808:NIOServerCnxnFactory$AcceptThread@296]
- Accepted socket connection from / 128.0.0.4:42854
114841 2017-06-22 11:24:18,422 [myid:2147483652] - INFO
[NIOWorkerThread-4:ZooKeeperServer@969] - Client attempting to renew session
0x40000007cef0001 at /128.0.0.4:42854
114842 2017-06-22 11:24:18,422 [myid:2147483652] - INFO
[NIOWorkerThread-4:ZooKeeperServer@678] - Established session 0x40000007cef0001
with negotiated timeout 20000 for client / 128.0.0.4:42854
114843 2017-06-22 11:24:18,423 [myid:2147483652] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:61808:NIOServerCnxnFactory$AcceptThread@296]
- Accepted socket connection from / 128.0.0.4:42862
114844 2017-06-22 11:24:18,423 [myid:2147483652] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:61808:NIOSe
{code}
After some time ..
{code:java}
114851 2017-06-22 11:24:18,423 [myid:2147483652] - INFO
[NIOWorkerThread-12:ZooKeeperServer@678] - Established session
0x40000007cef0003 with negotiated timeout 20000 for client /
128.0.0.4:42866
114852 2017-06-22 11:24:19,001 [myid:2147483652] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:61808:NIOServerCnxnFactory$AcceptThread@296]
- Accepted socket connection from / 128.0.0.4:42892
114853 2017-06-22 11:24:19,001 [myid:2147483652] - INFO
[NIOWorkerThread-13:ZooKeeperServer@964] - Client attempting to establish new
session at /128.0.0.4:42892
114854 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
[SessionTracker:ZooKeeperServer@384] - Expiring session 0x40000007cef016c,
timeout of 20000ms exceeded
114855 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
[SessionTracker:QuorumZooKeeperServer@132] - Submitting global closeSession
request for session 0x40000007cef016c
114856 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
[SessionTracker:ZooKeeperServer@384] - Expiring session 0x40000007cef016d,
timeout of 20000ms exceeded
114857 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
[ProcessThread(sid:2147483652 cport:-1)::PrepRequestProcessor@649] - Processed
session termination for sessionid: 0x40000007cef016c
114858 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
[SessionTracker:QuorumZooKeeperServer@132] - Submitting global closeSession
request for session 0x40000007cef016d
114859 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
[ProcessThread(sid:2147483652 cport:-1)::PrepRequestProcessor@649] - Processed
session termination for sessionid: 0x40000007cef016d
114860 2017-06-22 11:24:19,579 [myid:2147483652] - INFO
[QuorumPeer[myid=2147483652](plain=/0:0:0:0:0:0:0:0:61808)(secure=disabled):Leader@613]
- Shutting down
114861 2017-06-22 11:24:19,579 [myid:2147483652] - INFO
[QuorumPeer[myid=2147483652](plain=/0:0:0:0:0:0:0:0:61808)(secure=disabled):Leader@619]
- Shutdown called
114862 java.lang.Exception: shutdown Leader! reason: Not sufficient followers
synced, only synced with sids: [ [2147483652] ]
114863 at
org.apache.zookeeper.server.quorum.Leader.shutdown(Leader.java:619)
114864 at org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:590)
114865 at
org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1077)
114866 2017-06-22 11:24:19,579 [myid:2147483652] - INFO
[QuorumPeer[myid=2147483652](plain=/0:0:0:0:0:0:0:0:61808)(secure=disabled):MBeanRegistry@119]
- Unregister MBean [org.
apache.ZooKeeperService:name0=ReplicatedServer_id2147483652,name1=replica.2147483652,name2=Leader,name3=Connections,name4=128.0.0.4,name5=0x40000007cef006b]
114867 2017-06-22 11:24:19,579 [myid:2147483652] - INFO
[LearnerCnxAcceptor-0.0.0.0/0.0.0.0:61809:Leader$LearnerCnxAcceptor@373] -
exception while shutting down acceptor: java.net. SocketException: Socket
closed
114868 2017-06-22 11:24:19,581 [myid:2147483652] - INFO
[QuorumPeer[myid=2147483652](plain=/0:0:0:0:0:0:0:0:61808)(secure=disabled):NIOServerCnxn@606]
- Closed socket connection for client /128.0.0.4:41674 which had
sessionid 0x40000007cef006b
{code}
was:
Hi
I am seeing below error in ZK logs : "Unexpected exception causing shutdown
while sock still open java.io.EOFException".
I am using zookeeper-3.5.1-alpha version.
it is ensemble of 2 servers
Could you please help me resolve this issue
Thanks
config
{code:java}
initLimit=10
syncLimit=5
maxClientCnxns=0
tickTime=2000
quorumListenOnAllIPs=true
dataDir=/var/run/zookeeper/conf/default
admin.enableServer=false
standaloneEnabled=false
{code}
zookeeper server logs
{code:java}
114829 2017-06-22 11:24:18,182 [myid:2147483652] - INFO
[ProcessThread(sid:2147483652 cport:-1)::PrepRequestProcessor@649] - Processed
session termination for sessionid: 0x40000007cef003d
114830 2017-06-22 11:24:18,182 [myid:2147483652] - INFO
[NIOWorkerThread-8:MBeanRegistry@119] - Unregister MBean
[org.apache.ZooKeeperService:name0=ReplicatedServer_id2147483652,
name1=replica.2147483652,name2=Leader,name3=Connections,name4=128.0.0.5,name5=0x40000007cef003d]
114831 2017-06-22 11:24:18,183 [myid:2147483652] - INFO
[NIOWorkerThread-8:NIOServerCnxn@606] - Closed socket connection for client
/128.0.0.5:34651 which had sessionid 0x40000007cef003d
114832 2017-06-22 11:24:18,421 [myid:2147483652] - ERROR
[LearnerHandler-/128.0.0.5:33610:LearnerHandler@604] - Unexpected exception
causing shutdown while sock still open
114833 java.io.EOFException
114834 at java.io.DataInputStream.readInt(DataInputStream.java:403)
114835 at
org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
114836 at
org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
114837 at
org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
114838 at
org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:515)
114839 2017-06-22 11:24:18,422 [myid:2147483652] - WARN
[LearnerHandler-/128.0.0.5:33610:LearnerHandler@619] - ******* GOODBYE
/128.0.0.5:33610 ********
114840 2017-06-22 11:24:18,422 [myid:2147483652] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:61808:NIOServerCnxnFactory$AcceptThread@296]
- Accepted socket connection from / 128.0.0.4:42854
114841 2017-06-22 11:24:18,422 [myid:2147483652] - INFO
[NIOWorkerThread-4:ZooKeeperServer@969] - Client attempting to renew session
0x40000007cef0001 at /128.0.0.4:42854
114842 2017-06-22 11:24:18,422 [myid:2147483652] - INFO
[NIOWorkerThread-4:ZooKeeperServer@678] - Established session 0x40000007cef0001
with negotiated timeout 20000 for client / 128.0.0.4:42854
114843 2017-06-22 11:24:18,423 [myid:2147483652] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:61808:NIOServerCnxnFactory$AcceptThread@296]
- Accepted socket connection from / 128.0.0.4:42862
114844 2017-06-22 11:24:18,423 [myid:2147483652] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:61808:NIOSe
{code}
After some time ..
{code:java}
114851 2017-06-22 11:24:18,423 [myid:2147483652] - INFO
[NIOWorkerThread-12:ZooKeeperServer@678] - Established session
0x40000007cef0003 with negotiated timeout 20000 for client /
128.0.0.4:42866
114852 2017-06-22 11:24:19,001 [myid:2147483652] - INFO
[NIOServerCxnFactory.AcceptThread:/0.0.0.0:61808:NIOServerCnxnFactory$AcceptThread@296]
- Accepted socket connection from / 128.0.0.4:42892
114853 2017-06-22 11:24:19,001 [myid:2147483652] - INFO
[NIOWorkerThread-13:ZooKeeperServer@964] - Client attempting to establish new
session at /128.0.0.4:42892
114854 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
[SessionTracker:ZooKeeperServer@384] - Expiring session 0x40000007cef016c,
timeout of 20000ms exceeded
114855 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
[SessionTracker:QuorumZooKeeperServer@132] - Submitting global closeSession
request for session 0x40000007cef016c
114856 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
[SessionTracker:ZooKeeperServer@384] - Expiring session 0x40000007cef016d,
timeout of 20000ms exceeded
114857 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
[ProcessThread(sid:2147483652 cport:-1)::PrepRequestProcessor@649] - Processed
session termination for sessionid: 0x40000007cef016c
114858 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
[SessionTracker:QuorumZooKeeperServer@132] - Submitting global closeSession
request for session 0x40000007cef016d
114859 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
[ProcessThread(sid:2147483652 cport:-1)::PrepRequestProcessor@649] - Processed
session termination for sessionid: 0x40000007cef016d
114860 2017-06-22 11:24:19,579 [myid:2147483652] - INFO
[QuorumPeer[myid=2147483652](plain=/0:0:0:0:0:0:0:0:61808)(secure=disabled):Leader@613]
- Shutting down
114861 2017-06-22 11:24:19,579 [myid:2147483652] - INFO
[QuorumPeer[myid=2147483652](plain=/0:0:0:0:0:0:0:0:61808)(secure=disabled):Leader@619]
- Shutdown called
114862 java.lang.Exception: shutdown Leader! reason: Not sufficient followers
synced, only synced with sids: [ [2147483652] ]
114863 at
org.apache.zookeeper.server.quorum.Leader.shutdown(Leader.java:619)
114864 at org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:590)
114865 at
org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1077)
114866 2017-06-22 11:24:19,579 [myid:2147483652] - INFO
[QuorumPeer[myid=2147483652](plain=/0:0:0:0:0:0:0:0:61808)(secure=disabled):MBeanRegistry@119]
- Unregister MBean [org.
apache.ZooKeeperService:name0=ReplicatedServer_id2147483652,name1=replica.2147483652,name2=Leader,name3=Connections,name4=128.0.0.4,name5=0x40000007cef006b]
114867 2017-06-22 11:24:19,579 [myid:2147483652] - INFO
[LearnerCnxAcceptor-0.0.0.0/0.0.0.0:61809:Leader$LearnerCnxAcceptor@373] -
exception while shutting down acceptor: java.net. SocketException: Socket
closed
114868 2017-06-22 11:24:19,581 [myid:2147483652] - INFO
[QuorumPeer[myid=2147483652](plain=/0:0:0:0:0:0:0:0:61808)(secure=disabled):NIOServerCnxn@606]
- Closed socket connection for client /128.0.0.4:41674 which had
sessionid 0x40000007cef006b
{code}
> Getting this error in ZK server logs : shutdown Leader! reason: Not
> sufficient followers synced, only synced with sids
> ----------------------------------------------------------------------------------------------------------------------
>
> Key: ZOOKEEPER-2848
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2848
> Project: ZooKeeper
> Issue Type: Bug
> Reporter: prashantkumar
>
> Hi
> I am seeing below error in ZK logs :
> "Unexpected exception causing shutdown while sock still open
> java.io.EOFException"
> and then ZK server shuts down with "shutdown Leader! reason: Not sufficient
> followers synced, only synced with sids: " error.
> I am using zookeeper-3.5.1-alpha version.
> it is ensemble of 2 servers
> Could you please help me resolve this issue
> Thanks
>
> config
> {code:java}
> initLimit=10
> syncLimit=5
> maxClientCnxns=0
> tickTime=2000
> quorumListenOnAllIPs=true
> dataDir=/var/run/zookeeper/conf/default
> admin.enableServer=false
> standaloneEnabled=false
> {code}
> zookeeper server logs
> {code:java}
> 114829 2017-06-22 11:24:18,182 [myid:2147483652] - INFO
> [ProcessThread(sid:2147483652 cport:-1)::PrepRequestProcessor@649] -
> Processed session termination for sessionid:
> 0x40000007cef003d
> 114830 2017-06-22 11:24:18,182 [myid:2147483652] - INFO
> [NIOWorkerThread-8:MBeanRegistry@119] - Unregister MBean
> [org.apache.ZooKeeperService:name0=ReplicatedServer_id2147483652,
> name1=replica.2147483652,name2=Leader,name3=Connections,name4=128.0.0.5,name5=0x40000007cef003d]
> 114831 2017-06-22 11:24:18,183 [myid:2147483652] - INFO
> [NIOWorkerThread-8:NIOServerCnxn@606] - Closed socket connection for client
> /128.0.0.5:34651 which had sessionid 0x40000007cef003d
> 114832 2017-06-22 11:24:18,421 [myid:2147483652] - ERROR
> [LearnerHandler-/128.0.0.5:33610:LearnerHandler@604] - Unexpected exception
> causing shutdown while sock still open
> 114833 java.io.EOFException
> 114834 at java.io.DataInputStream.readInt(DataInputStream.java:403)
> 114835 at
> org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
> 114836 at
> org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83)
> 114837 at
> org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99)
> 114838 at
> org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:515)
> 114839 2017-06-22 11:24:18,422 [myid:2147483652] - WARN
> [LearnerHandler-/128.0.0.5:33610:LearnerHandler@619] - ******* GOODBYE
> /128.0.0.5:33610 ********
> 114840 2017-06-22 11:24:18,422 [myid:2147483652] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:61808:NIOServerCnxnFactory$AcceptThread@296]
> - Accepted socket connection from / 128.0.0.4:42854
> 114841 2017-06-22 11:24:18,422 [myid:2147483652] - INFO
> [NIOWorkerThread-4:ZooKeeperServer@969] - Client attempting to renew session
> 0x40000007cef0001 at /128.0.0.4:42854
> 114842 2017-06-22 11:24:18,422 [myid:2147483652] - INFO
> [NIOWorkerThread-4:ZooKeeperServer@678] - Established session
> 0x40000007cef0001 with negotiated timeout 20000 for client /
> 128.0.0.4:42854
> 114843 2017-06-22 11:24:18,423 [myid:2147483652] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:61808:NIOServerCnxnFactory$AcceptThread@296]
> - Accepted socket connection from / 128.0.0.4:42862
> 114844 2017-06-22 11:24:18,423 [myid:2147483652] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:61808:NIOSe
>
> {code}
>
> After some time ..
> {code:java}
>
> 114851 2017-06-22 11:24:18,423 [myid:2147483652] - INFO
> [NIOWorkerThread-12:ZooKeeperServer@678] - Established session
> 0x40000007cef0003 with negotiated timeout 20000 for client /
> 128.0.0.4:42866
> 114852 2017-06-22 11:24:19,001 [myid:2147483652] - INFO
> [NIOServerCxnFactory.AcceptThread:/0.0.0.0:61808:NIOServerCnxnFactory$AcceptThread@296]
> - Accepted socket connection from / 128.0.0.4:42892
> 114853 2017-06-22 11:24:19,001 [myid:2147483652] - INFO
> [NIOWorkerThread-13:ZooKeeperServer@964] - Client attempting to establish new
> session at /128.0.0.4:42892
> 114854 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
> [SessionTracker:ZooKeeperServer@384] - Expiring session 0x40000007cef016c,
> timeout of 20000ms exceeded
> 114855 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
> [SessionTracker:QuorumZooKeeperServer@132] - Submitting global closeSession
> request for session 0x40000007cef016c
> 114856 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
> [SessionTracker:ZooKeeperServer@384] - Expiring session 0x40000007cef016d,
> timeout of 20000ms exceeded
> 114857 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
> [ProcessThread(sid:2147483652 cport:-1)::PrepRequestProcessor@649] -
> Processed session termination for sessionid:
> 0x40000007cef016c
> 114858 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
> [SessionTracker:QuorumZooKeeperServer@132] - Submitting global closeSession
> request for session 0x40000007cef016d
> 114859 2017-06-22 11:24:19,211 [myid:2147483652] - INFO
> [ProcessThread(sid:2147483652 cport:-1)::PrepRequestProcessor@649] -
> Processed session termination for sessionid:
> 0x40000007cef016d
> 114860 2017-06-22 11:24:19,579 [myid:2147483652] - INFO
> [QuorumPeer[myid=2147483652](plain=/0:0:0:0:0:0:0:0:61808)(secure=disabled):Leader@613]
> - Shutting down
> 114861 2017-06-22 11:24:19,579 [myid:2147483652] - INFO
> [QuorumPeer[myid=2147483652](plain=/0:0:0:0:0:0:0:0:61808)(secure=disabled):Leader@619]
> - Shutdown called
> 114862 java.lang.Exception: shutdown Leader! reason: Not sufficient followers
> synced, only synced with sids: [ [2147483652] ]
> 114863 at
> org.apache.zookeeper.server.quorum.Leader.shutdown(Leader.java:619)
> 114864 at org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:590)
> 114865 at
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1077)
> 114866 2017-06-22 11:24:19,579 [myid:2147483652] - INFO
> [QuorumPeer[myid=2147483652](plain=/0:0:0:0:0:0:0:0:61808)(secure=disabled):MBeanRegistry@119]
> - Unregister MBean [org.
> apache.ZooKeeperService:name0=ReplicatedServer_id2147483652,name1=replica.2147483652,name2=Leader,name3=Connections,name4=128.0.0.4,name5=0x40000007cef006b]
> 114867 2017-06-22 11:24:19,579 [myid:2147483652] - INFO
> [LearnerCnxAcceptor-0.0.0.0/0.0.0.0:61809:Leader$LearnerCnxAcceptor@373] -
> exception while shutting down acceptor: java.net. SocketException:
> Socket closed
> 114868 2017-06-22 11:24:19,581 [myid:2147483652] - INFO
> [QuorumPeer[myid=2147483652](plain=/0:0:0:0:0:0:0:0:61808)(secure=disabled):NIOServerCnxn@606]
> - Closed socket connection for client /128.0.0.4:41674 which had
> sessionid 0x40000007cef006b
> {code}
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
