Ah yeah the ConnectionLoss bubbled all the way up and it should have been retried, see https://issues.apache.org/jira/browse/HBASE-3065
J-D On Mon, Apr 25, 2011 at 11:25 PM, Gaojinchao <[email protected]> wrote: > Sorry, I don't know about zk. Please help me. > Thanks. > Do you mean that need change any ZK parameter? > > This is all logs about zk, Hmaster and client. > It seems like the problem is zk leader crashed. > > client logs: > > 11/04/26 12:25:04 INFO zookeeper.ClientCnxn: Unable to read additional data > from server sessionid 0x2f8fc38a81003b, likely server has closed socket, > closing socket connection and attempting reconnect > java.io.IOException: java.io.IOException: Unable to ensure that the table > will be enabled because of a ZooKeeper issue > at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native > Method) > at > sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39) > at > sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27) > at java.lang.reflect.Constructor.newInstance(Constructor.java:513) > at > org.apache.hadoop.ipc.RemoteException.instantiateException(RemoteException.java:96) > at > org.apache.hadoop.ipc.RemoteException.unwrapRemoteException(RemoteException.java:80) > at > org.apache.hadoop.hbase.client.HBaseAdmin.createTableAsync(HBaseAdmin.java:342) > at > org.apache.hadoop.hbase.client.HBaseAdmin.createTable(HBaseAdmin.java:302) > at > com.huawei.smartcare.performanceTuning.createTable.main(createTable.java:103) > Caused by: org.apache.hadoop.ipc.RemoteException: java.io.IOException: Unable > to ensure that the table will be enabled because of a ZooKeeper issue > at org.apache.hadoop.hbase.master.HMaster.createTable(HMaster.java:791) > at org.apache.hadoop.hbase.master.HMaster.createTable(HMaster.java:776) > at org.apache.hadoop.hbase.master.HMaster.createTable(HMaster.java:743) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > at java.lang.reflect.Method.invoke(Method.java:597) > at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:570) > at > org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1039) > Caused by: org.apache.zookeeper.KeeperException$ConnectionLossException: > KeeperErrorCode = ConnectionLoss for /hbase/table/ufdr > at org.apache.zookeeper.KeeperException.create(KeeperException.java:90) > at org.apache.zookeeper.KeeperException.create(KeeperException.java:42) > at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:728) > at > org.apache.hadoop.hbase.zookeeper.ZKUtil.deleteNodeFailSilent(ZKUtil.java:978) > at > org.apache.hadoop.hbase.zookeeper.ZKTable.setEnabledTable(ZKTable.java:297) > at org.apache.hadoop.hbase.master.HMaster.createTable(HMaster.java:789) > ... 8 more > > at org.apache.hadoop.hbase.ipc.HBaseClient.call(HBaseClient.java:771) > at > org.apache.hadoop.hbase.ipc.HBaseRPC$Invoker.invoke(HBaseRPC.java:257) > at $Proxy4.createTable(Unknown Source) > at > org.apache.hadoop.hbase.client.HBaseAdmin.createTableAsync(HBaseAdmin.java:340) > ... 2 more > > Hmaster Logs: > 2011-04-26 12:25:04,477 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: > closing hlog writer in > hdfs://C4C1:9000/hbase/ufdr/93b8fb6c7f35c2b32a2d510be764ccd2/.logs > 2011-04-26 12:25:04,513 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLog: > Moved 1 log files to /hbase/ufdr/93b8fb6c7f35c2b32a2d510be764ccd2/.oldlogs > 2011-04-26 12:25:04,537 INFO org.apache.zookeeper.ClientCnxn: Unable to read > additional data from server sessionid 0x2f8fc38a810006, likely server has > closed socket, closing socket connection and attempting reconnect > 2011-04-26 12:25:04,538 WARN org.apache.hadoop.hbase.zookeeper.ZKTable: > Moving table ufdr state to enabled but was already enabled > 2011-04-26 12:25:04,642 INFO org.apache.zookeeper.ClientCnxn: Opening socket > connection to server C4C2/157.5.100.2:2181 > 2011-04-26 12:25:04,642 INFO org.apache.zookeeper.ClientCnxn: Socket > connection established to C4C2/157.5.100.2:2181, initiating session > 2011-04-26 12:25:04,644 INFO org.apache.zookeeper.ClientCnxn: Unable to read > additional data from server sessionid 0x2f8fc38a810006, likely server has > closed socket, closing socket connection and attempting reconnect > 2011-04-26 12:25:05,430 INFO org.apache.zookeeper.ClientCnxn: Opening socket > connection to server C4C3/157.5.100.3:2181 > 2011-04-26 12:25:05,431 WARN org.apache.zookeeper.ClientCnxn: Session > 0x2f8fc38a810006 for server null, unexpected error, closing socket connection > and attempting reconnect > java.net.ConnectException: Connection refused > at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) > at > sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574) > at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1119) > 2011-04-26 12:25:05,606 INFO org.apache.zookeeper.ClientCnxn: Opening socket > connection to server C4C1/157.5.100.1:2181 > 2011-04-26 12:25:05,607 INFO org.apache.zookeeper.ClientCnxn: Socket > connection established to C4C1/157.5.100.1:2181, initiating session > 2011-04-26 12:25:05,607 INFO org.apache.zookeeper.ClientCnxn: Unable to read > additional data from server sessionid 0x2f8fc38a810006, likely server has > closed socket, closing socket connection and attempting reconnect > 2011-04-26 12:25:06,569 INFO org.apache.zookeeper.ClientCnxn: Opening socket > connection to server C4C2/157.5.100.2:2181 > 2011-04-26 12:25:06,570 INFO org.apache.zookeeper.ClientCnxn: Socket > connection established to C4C2/157.5.100.2:2181, initiating session > 2011-04-26 12:25:06,571 INFO org.apache.zookeeper.ClientCnxn: Unable to read > additional data from server sessionid 0x2f8fc38a810006, likely server has > closed socket, closing socket connection and attempting reconnect > 2011-04-26 12:25:06,722 INFO org.apache.zookeeper.ClientCnxn: Opening socket > connection to server C4C3/157.5.100.3:2181 > 2011-04-26 12:25:06,723 WARN org.apache.zookeeper.ClientCnxn: Session > 0x2f8fc38a810006 for server null, unexpected error, closing socket connection > and attempting reconnect > java.net.ConnectException: Connection refused > at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) > at > sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:574) > at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1119) > 2011-04-26 12:25:07,496 INFO org.apache.zookeeper.ClientCnxn: Opening socket > connection to server C4C1/157.5.100.1:2181 > 2011-04-26 12:25:07,496 INFO org.apache.zookeeper.ClientCnxn: Socket > connection established to C4C1/157.5.100.1:2181, initiating session > 2011-04-26 12:25:07,497 INFO org.apache.zookeeper.ClientCnxn: Session > establishment complete on server C4C1/157.5.100.1:2181, sessionid = > 0x2f8fc38a810006, negotiated timeout = 180000 > > ZK logs: > 2011-04-26 12:25:04,507 WARN > org.apache.zookeeper.server.quorum.QuorumCnxManager: Connection broken for id > 2, my id = 1, error = java.io.IOException: Channel eof > 2011-04-26 12:25:04,507 WARN org.apache.zookeeper.server.quorum.Learner: > Exception when following the leader > java.io.EOFException > at java.io.DataInputStream.readInt(DataInputStream.java:375) > at > org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63) > at > org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:84) > at > org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:108) > at > org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:140) > at > org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:78) > at > org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:644) > 2011-04-26 12:25:04,508 INFO org.apache.zookeeper.server.quorum.Learner: > shutdown called > java.lang.Exception: shutdown Follower > at > org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166) > at > org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:648) > 2011-04-26 12:25:04,508 INFO org.apache.zookeeper.server.NIOServerCnxn: > Closed socket connection for client /157.5.100.2:58431 which had sessionid > 0x12f8fc388e70002 > 2011-04-26 12:25:04,509 INFO org.apache.zookeeper.server.NIOServerCnxn: > Closed socket connection for client /157.5.100.3:47415 which had sessionid > 0x12f8fc388e70004 > 2011-04-26 12:25:04,510 INFO > org.apache.zookeeper.server.FinalRequestProcessor: shutdown of request > processor complete > 2011-04-26 12:25:04,510 INFO > org.apache.zookeeper.server.quorum.CommitProcessor: CommitProcessor exited > loop! > 2011-04-26 12:25:04,510 INFO > org.apache.zookeeper.server.quorum.FollowerRequestProcessor: > FollowerRequestProcessor exited loop! > 2011-04-26 12:25:04,510 INFO > org.apache.zookeeper.server.SyncRequestProcessor: SyncRequestProcessor exited! > 2011-04-26 12:25:04,510 INFO org.apache.zookeeper.server.quorum.QuorumPeer: > LOOKING > 2011-04-26 12:25:04,529 INFO > org.apache.zookeeper.server.persistence.FileSnap: Reading snapshot > /tmp/hbase-root/zookeeper/version-2/snapshot.ad00000000 > 2011-04-26 12:25:04,617 INFO org.apache.zookeeper.server.NIOServerCnxn: > Accepted socket connection from /157.5.100.1:47986 > 2011-04-26 12:25:04,618 WARN org.apache.zookeeper.server.NIOServerCnxn: > Exception causing close of session 0x0 due to java.io.IOException: > ZooKeeperServer not running > 2011-04-26 12:25:04,618 INFO org.apache.zookeeper.server.NIOServerCnxn: > Closed socket connection for client /157.5.100.1:47986 (no session > established for client) > 2011-04-26 12:25:04,691 INFO org.apache.zookeeper.server.NIOServerCnxn: > Accepted socket connection from /157.5.100.5:46718 > 2011-04-26 12:25:04,692 WARN org.apache.zookeeper.server.NIOServerCnxn: > Exception causing close of session 0x0 due to java.io.IOException: > ZooKeeperServer not running > 2011-04-26 12:25:04,692 INFO org.apache.zookeeper.server.NIOServerCnxn: > Closed socket connection for client /157.5.100.5:46718 (no session > established for client) > 2011-04-26 12:25:04,709 INFO > org.apache.zookeeper.server.quorum.FastLeaderElection: New election. My id = > 1, Proposed zxid = 743029366343 > 2011-04-26 12:25:04,710 INFO > org.apache.zookeeper.server.quorum.FastLeaderElection: Notification: 1 > (n.leader), 743029366343 (n.zxid), 2 (n.round), LOOKING (n.state), 1 (n.sid), > LOOKING (my state) > 2011-04-26 12:25:04,710 WARN > org.apache.zookeeper.server.quorum.QuorumCnxManager: Exception when using > channel: for id 2 my id = 1 error = java.nio.channels.ClosedChannelException > 2011-04-26 12:25:04,710 WARN > org.apache.zookeeper.server.quorum.QuorumCnxManager: Send worker leaving > thread > 2011-04-26 12:25:04,717 INFO > org.apache.zookeeper.server.quorum.FastLeaderElection: Notification: 0 > (n.leader), 743029366343 (n.zxid), 2 (n.round), LOOKING (n.state), 0 (n.sid), > LOOKING (my state) > 2011-04-26 12:25:04,718 INFO > org.apache.zookeeper.server.quorum.FastLeaderElection: Notification: 1 > (n.leader), 743029366343 (n.zxid), 2 (n.round), LOOKING (n.state), 0 (n.sid), > LOOKING (my state) > 2011-04-26 12:25:04,918 INFO org.apache.zookeeper.server.quorum.QuorumPeer: > LEADING > 2011-04-26 12:25:04,920 INFO org.apache.zookeeper.server.quorum.Leader: TCP > NoDelay set to: true > 2011-04-26 12:25:04,921 INFO org.apa > > -- >
