[ https://issues.apache.org/jira/browse/HBASE-21811?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16758890#comment-16758890 ]
Hadoop QA commented on HBASE-21811: ----------------------------------- | (x) *{color:red}-1 overall{color}* | \\ \\ || Vote || Subsystem || Runtime || Comment || | {color:blue}0{color} | {color:blue} reexec {color} | {color:blue} 0m 14s{color} | {color:blue} Docker mode activated. {color} | || || || || {color:brown} Prechecks {color} || | {color:green}+1{color} | {color:green} hbaseanti {color} | {color:green} 0m 0s{color} | {color:green} Patch does not have any anti-patterns. {color} | | {color:green}+1{color} | {color:green} @author {color} | {color:green} 0m 0s{color} | {color:green} The patch does not contain any @author tags. {color} | | {color:green}+1{color} | {color:green} test4tests {color} | {color:green} 0m 0s{color} | {color:green} The patch appears to include 1 new or modified test files. {color} | || || || || {color:brown} master Compile Tests {color} || | {color:blue}0{color} | {color:blue} mvndep {color} | {color:blue} 0m 26s{color} | {color:blue} Maven dependency ordering for branch {color} | | {color:green}+1{color} | {color:green} mvninstall {color} | {color:green} 4m 15s{color} | {color:green} master passed {color} | | {color:green}+1{color} | {color:green} compile {color} | {color:green} 2m 15s{color} | {color:green} master passed {color} | | {color:green}+1{color} | {color:green} checkstyle {color} | {color:green} 1m 22s{color} | {color:green} master passed {color} | | {color:green}+1{color} | {color:green} shadedjars {color} | {color:green} 4m 5s{color} | {color:green} branch has no errors when building our shaded downstream artifacts. {color} | | {color:green}+1{color} | {color:green} findbugs {color} | {color:green} 2m 39s{color} | {color:green} master passed {color} | | {color:green}+1{color} | {color:green} javadoc {color} | {color:green} 0m 43s{color} | {color:green} master passed {color} | || || || || {color:brown} Patch Compile Tests {color} || | {color:blue}0{color} | {color:blue} mvndep {color} | {color:blue} 0m 16s{color} | {color:blue} Maven dependency ordering for patch {color} | | {color:green}+1{color} | {color:green} mvninstall {color} | {color:green} 4m 9s{color} | {color:green} the patch passed {color} | | {color:green}+1{color} | {color:green} compile {color} | {color:green} 2m 16s{color} | {color:green} the patch passed {color} | | {color:green}+1{color} | {color:green} javac {color} | {color:green} 2m 16s{color} | {color:green} the patch passed {color} | | {color:green}+1{color} | {color:green} checkstyle {color} | {color:green} 1m 19s{color} | {color:green} the patch passed {color} | | {color:green}+1{color} | {color:green} whitespace {color} | {color:green} 0m 0s{color} | {color:green} The patch has no whitespace issues. {color} | | {color:green}+1{color} | {color:green} shadedjars {color} | {color:green} 4m 8s{color} | {color:green} patch has no errors when building our shaded downstream artifacts. {color} | | {color:green}+1{color} | {color:green} hadoopcheck {color} | {color:green} 8m 38s{color} | {color:green} Patch does not cause any errors with Hadoop 2.7.4 or 3.0.0. {color} | | {color:green}+1{color} | {color:green} findbugs {color} | {color:green} 2m 49s{color} | {color:green} the patch passed {color} | | {color:green}+1{color} | {color:green} javadoc {color} | {color:green} 0m 45s{color} | {color:green} the patch passed {color} | || || || || {color:brown} Other Tests {color} || | {color:green}+1{color} | {color:green} unit {color} | {color:green} 3m 23s{color} | {color:green} hbase-procedure in the patch passed. {color} | | {color:red}-1{color} | {color:red} unit {color} | {color:red}127m 54s{color} | {color:red} hbase-server in the patch failed. {color} | | {color:green}+1{color} | {color:green} asflicense {color} | {color:green} 0m 53s{color} | {color:green} The patch does not generate ASF License warnings. {color} | | {color:black}{color} | {color:black} {color} | {color:black}173m 19s{color} | {color:black} {color} | \\ \\ || Reason || Tests || | Failed junit tests | hadoop.hbase.master.assignment.TestWakeUpUnexpectedProcedure | | | hadoop.hbase.replication.TestSyncReplicationStandbyKillRS | \\ \\ || Subsystem || Report/Notes || | Docker | Client=17.05.0-ce Server=17.05.0-ce Image:yetus/hbase:b002b0b | | JIRA Issue | HBASE-21811 | | JIRA Patch URL | https://issues.apache.org/jira/secure/attachment/12957355/HBASE-21811-v1.patch | | Optional Tests | dupname asflicense javac javadoc unit findbugs shadedjars hadoopcheck hbaseanti checkstyle compile | | uname | Linux ca520ca841fd 4.4.0-138-generic #164-Ubuntu SMP Tue Oct 2 17:16:02 UTC 2018 x86_64 GNU/Linux | | Build tool | maven | | Personality | /home/jenkins/jenkins-slave/workspace/PreCommit-HBASE-Build/component/dev-support/hbase-personality.sh | | git revision | master / 64c32720d6 | | maven | version: Apache Maven 3.5.4 (1edded0938998edf8bf061f1ceb3cfdeccf443fe; 2018-06-17T18:33:14Z) | | Default Java | 1.8.0_181 | | findbugs | v3.1.0-RC3 | | unit | https://builds.apache.org/job/PreCommit-HBASE-Build/15851/artifact/patchprocess/patch-unit-hbase-server.txt | | Test Results | https://builds.apache.org/job/PreCommit-HBASE-Build/15851/testReport/ | | Max. process+thread count | 5052 (vs. ulimit of 10000) | | modules | C: hbase-procedure hbase-server U: . | | Console output | https://builds.apache.org/job/PreCommit-HBASE-Build/15851/console | | Powered by | Apache Yetus 0.8.0 http://yetus.apache.org | This message was automatically generated. > region can be opened on two servers due to race condition with procedures and > server reports > -------------------------------------------------------------------------------------------- > > Key: HBASE-21811 > URL: https://issues.apache.org/jira/browse/HBASE-21811 > Project: HBase > Issue Type: Bug > Components: amv2 > Affects Versions: 3.0.0 > Reporter: Sergey Shelukhin > Assignee: Sergey Shelukhin > Priority: Blocker > Fix For: 3.0.0, 2.2.0 > > Attachments: HBASE-21811-UT.patch, HBASE-21811-v1.patch, > HBASE-21811.patch > > > Looks like the region server responses are being processed incorrectly in > places allowing te region to be opened on two servers. > * The region server report handling in procedures should check which server > is reporting. > * Also although I didn't check (and it isn't implicated in this bug), RS must > check in OPEN that it's actually the correct RS master sent open to (w.r.t. > start timestamp) > This was previosuly "mitigated" by master killing the RS with incorrect > reports, but due to race conditions with reports and assignment the kill was > replaced with a warning, so now this condition persists. > Regardless, the kill approach is not a good fix because there's still a > window when a region can be opened on two servers. > A region is being opened by server_48c. The server dies, and we process the > retry correctly (retry=3 because 2 previous similar open failures were > processed correctly). > We start opening it on server_1aa now. > {noformat} > 2019-01-28 18:12:09,862 INFO [KeepAlivePEWorker-104] > assignment.RegionStateStore: pid=4915 updating hbase:meta > row=8be2a423b16471b9417f0f7de04281c6, regionState=ABNORMALLY_CLOSED > 2019-01-28 18:12:09,862 INFO [KeepAlivePEWorker-104] > procedure.ServerCrashProcedure: pid=11944, > state=RUNNABLE:SERVER_CRASH_ASSIGN, hasLock=true; ServerCrashProcedure > server=server_48c,17020,1548726406632, splitWal=true, meta=false found RIT > pid=4915, ppid=7, state=WAITING:REGION_STATE_TRANSITION_CONFIRM_OPENED, > hasLock=true; TransitRegionStateProcedure table=table, > region=8be2a423b16471b9417f0f7de04281c6, ASSIGN; rit=OPENING, > location=server_48c,17020,1548726406632, table=table, > region=8be2a423b16471b9417f0f7de04281c6 > 2019-01-28 18:12:10,778 INFO [KeepAlivePEWorker-80] > assignment.TransitRegionStateProcedure: Retry=3 of max=2147483647; pid=4915, > ppid=7, state=RUNNABLE:REGION_STATE_TRANSITION_CONFIRM_OPENED, hasLock=true; > TransitRegionStateProcedure table=table, > region=8be2a423b16471b9417f0f7de04281c6, ASSIGN; rit=ABNORMALLY_CLOSED, > location=null > ... > 2019-01-28 18:12:10,902 INFO [KeepAlivePEWorker-80] > assignment.TransitRegionStateProcedure: Starting pid=4915, ppid=7, > state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE, hasLock=true; > TransitRegionStateProcedure table=table, > region=8be2a423b16471b9417f0f7de04281c6, ASSIGN; rit=ABNORMALLY_CLOSED, > location=null; forceNewPlan=true, retain=false > 2019-01-28 18:12:11,114 INFO [PEWorker-7] assignment.RegionStateStore: > pid=4915 updating hbase:meta row=8be2a423b16471b9417f0f7de04281c6, > regionState=OPENING, regionLocation=server_1aa,17020,1548727658713 > {noformat} > However, we get the remote procedure failure from 48c after we've already > started that. > It actually tried to open on the restarted RS, which makes me wonder if this > is safe also w.r.t. other races - what if RS already initialized and didn't > error out? > Need to check if we verify the start code expected by master on RS when > opening. > {noformat} > 2019-01-28 18:12:12,179 WARN [RSProcedureDispatcher-pool4-t362] > assignment.RegionRemoteProcedureBase: The remote operation pid=11050, > ppid=4915, state=SUCCESS, hasLock=false; > org.apache.hadoop.hbase.master.assignment.OpenRegionProcedure for region > {ENCODED => 8be2a423b16471b9417f0f7de04281c6 ... to server > server_48c,17020,1548726406632 failed > org.apache.hadoop.hbase.ipc.ServerNotRunningYetException: > org.apache.hadoop.hbase.ipc.ServerNotRunningYetException: Server > server_48c,17020,1548727752747 is not running yet > 2019-01-28 18:12:12,179 WARN [RSProcedureDispatcher-pool4-t362] > procedure.RSProcedureDispatcher: server server_48c,17020,1548726406632 is not > up for a while; try a new one > {noformat} > Without any other reason (at least logged), the RIT immediately retries again > and chooses a new candidate. It then retries again and goes to the new 48c, > but that's unrelated. > {noformat} > 2019-01-28 18:12:12,289 INFO [KeepAlivePEWorker-100] > assignment.TransitRegionStateProcedure: Retry=4 of max=2147483647; pid=4915, > ppid=7, state=RUNNABLE:REGION_STATE_TRANSITION_CONFIRM_OPENED, hasLock=true; > TransitRegionStateProcedure table=table, > region=8be2a423b16471b9417f0f7de04281c6, ASSIGN; rit=OPENING, > location=server_1aa,17020,1548727658713 > ... > 2019-01-28 18:12:12,668 INFO [PEWorker-9] assignment.RegionStateStore: > pid=4915 updating hbase:meta row=8be2a423b16471b9417f0f7de04281c6, > regionState=OPENING, regionLocation=server_fd3,17020,1548727536972 > .... > 2019-01-28 18:26:29,480 INFO [KeepAlivePEWorker-154] > assignment.RegionStateStore: pid=4915 updating hbase:meta > row=8be2a423b16471b9417f0f7de04281c6, regionState=OPENING, > regionLocation=server_48c,17020,1548727752747 > {noformat} > What does happen though is that 1aa, that never got a chance to respond at > the time that the RIT erroneously retried above, finishes opening the region > - which master ignores > {noformat} > 2019-01-28 18:27:42,424 WARN > [RpcServer.default.FPBQ.Fifo.handler=29,queue=4,port=17000] > assignment.TransitRegionStateProcedure: Received report OPENED transition > from server_1aa,17020,1548727658713 for rit=OPENING, > location=server_48c,17020,1548727752747, table=table, > region=8be2a423b16471b9417f0f7de04281c6, pid=4915 but the region is not on > it, should be a retry, ignore > {noformat} > And starts spamming these warnings until finally the region is open in two > places. > {noformat} > 2019-01-28 18:27:45,500 WARN > [RpcServer.default.FPBQ.Fifo.handler=42,queue=2,port=17000] > assignment.AssignmentManager: rit=OPENING, > location=server_48c,17020,1548727752747, table=table, > region=8be2a423b16471b9417f0f7de04281c6 reported OPEN on > server=server_1aa,17020,1548727658713 but state has otherwise > ... > 2019-01-28 18:51:21,197 WARN > [RpcServer.default.FPBQ.Fifo.handler=10,queue=0,port=17000] > assignment.AssignmentManager: rit=OPEN, > location=server_48c,17020,1548727752747, table=table, > region=8be2a423b16471b9417f0f7de04281c6 reported OPEN on > server=server_1aa,17020,1548727658713 but state has otherwise > {noformat} > This can result in data loss. -- This message was sent by Atlassian JIRA (v7.6.3#76005)