[
https://issues.apache.org/jira/browse/HBASE-12707?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Ted Yu resolved HBASE-12707.
----------------------------
Resolution: Cannot Reproduce
> TestMasterObserver#testTableOperations may fail due to race condition
> ---------------------------------------------------------------------
>
> Key: HBASE-12707
> URL: https://issues.apache.org/jira/browse/HBASE-12707
> Project: HBase
> Issue Type: Test
> Reporter: Ted Yu
> Priority: Minor
>
> Here was the failure I saw:
> {code}
> testTableOperations(org.apache.hadoop.hbase.coprocessor.TestMasterObserver)
> Time elapsed: 5.153 sec <<< FAILURE!
> java.lang.AssertionError: Delete table handler should be called.
> at org.junit.Assert.fail(Assert.java:88)
> at org.junit.Assert.assertTrue(Assert.java:41)
> at
> org.apache.hadoop.hbase.coprocessor.TestMasterObserver.testTableOperations(TestMasterObserver.java:1302)
> {code}
> Here is relevant part of test output:
> {code}
> 2014-12-18 00:18:47,788 DEBUG [MASTER_TABLE_OPERATIONS-kiyo:56800-0]
> backup.HFileArchiver(438): Finished archiving from class
> org.apache.hadoop.hbase.backup.HFileArchiver$FileablePath,
> file:hdfs://localhost:49506/user/hortonzy/test-data/caaed63b-db6f-4dad-a455-3f63897555f7/.tmp/data/default/observed_table/294700c0c28e634c9e046d5368559666/recovered.edits/7.seqid,
> to
> hdfs://localhost:49506/user/hortonzy/test-data/caaed63b-db6f-4dad-a455-3f63897555f7/archive/data/default/observed_table/294700c0c28e634c9e046d5368559666/recovered.edits/7.seqid
> 2014-12-18 00:18:47,789 INFO [IPC Server handler 2 on 49506]
> blockmanagement.BlockManager(1074): BLOCK* addToInvalidates:
> blk_1073741879_1055 127.0.0.1:60154 127.0.0.1:38435
> 2014-12-18 00:18:47,789 DEBUG [MASTER_TABLE_OPERATIONS-kiyo:56800-0]
> backup.HFileArchiver(453): Deleted all region files in:
> hdfs://localhost:49506/user/hortonzy/test-data/caaed63b-db6f-4dad-a455-3f63897555f7/.tmp/data/default/observed_table/294700c0c28e634c9e046d5368559666
> 2014-12-18 00:18:47,790 INFO [IPC Server handler 0 on 49506]
> blockmanagement.BlockManager(1074): BLOCK* addToInvalidates:
> blk_1073741883_1059 127.0.0.1:60154 127.0.0.1:38435
> 2014-12-18 00:18:47,791 DEBUG [MASTER_TABLE_OPERATIONS-kiyo:56800-0]
> handler.DeleteTableHandler(160): Table 'observed_table' archived!
> 2014-12-18 00:18:47,791 DEBUG [MASTER_TABLE_OPERATIONS-kiyo:56800-0]
> handler.DeleteTableHandler(110): Removing 'observed_table' descriptor.
> 2014-12-18 00:18:47,792 DEBUG [MASTER_TABLE_OPERATIONS-kiyo:56800-0]
> handler.DeleteTableHandler(116): Removing 'observed_table' from region states.
> 2014-12-18 00:18:47,792 DEBUG [MASTER_TABLE_OPERATIONS-kiyo:56800-0]
> handler.DeleteTableHandler(120): Marking 'observed_table' as deleted.
> 2014-12-18 00:18:47,874 DEBUG
> [B.defaultRpcServer.handler=2,queue=0,port=56800]
> util.FSTableDescriptors(177): Exception during readTableDecriptor. Current
> table name = observed_table
> org.apache.hadoop.hbase.TableInfoMissingException: No table descriptor file
> under
> hdfs://localhost:49506/user/hortonzy/test-data/caaed63b-db6f-4dad-a455-3f63897555f7/data/default/observed_table
> at
> org.apache.hadoop.hbase.util.FSTableDescriptors.getTableDescriptorFromFs(FSTableDescriptors.java:509)
> at
> org.apache.hadoop.hbase.util.FSTableDescriptors.getTableDescriptorFromFs(FSTableDescriptors.java:487)
> at
> org.apache.hadoop.hbase.util.FSTableDescriptors.get(FSTableDescriptors.java:172)
> at
> org.apache.hadoop.hbase.master.HMaster.listTableDescriptors(HMaster.java:2166)
> at
> org.apache.hadoop.hbase.master.MasterRpcServices.getTableDescriptors(MasterRpcServices.java:788)
> at
> org.apache.hadoop.hbase.protobuf.generated.MasterProtos$MasterService$2.callBlockingMethod(MasterProtos.java:42402)
> at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2028)
> at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:108)
> at
> org.apache.hadoop.hbase.ipc.RpcExecutor.consumerLoop(RpcExecutor.java:112)
> at org.apache.hadoop.hbase.ipc.RpcExecutor$1.run(RpcExecutor.java:92)
> at java.lang.Thread.run(Thread.java:724)
> 2014-12-18 00:18:47,875 INFO [main] client.HBaseAdmin(738): Deleted
> observed_table
> 2014-12-18 00:18:47,880 WARN [main] hbase.MetaTableAccessor$1(344): No
> serialized HRegionInfo in
> keyvalues={observed_table,,1418861912253.8551edbe4ffb771a607ad362bfc6642d./info:seqnumDuringOpen/1418861917732/Put/vlen=8/seqid=0,
>
> observed_table,,1418861912253.8551edbe4ffb771a607ad362bfc6642d./info:server/1418861917732/Put/vlen=28/seqid=0,
>
> observed_table,,1418861912253.8551edbe4ffb771a607ad362bfc6642d./info:serverstartcode/1418861917732/Put/vlen=8/seqid=0}
> 2014-12-18 00:18:47,924 INFO [main] hbase.ResourceChecker(171): after:
> coprocessor.TestMasterObserver#testTableOperations Thread=600 (was 475)
> {code}
> Here is related code in DeleteTableHandler#handleTableOperation():
> {code}
> removeTableData(regions);
> if (cpHost != null) {
> cpHost.postDeleteTableHandler(this.tableName);
> {code}
> Table data is removed first, then postDeleteTableHandler is called.
> However, the loop in HBaseAdmin checks for the presence of TableDescriptor.
> The loop exits if TableDescriptor is not found. Hence the assertion in test
> may be executed earlier than postDeleteTableHandler is called, leading to
> test failure.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
