Ted Yu created HBASE-12685:
------------------------------
Summary: TestSplitLogManager#testLogFilesAreArchived sometimes
times out due to race condition
Key: HBASE-12685
URL: https://issues.apache.org/jira/browse/HBASE-12685
Project: HBase
Issue Type: Test
Reporter: Ted Yu
Assignee: Ted Yu
Priority: Minor
>From
>https://builds.apache.org/job/hbase-0.98/739/testReport/org.apache.hadoop.hbase.master/TestSplitLogManager/testLogFilesAreArchived/
> :
{code}
2014-12-14 14:40:30,420 INFO [Thread-27] master.SplitLogManager(325): started
splitting 1 logs in
[/home/jenkins/jenkins-slave/workspace/HBase-0.98/hbase-server/target/test-data/c065c13d-bc83-48e7-9178-51a14df531c3/testLogFilesAreArchived/f7ae1e8f-c848-4089-b5b1-20aff73c81dd]
2014-12-14 14:40:30,422 WARN [Thread-31] master.TestSplitLogManager$5(527):
org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode
for /hbase/splitWAL/f7ae1e8f-c848-4089-b5b1-20aff73c81dd%2Ffoo%2C1%2C1
2014-12-14 14:40:30,423 DEBUG [main-EventThread] master.SplitLogManager(703):
put up splitlog task at znode
/hbase/splitWAL/f7ae1e8f-c848-4089-b5b1-20aff73c81dd%2Ffoo%2C1%2C1
{code}
The thread which mocks split done called ZKUtil.setData() before
SplitLogManager put up the splitlog task znode. The setting of done to true
should exclude the above scenario.
Otherwise log split task would miss the split done mock, resulting in test
failure:
{code}
2014-12-14 14:41:18,562 INFO [main-EventThread] master.SplitLogManager(753):
task /hbase/splitWAL/RESCAN0000000004 entered state: DONE dummy-master,1,1
2014-12-14 14:41:18,563 DEBUG [main-EventThread]
zookeeper.ZooKeeperWatcher(312):
split-log-manager-testsa62d20ae-9904-4dc6-9e79-b7d98486dd49-0x14a493e58af0000,
quorum=localhost:50869, baseZNode=/hbase Received ZooKeeper Event,
type=NodeDeleted, state=SyncConnected, path=/hbase/splitWAL/RESCAN0000000004
2014-12-14 14:41:18,563 DEBUG [main-EventThread]
master.SplitLogManager$DeleteAsyncCallback(1712): deleted
/hbase/splitWAL/RESCAN0000000004
2014-12-14 14:41:18,563 DEBUG [main-EventThread] master.SplitLogManager(935):
deleted task without in memory state /hbase/splitWAL/RESCAN0000000004
2014-12-14 14:41:20,562 INFO [dummy-master,1,1.splitLogManagerTimeoutMonitor]
master.SplitLogManager$TimeoutMonitor(1502): total tasks = 1 unassigned = 1
tasks={/hbase/splitWAL/f7ae1e8f-c848-4089-b5b1-20aff73c81dd%2Ffoo%2C1%2C1=last_update
= -1 last_version = -1 cur_worker_name = null status = in_progress incarnation
= 0 resubmits = 0 batch = installed = 1 done = 0 error = 0}
2014-12-14 14:41:25,568 INFO [dummy-master,1,1.splitLogManagerTimeoutMonitor]
master.SplitLogManager$TimeoutMonitor(1502): total tasks = 1 unassigned = 1
tasks={/hbase/splitWAL/f7ae1e8f-c848-4089-b5b1-20aff73c81dd%2Ffoo%2C1%2C1=last_update
= -1 last_version = -1 cur_worker_name = null status = in_progress incarnation
= 0 resubmits = 0 batch = installed = 1 done = 0 error = 0}
2014-12-14 14:41:30,399 WARN [Thread-27] master.SplitLogManager(441):
Interrupted while waiting for log splits to be completed
{code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
