Mailing-List: contact issues-help@hbase.apache.org; run by ezmlm
Precedence: bulk
Date: Tue, 3 Mar 2015 14:38:05 +0000 (UTC)
From: "zhangduo (JIRA)" <jira@apache.org>
To: issues@hbase.apache.org
Message-ID: <JIRA.12778964.1425364650000.64203.1425393485717@Atlassian.JIRA>
In-Reply-To: <JIRA.12778964.1425364650000@Atlassian.JIRA>
References: <JIRA.12778964.1425364650000@Atlassian.JIRA>
 <JIRA.12778964.1425364650032@arcas>
Subject: [jira] [Commented] (HBASE-13145)
 TestNamespaceAuditor.testRegionMerge is flaky
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: 7bit


    [ https://issues.apache.org/jira/browse/HBASE-13145?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14345132#comment-14345132 ] 

zhangduo commented on HBASE-13145:
----------------------------------

I think I found the problem.

{code:title=ChoreService.java}
  public synchronized boolean scheduleChore(ScheduledChore chore) {
      ...
      ScheduledFuture<?> future =
          scheduler.scheduleAtFixedRate(chore, chore.getInitialDelay(), chore.getPeriod(),
            chore.getTimeUnit());
      chore.setChoreServicer(this);
      ...
  }
{code}
So we schedule the chore first, and then set chore servicer. And for CompactionChecker, the initialDelay is 0, so it is possible that the chore is run before we set chore servicer for it. And see this
{code:title=ScheduledChore.java}
  public void run() {
    ...
    else if (stopper.isStopped() || !isScheduled()) {
      cancel(false);
      cleanup();
      if (LOG.isInfoEnabled()) LOG.info("Chore: " + getName() + " was stopped");
    }
    ...
  }
    ...
  public synchronized boolean isScheduled() {
    return choreServicer != null && choreServicer.isChoreScheduled(this);
  }
{code}
So it is possible that isScheduled() returns false and we start to cancel the chore. You can insert a sleep between scheduled chore and set chore servicer, then you can always get the log ' Chore: CompactionChecker was stopped'. But it does not always actually cancel the chore because the cancel method's implementation.
{code:title=ScheduledChore.java}
  public synchronized void cancel(boolean mayInterruptIfRunning) {
    if (isScheduled()) choreServicer.cancelChore(this, mayInterruptIfRunning);

    choreServicer = null;
  }
{code}
So if you insert a sleep before cancel(remember to set a larger sleep time here), then you can make the test always fail.

> TestNamespaceAuditor.testRegionMerge is flaky
> ---------------------------------------------
>
>                 Key: HBASE-13145
>                 URL: https://issues.apache.org/jira/browse/HBASE-13145
>             Project: HBase
>          Issue Type: Bug
>          Components: test
>    Affects Versions: 2.0.0, 1.1.0
>            Reporter: zhangduo
>            Assignee: zhangduo
>         Attachments: HBASE-13145.patch
>
>
> Dig into the log
> https://builds.apache.org/job/HBase-TRUNK/6197/artifact/hbase-server/target/surefire-reports/org.apache.hadoop.hbase.namespace.TestNamespaceAuditor-output.txt
> Seems a split operation which we expect to success is started before we finishing a merge and cause an infinite sleep loop.
> I guess the problem is here
> {code:title=TestNamespaceAuditor.java}
>     // merge the two regions
>     admin.mergeRegions(hris.get(0).getEncodedNameAsBytes(),
>       hris.get(1).getEncodedNameAsBytes(), false);
>     
>     while (admin.getTableRegions(tableTwo).size() == initialRegions) {
>       Thread.sleep(100);
>     }
> {code}
> I guess that during a merge, we can get more region count than before because we first online the new region and then offline the two old regions.
> So change it to admin.getTableRegions(tableTwo).size() != initialRegions - 1 may work.
> And we can modify the while loop to use Waiter.waitFor which can provide more useful information when test failed.


--
This message was sent by Atlassian JIRA
(v6.3.4#6332)