Description
2014-03-25 07:28:14,714 DEBUG [RegionOpenAndInitThread-testHBase3583-1] regionserver.HRegion(563): Instantiated testHBase3583,,1395732494518. 0cf2d2dd97dfedc860c5aa76c193e3e4. 2014-03-25 07:28:14,714 DEBUG [RegionOpenAndInitThread-testHBase3583-1] regionserver.HRegion(1037): Closing testHBase3583,,1395732494518.0cf2d2dd97dfedc860c5aa76c193e3e4.: disabling compactions & flushes 2014-03-25 07:28:14,714 DEBUG [RegionOpenAndInitThread-testHBase3583-1] regionserver.HRegion(1064): Updates disabled for region testHBase3583,,1395732494518. 0cf2d2dd97dfedc860c5aa76c193e3e4. ... 2014-03-25 07:28:14,763 INFO [AM.ZK.Worker-pool3-t15] master.RegionStates(316): Transitioned {0cf2d2dd97dfedc860c5aa76c193e3e4 state=PENDING_OPEN, ts=1395732494729, server=asf002.sp2.ygridcore.net,45836,1395732453985} to {0cf2d2dd97dfedc860c5aa76c193e3e4 state=OPENING, ts=1395732494763, server=asf002.sp2.ygridcore.net,45836, 1395732453985} 2014-03-25 07:28:14,778 INFO [RS_LOG_REPLAY_OPS-asf002:45836-0-Writer-2] zookeeper.RecoverableZooKeeper(120): Process identifier=hconnection-0x145ee7f connecting to ZooKeeper ensemble=localhost:50878 2014-03-25 07:28:14,784 DEBUG [RS_LOG_REPLAY_OPS-asf002:45836-0-Writer-2-EventThread] zookeeper.ZooKeeperWatcher(309): hconnection-0x145ee7f, quorum=localhost:50878, baseZNode=/hbase Received ZooKeeper Event, type=None, state=SyncConnected, path=null 2014-03-25 07:28:14,785 DEBUG [RS_LOG_REPLAY_OPS-asf002:45836-0-Writer-2-EventThread] zookeeper.ZooKeeperWatcher(393): hconnection-0x145ee7f-0x144f82314c6001b connected 2014-03-25 07:28:14,788 INFO [StoreOpener-0cf2d2dd97dfedc860c5aa76c193e3e4-1] compactions.CompactionConfiguration(88): size [134217728, 9223372036854775807); files [3, 10); ratio 1.200000; off-peak ratio 5.000000; throttle point 2684354560; delete expired; major period 604800000, major jitter 0.500000 2014-03-25 07:28:14,793 DEBUG [RS_LOG_REPLAY_OPS-asf002:45836-0-Writer-2] zookeeper.ZKUtil(689): hconnection-0x145ee7f-0x144f82314c6001b, quorum=localhost:50878, baseZNode=/hbase Unable to get data of znode /hbase/table/TestTable.testRecovery because node does not exist (not an error) 2014-03-25 07:28:14,796 INFO [StoreOpener-0cf2d2dd97dfedc860c5aa76c193e3e4-1] compactions.CompactionConfiguration(88): size [134217728, 9223372036854775807); files [3, 10); ratio 1.200000; off-peak ratio 5.000000; throttle point 2684354560; delete expired; major period 604800000, major jitter 0.500000 2014-03-25 07:28:14,808 ERROR [Priority.RpcServer.handler=7,port=45836] coprocessor.CoprocessorHost(482): The coprocessor org.apache.hadoop.hbase.coprocessor. SimpleRegionObserver threw an unexpected exception java.lang.AssertionError at org.junit.Assert.fail(Assert.java:86) at org.junit.Assert.assertTrue(Assert.java:41) at org.junit.Assert.assertNotNull(Assert.java:621) at org.junit.Assert.assertNotNull(Assert.java:631) at org.apache.hadoop.hbase.coprocessor.SimpleRegionObserver.postGetClosestRowBefore(SimpleRegionObserver.java:512) at org.apache.hadoop.hbase.regionserver.RegionCoprocessorHost.postGetClosestRowBefore(RegionCoprocessorHost.java:970) at org.apache.hadoop.hbase.regionserver.HRegion.getClosestRowBefore(HRegion.java:1821) at org.apache.hadoop.hbase.regionserver.HRegionServer.get(HRegionServer.java:2851) at org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:29493) at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2020) at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:98) at org.apache.hadoop.hbase.ipc.SimpleRpcScheduler.consumerLoop(SimpleRpcScheduler.java:162) at org.apache.hadoop.hbase.ipc.SimpleRpcScheduler.access$000(SimpleRpcScheduler.java:38) at org.apache.hadoop.hbase.ipc.SimpleRpcScheduler$1.run(SimpleRpcScheduler.java:110) at java.lang.Thread.run(Thread.java:662) 2014-03-25 07:28:14,808 FATAL [Priority.RpcServer.handler=7,port=45836] regionserver.HRegionServer(1836): ABORTING region server asf002.sp2.ygridcore.net,45836,1395732453985: The coprocessor org.apache.hadoop.hbase.coprocessor.SimpleRegionObserver threw an unexpected exception java.lang.AssertionError at org.junit.Assert.fail(Assert.java:86) at org.junit.Assert.assertTrue(Assert.java:41) at org.junit.Assert.assertNotNull(Assert.java:621) at org.junit.Assert.assertNotNull(Assert.java:631) at org.apache.hadoop.hbase.coprocessor.SimpleRegionObserver.postGetClosestRowBefore(SimpleRegionObserver.java:512) at org.apache.hadoop.hbase.regionserver.RegionCoprocessorHost.postGetClosestRowBefore(RegionCoprocessorHost.java:970) at org.apache.hadoop.hbase.regionserver.HRegion.getClosestRowBefore(HRegion.java:1821) at org.apache.hadoop.hbase.regionserver.HRegionServer.get(HRegionServer.java:2851) at org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:29493) at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2020) at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:98) at org.apache.hadoop.hbase.ipc.SimpleRpcScheduler.consumerLoop(SimpleRpcScheduler.java:162) at org.apache.hadoop.hbase.ipc.SimpleRpcScheduler.access$000(SimpleRpcScheduler.java:38) at org.apache.hadoop.hbase.ipc.SimpleRpcScheduler$1.run(SimpleRpcScheduler.java:110) at java.lang.Thread.run(Thread.java:662)
When get request was issued, testHBase3583,,1395732494518.0cf2d2dd97dfedc860c5aa76c193e3e4. hasn't completed opening.
This led to region server abort because of the following assertion in SimpleRegionObserver#postGetClosestRowBefore:
assertNotNull(result);
TestRegionObserverInterface#testHBase3583 should wait for all regions to be assigned