Sergey Shelukhin created HBASE-21531:
----------------------------------------
Summary: race between region report and region move causes master
to kill RS
Key: HBASE-21531
URL: https://issues.apache.org/jira/browse/HBASE-21531
Project: HBase
Issue Type: Bug
Reporter: Sergey Shelukhin
In this case the delay between the ack from RS and the region report was 1.5s,
so I'm not sure what caused the race (network hiccup? unreported retry by
protobuf transport?) but in any case I don't see anything that prevents this
from happening in a normal case, with a narrowed time window. Any delay (e.g. a
GC pause on RS right after the report is built, and ack is sent for the close)
or retries expands the window.
Master starts moving the region and the source RS acks by 21:51,206
{noformat}
Master:
2018-11-21 21:21:49,024 INFO [master/6:17000.Chore.1] master.HMaster: balance
hri=<region hash>, source=<RS 1>,17020,1542754626176, destination=<RS
2>,17020,1542863268158
...
Server:
2018-11-21 21:21:49,394 INFO [RS_CLOSE_REGION-regionserver/<RS 1>:17020-1]
handler.UnassignRegionHandler: Close <region hash>
...
2018-11-21 21:21:51,095 INFO [RS_CLOSE_REGION-regionserver/<RS 1>:17020-1]
handler.UnassignRegionHandler: Closed <region hash>
{noformat}
By then the region is removed from onlineRegions, so the master proceeds.
{noformat}
2018-11-21 21:21:51,206 INFO [PEWorker-4] procedure2.ProcedureExecutor:
Finished subprocedure(s) of pid=667,
state=RUNNABLE:REGION_STATE_TRANSITION_CONFIRM_CLOSED, hasLock=true;
TransitRegionStateProcedure table=dummy_table, region=<region hash>,
REOPEN/MOVE; resume parent processing.
2018-11-21 21:21:51,386 INFO [PEWorker-13] assignment.RegionStateStore:
pid=667 updating hbase:meta row=<region hash>, regionState=OPENING,
regionLocation=<RS 2>,17020,1542863268158
{noformat}
There are no obvious errors/delays that I see in RS log, and it doesn't log
starting to send the report.
However, at 21:52.853 the report is processed that still contains this region.
{noformat}
2018-11-21 21:21:52,853 WARN
[RpcServer.default.FPBQ.Fifo.handler=48,queue=3,port=17000]
assignment.AssignmentManager: Killing <RS 1>,17020,1542754626176: rit=OPENING,
location=<RS 2>,17020,1542863268158, table=dummy_table, region=<region hash>
reported OPEN on server=<RS 1>,17020,1542754626176 but state has otherwise.
***** ABORTING region server <RS 1>,17020,1542754626176:
org.apache.hadoop.hbase.YouAreDeadException: rit=OPENING, location=<RS
2>,17020,1542863268158, table=dummy_table, region=<region hash> reported OPEN
on server=<RS 1>,17020,1542754626176 but state has otherwise.
{noformat}
RS shuts down in an orderly manner and it can be seen from the log that this
region is actually not present (there's no line indicating it's being closed,
unlike for other regions).
I think there needs to be some sort of versioning in RS reports to allow master
to account for concurrent operations and avoid races.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
