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 2015/07/04 16:31:04 UTC

[jira] [Resolved] (HBASE-12707) TestMasterObserver#testTableOperations may fail due to race condition

     [ 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)