[
https://issues.apache.org/jira/browse/HBASE-21307?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16655253#comment-16655253
]
stack commented on HBASE-21307:
-------------------------------
Thank you [~allan163]. I appreciate the discussion. I did not make the
connection to HBASE-21288. I was going to say that my issue was different but
on closer inspection -- see below -- it seems indeed to be a case of
HBASE-21288... (we queue an SCP for a different server).
{code}
2018-10-13 15:57:11,672 DEBUG
org.apache.hadoop.hbase.procedure2.ProcedureExecutor: Stored pid=3002482,
state=RUNNABLE:MOVE_REGION_UNASSIGN; MoveRegionProcedure
hri=834e00afb73b93cbb7fedb3bd3ecde1b,
source=vc1010.halxg.cloudera.com,22101,1539402130080,
destination=vc0430.halxg.cloudera.com,22101,1539402135919
2018-10-13 15:57:11,678 INFO
org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler: xlock for
pid=3002482, state=RUNNABLE:MOVE_REGION_UNASSIGN; MoveRegionProcedure
hri=834e00afb73b93cbb7fedb3bd3ecde1b,
source=vc1010.halxg.cloudera.com,22101,1539402130080,
destination=vc0430.halxg.cloudera.com,22101,1539402135919
2018-10-13 15:57:11,701 INFO
org.apache.hadoop.hbase.procedure2.ProcedureExecutor: Initialized
subprocedures=[{pid=3002483, ppid=3002482,
state=RUNNABLE:REGION_TRANSITION_DISPATCH; UnassignProcedure
table=IntegrationTestBigLinkedList_20180622115214,
region=834e00afb73b93cbb7fedb3bd3ecde1b, override=true,
server=vc1010.halxg.cloudera.com,22101,1539402130080}]
2018-10-13 15:57:11,718 INFO
org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler: xlock for
pid=3002483, ppid=3002482, state=RUNNABLE:REGION_TRANSITION_DISPATCH;
UnassignProcedure table=IntegrationTestBigLinkedList_20180622115214,
region=834e00afb73b93cbb7fedb3bd3ecde1b, override=true,
server=vc1010.halxg.cloudera.com,22101,1539402130080
2018-10-13 15:57:11,751 INFO
org.apache.hadoop.hbase.master.assignment.RegionStateStore: pid=3002483
updating hbase:meta row=834e00afb73b93cbb7fedb3bd3ecde1b, regionState=CLOSING,
regionLocation=vc1010.halxg.cloudera.com,22101,1539237401308
2018-10-13 15:57:11,754 INFO
org.apache.hadoop.hbase.master.assignment.RegionTransitionProcedure: Dispatch
pid=3002483, ppid=3002482, state=RUNNABLE:REGION_TRANSITION_DISPATCH,
locked=true; UnassignProcedure
table=IntegrationTestBigLinkedList_20180622115214,
region=834e00afb73b93cbb7fedb3bd3ecde1b, override=true,
server=vc1010.halxg.cloudera.com,22101,1539402130080
2018-10-13 15:57:11,754 WARN
org.apache.hadoop.hbase.master.assignment.RegionTransitionProcedure: Remote
call failed pid=3002483, ppid=3002482,
state=RUNNABLE:REGION_TRANSITION_DISPATCH, locked=true; UnassignProcedure
table=IntegrationTestBigLinkedList_20180622115214,
region=834e00afb73b93cbb7fedb3bd3ecde1b, override=true,
server=vc1010.halxg.cloudera.com,22101,1539402130080 rit=CLOSING,
location=vc1010.halxg.cloudera.com,22101,1539237401308
org.apache.hadoop.hbase.procedure2.NoServerDispatchException:
vc1010.halxg.cloudera.com,22101,1539237401308; pid=3002483, ppid=3002482,
state=RUNNABLE:REGION_TRANSITION_DISPATCH, locked=true; UnassignProcedure
table=IntegrationTestBigLinkedList_20180622115214,
region=834e00afb73b93cbb7fedb3bd3ecde1b, override=true,
server=vc1010.halxg.cloudera.com,22101,1539402130080
at
org.apache.hadoop.hbase.procedure2.RemoteProcedureDispatcher.addOperationToNode(RemoteProcedureDispatcher.java:177)
at
org.apache.hadoop.hbase.master.assignment.RegionTransitionProcedure.addToRemoteDispatcher(RegionTransitionProcedure.java:276)
at
org.apache.hadoop.hbase.master.assignment.UnassignProcedure.updateTransition(UnassignProcedure.java:206)
at
org.apache.hadoop.hbase.master.assignment.RegionTransitionProcedure.execute(RegionTransitionProcedure.java:369)
at
org.apache.hadoop.hbase.master.assignment.RegionTransitionProcedure.execute(RegionTransitionProcedure.java:97)
at
org.apache.hadoop.hbase.procedure2.Procedure.doExecute(Procedure.java:953)
at
org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execProcedure(ProcedureExecutor.java:1754)
at
org.apache.hadoop.hbase.procedure2.ProcedureExecutor.executeProcedure(ProcedureExecutor.java:1532)
at
org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$1100(ProcedureExecutor.java:79)
at
org.apache.hadoop.hbase.procedure2.ProcedureExecutor$WorkerThread.run(ProcedureExecutor.java:2059)
2018-10-13 15:57:11,755 WARN
org.apache.hadoop.hbase.master.assignment.UnassignProcedure: Expiring
vc1010.halxg.cloudera.com,22101,1539237401308, pid=3002483, ppid=3002482,
state=RUNNABLE:REGION_TRANSITION_DISPATCH, locked=true; UnassignProcedure
table=IntegrationTestBigLinkedList_20180622115214,
region=834e00afb73b93cbb7fedb3bd3ecde1b, override=true,
server=vc1010.halxg.cloudera.com,22101,1539402130080 rit=CLOSING,
location=vc1010.halxg.cloudera.com,22101,1539237401308;
exception=NoServerDispatchException
2018-10-13 15:57:11,755 DEBUG org.apache.hadoop.hbase.master.DeadServer: Added
vc1010.halxg.cloudera.com,22101,1539237401308; numProcessing=1
2018-10-13 15:57:11,756 INFO org.apache.hadoop.hbase.master.ServerManager:
Expiration called on vc1010.halxg.cloudera.com,22101,1539237401308 but NOT
online
2018-10-13 15:57:11,756 INFO org.apache.hadoop.hbase.master.ServerManager:
Processing expiration of vc1010.halxg.cloudera.com,22101,1539237401308 on
vc0212.halxg.cloudera.com,22001,1539393249841
2018-10-13 15:57:11,791 DEBUG
org.apache.hadoop.hbase.procedure2.ProcedureExecutor: Stored pid=3002484,
state=RUNNABLE:SERVER_CRASH_START; ServerCrashProcedure
server=vc1010.halxg.cloudera.com,22101,1539237401308, splitWal=true, meta=false
2018-10-13 15:57:11,791 DEBUG
org.apache.hadoop.hbase.master.assignment.AssignmentManager:
Added=vc1010.halxg.cloudera.com,22101,1539237401308 to dead servers, submitted
shutdown handler to be executed meta=false
2018-10-13 15:57:11,810 DEBUG org.apache.hadoop.hbase.master.DeadServer:
Started processing vc1010.halxg.cloudera.com,22101,1539237401308;
numProcessing=1
2018-10-13 15:57:11,810 INFO
org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure: Start
pid=3002484, state=RUNNABLE:SERVER_CRASH_START, locked=true;
ServerCrashProcedure server=vc1010.halxg.cloudera.com,22101,1539237401308,
splitWal=true, meta=false
2018-10-13 15:57:12,010 DEBUG
org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure: Splitting WALs
pid=3002484, state=RUNNABLE:SERVER_CRASH_SPLIT_LOGS, locked=true;
ServerCrashProcedure server=vc1010.halxg.cloudera.com,22101,1539237401308,
splitWal=true, meta=false
2018-10-13 15:57:12,013 INFO org.apache.hadoop.hbase.master.MasterWalManager:
Log dir for server vc1010.halxg.cloudera.com,22101,1539237401308 does not exist
2018-10-13 15:57:12,013 DEBUG org.apache.hadoop.hbase.master.SplitLogManager:
Dead splitlog workers [vc1010.halxg.cloudera.com,22101,1539237401308]
2018-10-13 15:57:12,013 INFO org.apache.hadoop.hbase.master.SplitLogManager:
Finished splitting (more than or equal to) 0 bytes in 0 log files in [] in 0ms
2018-10-13 15:57:12,013 DEBUG
org.apache.hadoop.hbase.master.procedure.ServerCrashProcedure: Done splitting
WALs pid=3002484, state=RUNNABLE:SERVER_CRASH_SPLIT_LOGS, locked=true;
ServerCrashProcedure server=vc1010.halxg.cloudera.com,22101,1539237401308,
splitWal=true, meta=false
pid=3002580, ppid=3002484, state=RUNNABLE:REGION_TRANSITION_QUEUE;
AssignProcedure table=IntegrationTestBigLinkedList_20180622115214,
region=834e00afb73b93cbb7fedb3bd3ecde1b
{code}
bq. ....Another question, why SCP rollbacked?
Its because I tried to bypass the MRP....by bypassing its UP subprocedure. It
'completed' but still had reference to original Procedure in RN.... The SCP
then tried to run but failed against this UP because it owned by another...
bq. Should we consider remove the reference when bypassing, like the early
solutions in HBASE-21213?
In this case, the earlier soln., would have been better. The MRP would have
been by-passed and then SCP would be able to run to completion rather than as
here it did a rollback and then needed fixup to get regions back online.
I believe [~Apache9] would argue that indeed, the operator needs to intervene
to 'fixup' this situation which I can appreciate but in this case, the RN
reference makes the original 'problem' larger.
Let me see if I can turn up another case where the Procedure reference in RN
makes things worse.
> [amv2] Deadlock when we move a Region from a not-online RegionServer
> --------------------------------------------------------------------
>
> Key: HBASE-21307
> URL: https://issues.apache.org/jira/browse/HBASE-21307
> Project: HBase
> Issue Type: Bug
> Components: amv2
> Affects Versions: 2.1.1
> Reporter: stack
> Assignee: stack
> Priority: Critical
> Fix For: 2.1.1
>
>
> Perhaps this doesn't happen in branch-2, but its problem in branch-2.1.
> Highlevel, we go to move a region, its unassign subprocedure fails its
> dispatch because the server is not online so it queues a SCP and waits on it
> to break the RPC. The SCP can't run though because the MRP holds lock on the
> region.
> I can bypass the MRP but then the SCP fails because Region is 'owned' by the
> MRP. See below:
> {code}
> 2018-10-12 16:29:53,423 INFO
> org.apache.hadoop.hbase.procedure2.ProcedureExecutor: Begin bypass
> pid=411982, ppid=411981, state=RUNNABLE:REGION_TRANSITION_DISPATCH,
> locked=true; UnassignProcedure
> table=IntegrationTestBigLinkedList_20180709093726,
> region=f5f9ff1e4b0f2d9555dabfcca71df568, override=true,
> server=va1002.halxg.cloudera.com,22101,1539368318649 with lockWait=0,
> override=true, recursive=true
> 2018-10-12 16:29:53,424 INFO
> org.apache.hadoop.hbase.procedure2.ProcedureExecutor: Bypassing pid=411982,
> ppid=411981, state=RUNNABLE:REGION_TRANSITION_DISPATCH, locked=true;
> UnassignProcedure table=IntegrationTestBigLinkedList_20180709093726,
> region=f5f9ff1e4b0f2d9555dabfcca71df568, override=true,
> server=va1002.halxg.cloudera.com,22101,1539368318649
> 2018-10-12 16:29:53,712 INFO
> org.apache.hadoop.hbase.procedure2.ProcedureExecutor: Bypassing pid=411981,
> state=WAITING:MOVE_REGION_ASSIGN, locked=true; MoveRegionProcedure
> hri=f5f9ff1e4b0f2d9555dabfcca71df568,
> source=va1002.halxg.cloudera.com,22101,1539368318649,
> destination=vd1021.halxg.cloudera.com,22101,1539368317897
> 2018-10-12 16:29:53,838 INFO
> org.apache.hadoop.hbase.procedure2.ProcedureExecutor: Bypassing pid=411982,
> ppid=411981, state=RUNNABLE:REGION_TRANSITION_DISPATCH, locked=true,
> bypass=LOG-REDACTED UnassignProcedure
> table=IntegrationTestBigLinkedList_20180709093726,
> region=f5f9ff1e4b0f2d9555dabfcca71df568, override=true,
> server=va1002.halxg.cloudera.com,22101,1539368318649 and its ancestors
> successfully, adding to queue
> 2018-10-12 16:29:53,839 INFO org.apache.hadoop.hbase.procedure2.Procedure:
> pid=411982, ppid=411981, state=RUNNABLE:REGION_TRANSITION_DISPATCH,
> locked=true, bypass=LOG-REDACTED UnassignProcedure
> table=IntegrationTestBigLinkedList_20180709093726,
> region=f5f9ff1e4b0f2d9555dabfcca71df568, override=true,
> server=va1002.halxg.cloudera.com,22101,1539368318649 bypassed, returning null
> to finish it
> 2018-10-12 16:29:53,954 INFO
> org.apache.hadoop.hbase.procedure2.ProcedureExecutor: Finished subprocedure
> pid=411982, resume processing parent pid=411981,
> state=RUNNABLE:MOVE_REGION_ASSIGN, locked=true, bypass=LOG-REDACTED
> MoveRegionProcedure hri=f5f9ff1e4b0f2d9555dabfcca71df568,
> source=va1002.halxg.cloudera.com,22101,1539368318649,
> destination=vd1021.halxg.cloudera.com,22101,1539368317897
> 2018-10-12 16:29:53,954 INFO org.apache.hadoop.hbase.procedure2.Procedure:
> pid=411981, state=RUNNABLE:MOVE_REGION_ASSIGN, locked=true,
> bypass=LOG-REDACTED MoveRegionProcedure hri=f5f9ff1e4b0f2d9555dabfcca71df568,
> source=va1002.halxg.cloudera.com,22101,1539368318649,
> destination=vd1021.halxg.cloudera.com,22101,1539368317897 bypassed, returning
> null to finish it
> 2018-10-12 16:29:53,956 INFO
> org.apache.hadoop.hbase.procedure2.ProcedureExecutor: Finished pid=411982,
> ppid=411981, state=SUCCESS, bypass=LOG-REDACTED UnassignProcedure
> table=IntegrationTestBigLinkedList_20180709093726,
> region=f5f9ff1e4b0f2d9555dabfcca71df568, override=true,
> server=va1002.halxg.cloudera.com,22101,1539368318649 in 3hrs, 49mins,
> 12.419sec, unfinishedSiblingCount=0
> 2018-10-12 16:29:54,058 INFO
> org.apache.hadoop.hbase.procedure2.ProcedureExecutor: Finished pid=411981,
> state=SUCCESS, bypass=LOG-REDACTED MoveRegionProcedure
> hri=f5f9ff1e4b0f2d9555dabfcca71df568,
> source=va1002.halxg.cloudera.com,22101,1539368318649,
> destination=vd1021.halxg.cloudera.com,22101,1539368317897 in 3hrs, 49mins,
> 12.878sec
> 2018-10-12 16:29:54,059 INFO
> org.apache.hadoop.hbase.master.procedure.MasterProcedureScheduler: xlock for
> pid=412210, ppid=411983, state=RUNNABLE:REGION_TRANSITION_QUEUE;
> AssignProcedure table=IntegrationTestBigLinkedList_20180709093726,
> region=f5f9ff1e4b0f2d9555dabfcca71df568
> 2018-10-12 16:29:54,105 WARN
> org.apache.hadoop.hbase.master.assignment.RegionTransitionProcedure:
> f5f9ff1e4b0f2d9555dabfcca71df568 owned by pid=411982, CANNOT run 'this'
> (pid=412210).
> ....
> {code}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
