You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hbase.apache.org by "Ted Yu (JIRA)" <ji...@apache.org> on 2014/12/28 16:15:13 UTC
[jira] [Created] (HBASE-12766)
TestSplitLogManager#testGetPreviousRecoveryMode sometimes fails due to race
condition
Ted Yu created HBASE-12766:
------------------------------
Summary: TestSplitLogManager#testGetPreviousRecoveryMode sometimes fails due to race condition
Key: HBASE-12766
URL: https://issues.apache.org/jira/browse/HBASE-12766
Project: HBase
Issue Type: Test
Reporter: Ted Yu
Priority: Minor
>From https://builds.apache.org/job/HBase-1.0/614/testReport/junit/org.apache.hadoop.hbase.master/TestSplitLogManager/testGetPreviousRecoveryMode/ :
{code}
java.lang.AssertionError: Mode4=LOG_SPLITTING
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.hadoop.hbase.master.TestSplitLogManager.testGetPreviousRecoveryMode(TestSplitLogManager.java:656)
...
2014-12-27 19:04:56,576 INFO [Thread-8] coordination.ZKSplitLogManagerCoordination(594): found orphan task testRecovery
2014-12-27 19:04:56,577 INFO [Thread-8] coordination.ZKSplitLogManagerCoordination(598): Found 1 orphan tasks and 0 rescan nodes
2014-12-27 19:04:56,578 DEBUG [main-EventThread] coordination.ZKSplitLogManagerCoordination(464): task not yet acquired /hbase/splitWAL/testRecovery ver = 0
2014-12-27 19:04:56,578 INFO [main-EventThread] coordination.ZKSplitLogManagerCoordination(548): creating orphan task /hbase/splitWAL/testRecovery
2014-12-27 19:04:56,578 INFO [main-EventThread] coordination.ZKSplitLogManagerCoordination(178): resubmitting unassigned orphan task /hbase/splitWAL/testRecovery
2014-12-27 19:04:56,578 INFO [main-EventThread] coordination.ZKSplitLogManagerCoordination(229): resubmitting task /hbase/splitWAL/testRecovery
2014-12-27 19:04:56,582 INFO [Thread-8] master.TestSplitLogManager(650): Mode1=LOG_SPLITTING
2014-12-27 19:04:56,584 DEBUG [main-EventThread] zookeeper.ZooKeeperWatcher(313): split-log-manager-tests58920b37-7850-44e5-8b97-871caff81fdb-0x14a8d231db70000, quorum=localhost:60541, baseZNode=/hbase Received ZooKeeper Event, type=NodeDataChanged, state=SyncConnected, path=/hbase/splitWAL/testRecovery
2014-12-27 19:04:56,584 INFO [Thread-8] master.TestSplitLogManager(653): Mode2=LOG_SPLITTING
2014-12-27 19:04:56,584 DEBUG [Thread-8] coordination.ZKSplitLogManagerCoordination(870): Distributed log replay=true
2014-12-27 19:04:56,585 WARN [main-EventThread] coordination.ZKSplitLogManagerCoordination$GetDataAsyncCallback(996): task znode /hbase/splitWAL/testRecovery vanished or not created yet.
2014-12-27 19:04:56,585 INFO [main-EventThread] coordination.ZKSplitLogManagerCoordination(472): task /hbase/splitWAL/RESCAN0000000001 entered state: DONE dummy-master,1,1
{code}
>From the above log we can see that by the time the following is called (line 654 in test):
{code}
slm.setRecoveryMode(false);
{code}
the split task was not done - it entered done state 1 millisecond later.
So ZKSplitLogManagerCoordination#hasSplitLogTask was true and isForInitialization parameter is false, leading to the execution of the following branch:
{code}
} else if (!isForInitialization) {
// splitlogtask hasn't drained yet, keep existing recovery mode
return;
{code}
Thus recoveryMode was left in LOG_SPLITTING state.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)