Support Questions
Find answers, ask questions, and share your expertise
Announcements
Alert: Welcome to the Unified Cloudera Community. Former HCC members be sure to read and learn how to activate your account here.

Could HBase's jvm pause generate high cpu usage?

Could HBase's jvm pause generate high cpu usage?

New Contributor

Hi all,

I saw temporal high cpu usage of hbase, and having trouble to find its reason.

Super long but ambiguous INFOs and WARNs are shown. I just guess that gc and heavy scan occurred at that time. :-(

2017-05-15 17:10:21,178 INFO  [B.fifo.QRpcServer.handler=8,queue=2,port=16020] shortcircuit.ShortCircuitCache: ShortCircuitCache(0x1f8da901): could not load 1077622016_BP-1164966310-10.20.173.233-1472808503162 due to InvalidToken exception.
org.apache.hadoop.security.token.SecretManager$InvalidToken: access control error while attempting to set up short-circuit access to /apps/hbase/data/data/default/CMT_KWD_ANLY/3ae8d49c9f6652bc74f98fc14627f253/0/520be239596b4c0bbccceade5a837d89
        at org.apache.hadoop.hdfs.BlockReaderFactory.requestFileDescriptors(BlockReaderFactory.java:589)
        at org.apache.hadoop.hdfs.BlockReaderFactory.createShortCircuitReplicaInfo(BlockReaderFactory.java:488)
        at org.apache.hadoop.hdfs.shortcircuit.ShortCircuitCache.create(ShortCircuitCache.java:784)
        at org.apache.hadoop.hdfs.shortcircuit.ShortCircuitCache.fetchOrCreate(ShortCircuitCache.java:718)
        at org.apache.hadoop.hdfs.BlockReaderFactory.getBlockReaderLocal(BlockReaderFactory.java:422)
        at org.apache.hadoop.hdfs.BlockReaderFactory.build(BlockReaderFactory.java:333)
        at org.apache.hadoop.hdfs.DFSInputStream.actualGetFromOneDataNode(DFSInputStream.java:1181)
        at org.apache.hadoop.hdfs.DFSInputStream.fetchBlockByteRange(DFSInputStream.java:1118)
        at org.apache.hadoop.hdfs.DFSInputStream.pread(DFSInputStream.java:1478)
        at org.apache.hadoop.hdfs.DFSInputStream.read(DFSInputStream.java:1441)
        at org.apache.hadoop.fs.FSDataInputStream.read(FSDataInputStream.java:92)
        at org.apache.hadoop.hbase.io.hfile.HFileBlock.positionalReadWithExtra(HFileBlock.java:722)
        at org.apache.hadoop.hbase.io.hfile.HFileBlock$AbstractFSReader.readAtOffset(HFileBlock.java:1420)
        at org.apache.hadoop.hbase.io.hfile.HFileBlock$FSReaderImpl.readBlockDataInternal(HFileBlock.java:1625)
        at org.apache.hadoop.hbase.io.hfile.HFileBlock$FSReaderImpl.readBlockData(HFileBlock.java:1504)
        at org.apache.hadoop.hbase.io.hfile.HFileReaderV2.readBlock(HFileReaderV2.java:439)
        at org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexReader.loadDataBlockWithScanInfo(HFileBlockIndex.java:269)
        at org.apache.hadoop.hbase.io.hfile.HFileReaderV2$AbstractScannerV2.seekTo(HFileReaderV2.java:636)
        at org.apache.hadoop.hbase.io.hfile.HFileReaderV2$AbstractScannerV2.seekTo(HFileReaderV2.java:586)
        at org.apache.hadoop.hbase.regionserver.StoreFileScanner.seekAtOrAfter(StoreFileScanner.java:260)
        at org.apache.hadoop.hbase.regionserver.StoreFileScanner.seek(StoreFileScanner.java:169)
        at org.apache.hadoop.hbase.regionserver.StoreScanner.seekScanners(StoreScanner.java:363)
        at org.apache.hadoop.hbase.regionserver.StoreScanner.<init>(StoreScanner.java:217)
        at org.apache.hadoop.hbase.regionserver.HStore.createScanner(HStore.java:2122)
        at org.apache.hadoop.hbase.regionserver.HStore.getScanner(HStore.java:2112)
        at org.apache.hadoop.hbase.regionserver.HRegion$RegionScannerImpl.<init>(HRegion.java:5568)
        at org.apache.hadoop.hbase.regionserver.HRegion.instantiateRegionScanner(HRegion.java:2626)
        at org.apache.hadoop.hbase.regionserver.HRegion.getScanner(HRegion.java:2612)
        at org.apache.hadoop.hbase.regionserver.HRegion.getScanner(HRegion.java:2594)
        at org.apache.hadoop.hbase.regionserver.RSRpcServices.scan(RSRpcServices.java:2280)
        at org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ClientService$2.callBlockingMethod(ClientProtos.java:32295)
        at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2127)
        at org.apache.hadoop.hbase.ipc.CallRunner.run(CallRunner.java:107)
        at org.apache.hadoop.hbase.ipc.RpcExecutor.consumerLoop(RpcExecutor.java:133)
        at org.apache.hadoop.hbase.ipc.RpcExecutor$1.run(RpcExecutor.java:108)
        at java.lang.Thread.run(Thread.java:745)
2017-05-15 17:10:21,178 INFO  [B.fifo.QRpcServer.handler=8,queue=2,port=16020] hdfs.DFSClient: Access token was invalid when connecting to /10.20.175.28:50010 : org.apache.hadoop.security.token.SecretManager$InvalidToken: access control error while attempting to set up short-circuit access to /apps/hbase/data/data/default/CMT_KWD_ANLY/3ae8d49c9f6652bc74f98fc14627f253/0/520be239596b4c0bbccceade5a837d89
2017-05-15 17:10:26,951 INFO  [JvmPauseMonitor] util.JvmPauseMonitor: Detected pause in JVM or host machine (eg GC): pause of approximately 2497ms
GC pool 'ParNew' had collection(s): count=1 time=23ms
2017-05-15 17:10:31,954 [B.fifo.QRpcServer.handler=20,queue=2,port=16020] ipc.RpcServer: (responseTooSlow): {"call":"Scan(org.apache.hadoop.hbase.protobuf.generated.ClientProtos$ScanRequest)","starttimems":1494835821154,"responsesize":10,"method":"Scan","processingtimems":10800,"client":my_ip_and_port,"queuetimems":0,"class":"HRegionServer"}

I think JVM pause INFO is the most meaningful one but still not positive, because its duration is too short than the high cpu time.

Thanks in advance!

4 REPLIES 4

Re: Could HBase's jvm pause generate high cpu usage?

JVM garbage collection is just one reason that a process can hang. In this case, you can see that the HBase RegionServer was not responsive but there was no JVM GC's that happened during that window.

This implies that there was some other reason that HBase stopped responding. Typically, there is something "beneath" HBase at the operating system or hardware level that caused the pause.

There are many reasons this could happen including: OS/Kernel bugs (update your system), swap, transparent huge pages, pauses by a hypervisor. You will have to investigate this yourself.

Re: Could HBase's jvm pause generate high cpu usage?

New Contributor

Josh, thanks for your comment.

Further question is, how could I know no GC happens? If you referred to the third log part, I rather thought there's GC is what that log means.

Re: Could HBase's jvm pause generate high cpu usage?

Yes, there was a JVM GC that happened but it only took 23 milliseconds, but your JVM paused for 2.5seconds. Therefore, the garbage collection is not your issue.

Re: Could HBase's jvm pause generate high cpu usage?

New Contributor

Oh, I missed the time. Thanks!!