{"id":114698,"date":"2022-09-14T07:00:00","date_gmt":"2022-09-14T04:00:00","guid":{"rendered":"https:\/\/www.javacodegeeks.com\/?p=114698"},"modified":"2022-09-12T14:19:59","modified_gmt":"2022-09-12T11:19:59","slug":"troubleshooting-deadlock-in-an-apache-opensource-library","status":"publish","type":"post","link":"https:\/\/www.javacodegeeks.com\/2022\/09\/troubleshooting-deadlock-in-an-apache-opensource-library.html","title":{"rendered":"Troubleshooting deadlock in an Apache opensource library"},"content":{"rendered":"

Apache PDFBox<\/a> is a popular open-source library that facilitates java applications to work with PDF documents. Recently we encountered a Deadlock that surfaced in this library. In this post we have shared how we troubleshooted and identified the root cause of the problem.<\/p>\n

What is Deadlock?<\/h2>\n

First let\u2019s try to understand what \u2018Deadlock\u2019 means. Several technical definitions aren\u2019t clear. \u2018Deadlock\u2019 definition is one among them :-). Deadlock\u2019s definition goes like this: \u201cDeadlock is a situation where a set of processes are blocked because each process is holding a resource and waiting for another resource acquired by some other process.\u201d<\/em> It\u2019s always easier to learn something new through examples and pictures. Let\u2019s look at the below practical example, which may help you to understand Deadlock better.<\/p>\n

\n
\"\"<\/a><\/figure>\n<\/div>\n
\n
\"\"<\/a><\/figure>\n<\/div>\n

Let\u2019s say there is only one train track, and this train track has six parts(part-1, part-2, part-3, part-4, part-5, part-6). Train-A starts at part-1 and Train-B starts at Part-6 on the same train track at the same time. Both trains travel at the same speed. Under this circumstance, Train-A and Train-B will reach a Deadlock state when they reach part-3 and part-4 of the train track. Because when Train-A is in part-3 of the train track, it will be stuck waiting for part-4 of the track, which Train-B holds. On the other hand, when Train-B is in part-4, it will be stuck waiting for part-3, which Train-A holds. Thus, both the trains can\u2019t move forward. This is a classic Deadlock situation. Similarly, once a Deadlock happens in the application, it cannot be recovered. The only way to recover from Deadlock is to restart the application. To learn more about Deadlock basics & troubleshooting, you may refer to this blog post<\/a>.<\/p>\n

Troubleshooting Deadlock<\/h2>\n

Now let\u2019s discuss about the Deadlock problem we faced in the application. From the above explanation you can understand that Deadlock is caused due to threads. Thus, to analyze Deadlock, you need to capture thread dump from the application. Thread dump is basically a snapshot of all threads that are running in your application. It contains information such as: stack trace, thread state, thread priority, \u2026 You can capture thread dump using one of the approaches given here<\/a>.<\/p>\n

\n
Note: Most of the time, you will not know whether the actual problem in your application is deadlock or not. What you will notice is unresponsiveness from the application. Thus, it\u2019s safe to capture all the prominent artifacts that are essential for troubleshooting such as: Garbage Collection log, thread dump, heap dump, netstat, iostat,\u2026 you may use yCrash open source script, which would capture 360-degree data (GC log, 3 snapshots of thread dump, heap dump, netstat, iostat, vmstat, top, top -H,\u2026) from your application stack within a minute and generate a bundle zip file.<\/pre>\n<\/div>\n
We uploaded the captured thread dump to fastThread<\/a> \u2013 a thread dump analysis tool. Tool immediately pointed out that the two threads caused the deadlock. Below is the excerpt from the fastThread report.<\/p>\n
\n
\"\"<\/a><\/figure>\n<\/div>\n
Tool pointed out the stack trace of the two threads that were in deadlock. Below is the stack trace of those two threads:
 
<\/div> <\/div><\/p>\n
\n
\"APP_Thread_50_WorkerTask_pool-5-thread-6\" #1899 prio=5 os_prio=0 tid=0x00007f894c405555 nid=0x44d1 waiting for monitor entry [0x00007f88e9c44000]\n   java.lang.Thread.State: BLOCKED (on object monitor)\n\tat org.apache.fontbox.ttf.TrueTypeFont.getTable(TrueTypeFont.java:147)\n\t- waiting to lock <0x00000002d216fec8> (a org.apache.fontbox.ttf.TrueTypeFont)\n\tat org.apache.fontbox.ttf.TrueTypeFont.getHorizontalMetrics(TrueTypeFont.java:229)\n\tat org.apache.fontbox.ttf.GlyphTable.getGlyphData(GlyphTable.java:210)\n\tat org.apache.fontbox.ttf.GlyphTable.getGlyph(GlyphTable.java:191)\n\t- locked <0x00000002d218ca28> (a org.apache.fontbox.ttf.RAFDataStream)\n\tat org.apache.fontbox.ttf.TrueTypeFont.getPath(TrueTypeFont.java:676)\n\tat org.apache.pdfbox.pdmodel.font.PDType1Font.getPath(PDType1Font.java:638)\n\tat org.apache.pdfbox.rendering.Type1Glyph2D.getPathForCharacterCode(Type1Glyph2D.java:83)\n\tat org.apache.pdfbox.rendering.PageDrawer.drawGlyph2D(PageDrawer.java:495)\n\tat org.apache.pdfbox.rendering.PageDrawer.showFontGlyph(PageDrawer.java:476)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.showGlyph(PDFStreamEngine.java:787)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.showGlyph(PDFStreamEngine.java:805)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.showText(PDFStreamEngine.java:743)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.showTextString(PDFStreamEngine.java:606)\n\tat org.apache.pdfbox.Contentstream.operator.text.ShowText.process(ShowText.java:56)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.processOperator(PDFStreamEngine.java:933)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.processStreamOperators(PDFStreamEngine.java:514)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.processStream(PDFStreamEngine.java:492)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.processPage(PDFStreamEngine.java:155)\n\tat org.apache.pdfbox.rendering.PageDrawer.drawPage(PageDrawer.java:277)\n\tat org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:347)\n\tat org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:268)\n\tat org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:228)\n\tat xxxxxxx.export.service.thumbnail.PDFSlideGeneratorServiceImpl$1.call(PDFSlideGeneratorServiceImpl.java:60)\n\tat xxxxxxx.ops.executor.util.ParallelExecutorTask.doCall(ParallelExecutorTask.java:43)\n\tat xxxxxxx.ops.executor.util.ParallelExecutor.executeTaskFromQueue(ParallelExecutor.java:154)\n\tat xxxxxxx.ops.executor.util.ParallelExecutor.access$100(ParallelExecutor.java:26)\n\tat xxxxxxx.ops.executor.util.ParallelExecutor$WorkerTask.doCall(ParallelExecutor.java:164)\n\tat xxxxxxx.ops.executor.util.UserContextAwareCallable.call(UserContextAwareCallable.java:89)\n\tat java.util.concurrent.FutureTask.run(FutureTask.java:266)\n\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\n\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\n\tat java.lang.Thread.run(Thread.java:748)<\/pre>\n<\/div>\n
\n
\"APP_Thread_WorkerTask_APP-pool-5-thread-5\" #1898 prio=5 os_prio=0 tid=0x00007f894c898900 nid=0x44d0 waiting for monitor entry [0x00007f88e9d45000]\n   java.lang.Thread.State: BLOCKED (on object monitor)\n\tat org.apache.fontbox.ttf.TrueTypeFont.readTable(TrueTypeFont.java:356)\n\t- waiting to lock <0x00000002d218ca28> (a org.apache.fontbox.ttf.RAFDataStream)\n\tat org.apache.fontbox.ttf.TrueTypeFont.getTable(TrueTypeFont.java:150)\n\t- locked <0x00000002d216fec8> (a org.apache.fontbox.ttf.TrueTypeFont)\n\tat org.apache.fontbox.ttf.TrueTypeFont.getCmap(TrueTypeFont.java:262)\n\tat org.apache.fontbox.ttf.TrueTypeFont.getUnicodeCmapImpl(TrueTypeFont.java:556)\n\tat org.apache.fontbox.ttf.TrueTypeFont.getUnicodeCmapLookup(TrueTypeFont.java:541)\n\tat org.apache.fontbox.ttf.TrueTypeFont.nameToGID(TrueTypeFont.java:629)\n\tat org.apache.fontbox.ttf.TrueTypeFont.hasGlyph(TrueTypeFont.java:698)\n\tat org.apache.pdfbox.pdmodel.font.PDType1Font.getNameInFont(PDType1Font.java:601)\n\tat org.apache.pdfbox.pdmodel.font.PDType1Font.hasGlyph(PDType1Font.java:645)\n\tat org.apache.pdfbox.rendering.Type1Glyph2D.getPathForCharacterCode(Type1Glyph2D.java:59)\n\tat org.apache.pdfbox.rendering.PageDrawer.drawGlyph2D(PageDrawer.java:495)\n\tat org.apache.pdfbox.rendering.PageDrawer.showFontGlyph(PageDrawer.java:476)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.showGlyph(PDFStreamEngine.java:787)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.showGlyph(PDFStreamEngine.java:805)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.showText(PDFStreamEngine.java:743)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.showTextString(PDFStreamEngine.java:606)\n\tat org.apache.pdfbox.Contentstream.operator.text.ShowText.process(ShowText.java:56)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.processOperator(PDFStreamEngine.java:933)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.processStreamOperators(PDFStreamEngine.java:514)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.processStream(PDFStreamEngine.java:492)\n\tat org.apache.pdfbox.Contentstream.PDFStreamEngine.processPage(PDFStreamEngine.java:155)\n\tat org.apache.pdfbox.rendering.PageDrawer.drawPage(PageDrawer.java:277)\n\tat org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:347)\n\tat org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:268)\n\tat org.apache.pdfbox.rendering.PDFRenderer.renderImage(PDFRenderer.java:228)\n\tat xxxxxxx.export.service.thumbnail.PDFSlideGeneratorServiceImpl$1.call(PDFSlideGeneratorServiceImpl.java:60)\n\tat xxxxxxx.ops.executor.util.ParallelExecutorTask.doCall(ParallelExecutorTask.java:43)\n\tat xxxxxxx.ops.executor.util.ParallelExecutor.executeTaskFromQueue(ParallelExecutor.java:154)\n\tat xxxxxxx.ops.executor.util.ParallelExecutor.access$100(ParallelExecutor.java:26)\n\tat xxxxxxx.ops.executor.util.ParallelExecutor$WorkerTask.doCall(ParallelExecutor.java:164)\n\tat xxxxxxx.ops.executor.util.UserContextAwareCallable.call(UserContextAwareCallable.java:89)\n\tat java.util.concurrent.FutureTask.run(FutureTask.java:266)\n\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\n\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\n\tat java.lang.Thread.run(Thread.java:748)<\/pre>\n<\/div>\n
You can see the \u2018APP_Thread_50_WorkerTask_pool-5-thread-6\u2019 <\/em>thread is in Deadlock with \u2018APP_Thread_50_WorkerTask_pool-5-thread-5\u2019<\/em> thread. From the stacktrace you can observe following two things:<\/p>\n
    \n
  1. \u2018APP_Thread_50_WorkerTask_pool-5-thread-6\u2019<\/em> has acquired the lock \u20180x00000002d218ca28\u2019<\/em> of the \u2018org.apache.fontbox.ttf.RAFDataStream\u2019<\/em> object and waiting to acquire the lock \u20180x00000002d216fec8\u2019<\/em> of the \u2018org.apache.fontbox.ttf.TrueTypeFont\u2019<\/em> object. <\/li>\n
  2. On the other hand, \u2018APP_Thread_50_WorkerTask_pool-5-thread-5\u2019<\/em> thread is trying to do the exact opposite, it acquired the lock \u20180x00000002d216fec8\u2019<\/em> of \u2018org.apache.fontbox.ttf.TrueTypeFont\u2019<\/em> object and waiting to acquire the lock \u20180x00000002d218ca28\u2019<\/em> of the \u2018org.apache.fontbox.ttf.RAFDataStream\u2019<\/em> object. <\/li>\n<\/ol>\n
    Indeed, it\u2019s a classic Deadlock condition. <\/p>\n
    Deadlock in Apache PDFBox<\/h2>\n
    If you notice two objects which are causing Deadlock are \u2018org.apache.fontbox.ttf.TrueTypeFont\u2019<\/em> and \u2018org.apache.fontbox.ttf.RAFDataStream\u2019<\/em>. Both of these objects are originating from the open source Apache PDFBox library.<\/p>\n
    Once seeing this bug, we searched in the Apache PDFBox bug database<\/a> to see whether this problem was already reported or not. We couldn\u2019t see this problem reported earlier. Thus, we went ahead and filed a new ticket in the Apache bug database with the details. Here is the ticket<\/a> that we filed, for your reference. The Apache PDFBox development team was highly responsive. They started acting on it right away and issued a fix within 2 \u2013 3 days. Great job from the PDFBox team. Truly enjoyed the open source community collaboration.<\/p>\n
    Video<\/h2>\n
    \n
    \n