You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@hbase.apache.org by "LiangJun He (Jira)" <ji...@apache.org> on 2022/05/12 15:53:00 UTC

[jira] [Created] (HBASE-27029) When HMaster is stopped, the HMaster local region cache cannot be flushed normally

LiangJun He created HBASE-27029:
-----------------------------------

             Summary: When HMaster is stopped, the HMaster local region cache cannot be flushed normally
                 Key: HBASE-27029
                 URL: https://issues.apache.org/jira/browse/HBASE-27029
             Project: HBase
          Issue Type: Bug
          Components: master
    Affects Versions: 3.0.0-alpha-3
            Reporter: LiangJun He
            Assignee: LiangJun He
             Fix For: 3.0.0-alpha-3


After HBASE-26951, HMaster can be stoped gracefully. For example, the internal threads of HMaster can be closed normally, but I found that the local region of HMaster still cannot be closed normally.

The following is my test error message:
{code:java}
Wed May 11 14:48:56 CST 2022 Terminating master
2022-05-11 14:48:56,382 INFO  [shutdown-hook-0] regionserver.ShutdownHook: Shutdown hook starting; hbase.shutdown.hook=true; fsShutdownHook=org.apache.hadoop.fs.FileSystem$Cache$ClientFinalizer@4f4c789f
2022-05-11 14:48:56,382 INFO  [shutdown-hook-0] master.HMaster: ***** STOPPING master 'emr-header-1.cluster-xxxxx,16000,1652240899395' *****
2022-05-11 14:48:56,382 INFO  [shutdown-hook-0] master.HMaster: STOPPED: Shutdown hook
......
......
2022-05-11 14:48:57,367 ERROR [KeepAlivePEWorker-41] assignment.RegionStateStore: FAILED persisting region=23a692981e91e944d380a8bdf4b50c7e state=OPEN
org.apache.hadoop.hbase.ipc.StoppedRpcClientException: Call to address=emr-worker-1.cluster-xxxxx:16020 failed on local exception: org.apache.hadoop.hbase.ipc.StoppedRpcClientException
    at java.lang.Thread.getStackTrace(Thread.java:1559)
    at org.apache.hadoop.hbase.util.FutureUtils.setStackTrace(FutureUtils.java:130)
    at org.apache.hadoop.hbase.util.FutureUtils.rethrow(FutureUtils.java:149)
    at org.apache.hadoop.hbase.util.FutureUtils.get(FutureUtils.java:172)
    at org.apache.hadoop.hbase.client.TableOverAsyncTable.put(TableOverAsyncTable.java:214)
    at org.apache.hadoop.hbase.master.assignment.RegionStateStore.updateRegionLocation(RegionStateStore.java:259)
    at org.apache.hadoop.hbase.master.assignment.RegionStateStore.updateRegionLocation(RegionStateStore.java:224)
    at org.apache.hadoop.hbase.master.assignment.AssignmentManager.persistToMeta(AssignmentManager.java:2034)
    at org.apache.hadoop.hbase.master.assignment.RegionRemoteProcedureBase.execute(RegionRemoteProcedureBase.java:297)
    at org.apache.hadoop.hbase.master.assignment.RegionRemoteProcedureBase.execute(RegionRemoteProcedureBase.java:57)
    at org.apache.hadoop.hbase.procedure2.Procedure.doExecute(Procedure.java:953)
    at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execProcedure(ProcedureExecutor.java:1667)
    at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.executeProcedure(ProcedureExecutor.java:1414)
    at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$1100(ProcedureExecutor.java:78)
    at org.apache.hadoop.hbase.procedure2.ProcedureExecutor$WorkerThread.run(ProcedureExecutor.java:1981)
    at --------Future.get--------(Unknown Source)
    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:210)
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient.onCallFinished(AbstractRpcClient.java:388)
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient.access$100(AbstractRpcClient.java:92)
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient$3.run(AbstractRpcClient.java:422)
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient$3.run(AbstractRpcClient.java:417)
    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.AbstractRpcClient.callMethod(AbstractRpcClient.java:443)
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient.access$300(AbstractRpcClient.java:92)
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient$RpcChannelImplementation.callMethod(AbstractRpcClient.java:614)
    at org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ClientService$Stub.mutate(ClientProtos.java:46147)
    at org.apache.hadoop.hbase.client.RawAsyncTableImpl.lambda$mutate$0(RawAsyncTableImpl.java:175)
    at org.apache.hadoop.hbase.client.ConnectionUtils.call(ConnectionUtils.java:616)
    at org.apache.hadoop.hbase.client.RawAsyncTableImpl.mutate(RawAsyncTableImpl.java:174)
    at org.apache.hadoop.hbase.client.RawAsyncTableImpl.voidMutate(RawAsyncTableImpl.java:181)
    at org.apache.hadoop.hbase.client.RawAsyncTableImpl.lambda$null$8(RawAsyncTableImpl.java:249)
    at org.apache.hadoop.hbase.client.AsyncSingleRequestRpcRetryingCaller.call(AsyncSingleRequestRpcRetryingCaller.java:82)
    at org.apache.hadoop.hbase.client.AsyncSingleRequestRpcRetryingCaller.lambda$doCall$7(AsyncSingleRequestRpcRetryingCaller.java:115)
    at org.apache.hadoop.hbase.util.FutureUtils.lambda$addListener$0(FutureUtils.java:68)
    at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:760)
    at java.util.concurrent.CompletableFuture.uniWhenCompleteStage(CompletableFuture.java:778)
    at java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:2140)
    at org.apache.hadoop.hbase.util.FutureUtils.addListener(FutureUtils.java:61)
    at org.apache.hadoop.hbase.client.AsyncSingleRequestRpcRetryingCaller.doCall(AsyncSingleRequestRpcRetryingCaller.java:106)
    at org.apache.hadoop.hbase.client.AsyncRpcRetryingCaller.lambda$tryScheduleRetry$0(AsyncRpcRetryingCaller.java:142)
    at org.apache.hbase.thirdparty.io.netty.util.HashedWheelTimer$HashedWheelTimeout.run(HashedWheelTimer.java:715)
    at org.apache.hbase.thirdparty.io.netty.util.concurrent.ImmediateExecutor.execute(ImmediateExecutor.java:34)
    at org.apache.hbase.thirdparty.io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:703)
    at org.apache.hbase.thirdparty.io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:790)
    at org.apache.hbase.thirdparty.io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:503)
    at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.hadoop.hbase.ipc.StoppedRpcClientException
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient.getConnection(AbstractRpcClient.java:360)
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient.callMethod(AbstractRpcClient.java:440)
    ... 23 more
2022-05-11 14:48:57,367 WARN  [KeepAlivePEWorker-41] assignment.RegionRemoteProcedureBase: Failed updating meta, suspend 1secs pid=1793261, ppid=1791968, state=RUNNABLE, hasLock=true; OpenRegionProcedure 23a692981e91e944d380a8bdf4b50c7e, server=emr-worker-2.cluster-xxxx,16020,1652240898881, retry=org.apache.hadoop.hbase.util.RetryCounter@2f42033b; state=OPEN, location=emr-worker-2.cluster-18941,16020,1652240898881, table=usertable, region=23a692981e91e944d380a8bdf4b50c7e;
org.apache.hadoop.hbase.ipc.StoppedRpcClientException: Call to address=emr-worker-1.cluster-18941:16020 failed on local exception: org.apache.hadoop.hbase.ipc.StoppedRpcClientException
    at java.lang.Thread.getStackTrace(Thread.java:1559)
    at org.apache.hadoop.hbase.util.FutureUtils.setStackTrace(FutureUtils.java:130)
    at org.apache.hadoop.hbase.util.FutureUtils.rethrow(FutureUtils.java:149)
    at org.apache.hadoop.hbase.util.FutureUtils.get(FutureUtils.java:172)
    at org.apache.hadoop.hbase.client.TableOverAsyncTable.put(TableOverAsyncTable.java:214)
    at org.apache.hadoop.hbase.master.assignment.RegionStateStore.updateRegionLocation(RegionStateStore.java:259)
    at org.apache.hadoop.hbase.master.assignment.RegionStateStore.updateRegionLocation(RegionStateStore.java:224)
    at org.apache.hadoop.hbase.master.assignment.AssignmentManager.persistToMeta(AssignmentManager.java:2034)
    at org.apache.hadoop.hbase.master.assignment.RegionRemoteProcedureBase.execute(RegionRemoteProcedureBase.java:297)
    at org.apache.hadoop.hbase.master.assignment.RegionRemoteProcedureBase.execute(RegionRemoteProcedureBase.java:57)
    at org.apache.hadoop.hbase.procedure2.Procedure.doExecute(Procedure.java:953)
    at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execProcedure(ProcedureExecutor.java:1667)
    at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.executeProcedure(ProcedureExecutor.java:1414)
    at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$1100(ProcedureExecutor.java:78)
    at org.apache.hadoop.hbase.procedure2.ProcedureExecutor$WorkerThread.run(ProcedureExecutor.java:1981)
    at --------Future.get--------(Unknown Source)
    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:210)
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient.onCallFinished(AbstractRpcClient.java:388)
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient.access$100(AbstractRpcClient.java:92)
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient$3.run(AbstractRpcClient.java:422)
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient$3.run(AbstractRpcClient.java:417)
    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.AbstractRpcClient.callMethod(AbstractRpcClient.java:443)
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient.access$300(AbstractRpcClient.java:92)
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient$RpcChannelImplementation.callMethod(AbstractRpcClient.java:614)
    at org.apache.hadoop.hbase.shaded.protobuf.generated.ClientProtos$ClientService$Stub.mutate(ClientProtos.java:46147)
    at org.apache.hadoop.hbase.client.RawAsyncTableImpl.lambda$mutate$0(RawAsyncTableImpl.java:175)
    at org.apache.hadoop.hbase.client.ConnectionUtils.call(ConnectionUtils.java:616)
    at org.apache.hadoop.hbase.client.RawAsyncTableImpl.mutate(RawAsyncTableImpl.java:174)
    at org.apache.hadoop.hbase.client.RawAsyncTableImpl.voidMutate(RawAsyncTableImpl.java:181)
    at org.apache.hadoop.hbase.client.RawAsyncTableImpl.lambda$null$8(RawAsyncTableImpl.java:249)
    at org.apache.hadoop.hbase.client.AsyncSingleRequestRpcRetryingCaller.call(AsyncSingleRequestRpcRetryingCaller.java:82)
    at org.apache.hadoop.hbase.client.AsyncSingleRequestRpcRetryingCaller.lambda$doCall$7(AsyncSingleRequestRpcRetryingCaller.java:115)
    at org.apache.hadoop.hbase.util.FutureUtils.lambda$addListener$0(FutureUtils.java:68)
    at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:760)
    at java.util.concurrent.CompletableFuture.uniWhenCompleteStage(CompletableFuture.java:778)
    at java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:2140)
    at org.apache.hadoop.hbase.util.FutureUtils.addListener(FutureUtils.java:61)
    at org.apache.hadoop.hbase.client.AsyncSingleRequestRpcRetryingCaller.doCall(AsyncSingleRequestRpcRetryingCaller.java:106)
    at org.apache.hadoop.hbase.client.AsyncRpcRetryingCaller.lambda$tryScheduleRetry$0(AsyncRpcRetryingCaller.java:142)
    at org.apache.hbase.thirdparty.io.netty.util.HashedWheelTimer$HashedWheelTimeout.run(HashedWheelTimer.java:715)
    at org.apache.hbase.thirdparty.io.netty.util.concurrent.ImmediateExecutor.execute(ImmediateExecutor.java:34)
    at org.apache.hbase.thirdparty.io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:703)
    at org.apache.hbase.thirdparty.io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:790)
    at org.apache.hbase.thirdparty.io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:503)
    at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.hadoop.hbase.ipc.StoppedRpcClientException
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient.getConnection(AbstractRpcClient.java:360)
    at org.apache.hadoop.hbase.ipc.AbstractRpcClient.callMethod(AbstractRpcClient.java:440)
    ... 23 more
.....
.....
2022-05-11 14:49:13,232 INFO  [master/emr-header-1:16000] region.MasterRegion: Closing local region {ENCODED => 1595e783b53d99cd5eef43b6debb2682, NAME => 'master:store,,1.1595e783b53d99cd5eef43b6debb2682.', STARTKEY => '', ENDKEY => ''}, isAbort=true
2022-05-11 14:49:13,237 INFO  [master/emr-header-1:16000] regionserver.HRegion: Closing region master:store,,1.1595e783b53d99cd5eef43b6debb2682.
2022-05-11 14:49:13,243 ERROR [master/emr-header-1:16000] regionserver.HRegion: Memstore data size is 139232 in region master:store,,1.1595e783b53d99cd5eef43b6debb2682.
2022-05-11 14:49:13,243 INFO  [master/emr-header-1:16000] regionserver.HRegion: Closed master:store,,1.1595e783b53d99cd5eef43b6debb2682.
2022-05-11 14:49:13,377 ERROR [main] master.HMasterCommandLine: Master exiting
java.lang.RuntimeException: HMaster Aborted
    at org.apache.hadoop.hbase.master.HMasterCommandLine.startMaster(HMasterCommandLine.java:251)
    at org.apache.hadoop.hbase.master.HMasterCommandLine.run(HMasterCommandLine.java:144)
    at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:76)
    at org.apache.hadoop.hbase.util.ServerCommandLine.doMain(ServerCommandLine.java:144)
    at org.apache.hadoop.hbase.master.HMaster.main(HMaster.java:3209) {code}
 

Finally HMaster exit due to abort, the local region cache cannot be flushed normally

successfully.

 

I also found another error that also causes the same problem:
{code:java}
2022-05-11 23:57:03,228 INFO  [master/emr-header-1:16000] hbase.HBaseServerBase: Shutdown executor service
2022-05-11 23:57:03,229 INFO  [master/emr-header-1:16000] procedure2.RemoteProcedureDispatcher: Stopping procedure remote dispatcher
2022-05-11 23:57:03,229 INFO  [master/emr-header-1:16000] procedure2.ProcedureExecutor: Stopping
2022-05-11 23:57:05,481 WARN  [master/emr-header-1:16000] procedure2.StoppableThread: Waiting termination of thread PEWorker-7, 2.2510 sec; sending interrupt
2022-05-11 23:57:05,481 ERROR [PEWorker-7] assignment.RegionStateStore: FAILED persisting region=7ff63515f9ce9d876618e3f1bee7dc03 state=OPEN
java.io.InterruptedIOException
        at org.apache.hadoop.hbase.util.FutureUtils.get(FutureUtils.java:170)
        at org.apache.hadoop.hbase.client.TableOverAsyncTable.put(TableOverAsyncTable.java:214)
        at org.apache.hadoop.hbase.master.assignment.RegionStateStore.updateRegionLocation(RegionStateStore.java:259)
        at org.apache.hadoop.hbase.master.assignment.RegionStateStore.updateRegionLocation(RegionStateStore.java:224)
        at org.apache.hadoop.hbase.master.assignment.AssignmentManager.persistToMeta(AssignmentManager.java:2034)
        at org.apache.hadoop.hbase.master.assignment.RegionRemoteProcedureBase.execute(RegionRemoteProcedureBase.java:297)
        at org.apache.hadoop.hbase.master.assignment.RegionRemoteProcedureBase.execute(RegionRemoteProcedureBase.java:57)
        at org.apache.hadoop.hbase.procedure2.Procedure.doExecute(Procedure.java:953)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execProcedure(ProcedureExecutor.java:1667)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.executeProcedure(ProcedureExecutor.java:1414)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$1100(ProcedureExecutor.java:78)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor$WorkerThread.run(ProcedureExecutor.java:1981)
Caused by: java.lang.InterruptedException
        at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:347)
        at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1895)
        at org.apache.hadoop.hbase.util.FutureUtils.get(FutureUtils.java:168)
        ... 11 more
2022-05-11 23:57:05,482 WARN  [PEWorker-7] assignment.RegionRemoteProcedureBase: Failed updating meta, suspend 1secs pid=1845211, ppid=1844964, state=RUNNABLE, hasLock=true; OpenRegionProcedure 7ff63515f9
ce9d876618e3f1bee7dc03, server=emr-worker-2.cluster-18941,16020,1652263346995, retry=org.apache.hadoop.hbase.util.RetryCounter@4a8e233; state=OPEN, location=emr-worker-2.cluster-18941,16020,1652263346995,
 table=usertable, region=7ff63515f9ce9d876618e3f1bee7dc03;
java.io.InterruptedIOException
        at org.apache.hadoop.hbase.util.FutureUtils.get(FutureUtils.java:170)
        at org.apache.hadoop.hbase.client.TableOverAsyncTable.put(TableOverAsyncTable.java:214)
        at org.apache.hadoop.hbase.master.assignment.RegionStateStore.updateRegionLocation(RegionStateStore.java:259)
        at org.apache.hadoop.hbase.master.assignment.RegionStateStore.updateRegionLocation(RegionStateStore.java:224)
        at org.apache.hadoop.hbase.master.assignment.AssignmentManager.persistToMeta(AssignmentManager.java:2034)
        at org.apache.hadoop.hbase.master.assignment.RegionRemoteProcedureBase.execute(RegionRemoteProcedureBase.java:297)
        at org.apache.hadoop.hbase.master.assignment.RegionRemoteProcedureBase.execute(RegionRemoteProcedureBase.java:57)
        at org.apache.hadoop.hbase.procedure2.Procedure.doExecute(Procedure.java:953)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execProcedure(ProcedureExecutor.java:1667)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.executeProcedure(ProcedureExecutor.java:1414)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$1100(ProcedureExecutor.java:78)
        at org.apache.hadoop.hbase.procedure2.ProcedureExecutor$WorkerThread.run(ProcedureExecutor.java:1981)
Caused by: java.lang.InterruptedException
        at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:347)
        at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1895)
        at org.apache.hadoop.hbase.util.FutureUtils.get(FutureUtils.java:168)
        ... 11 more {code}



--
This message was sent by Atlassian Jira
(v8.20.7#820007)