Hello Guru!
Greetings. Before answering how we classify high cpu consuming threads, I would like to highlight few serious problems in your application, which is making your application unresponsive.
a. Deadlock in Apache pdfbox library
Below are the two threads from Apache pdfbox library which are in deadlock. What version of Apache pdfbox library are you using?
'Thread APP_Thread_50408_759_100162222_WorkerTask_1652842343227_P_Th_SPR-APP-pool-5-thread-6' is in deadlock with thread 'APP_Thread_50408_759_100162222_WorkerTask_1652842343227_P_Th_SPR-APP-pool-5-thread-5'
APP_Thread_50408_759_100162222_WorkerTask_1652842343227_P_Th_SPR-APP-pool-5-thread-6 PRIORITY : 5 THREAD ID : 0X00007F894C406000 NATIVE ID : 0X44D1 NATIVE ID (DECIMAL) : 17617 STATE : BLOCKED stackTrace: java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.fontbox.ttf.TrueTypeFont.getTable(TrueTypeFont.java:147) - waiting to lock <0x00000002d216fec8> (a org.apache.fontbox.ttf.TrueTypeFont) at org.apache.fontbox.ttf.TrueTypeFont.getHorizontalMetrics(TrueTypeFont.java:229) at org.apache.fontbox.ttf.GlyphTable.getGlyphData(GlyphTable.java:210) at org.apache.fontbox.ttf.GlyphTable.getGlyph(GlyphTable.java:191) - locked <0x00000002d218ca28> (a org.apache.fontbox.ttf.RAFDataStream) at org.apache.fontbox.ttf.TrueTypeFont.getPath(TrueTypeFont.java:676) at org.apache.pdfbox.pdmodel.font.PDType1Font.getPath(PDType1Font.java:638) at org.apache.pdfbox.rendering.Type1Glyph2D.getPathForCharacterCode(Type1Glyph2D.java:83) at org.apache.pdfbox.rendering.PageDrawer.drawGlyph2D(PageDrawer.java:495) at org.apache.pdfbox.rendering.PageDrawer.showFontGlyph(PageDrawer.java:476) at org.apache.pdfbox.contentstream.PDFStreamEngine.showGlyph(PDFStreamEngine.java:787) at org.apache.pdfbox.contentstream.PDFStreamEngine.showGlyph(PDFStreamEngine.java:805) at org.apache.pdfbox.contentstream.PDFStreamEngine.showText(PDFStreamEngine.java:743) at org.apache.pdfbox.contentstream.PDFStreamEngine.showTextString(PDFStreamEngine.java:606) at org.apache.pdfbox.contentstream.operator.text.ShowText.process(ShowText.java:56) at org.apache.pdfbox.contentstream.PDFStreamEngine.processOperator(PDFStreamEngine.java:933) at org.apache.pdfbox.contentstream.PDFStreamEngine.processStreamOperators(PDFStreamEngine.java:514) at org.apache.pdfbox.contentstream.PDFStreamEngine.processStream(PDFStreamEngine.java:492) at org.apache.pdfbox.contentstream.PDFStreamEngine.processPage(PDFStreamEngine.java:155) at org.apache.pdfbox.rendering.PageDrawer.drawPage(PageDrawer.java:277) at org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:347) at org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:268) at org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:228) at com.spr.export.service.thumbnail.PDFSlideGeneratorServiceImpl$1.call(PDFSlideGeneratorServiceImpl.java:60) at com.spr.ops.executor.util.ParallelExecutorTask.doCall(ParallelExecutorTask.java:43) at com.spr.ops.executor.util.ParallelExecutor.executeTaskFromQueue(ParallelExecutor.java:154) at com.spr.ops.executor.util.ParallelExecutor.access$100(ParallelExecutor.java:26) at com.spr.ops.executor.util.ParallelExecutor$WorkerTask.doCall(ParallelExecutor.java:164) at com.spr.ops.executor.util.UserContextAwareCallable.call(UserContextAwareCallable.java:89) at java.util.concurrent.FutureTask.run(FutureTask.java:266) 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) APP_Thread_50408_759_100162222_WorkerTask_1652842343227_P_Th_SPR-APP-pool-5-thread-5 PRIORITY : 5 THREAD ID : 0X00007F894C404800 NATIVE ID : 0X44D0 NATIVE ID (DECIMAL) : 17616 STATE : BLOCKED stackTrace: java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.fontbox.ttf.TrueTypeFont.readTable(TrueTypeFont.java:356) - waiting to lock <0x00000002d218ca28> (a org.apache.fontbox.ttf.RAFDataStream) at org.apache.fontbox.ttf.TrueTypeFont.getTable(TrueTypeFont.java:150) - locked <0x00000002d216fec8> (a org.apache.fontbox.ttf.TrueTypeFont) at org.apache.fontbox.ttf.TrueTypeFont.getCmap(TrueTypeFont.java:262) at org.apache.fontbox.ttf.TrueTypeFont.getUnicodeCmapImpl(TrueTypeFont.java:556) at org.apache.fontbox.ttf.TrueTypeFont.getUnicodeCmapLookup(TrueTypeFont.java:541) at org.apache.fontbox.ttf.TrueTypeFont.nameToGID(TrueTypeFont.java:629) at org.apache.fontbox.ttf.TrueTypeFont.hasGlyph(TrueTypeFont.java:698) at org.apache.pdfbox.pdmodel.font.PDType1Font.getNameInFont(PDType1Font.java:601) at org.apache.pdfbox.pdmodel.font.PDType1Font.hasGlyph(PDType1Font.java:645) at org.apache.pdfbox.rendering.Type1Glyph2D.getPathForCharacterCode(Type1Glyph2D.java:59) at org.apache.pdfbox.rendering.PageDrawer.drawGlyph2D(PageDrawer.java:495) at org.apache.pdfbox.rendering.PageDrawer.showFontGlyph(PageDrawer.java:476) at org.apache.pdfbox.contentstream.PDFStreamEngine.showGlyph(PDFStreamEngine.java:787) at org.apache.pdfbox.contentstream.PDFStreamEngine.showGlyph(PDFStreamEngine.java:805) at org.apache.pdfbox.contentstream.PDFStreamEngine.showText(PDFStreamEngine.java:743) at org.apache.pdfbox.contentstream.PDFStreamEngine.showTextString(PDFStreamEngine.java:606) at org.apache.pdfbox.contentstream.operator.text.ShowText.process(ShowText.java:56) at org.apache.pdfbox.contentstream.PDFStreamEngine.processOperator(PDFStreamEngine.java:933) at org.apache.pdfbox.contentstream.PDFStreamEngine.processStreamOperators(PDFStreamEngine.java:514) at org.apache.pdfbox.contentstream.PDFStreamEngine.processStream(PDFStreamEngine.java:492) at org.apache.pdfbox.contentstream.PDFStreamEngine.processPage(PDFStreamEngine.java:155) at org.apache.pdfbox.rendering.PageDrawer.drawPage(PageDrawer.java:277) at org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:347) at org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:268) at org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:228) at com.spr.export.service.thumbnail.PDFSlideGeneratorServiceImpl$1.call(PDFSlideGeneratorServiceImpl.java:60) at com.spr.ops.executor.util.ParallelExecutorTask.doCall(ParallelExecutorTask.java:43) at com.spr.ops.executor.util.ParallelExecutor.executeTaskFromQueue(ParallelExecutor.java:154) at com.spr.ops.executor.util.ParallelExecutor.access$100(ParallelExecutor.java:26) at com.spr.ops.executor.util.ParallelExecutor$WorkerTask.doCall(ParallelExecutor.java:164) at com.spr.ops.executor.util.UserContextAwareCallable.call(UserContextAwareCallable.java:89) at java.util.concurrent.FutureTask.run(FutureTask.java:266) 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)
b. 394 threads in BLOCKED state
Because of deadlock reported in #a, 394 threads are in BLOCKED state with exact same stacktrace. Below is stacktrace of those threads. Once #a is resolved, this problem should go away.
java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.fontbox.ttf.TrueTypeFont.readPostScriptNames(TrueTypeFont.java:472) - waiting to lock <0x00000002d216fec8> (a org.apache.fontbox.ttf.TrueTypeFont) at org.apache.fontbox.ttf.TrueTypeFont.nameToGID(TrueTypeFont.java:615) at org.apache.fontbox.ttf.TrueTypeFont.hasGlyph(TrueTypeFont.java:698) at org.apache.pdfbox.pdmodel.font.PDType1Font.getNameInFont(PDType1Font.java:584) at org.apache.pdfbox.pdmodel.font.PDType1Font.hasGlyph(PDType1Font.java:645) at org.apache.pdfbox.rendering.Type1Glyph2D.getPathForCharacterCode(Type1Glyph2D.java:59) at org.apache.pdfbox.rendering.PageDrawer.drawGlyph2D(PageDrawer.java:495) at org.apache.pdfbox.rendering.PageDrawer.showFontGlyph(PageDrawer.java:476) at org.apache.pdfbox.contentstream.PDFStreamEngine.showGlyph(PDFStreamEngine.java:787) at org.apache.pdfbox.contentstream.PDFStreamEngine.showGlyph(PDFStreamEngine.java:805) at org.apache.pdfbox.contentstream.PDFStreamEngine.showText(PDFStreamEngine.java:743) at org.apache.pdfbox.contentstream.PDFStreamEngine.showTextString(PDFStreamEngine.java:606) at org.apache.pdfbox.contentstream.operator.text.ShowText.process(ShowText.java:56) at org.apache.pdfbox.contentstream.PDFStreamEngine.processOperator(PDFStreamEngine.java:933) at org.apache.pdfbox.contentstream.PDFStreamEngine.processStreamOperators(PDFStreamEngine.java:514) at org.apache.pdfbox.contentstream.PDFStreamEngine.processStream(PDFStreamEngine.java:492) at org.apache.pdfbox.contentstream.PDFStreamEngine.processPage(PDFStreamEngine.java:155) at org.apache.pdfbox.rendering.PageDrawer.drawPage(PageDrawer.java:277) at org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:347) at org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:268) at org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:228) at com.spr.export.service.thumbnail.PDFSlideGeneratorServiceImpl$1.call(PDFSlideGeneratorServiceImpl.java:60) at com.spr.ops.executor.util.ParallelExecutorTask.doCall(ParallelExecutorTask.java:43) at com.spr.ops.executor.util.ParallelExecutor.executeTaskFromQueue(ParallelExecutor.java:154) at com.spr.ops.executor.util.ParallelExecutor.access$100(ParallelExecutor.java:26) at com.spr.ops.executor.util.ParallelExecutor$WorkerTask.doCall(ParallelExecutor.java:164) at com.spr.ops.executor.util.UserContextAwareCallable.call(UserContextAwareCallable.java:89) at java.util.concurrent.FutureTask.run(FutureTask.java:266) 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)
c. 924 threads in WAITING state
There are 924 threads which are in WAITING state. They all are having exact same stacktrace. They are WAITING to be joined. These many threads with same stack trace can make your application unresponsive.
java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.lang.Thread.join(Thread.java:1252) - locked <0x0000000507a20158> (a java.lang.Thread) at java.lang.Thread.join(Thread.java:1326) at net.bramp.ffmpeg.progress.AbstractSocketProgressParser.stop(AbstractSocketProgressParser.java:86) at net.bramp.ffmpeg.progress.TcpProgressParser.stop(TcpProgressParser.java:34) - locked <0x0000000508166110> (a net.bramp.ffmpeg.progress.TcpProgressParser) at net.bramp.ffmpeg.progress.AbstractSocketProgressParser.close(AbstractSocketProgressParser.java:95) at net.bramp.ffmpeg.FFmpeg.run(FFmpeg.java:200) at com.spr.utils.core.media.VideoProcessingUtils.captureThumbnailAtGivenTimestamp(VideoProcessingUtils.java:489) at com.spr.utils.core.media.VideoProcessingUtils.grabFrames(VideoProcessingUtils.java:397) at com.spr.image.MediaServiceImpl.getThumbnailForVideoUrl(MediaServiceImpl.java:828) at sun.reflect.GeneratedMethodAccessor118.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at xxxxxxx.server.UnaryCallHandler.lambda$null$0(UnaryCallHandler.java:72) at xxxxxxx.server.UnaryCallHandler$$Lambda$3329/85526597.run(Unknown Source) at xxxxxxx.common.MicroServiceUtils.lambda$runInContext$0(MicroServiceUtils.java:38) at xxxxxxx.common.MicroServiceUtils$$Lambda$3331/722197770.call(Unknown Source) at xxxxxxx.common.InvocationContext.runInContext(InvocationContext.java:206) at xxxxxxx.common.MicroServiceUtils.runInContext(MicroServiceUtils.java:37) at xxxxxxx.server.UnaryCallHandler.lambda$createHandler$1(UnaryCallHandler.java:65) at xxxxxxx.server.UnaryCallHandler$$Lambda$3097/1740133606.invoke(Unknown Source) at io.grpc.stub.ServerCalls$UnaryServerCallHandler$UnaryServerCallListener.onHalfClose(ServerCalls.java:182) at io.grpc.PartialForwardingServerCallListener.onHalfClose(PartialForwardingServerCallListener.java:35) at io.grpc.ForwardingServerCallListener.onHalfClose(ForwardingServerCallListener.java:23) at io.grpc.ForwardingServerCallListener$SimpleForwardingServerCallListener.onHalfClose(ForwardingServerCallListener.java:40) at xxxxxxx.common.PrometheusMetricsInterceptor$2.onHalfClose(PrometheusMetricsInterceptor.java:109) at io.grpc.PartialForwardingServerCallListener.onHalfClose(PartialForwardingServerCallListener.java:35) at io.grpc.ForwardingServerCallListener.onHalfClose(ForwardingServerCallListener.java:23) at io.grpc.ForwardingServerCallListener$SimpleForwardingServerCallListener.onHalfClose(ForwardingServerCallListener.java:40) at io.grpc.Contexts$ContextualizedServerCallListener.onHalfClose(Contexts.java:86) at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.halfClosed(ServerCallImpl.java:331) at io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1HalfClosed.runInContext(ServerImpl.java:797) at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123) 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)
d. How we classify high CPU consuming threads
Here is a post which explains how we classify high CPU consuming threads and it also has explanation for the fake runnable threads that you are pointing out. However this is not a accurate way to determine CPU consuming threads.
Inorder to accurately point the lines of code causing the CPU spike, you need to analyze not only thread dumps but also 'top -H -p {PID}' command output, where {PID} is your Java application's process Id which is experiencing CPU spike. When you issue this ‘top’ command with given arguments, it will list all the threads running in the application and amount of CPU each one of the thread consume. Once you have both the data, you can identify high CPU consuming thread and lines of code they are executing.
You can use the open source yCrash script which will capture 360-degree application level artifacts (like GC logs, 3 snapshots of thread dumps, heap dumps) and system level artifacts (like top, top -H, netstat, vmstat, iostat, dmesg, diskusage, kernel parameters...). Once you have these data, either you can manually analyze them or upload it to yCrash tool. Tool analyzes all these dataset and generates an instant root cause analysis report pointing out exact line of code causing the CPU spike. Here is more detailed information on how to diagnose high CPU spike.
Edit your Comment