Viraj Jasani created HBASE-28366:
------------------------------------
Summary: Mis-order of SCP and regionServerReport results into
region inconsistencies
Key: HBASE-28366
URL: https://issues.apache.org/jira/browse/HBASE-28366
Project: HBase
Issue Type: Bug
Affects Versions: 2.5.7, 3.0.0-beta-1, 2.4.17
Reporter: Viraj Jasani
If the regionserver is online but due to network issue, if it's rs ephemeral
node gets deleted in zookeeper, active master schedules the SCP. However, if
the regionserver is alive, it can still send regionServerReport to active
master. In the case where SCP assigns regions to other regionserver that were
previously hosted on the old regionserver (which is still alive), the old rs
can continue to sent regionServerReport to active master.
Eventually this results into region inconsistencies because region is alive on
two regionservers at the same time. While old regionserver can have zookeeper
connectivity issues, it can still make rpc calls to active master.
Logs:
SCP:
{code:java}
2024-01-29 16:50:33,956 INFO [RegionServerTracker-0]
assignment.AssignmentManager - Scheduled ServerCrashProcedure pid=9812440 for
server1-114.xyz,61020,1706541866103 (carryingMeta=false)
server1-114.xyz,61020,1706541866103/CRASHED/regionCount=364/lock=java.util.concurrent.locks.ReentrantReadWriteLock@5d5fc31[Write
locks = 1, Read locks = 0], oldState=ONLINE.
2024-01-29 16:50:33,956 DEBUG [RegionServerTracker-0]
procedure2.ProcedureExecutor - Stored pid=9812440,
state=RUNNABLE:SERVER_CRASH_START; ServerCrashProcedure
server1-114.xyz,61020,1706541866103, splitWal=true, meta=false
2024-01-29 16:50:33,973 INFO [PEWorker-36] procedure.ServerCrashProcedure -
Splitting WALs pid=9812440, state=RUNNABLE:SERVER_CRASH_SPLIT_LOGS,
locked=true; ServerCrashProcedure server1-114.xyz,61020,1706541866103,
splitWal=true, meta=false, isMeta: false
{code}
As part of SCP, d743ace9f70d55f55ba1ecc6dc49a5cb was assigned to another server:
{code:java}
2024-01-29 16:50:42,656 INFO [PEWorker-24] procedure.MasterProcedureScheduler -
Took xlock for pid=9818494, ppid=9812440,
state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE;
TransitRegionStateProcedure
table=PLATFORM_ENTITY.PLATFORM_IMMUTABLE_ENTITY_DATA,
region=d743ace9f70d55f55ba1ecc6dc49a5cb, ASSIGN
2024-01-29 16:50:43,106 INFO [PEWorker-23] assignment.RegionStateStore -
pid=9818494 updating hbase:meta row=d743ace9f70d55f55ba1ecc6dc49a5cb,
regionState=OPEN, repBarrier=12867482, openSeqNum=12867482,
regionLocation=server1-65.xyz,61020,1706165574050
{code}
rs abort, after ~5 min:
{code:java}
2024-01-29 16:54:27,235 ERROR [regionserver/server1-114:61020]
regionserver.HRegionServer - ***** ABORTING region server
server1-114.xyz,61020,1706541866103: Unexpected exception handling getData *****
org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode =
ConnectionLoss for /hbase/master
at org.apache.zookeeper.KeeperException.create(KeeperException.java:102)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:54)
at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1229)
at
org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.getData(RecoverableZooKeeper.java:414)
at org.apache.hadoop.hbase.zookeeper.ZKUtil.getDataInternal(ZKUtil.java:403)
at org.apache.hadoop.hbase.zookeeper.ZKUtil.getDataAndWatch(ZKUtil.java:367)
at
org.apache.hadoop.hbase.zookeeper.ZKNodeTracker.getData(ZKNodeTracker.java:180)
at
org.apache.hadoop.hbase.zookeeper.MasterAddressTracker.getMasterAddress(MasterAddressTracker.java:152)
at
org.apache.hadoop.hbase.regionserver.HRegionServer.createRegionServerStatusStub(HRegionServer.java:2892)
at
org.apache.hadoop.hbase.regionserver.HRegionServer.tryRegionServerReport(HRegionServer.java:1352)
at
org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:1142)
{code}
Several region transition failure report logs:
{code:java}
2024-01-29 16:55:13,029 INFO [_REGION-regionserver/server1-114:61020-0]
regionserver.HRegionServer - Failed report transition server { host_name:
"server1-114.xyz" port: 61020 start_code: 1706541866103 } transition {
transition_code: CLOSED region_info { region_id: 1671555604277 table_name {
namespace: "default" qualifier: "TABLE1" } start_key: "abc" end_key: "xyz"
offline: false split: false replica_id: 0 } proc_id: -1 }; retry (#0)
immediately.
java.net.UnknownHostException: Call to address=master-server1.xyz:61000 failed
on local exception: java.net.UnknownHostException: master-server1.xyz:61000
could not be resolved
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.ipc.IPCUtil.wrapException(IPCUtil.java:239)
at
org.apache.hadoop.hbase.ipc.AbstractRpcClient.onCallFinished(AbstractRpcClient.java:391)
at
org.apache.hadoop.hbase.ipc.AbstractRpcClient.access$100(AbstractRpcClient.java:92)
at
org.apache.hadoop.hbase.ipc.AbstractRpcClient$3.run(AbstractRpcClient.java:425)
at
org.apache.hadoop.hbase.ipc.AbstractRpcClient$3.run(AbstractRpcClient.java:420)
at org.apache.hadoop.hbase.ipc.Call.callComplete(Call.java:114)
at org.apache.hadoop.hbase.ipc.Call.setException(Call.java:129)
at
org.apache.hadoop.hbase.ipc.NettyRpcConnection.lambda$sendRequest$4(NettyRpcConnection.java:365)
at
org.apache.hbase.thirdparty.io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174)
at
org.apache.hbase.thirdparty.io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167)
at
org.apache.hbase.thirdparty.io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
at
org.apache.hbase.thirdparty.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:403)
at
org.apache.hbase.thirdparty.io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
at
org.apache.hbase.thirdparty.io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at
org.apache.hbase.thirdparty.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:750)
Caused by: java.net.UnknownHostException: master-server1.xyz:61000 could not be
resolved
at
org.apache.hadoop.hbase.ipc.RpcConnection.getRemoteInetAddress(RpcConnection.java:192)
at
org.apache.hadoop.hbase.ipc.NettyRpcConnection.connect(NettyRpcConnection.java:280)
at
org.apache.hadoop.hbase.ipc.NettyRpcConnection.access$900(NettyRpcConnection.java:79)
at
org.apache.hadoop.hbase.ipc.NettyRpcConnection$5.run(NettyRpcConnection.java:340)
at
org.apache.hadoop.hbase.ipc.HBaseRpcControllerImpl.notifyOnCancel(HBaseRpcControllerImpl.java:259)
at
org.apache.hadoop.hbase.ipc.NettyRpcConnection.sendRequest0(NettyRpcConnection.java:323)
at
org.apache.hadoop.hbase.ipc.NettyRpcConnection.lambda$sendRequest$4(NettyRpcConnection.java:363)
... 8 more
{code}
The server is later started after sometime:
{code:java}
Mon Jan 29 17:01:35 UTC 2024 Starting regionserver on server1-114.xyz
core file size (blocks, -c) unlimited
...
... {code}
In order to avoid region inconsistencies, we should clear regionserver ->
region reported map from active master. We can do it in two ways:
# Active: master should throw error while serving regionServerReport call if
the server is already considered dead due to deletion of ephemeral znode.
# Passive: run a chore that can compare the regionserver -> region map
generated from the regionserver reports with the actual live servers based on
the zk tracking, and remove any rs report that is no longer valid.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
