[
https://issues.apache.org/jira/browse/HBASE-20202?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16478340#comment-16478340
]
Sergey Soldatov commented on HBASE-20202:
-----------------------------------------
bq. On the the new master, it will notice this and re-run the step that was
doing the close step... That is what should happen sir.
Correct. It happens almost in that way. But in my case it's a bit more
complicated :
We have modified a table (chaos monkey changed bloom filter) and when
ModifyTableProcedure was executed, and master was killed during execution of
UnassignProcedure when one of the regions was closing
New master had the following list of not successful procedures during the
startup:
UnassignProcedure pid=766, ppid=754
MoveRegionProcedure pid=754, ppid=749
ModifyTableProcedure pid=749
Once master got online, UnassignProcedure started:
{noformat}
2018-05-15 21:48:23,787 INFO [PEWorker-8] assignment.RegionStateStore: pid=766
updating hbase:meta row=92e0d39ee7e6d19566c393bae58ab5c0, regionState=CLOSING
2018-05-15 21:48:23,820 INFO [PEWorker-8]
assignment.RegionTransitionProcedure: Dispatch pid=766, ppid=754,
state=RUNNABLE:REGION_TRANSITION_DISPATCH; UnassignProcedure
table=IntegrationTestBigLinkedList, region=92e0d39ee7e6d19566c393bae58ab5c0,
server=ctr-e138-15181
{noformat}
Not sure what exactly triggered that (any retry logic from the client? I don't
see any logs from the chaos monkey for that action), but suddenly master is
trying to execute an another ModifyTableProcedure. And it started from the
state
MODIFY_TABLE_REOPEN_ALL_REGIONS which tries to reopen all regions using
MoveRegionProcedure. And because our region is not online, it fails due that
checkOnline:
{noformat}
2018-05-15 21:48:29,684 INFO
[RpcServer.default.FPBQ.Fifo.handler=27,queue=0,port=20000] bzip2.Bzip2Factory:
Successfully loaded & initialized native-bzip2 library system-native
2018-05-15 21:48:29,685 INFO
[RpcServer.default.FPBQ.Fifo.handler=27,queue=0,port=20000] compress.CodecPool:
Got brand-new compressor [.bz2]
2018-05-15 21:48:29,744 INFO
[RpcServer.default.FPBQ.Fifo.handler=27,queue=0,port=20000] compress.CodecPool:
Got brand-new compressor [.lz4]
2018-05-15 21:48:29,788 INFO
[RpcServer.default.FPBQ.Fifo.handler=27,queue=0,port=20000] master.HMaster:
Client=hbase//172.27.86.70 modify IntegrationTestBigLinkedList
2018-05-15 21:48:29,902 DEBUG
[RpcServer.default.FPBQ.Fifo.handler=27,queue=0,port=20000]
procedure2.ProcedureExecutor: Stored pid=790,
state=RUNNABLE:MODIFY_TABLE_PREPARE; ModifyTableProcedure
table=IntegrationTestBigLinkedList
2018-05-15 21:48:29,969 DEBUG [PEWorker-4] util.FSTableDescriptors: Wrote into
hdfs://mycluster/apps/hbase/data/data/default/IntegrationTestBigLinkedList/.tabledesc/.tableinfo.0000000006
2018-05-15 21:48:29,972 DEBUG [PEWorker-4] util.FSTableDescriptors: Deleted
hdfs://mycluster/apps/hbase/data/data/default/IntegrationTestBigLinkedList/.tabledesc/.tableinfo.0000000005
2018-05-15 21:48:29,972 INFO [PEWorker-4] util.FSTableDescriptors: Updated
tableinfo=hdfs://mycluster/apps/hbase/data/data/default/IntegrationTestBigLinkedList/.tabledesc/.tableinfo.0000000006
2018-05-15 21:48:30,004 WARN [PEWorker-4] procedure.ModifyTableProcedure:
Retriable error trying to modify table=IntegrationTestBigLinkedList (in
state=MODIFY_TABLE_REOPEN_ALL_REGIONS)
org.apache.hadoop.hbase.client.DoNotRetryRegionException:
92e0d39ee7e6d19566c393bae58ab5c0 is not OPEN
at
org.apache.hadoop.hbase.master.procedure.AbstractStateMachineTableProcedure.checkOnline(AbstractStateMachineTableProcedure.java:193)
at
org.apache.hadoop.hbase.master.assignment.MoveRegionProcedure.<init>(MoveRegionProcedure.java:67)
at
org.apache.hadoop.hbase.master.assignment.AssignmentManager.createMoveRegionProcedure(AssignmentManager.java:767)
at
org.apache.hadoop.hbase.master.assignment.AssignmentManager.createReopenProcedures(AssignmentManager.java:705)
at
org.apache.hadoop.hbase.master.procedure.ModifyTableProcedure.executeFromState(ModifyTableProcedure.java:128)
at
org.apache.hadoop.hbase.master.procedure.ModifyTableProcedure.executeFromState(ModifyTableProcedure.java:50)
at
org.apache.hadoop.hbase.procedure2.StateMachineProcedure.execute(StateMachineProcedure.java:184)
at
org.apache.hadoop.hbase.procedure2.Procedure.doExecute(Procedure.java:850)
at
org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execProcedure(ProcedureExecutor.java:1472)
at
org.apache.hadoop.hbase.procedure2.ProcedureExecutor.executeProcedure(ProcedureExecutor.java:1240)
at
org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$800(ProcedureExecutor.java:75)
at
org.apache.hadoop.hbase.procedure2.ProcedureExecutor$WorkerThread.run(ProcedureExecutor.java:1760)
2018-05-15 21:48:30,027 WARN [PEWorker-4] procedure.ModifyTableProcedure:
Retriable error trying to modify table=IntegrationTestBigLinkedList (in
state=MODIFY_TABLE_REOPEN_ALL_REGIONS)
org.apache.hadoop.hbase.client.DoNotRetryRegionException:
92e0d39ee7e6d19566c393bae58ab5c0 is not OPEN
{noformat}
sometime later RS reported back that the transition is completed.
RS side:
{noformat}
2018-05-15 21:48:30,303 INFO
[RS_CLOSE_REGION-regionserver/ctr-e138-1518143905142-313088-01-000005:16020-2]
regionserver.HRegionServer: TRANSITION REPORTED server {
host_name: "ctr-e138-1518143905142-313088-01-000005.hwx.site"
port: 16020
start_code: 1526420112539
}
transition {
transition_code: CLOSED
region_info {
region_id: 1526420201907
table_name {
namespace: "default"
qualifier: "IntegrationTestBigLinkedList"
}
start_key: "UUUUUUUT"
end_key: "j\252\252\252\252\252\252\251"
offline: false
split: false
replica_id: 0
}
}
{noformat}
master side:
{noformat}
2018-05-15 21:48:30,301 DEBUG
[RpcServer.default.FPBQ.Fifo.handler=28,queue=1,port=20000]
assignment.RegionTransitionProcedure: Received report CLOSED seqId=-1, pid=766,
ppid=754, state=RUNNABLE:REGION_TRANSITION_DISPATCH; UnassignProcedure
table=IntegrationTestBigLinkedList, region=92e0d39ee7e6d19566c393bae58ab5c0,
server=ctr-e138-1518143905142-313088-01-000005.hwx.site,16020,1526420112539;
rit=CLOSING,
location=ctr-e138-1518143905142-313088-01-000005.hwx.site,16020,1526420112539
{noformat}
but that didn't trigger MoveRegionProcedure(pid=754). I believe because
ModifyTableProcedure(pid=790) was still continuously failing with early
mentioned retriable error (and it was doing that next hour)
I'm working on the test case to reproduce this problem but hopefully will have
more details soon.
> [AMv2] Don't move region if its a split parent or offlined
> ----------------------------------------------------------
>
> Key: HBASE-20202
> URL: https://issues.apache.org/jira/browse/HBASE-20202
> Project: HBase
> Issue Type: Sub-task
> Components: amv2
> Affects Versions: 2.0.0-beta-2
> Reporter: stack
> Assignee: stack
> Priority: Critical
> Fix For: 2.0.0
>
> Attachments: HBASE-20202.branch-2.001.patch,
> HBASE-20202.branch-2.002.patch, HBASE-20202.branch-2.003.patch,
> HBASE-20202.branch-2.003.patch
>
>
> Found this one running ITBLLs. We'd just finished splitting a region
> 91655de06786f786b0ee9c51280e1ee6 and then a move for it comes in. The move
> fails in an interesting way. The location has been removed from the
> regionnode kept by the Master. HBASE-20178 adds macro checks on context. Need
> to add a few checks to the likes of MoveRegionProcedure so we don't try to
> move an offlined/split parent.
> {code}
> 2018-03-14 10:21:45,678 INFO [PEWorker-2] procedure2.ProcedureExecutor:
> Finished pid=3177, state=SUCCESS; SplitTableRegionProcedure
> table=IntegrationTestBigLinkedList, parent=91655de06786f786b0ee9c51280e1ee6,
> daughterA=b67bf6b79eaa83de788b0519f782ce8e,
> daughterB=99cf6ddb38cad08e3aa7635b6cac2e7b in 10.0210sec
> 2018-03-14 10:21:45,679 INFO [PEWorker-15]
> procedure.MasterProcedureScheduler: pid=3194, ppid=3193,
> state=RUNNABLE:REGION_TRANSITION_DISPATCH; UnassignProcedure
> table=IntegrationTestBigLinkedList, region=af198ca64b196fb3d2f5b3e815b2dad0,
> server=ve0530.halxg.cloudera.com,16020,1521007509855,
> IntegrationTestBigLinkedList,\xAA\xAA\xAA\xAA\xAA\xAA\xAA\xA0,1521047891276.af198ca64b196fb3d2f5b3e815b2dad0.
> 2018-03-14 10:21:45,680 INFO [PEWorker-5]
> procedure.MasterProcedureScheduler: pid=3187,
> state=RUNNABLE:MOVE_REGION_UNASSIGN; MoveRegionProcedure
> hri=IntegrationTestBigLinkedList,\x0C0\xC3\x0C0\xC3\x0C0,1521045713137.91655de06786f786b0ee9c51280e1ee6.,
> source=ve0530.halxg.cloudera.com,16020,1521007509855,
> destination=ve0528.halxg.cloudera.com,16020,1521047890874,
> IntegrationTestBigLinkedList,\x0C0\xC3\x0C0\xC3\x0C0,1521045713137.91655de06786f786b0ee9c51280e1ee6.
> 2018-03-14 10:21:45,680 INFO [PEWorker-15] assignment.RegionStateStore:
> pid=3194 updating hbase:meta
> row=IntegrationTestBigLinkedList,\xAA\xAA\xAA\xAA\xAA\xAA\xAA\xA0,1521047891276.af198ca64b196fb3d2f5b3e815b2dad0.,
> regionState=CLOSING
> 2018-03-14 10:21:45,680 INFO [PEWorker-5] procedure2.ProcedureExecutor:
> Initialized subprocedures=[{pid=3195, ppid=3187,
> state=RUNNABLE:REGION_TRANSITION_DISPATCH; UnassignProcedure
> table=IntegrationTestBigLinkedList, region=91655de06786f786b0ee9c51280e1ee6,
> server=ve0530.halxg.cloudera.com,16020,1521007509855}]
> 2018-03-14 10:21:45,683 INFO [PEWorker-15]
> assignment.RegionTransitionProcedure: Dispatch pid=3194, ppid=3193,
> state=RUNNABLE:REGION_TRANSITION_DISPATCH; UnassignProcedure
> table=IntegrationTestBigLinkedList, region=af198ca64b196fb3d2f5b3e815b2dad0,
> server=ve0530.halxg.cloudera.com,16020,1521007509855; rit=CLOSING,
> location=ve0530.halxg.cloudera.com,16020,1521007509855
> 2018-03-14 10:21:45,752 INFO [PEWorker-15]
> procedure.MasterProcedureScheduler: pid=3195, ppid=3187,
> state=RUNNABLE:REGION_TRANSITION_DISPATCH; UnassignProcedure
> table=IntegrationTestBigLinkedList, region=91655de06786f786b0ee9c51280e1ee6,
> server=ve0530.halxg.cloudera.com,16020,1521007509855,
> IntegrationTestBigLinkedList,\x0C0\xC3\x0C0\xC3\x0C0,1521045713137.91655de06786f786b0ee9c51280e1ee6.
> 2018-03-14 10:21:45,753 ERROR [PEWorker-15] procedure2.ProcedureExecutor:
> CODE-BUG: Uncaught runtime exception: pid=3195, ppid=3187,
> state=RUNNABLE:REGION_TRANSITION_DISPATCH; UnassignProcedure
> table=IntegrationTestBigLinkedList, region=91655de06786f786b0ee9c51280e1ee6,
> server=ve0530.halxg.cloudera.com,16020,1521007509855
> java.lang.NullPointerException
>
>
>
> at
> java.util.concurrent.ConcurrentHashMap.get(ConcurrentHashMap.java:936)
> at
> org.apache.hadoop.hbase.master.assignment.RegionStates.getOrCreateServer(RegionStates.java:934)
> at
> org.apache.hadoop.hbase.master.assignment.RegionStates.addRegionToServer(RegionStates.java:962)
> at
> org.apache.hadoop.hbase.master.assignment.AssignmentManager.markRegionAsClosing(AssignmentManager.java:1548)
>
>
> at
> org.apache.hadoop.hbase.master.assignment.UnassignProcedure.updateTransition(UnassignProcedure.java:197)
> at
> org.apache.hadoop.hbase.master.assignment.RegionTransitionProcedure.execute(RegionTransitionProcedure.java:304)
>
>
> at
> org.apache.hadoop.hbase.master.assignment.RegionTransitionProcedure.execute(RegionTransitionProcedure.java:86)
> at
> org.apache.hadoop.hbase.procedure2.Procedure.doExecute(Procedure.java:845)
> at
> org.apache.hadoop.hbase.procedure2.ProcedureExecutor.execProcedure(ProcedureExecutor.java:1452)
> at
> org.apache.hadoop.hbase.procedure2.ProcedureExecutor.executeProcedure(ProcedureExecutor.java:1221)
> at
> org.apache.hadoop.hbase.procedure2.ProcedureExecutor.access$800(ProcedureExecutor.java:75)
> at
> org.apache.hadoop.hbase.procedure2.ProcedureExecutor$WorkerThread.run(ProcedureExecutor.java:1740)
>
>
>
> 2018-03-14 10:21:45,835 DEBUG [RSProcedureDispatcher-pool3-t22]
> ipc.NettyRpcConnection: Connecting to
> ve0530.halxg.cloudera.com/10.17.240.23:16020
> {code}
> Will work on this after HBASE-20178
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
