[
https://issues.apache.org/jira/browse/HBASE-10828?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Ted Yu updated HBASE-10828:
---------------------------
Description:
>From
>https://builds.apache.org/job/PreCommit-HBASE-Build/9086/testReport/org.apache.hadoop.hbase.coprocessor/TestRegionObserverInterface/testHBase3583/
> :
{code}
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)
{code}
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:
{code}
assertNotNull(result);
{code}
TestRegionObserverInterface#testHBase3583 should wait for all regions to be
assigned
was:
>From
>https://builds.apache.org/job/PreCommit-HBASE-Build/9086/testReport/org.apache.hadoop.hbase.coprocessor/TestRegionObserverInterface/testHBase3583/
> :
{code}
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)
{code}
When get request was issued,
testHBase3583,,1395732494518.0cf2d2dd97dfedc860c5aa76c193e3e4. hasn't completed
opening.
This led to region server abort.
TestRegionObserverInterface#testHBase3583 should wait for all regions to be
assigned
> TestRegionObserverInterface#testHBase3583 should wait for all regions to be
> assigned
> ------------------------------------------------------------------------------------
>
> Key: HBASE-10828
> URL: https://issues.apache.org/jira/browse/HBASE-10828
> Project: HBase
> Issue Type: Test
> Reporter: Ted Yu
> Assignee: Ted Yu
> Priority: Minor
> Attachments: 10828-v1.txt
>
>
> From
> https://builds.apache.org/job/PreCommit-HBASE-Build/9086/testReport/org.apache.hadoop.hbase.coprocessor/TestRegionObserverInterface/testHBase3583/
> :
> {code}
> 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)
> {code}
> 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:
> {code}
> assertNotNull(result);
> {code}
> TestRegionObserverInterface#testHBase3583 should wait for all regions to be
> assigned
--
This message was sent by Atlassian JIRA
(v6.2#6252)
