[ 
https://issues.apache.org/jira/browse/HBASE-20035?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16373403#comment-16373403
 ] 

Hudson commented on HBASE-20035:
--------------------------------

FAILURE: Integrated in Jenkins build HBase-Trunk_matrix #4631 (See 
[https://builds.apache.org/job/HBase-Trunk_matrix/4631/])
HBASE-20035 Stabilize the flaky TestQuotaStatusRPCs (elserj: rev 
4cf846d08570256115ac8c2787d0f7fbf162be23)
* (edit) 
hbase-server/src/test/java/org/apache/hadoop/hbase/quotas/TestQuotaStatusRPCs.java


> .TestQuotaStatusRPCs.testQuotaStatusFromMaster failed with NPEs and 
> RuntimeExceptions
> -------------------------------------------------------------------------------------
>
>                 Key: HBASE-20035
>                 URL: https://issues.apache.org/jira/browse/HBASE-20035
>             Project: HBase
>          Issue Type: Sub-task
>            Reporter: stack
>            Assignee: Josh Elser
>            Priority: Major
>             Fix For: 2.0.0-beta-2
>
>         Attachments: HBASE-20035.001.branch-2.patch
>
>
> It failed the nightly.
> Says this...
> Error Message
> Waiting timed out after [30,000] msec
> Stacktrace
> java.lang.AssertionError: Waiting timed out after [30,000] msec
>       at 
> org.apache.hadoop.hbase.quotas.TestQuotaStatusRPCs.testQuotaStatusFromMaster(TestQuotaStatusRPCs.java:267)
> ... but looking in log I see following:
> Odd thing is the test is run three times and it failed all three times for 
> same reason.
> [ERROR] Failures: 
> [ERROR] 
> org.apache.hadoop.hbase.quotas.TestQuotaStatusRPCs.testQuotaStatusFromMaster(org.apache.hadoop.hbase.quotas.TestQuotaStatusRPCs)
> [ERROR]   Run 1: TestQuotaStatusRPCs.testQuotaStatusFromMaster:267 Waiting 
> timed out after [30,000] msec
> [ERROR]   Run 2: TestQuotaStatusRPCs.testQuotaStatusFromMaster:267 Waiting 
> timed out after [30,000] msec
> [ERROR]   Run 3: TestQuotaStatusRPCs.testQuotaStatusFromMaster:267 Waiting 
> timed out after [30,000] msec
> If you go to build artifacts you can download full -output.txt log. I see 
> stuff like this which might be ok....
> {code}
> 2018-02-21 01:29:59,546 INFO  
> [StoreCloserThread-testQuotaStatusFromMaster4,0,1519176558800.1dbd00f38915cd276410065f85140b26.-1]
>  regionserver.HStore(930): Closed f1
> 2018-02-21 01:29:59,551 ERROR [master/ad51e354307e:0.Chore.2] 
> hbase.ScheduledChore(189): Caught error
> java.lang.RuntimeException: java.util.concurrent.RejectedExecutionException: 
> Task 
> org.apache.hadoop.hbase.client.ResultBoundedCompletionService$QueueingFuture@79ec2ef9
>  rejected from java.util.concurrent.ThreadPoolExecutor@5198a326[Terminated, 
> pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 142]
>   at 
> org.apache.hadoop.hbase.client.RpcRetryingCallerImpl.callWithoutRetries(RpcRetryingCallerImpl.java:200)
>   at org.apache.hadoop.hbase.client.ClientScanner.call(ClientScanner.java:269)
>   at 
> org.apache.hadoop.hbase.client.ClientScanner.loadCache(ClientScanner.java:437)
>   at 
> org.apache.hadoop.hbase.client.ClientScanner.nextWithSyncCache(ClientScanner.java:312)
>   at org.apache.hadoop.hbase.client.ClientScanner.next(ClientScanner.java:597)
>   at 
> org.apache.hadoop.hbase.quotas.QuotaRetriever.next(QuotaRetriever.java:106)
>   at 
> org.apache.hadoop.hbase.quotas.QuotaRetriever$Iter.<init>(QuotaRetriever.java:125)
>   at 
> org.apache.hadoop.hbase.quotas.QuotaRetriever.iterator(QuotaRetriever.java:117)
>   at 
> org.apache.hadoop.hbase.quotas.QuotaObserverChore.fetchAllTablesWithQuotasDefined(QuotaObserverChore.java:458)
>   at 
> org.apache.hadoop.hbase.quotas.QuotaObserverChore._chore(QuotaObserverChore.java:148)
>   at 
> org.apache.hadoop.hbase.quotas.QuotaObserverChore.chore(QuotaObserverChore.java:136)
>   at org.apache.hadoop.hbase.ScheduledChore.run(ScheduledChore.java:186)
>   at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>   at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
>   at 
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
>   at 
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
>   at 
> org.apache.hadoop.hbase.JitterScheduledThreadPoolExecutorImpl$JitteredRunnableScheduledFuture.run(JitterScheduledThreadPoolExecutorImpl.java:111)
>   at 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>   at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>   at java.lang.Thread.run(Thread.java:748)
> Caused by: java.util.concurrent.RejectedExecutionException: Task 
> org.apache.hadoop.hbase.client.ResultBoundedCompletionService$QueueingFuture@79ec2ef9
>  rejected from java.util.concurrent.ThreadPoolExecutor@5198a326[Terminated, 
> pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 142]
>   at 
> java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063)
>   at 
> java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830)
>   at 
> java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1379)
>   at 
> org.apache.hadoop.hbase.client.ResultBoundedCompletionService.submit(ResultBoundedCompletionService.java:171)
>   at 
> org.apache.hadoop.hbase.client.ScannerCallableWithReplicas.addCallsForCurrentReplica(ScannerCallableWithReplicas.java:320)
>   at 
> org.apache.hadoop.hbase.client.ScannerCallableWithReplicas.call(ScannerCallableWithReplicas.java:182)
>   at 
> org.apache.hadoop.hbase.client.ScannerCallableWithReplicas.call(ScannerCallableWithReplicas.java:58)
>   at 
> org.apache.hadoop.hbase.client.RpcRetryingCallerImpl.callWithoutRetries(RpcRetryingCallerImpl.java:192)
>   ... 19 more
> {code}
> .. but then this which looks less ok:
> {code}
> 2018-02-21 01:30:24,044 DEBUG 
> [RpcServer.default.FPBQ.Fifo.handler=4,queue=0,port=39067] 
> ipc.CallRunner(141): callId: 16 service: RegionServerStatusService 
> methodName: ReportRegionSpaceUse size: 109 connection: 172.17.0.2:57185 
> deadline: 1519176634044
> org.apache.hadoop.hbase.PleaseHoldException: Master is initializing
>   at 
> org.apache.hadoop.hbase.master.HMaster.checkInitialized(HMaster.java:2741)
>   at 
> org.apache.hadoop.hbase.master.MasterRpcServices.reportRegionSpaceUse(MasterRpcServices.java:2135)
>   at 
> org.apache.hadoop.hbase.shaded.protobuf.generated.RegionServerStatusProtos$RegionServerStatusService$2.callBlockingMethod(RegionServerStatusProtos.java:11053)
>   at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:406)
>   at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:130)
>   at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(RpcExecutor.java:324)
>   at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(RpcExecutor.java:304)
> 2018-02-21 01:30:24,046 ERROR [regionserver/ad51e354307e:0.Chore.1] 
> hbase.ScheduledChore(189): Caught error
> java.io.UncheckedIOException: org.apache.hadoop.hbase.TableNotFoundException: 
> hbase:quota
>   at 
> org.apache.hadoop.hbase.client.ResultScanner$1.hasNext(ResultScanner.java:55)
>   at 
> org.apache.hadoop.hbase.quotas.SpaceQuotaRefresherChore.fetchSnapshotsFromQuotaTable(SpaceQuotaRefresherChore.java:151)
>   at 
> org.apache.hadoop.hbase.quotas.SpaceQuotaRefresherChore.chore(SpaceQuotaRefresherChore.java:84)
>   at org.apache.hadoop.hbase.ScheduledChore.run(ScheduledChore.java:186)
>   at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>   at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
>   at 
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
>   at 
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
>   at 
> org.apache.hadoop.hbase.JitterScheduledThreadPoolExecutorImpl$JitteredRunnableScheduledFuture.run(JitterScheduledThreadPoolExecutorImpl.java:111)
>   at 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>   at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>   at java.lang.Thread.run(Thread.java:748)
> Caused by: org.apache.hadoop.hbase.TableNotFoundException: hbase:quota
>   at 
> org.apache.hadoop.hbase.client.ConnectionImplementation.locateRegionInMeta(ConnectionImplementation.java:842)
>   at 
> org.apache.hadoop.hbase.client.ConnectionImplementation.locateRegion(ConnectionImplementation.java:733)
>   at 
> org.apache.hadoop.hbase.client.ConnectionUtils$ShortCircuitingClusterConnection.locateRegion(ConnectionUtils.java:131)
>   at 
> org.apache.hadoop.hbase.client.RpcRetryingCallerWithReadReplicas.getRegionLocations(RpcRetryingCallerWithReadReplicas.java:325)
>   at 
> org.apache.hadoop.hbase.client.ScannerCallableWithReplicas.call(ScannerCallableWithReplicas.java:153)
>   at 
> org.apache.hadoop.hbase.client.ScannerCallableWithReplicas.call(ScannerCallableWithReplicas.java:58)
>   at 
> org.apache.hadoop.hbase.client.RpcRetryingCallerImpl.callWithoutRetries(RpcRetryingCallerImpl.java:192)
>   at org.apache.hadoop.hbase.client.ClientScanner.call(ClientScanner.java:269)
>   at 
> org.apache.hadoop.hbase.client.ClientScanner.loadCache(ClientScanner.java:437)
>   at 
> org.apache.hadoop.hbase.client.ClientScanner.nextWithSyncCache(ClientScanner.java:312)
>   at org.apache.hadoop.hbase.client.ClientScanner.next(ClientScanner.java:597)
>   at 
> org.apache.hadoop.hbase.client.ResultScanner$1.hasNext(ResultScanner.java:53)
>   ... 11 more
> 2018-02-21 01:30:24,179 DEBUG [Time-limited test-EventThread] 
> zookeeper.ZKWatcher(443): master:39067-0x161b5fb62d10000, 
> quorum=localhost:49877, baseZNode=/hbase Received ZooKeeper Event, 
> type=NodeChildrenChanged, state=SyncConnected, path=/hbase/namespace
> 2018-02-21 01:30:24,604 INFO  [PEWorker-13] 
> procedure2.ProcedureExecutor(1247): Finished pid=6, state=SUCCESS; 
> CreateNamespaceProcedure, namespace=hbase in 1.0980sec
> 2018-02-21 01:30:24,772 DEBUG [Time-limited test-EventThread] 
> zookeeper.ZKWatcher(443): master:39067-0x161b5fb62d10000, 
> quorum=localhost:49877, baseZNode=/hbase Received ZooKeeper Event, 
> type=NodeDataChanged, state=SyncConnected, path=/hbase/namespace/default
> 2018-02-21 01:30:24,830 DEBUG [Time-limited test-EventThread] 
> zookeeper.ZKWatcher(443): master:39067-0x161b5fb62d10000, 
> quorum=localhost:49877, baseZNode=/hbase Received ZooKeeper Event, 
> type=NodeDataChanged, state=SyncConnected, path=/hbase/namespace/hbase
> 2018-02-21 01:30:24,831 INFO  [M:0;ad51e354307e:39067] master.HMaster(927): 
> Master has completed initialization 17.276sec
> 2018-02-21 01:30:24,832 INFO  [M:0;ad51e354307e:39067] 
> quotas.MasterQuotaManager(87): Quota table not found. Creating...
> 2018-02-21 01:30:24,833 INFO  [M:0;ad51e354307e:39067] master.HMaster(1783): 
> Client=null/null create 'hbase:quota', {NAME => 'q', VERSIONS => '1', 
> EVICT_BLOCKS_ON_CLOSE => 'false', NEW_VERSION_BEHAVIOR => 'false', 
> KEEP_DELETED_CELLS => 'FALSE', CACHE_DATA_ON_WRITE => 'false', 
> DATA_BLOCK_ENCODING => 'NONE', TTL => 'FOREVER', MIN_VERSIONS => '0', 
> REPLICATION_SCOPE => '0', BLOOMFILTER => 'ROW', CACHE_INDEX_ON_WRITE => 
> 'false', IN_MEMORY => 'false', CACHE_BLOOMS_ON_WRITE => 'false', 
> PREFETCH_BLOCKS_ON_OPEN => 'false', COMPRESSION => 'NONE', BLOCKCACHE => 
> 'true', BLOCKSIZE => '65536'}, {NAME => 'u', VERSIONS => '1', 
> EVICT_BLOCKS_ON_CLOSE => 'false', NEW_VERSION_BEHAVIOR => 'false', 
> KEEP_DELETED_CELLS => 'FALSE', CACHE_DATA_ON_WRITE => 'false', 
> DATA_BLOCK_ENCODING => 'NONE', TTL => 'FOREVER', MIN_VERSIONS => '0', 
> REPLICATION_SCOPE => '0', BLOOMFILTER => 'ROW', CACHE_INDEX_ON_WRITE => 
> 'false', IN_MEMORY => 'false', CACHE_BLOOMS_ON_WRITE => 'false', 
> PREFETCH_BLOCKS_ON_OPEN => 'false', COMPRESSION => 'NONE', BLOCKCACHE => 
> 'true', BLOCKSIZE => '65536'}
> 2018-02-21 01:30:24,979 ERROR 
> [RpcServer.default.FPBQ.Fifo.handler=4,queue=0,port=39067] 
> ipc.RpcServer(464): Unexpected throwable object
> java.lang.NullPointerException
>   at 
> org.apache.hadoop.hbase.master.MasterRpcServices.reportRegionSpaceUse(MasterRpcServices.java:2142)
>   at 
> org.apache.hadoop.hbase.shaded.protobuf.generated.RegionServerStatusProtos$RegionServerStatusService$2.callBlockingMethod(RegionServerStatusProtos.java:11053)
>   at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:406)
>   at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:130)
>   at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(RpcExecutor.java:324)
>   at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(RpcExecutor.java:304)
> 2018-02-21 01:30:24,980 DEBUG 
> [RpcServer.default.FPBQ.Fifo.handler=4,queue=0,port=39067] 
> ipc.CallRunner(141): callId: 18 service: RegionServerStatusService 
> methodName: ReportRegionSpaceUse size: 109 connection: 172.17.0.2:57185 
> deadline: 1519176634979
> java.io.IOException
>   at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:465)
>   at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:130)
>   at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(RpcExecutor.java:324)
>   at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(RpcExecutor.java:304)
> Caused by: java.lang.NullPointerException
>   at 
> org.apache.hadoop.hbase.master.MasterRpcServices.reportRegionSpaceUse(MasterRpcServices.java:2142)
>   at 
> org.apache.hadoop.hbase.shaded.protobuf.generated.RegionServerStatusProtos$RegionServerStatusService$2.callBlockingMethod(RegionServerStatusProtos.java:11053)
>   at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:406)
>   ... 3 more
> 2018-02-21 01:30:24,982 DEBUG [regionserver/ad51e354307e:0.Chore.1] 
> regionserver.HRegionServer(1245): Failed to report region sizes to Master. 
> This will be retried.
> java.io.IOException: java.io.IOException
>   at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:465)
>   at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:130)
>   at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(RpcExecutor.java:324)
>   at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(RpcExecutor.java:304)
> Caused by: java.lang.NullPointerException
>   at 
> org.apache.hadoop.hbase.master.MasterRpcServices.reportRegionSpaceUse(MasterRpcServices.java:2142)
>   at 
> org.apache.hadoop.hbase.shaded.protobuf.generated.RegionServerStatusProtos$RegionServerStatusService$2.callBlockingMethod(RegionServerStatusProtos.java:11053)
>   at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:406)
>   ... 3 more
>   at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
>   at 
> sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
>   at 
> sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
>   at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
>   at 
> org.apache.hadoop.hbase.ipc.RemoteWithExtrasException.instantiateException(RemoteWithExtrasException.java:100)
>   at 
> org.apache.hadoop.hbase.ipc.RemoteWithExtrasException.unwrapRemoteException(RemoteWithExtrasException.java:90)
>   at 
> org.apache.hadoop.hbase.shaded.protobuf.ProtobufUtil.makeIOExceptionOfException(ProtobufUtil.java:358)
>   at 
> org.apache.hadoop.hbase.shaded.protobuf.ProtobufUtil.getRemoteException(ProtobufUtil.java:335)
>   at 
> org.apache.hadoop.hbase.regionserver.HRegionServer.reportRegionSizesForQuotas(HRegionServer.java:1224)
>   at 
> org.apache.hadoop.hbase.quotas.FileSystemUtilizationChore.reportRegionSizesToMaster(FileSystemUtilizationChore.java:187)
>   at 
> org.apache.hadoop.hbase.quotas.FileSystemUtilizationChore.chore(FileSystemUtilizationChore.java:136)
>   at org.apache.hadoop.hbase.ScheduledChore.run(ScheduledChore.java:186)
>   at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>   at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
>   at 
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
>   at 
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
>   at 
> org.apache.hadoop.hbase.JitterScheduledThreadPoolExecutorImpl$JitteredRunnableScheduledFuture.run(JitterScheduledThreadPoolExecutorImpl.java:111)
>   at 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>   at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>   at java.lang.Thread.run(Thread.java:748)
> Caused by: 
> org.apache.hadoop.hbase.ipc.RemoteWithExtrasException(java.io.IOException): 
> java.io.IOException
>   at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:465)
>   at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:130)
>   at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(RpcExecutor.java:324)
>   at org.apache.hadoop.hbase.ipc.RpcExecutor$Handler.run(RpcExecutor.java:304)
> Caused by: java.lang.NullPointerException
>   at 
> org.apache.hadoop.hbase.master.MasterRpcServices.reportRegionSpaceUse(MasterRpcServices.java:2142)
>   at 
> org.apache.hadoop.hbase.shaded.protobuf.generated.RegionServerStatusProtos$RegionServerStatusService$2.callBlockingMethod(RegionServerStatusProtos.java:11053)
>   at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:406)
>   ... 3 more
> {code}
> You might have some input mighty [~elserj] ? Thanks sir. It failed only this 
> once. I could up the timeouts from 30 seconds because that allowed but my 
> guess it he NPE does us in. Thanks sir.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

Reply via email to