Rushabh S Shah created HBASE-22601: -------------------------------------- Summary: Misconfigured addition of peers leads to cluster shutdown. Key: HBASE-22601 URL: https://issues.apache.org/jira/browse/HBASE-22601 Project: HBase Issue Type: Bug Affects Versions: 1.3.2 Reporter: Rushabh S Shah
Recently we added a peer to a production cluster which were in different kerberos realm. *Steps to reproduce:* 1. Add a misconfigured peer which is in different kerberos realm. 2. Remove that peer. 3. All region servers will start to crash. *RCA* Enabled trace logging on one Region server for a short amount of time. After adding peer, saw the following log lines. {noformat} 2019-06-18 22:19:20,949 INFO [main-EventThread] replication.ReplicationTrackerZKImpl - /hbase/replication/peers znode expired, triggering peerListChanged event 2019-06-18 22:19:20,992 INFO [main-EventThread] replication.ReplicationPeersZKImpl - Added new peer cluster=<dev-cluster-zookeeper>:/hbase 2019-06-18 22:19:21,113 INFO [main-EventThread] zookeeper.RecoverableZooKeeper - Process identifier=hconnection-0x794a56d6 connecting to ZooKeeper ensemble=<dev-cluster-zookeeper> 2019-06-18 22:20:01,280 WARN [main-EventThread] zookeeper.ZKUtil - hconnection-0x794a56d6-0x16b56265fbebb1b, quorum=<dev-cluster-zookeeper>, baseZNode=/hbase Unable to set watcher on znode (/hbase/hbaseid) org.apache.zookeeper.KeeperException$AuthFailedException: KeeperErrorCode = AuthFailed for /hbase/hbaseid at org.apache.zookeeper.KeeperException.create(KeeperException.java:123) at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1102) at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.exists(RecoverableZooKeeper.java:220) at org.apache.hadoop.hbase.zookeeper.ZKUtil.checkExists(ZKUtil.java:421) at org.apache.hadoop.hbase.zookeeper.ZKClusterId.readClusterIdZNode(ZKClusterId.java:65) at org.apache.hadoop.hbase.client.ZooKeeperRegistry.getClusterId(ZooKeeperRegistry.java:105) at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.retrieveClusterId(ConnectionManager.java:922) at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.<init>(ConnectionManager.java:706) at org.apache.hadoop.hbase.client.ConnectionManager$HConnectionImplementation.<init>(ConnectionManager.java:638) at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:423) at org.apache.hadoop.hbase.client.ConnectionFactory.createConnection(ConnectionFactory.java:238) at org.apache.hadoop.hbase.client.ConnectionManager.createConnection(ConnectionManager.java:432) at org.apache.hadoop.hbase.client.ConnectionManager.createConnectionInternal(ConnectionManager.java:341) at org.apache.hadoop.hbase.client.HConnectionManager.createConnection(HConnectionManager.java:144) at org.apache.hadoop.hbase.replication.regionserver.HBaseInterClusterReplicationEndpoint.init(HBaseInterClusterReplicationEndpoint.java:135) at com.salesforce.hbase.replication.TenantReplicationEndpoint.init(TenantReplicationEndpoint.java:30) at org.apache.hadoop.hbase.replication.regionserver.ReplicationSourceManager.getReplicationSource(ReplicationSourceManager.java:517) at org.apache.hadoop.hbase.replication.regionserver.ReplicationSourceManager.addSource(ReplicationSourceManager.java:273) at org.apache.hadoop.hbase.replication.regionserver.ReplicationSourceManager.peerListChanged(ReplicationSourceManager.java:635) at org.apache.hadoop.hbase.replication.ReplicationTrackerZKImpl$PeersWatcher.nodeChildrenChanged(ReplicationTrackerZKImpl.java:192) at org.apache.hadoop.hbase.zookeeper.ZooKeeperWatcher.process(ZooKeeperWatcher.java:643) at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:544) at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:519) 2019-06-18 22:20:43,002 TRACE [Source,<dev-cluster>] regionserver.ReplicationSource - Cannot contact the peer's zk ensemble, sleeping 1000 times 1 <same stack trace as before> 2019-06-18 22:20:44,008 TRACE [Source,<dev-cluster>] regionserver.ReplicationSource - Cannot contact the peer's zk ensemble, sleeping 1000 times 2 <same stack trace as before> {noformat} This goes on and on until we removed the peer. After removing the peer, {noformat} 2019-06-18 22:21:20,731 INFO [main-EventThread] replication.ReplicationTrackerZKImpl - /hbase/replication/peers/<dev-cluster> znode expired, triggering peerRemoved event 2019-06-18 22:21:20,731 INFO [main-EventThread] regionserver.ReplicationSourceManager - Closing the following queue <dev-cluster>, currently have 2 and another 0 that were recovered 2019-06-18 22:21:20,733 INFO [main-EventThread] regionserver.ReplicationSourceManager - Number of deleted recovered sources for <dev-cluster>: 0 2019-06-18 22:21:20,734 INFO [main-EventThread] regionserver.ReplicationSource - Closing source <dev-cluster> because: Replication stream was removed by a user 2019-06-18 22:21:20,734 INFO [main-EventThread] replication.TenantReplicationEndpoint - Stopping endpoint 2019-06-18 22:21:20,736 INFO [main-EventThread] client.ConnectionManager$HConnectionImplementation - Closing zookeeper sessionid=0x16b56265fbebb1b 2019-06-18 22:21:20,736 DEBUG [main-EventThread] ipc.RpcClientImpl - Stopping rpc client 2019-06-18 22:21:20,738 INFO [main-EventThread] regionserver.ReplicationSourceManager - Done with the queue <dev-cluster> 2019-06-18 22:21:20,744 DEBUG [main-EventThread] replication.ReplicationQueuesZKImpl - Peer /hbase/replication/hfile-refs/<dev-cluster> not found in hfile reference queue. 2019-06-18 22:21:28,066 INFO [Source,<dev-cluster>] regionserver.ReplicationSource - Replicating d12a5eb3-16bd-4910-91ed-41e0e7990007 -> null 2019-06-18 22:21:28,067 DEBUG [Source,<dev-cluster>] regionserver.ReplicationSource - Starting up worker for wal group <rs-serner-name>%2C60020%2C1560896050398 2019-06-18 22:21:28,069 ERROR [050398,<dev-cluster>] regionserver.ReplicationSource - Unexpected exception in ReplicationSourceWorkerThread, currentPath=null java.lang.IllegalArgumentException: Peer with id= <dev-cluster> is not connected at org.apache.hadoop.hbase.replication.ReplicationPeersZKImpl.getStatusOfPeer(ReplicationPeersZKImpl.java:217) at org.apache.hadoop.hbase.replication.regionserver.ReplicationSource.isPeerEnabled(ReplicationSource.java:363) at org.apache.hadoop.hbase.replication.regionserver.ReplicationSource$ReplicationSourceWorkerThread.run(ReplicationSource.java:549) 2019-06-18 22:21:28,070 INFO [050398,dev7hdaas_prd] regionserver.HRegionServer - STOPPED: Unexpected exception in ReplicationSourceWorkerThread 2019-06-18 22:21:28,071 INFO [/10.231.90.212:60020] regionserver.SplitLogWorker - Sending interrupt to stop the worker thread 2019-06-18 22:21:28,073 INFO [/10.231.90.212:60020] regionserver.HRegionServer - Stopping infoServer 2019-06-18 22:21:28,075 INFO [as-dnds4-3-prd:60020] regionserver.SplitLogWorker - SplitLogWorker interrupted. Exiting. 2019-06-18 22:21:28,076 INFO [as-dnds4-3-prd:60020] regionserver.SplitLogWorker - SplitLogWorker <rs-server-name>,60020,1560896050398 exiting 2019-06-18 22:21:28,181 INFO [/10.231.90.212:60020] regionserver.HeapMemoryManager - Stopping HeapMemoryTuner chore. 2019-06-18 22:21:28,181 INFO [/10.231.90.212:60020] flush.RegionServerFlushTableProcedureManager - Stopping region server flush procedure manager gracefully. {noformat} Also verified from jstacks I captured between addition of peer and removal of peer, the Replication source thread was sleeping waiting to connect to peer. {noformat} "main-EventThread.replicationSource,<dev-cluster>" #1923 daemon prio=5 os_prio=0 tid=0x00007f1ad18f4800 nid=0x25a47 waiting on condition [0x00007f1220314000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.apache.hadoop.hbase.replication.regionserver.ReplicationSource.sleepForRetries(ReplicationSource.java:349) at org.apache.hadoop.hbase.replication.regionserver.ReplicationSource.run(ReplicationSource.java:306) {noformat} According to me, the bug lies here: {code:java|title=ReplicationSource.java|borderStyle=solid} // Some comments here public void run() { { .... .... while (this.isSourceActive() && this.peerClusterId == null) { this.peerClusterId = replicationEndpoint.getPeerUUID(); if (this.isSourceActive() && this.peerClusterId == null) { if (sleepForRetries("Cannot contact the peer's zk ensemble", sleepMultiplier)) { sleepMultiplier++; } } } !-- There is a bug here. We should check that peerClusterId is not null. If null, then terminate the thread. --> // In rare case, zookeeper setting may be messed up. That leads to the incorrect // peerClusterId value, which is the same as the source clusterId if (clusterId.equals(peerClusterId) && !replicationEndpoint.canReplicateToSameCluster()) { this.terminate("ClusterId " + clusterId + " is replicating to itself: peerClusterId " + peerClusterId + " which is not allowed by ReplicationEndpoint:" + replicationEndpoint.getClass().getName(), null, false); this.manager.closeQueue(this); return; } .... .... } {code} -- This message was sent by Atlassian JIRA (v7.6.3#76005)