I encountered a deadlock when using PDF.kit. The creation of a PdfExtractor seems to cause the kit to create a JPanel. But the code creating the extractor was being run at a time when calls to swing were not safe. See stack trace below.
Why is the kit creating UI components at this time? Is there a way to use the extractor without creating UI components?
at java.awt.Component.setFont(Component.java:1874)
- waiting to lock (a java.awt.Component$AWTTreeLock)
at java.awt.Container.setFont(Container.java:1743)
at javax.swing.JComponent.setFont(JComponent.java:2751)
at javax.swing.LookAndFeel.installColorsAndFont(LookAndFeel.java:208)
at javax.swing.plaf.basic.BasicPanelUI.installDefaults(BasicPanelUI.java:66)
at javax.swing.plaf.basic.BasicPanelUI.installUI(BasicPanelUI.java:56)
at javax.swing.JComponent.setUI(JComponent.java:664)
at javax.swing.JPanel.setUI(JPanel.java:153)
at javax.swing.JPanel.updateUI(JPanel.java:126)
at javax.swing.JPanel.(JPanel.java:86)
at javax.swing.JPanel.(JPanel.java:109)
at javax.swing.JPanel.(JPanel.java:117)
at com.aspose.pdf.kit.pj.(Unknown Source)
at com.aspose.pdf.kit.ph.(Unknown Source)
at com.aspose.pdf.kit.PdfViewer.(Unknown Source)
at com.aspose.pdf.kit.dc.(Unknown Source)
at com.aspose.pdf.kit.PdfExtractor.(Unknown Source)
at FFScraping.PDFImporter.getTextAndThumbFromStream(PDFImporter.java:156)
Hi Steven,
Attached is a simple program that demonstrates the fact that PdfExtractor is making unexpected calls in its constructor routine.
Restating the problem, I don’t expect PDFKit to be making calls that are not thread-safe as I need to use it in threads that are not safe for SWING or AWT calls.
In my case, I found the problem because it led to a deadlock. I was reading PDF files in one thread and updating a list in another thread (the thread safe for UI). My threads use synchronize to control the use of a share resource. But to my surprise, the cell renderer’s lock prevent PdfExtractor from running while it was waiting for the shared resource to be free. But the cell renderer was held off waiting for the shared resource to be free: classic deadlock.
In the attached program, you are asked to select a PDF file. I’ve not tried one that doesn’t fail, but I’ve included one any anyway. Once that file is selected, you are presented with a window with some text, two buttons and a list. The list has a custom cell renderer that will stall for 10 seconds when one button is pressed and executes immediately when the other is pressed.
Clicking on either button updates the list and sets a flag so a separate thread will use PDF kit to extract text, meta data and make a thumbnail. Since the cell renderer runs from inside the swing thread after the lock is obtained, no other thread can proceed if it needs the same lock.
You’ll observe that the PdfExtractor constructor stalls until the cell renderer completes.
If your IDE has a way to dump the thread state, you may see where in the PDF Kit things are held up. I’m using JetBrains IDEA and it produces the following valuable output:
Log setup.
Setting List Value to ‘New Value at Sat Feb 23 14:26:38 PST 2013’
Setting flag to trigger other thread
Stalling for 10 seconds
Starting the file reading operation.
Creating PdfExtractor
2013-02-23 14:26:42
Full thread dump Java HotSpot™ 64-Bit Server VM (23.6-b04 mixed mode):
“Thread-1” prio=5 tid=0x00007fdd6433c000 nid=0x4517 waiting for monitor entry [0x00000001195cc000]
java.lang.Thread.State: BLOCKED (on object monitor)
at java.awt.Component.setFont(Component.java:1874)
- waiting to lock (a java.awt.Component$AWTTreeLock)
at java.awt.Container.setFont(Container.java:1743)
at javax.swing.JComponent.setFont(JComponent.java:2751)
at javax.swing.LookAndFeel.installColorsAndFont(LookAndFeel.java:208)
at javax.swing.plaf.basic.BasicPanelUI.installDefaults(BasicPanelUI.java:66)
at javax.swing.plaf.basic.BasicPanelUI.installUI(BasicPanelUI.java:56)
at javax.swing.JComponent.setUI(JComponent.java:664)
at javax.swing.JPanel.setUI(JPanel.java:153)
at javax.swing.JPanel.updateUI(JPanel.java:126)
at javax.swing.JPanel.(JPanel.java:86)
at javax.swing.JPanel.(JPanel.java:109)
at javax.swing.JPanel.(JPanel.java:117)
at com.aspose.pdf.kit.pj.(Unknown Source)
at com.aspose.pdf.kit.ph.(Unknown Source)
at com.aspose.pdf.kit.PdfViewer.(Unknown Source)
at com.aspose.pdf.kit.dc.(Unknown Source)
at com.aspose.pdf.kit.PdfExtractor.(Unknown Source)
at DeadlockTest.readTheFile(DeadlockTest.java:90)
at DeadlockTest$OtherThread.run(DeadlockTest.java:252)
“TimerQueue” daemon prio=5 tid=0x00007fdd638b8000 nid=0xca13 waiting on condition [0x00000001198ff000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
at java.util.concurrent.DelayQueue.take(DelayQueue.java:209)
at javax.swing.TimerQueue.run(TimerQueue.java:171)
at java.lang.Thread.run(Thread.java:722)
“Java2D Disposer” daemon prio=5 tid=0x00007fdd638b6800 nid=0x9503 in Object.wait() [0x00000001142ed000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
- locked (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
at sun.java2d.Disposer.run(Disposer.java:145)
at java.lang.Thread.run(Thread.java:722)
“Java2D Queue Flusher” daemon prio=5 tid=0x00007fdd64252800 nid=0x8b1f in Object.wait() [0x0000000113ad4000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on (a sun.java2d.opengl.OGLRenderQueue$QueueFlusher)
at sun.java2d.opengl.OGLRenderQueue$QueueFlusher.run(OGLRenderQueue.java:208)
- locked (a sun.java2d.opengl.OGLRenderQueue$QueueFlusher)
“DestroyJavaVM” prio=5 tid=0x00007fdd63030800 nid=0x1c03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
“AWT-EventQueue-0” prio=5 tid=0x00007fdd63004000 nid=0x870b waiting on condition [0x0000000113908000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at DeadlockTest$MyCellRenderer.getListCellRendererComponent(DeadlockTest.java:397)
at javax.swing.plaf.basic.BasicListUI.updateLayoutState(BasicListUI.java:1361)
at javax.swing.plaf.basic.BasicListUI.maybeUpdateLayoutState(BasicListUI.java:1311)
at javax.swing.plaf.basic.BasicListUI.getPreferredSize(BasicListUI.java:578)
at javax.swing.plaf.ComponentUI.getMinimumSize(ComponentUI.java:204)
at javax.swing.JComponent.getMinimumSize(JComponent.java:1742)
at javax.swing.BoxLayout.checkRequests(BoxLayout.java:482)
at javax.swing.BoxLayout.layoutContainer(BoxLayout.java:424)
- locked (a javax.swing.BoxLayout)
at java.awt.Container.layout(Container.java:1503)
at java.awt.Container.doLayout(Container.java:1492)
at java.awt.Container.validateTree(Container.java:1688)
at java.awt.Container.validateTree(Container.java:1697)
at java.awt.Container.validateTree(Container.java:1697)
at java.awt.Container.validateTree(Container.java:1697)
at java.awt.Container.validate(Container.java:1623)
- locked (a java.awt.Component$AWTTreeLock)
at javax.swing.RepaintManager.validateInvalidComponents(RepaintManager.java:653)
at javax.swing.RepaintManager$ProcessingRunnable.run(RepaintManager.java:1620)
at java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:251)
at java.awt.EventQueue.dispatchEventImpl(EventQueue.java:721)
at java.awt.EventQueue.access$200(EventQueue.java:103)
at java.awt.EventQueue$3.run(EventQueue.java:682)
at java.awt.EventQueue$3.run(EventQueue.java:680)
at java.security.AccessController.doPrivileged(Native Method)
at java.security.ProtectionDomain$1.doIntersectionPrivilege(ProtectionDomain.java:76)
at java.awt.EventQueue.dispatchEvent(EventQueue.java:691)
at java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:242)
at java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:161)
at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:150)
at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:146)
at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:138)
at java.awt.EventDispatchThread.run(EventDispatchThread.java:91)
“AWT-Shutdown” prio=5 tid=0x00007fdd6484f800 nid=0x5007 in Object.wait() [0x000000010f0d4000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on (a java.lang.Object)
at java.lang.Object.wait(Object.java:503)
at sun.awt.AWTAutoShutdown.run(AWTAutoShutdown.java:287)
- locked (a java.lang.Object)
at java.lang.Thread.run(Thread.java:722)
“AppKit Thread” daemon prio=5 tid=0x00007fdd6483a800 nid=0x707 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
“Monitor Ctrl-Break” daemon prio=5 tid=0x00007fdd642c4000 nid=0x4e03 runnable [0x000000010ed24000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:150)
at java.net.SocketInputStream.read(SocketInputStream.java:121)
at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:283)
at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:325)
at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:177)
- locked (a java.io.InputStreamReader)
at java.io.InputStreamReader.read(InputStreamReader.java:184)
at java.io.BufferedReader.fill(BufferedReader.java:154)
at java.io.BufferedReader.readLine(BufferedReader.java:317)
- locked (a java.io.InputStreamReader)
at java.io.BufferedReader.readLine(BufferedReader.java:382)
at com.intellij.rt.execution.application.AppMain$1.run(AppMain.java:85)
at java.lang.Thread.run(Thread.java:722)
“Service Thread” daemon prio=5 tid=0x00007fdd6288a000 nid=0x4c03 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
“C2 CompilerThread1” daemon prio=5 tid=0x00007fdd62889800 nid=0x4b03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
“C2 CompilerThread0” daemon prio=5 tid=0x00007fdd62887800 nid=0x4a03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
“Signal Dispatcher” daemon prio=5 tid=0x00007fdd62886800 nid=0x4903 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
“Finalizer” daemon prio=5 tid=0x00007fdd62857000 nid=0x3b03 in Object.wait() [0x000000010dd78000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
- locked (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:177)
“Reference Handler” daemon prio=5 tid=0x00007fdd62856000 nid=0x3a03 in Object.wait() [0x000000010dc75000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:503)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
- locked (a java.lang.ref.Reference$Lock)
“VM Thread” prio=5 tid=0x00007fdd62853800 nid=0x3903 runnable
“GC task thread#0 (ParallelGC)” prio=5 tid=0x00007fdd6280d000 nid=0x3103 runnable
“GC task thread#1 (ParallelGC)” prio=5 tid=0x00007fdd6280e000 nid=0x3203 runnable
“GC task thread#2 (ParallelGC)” prio=5 tid=0x00007fdd6280e800 nid=0x3303 runnable
“GC task thread#3 (ParallelGC)” prio=5 tid=0x00007fdd6280f000 nid=0x3403 runnable
“GC task thread#4 (ParallelGC)” prio=5 tid=0x00007fdd6280f800 nid=0x3503 runnable
“GC task thread#5 (ParallelGC)” prio=5 tid=0x00007fdd62810800 nid=0x3603 runnable
“GC task thread#6 (ParallelGC)” prio=5 tid=0x00007fdd62811000 nid=0x3703 runnable
“GC task thread#7 (ParallelGC)” prio=5 tid=0x00007fdd62811800 nid=0x3803 runnable
“VM Periodic Task Thread” prio=5 tid=0x00007fdd62868800 nid=0x4d03 waiting on condition
JNI global references: 752
Heap
PSYoungGen total 24512K, used 18457K [0x00000007e4ab0000, 0x00000007e7a90000, 0x0000000800000000)
eden space 21056K, 79% used [0x00000007e4ab0000,0x00000007e5af3a38,0x00000007e5f40000)
from space 3456K, 52% used [0x00000007e5f40000,0x00000007e6102ab0,0x00000007e62a0000)
to space 3456K, 0% used [0x00000007e7730000,0x00000007e7730000,0x00000007e7a90000)
ParOldGen total 56000K, used 80K [0x00000007ae000000, 0x00000007b16b0000, 0x00000007e4ab0000)
object space 56000K, 0% used [0x00000007ae000000,0x00000007ae014010,0x00000007b16b0000)
PSPermGen total 21248K, used 16809K [0x00000007a8e00000, 0x00000007aa2c0000, 0x00000007ae000000)
object space 21248K, 79% used [0x00000007a8e00000,0x00000007a9e6a4d0,0x00000007aa2c0000)
Hi Steven,
com.aspose.pdf.kit.PdfExtractor extractor = new com.aspose.pdf.kit.PdfExtractor();<o:p></o:p>
System.out.println("Opening stream, binding and extracting text");
extractor.bindPdf("C:\\pdftest\\1916 Nokia.PDF");
extractor.extractText();
extractor.getText("C:\\pdftest\\1916 Nokia.txt");
System.out.println("Sending text to output stream");
ByteArrayOutputStream out = new ByteArrayOutputStream();
extractor.getText(out);
//textContent = out.toString();
System.out.println("Reseting stream and geting meta data");
// inputStream.reset();
com.aspose.pdf.kit.PdfFileInfo info = new com.aspose.pdf.kit.PdfFileInfo("C:\\pdftest\\1916 Nokia.PDF");
// System.out.println(info.getMetaInfo(DefaultMetadataProperties.CreateDate));
ByteArrayOutputStream out2 = new ByteArrayOutputStream();
System.out.println("Reseting stream and creating thumb");
com.aspose.pdf.kit.PdfConverter converter = new com.aspose.pdf.kit.PdfConverter();
converter.bindPdf("C:\\pdftest\\1916 Nokia.PDF");
converter.setStartPage(1);
converter.setEndPage(1);
converter.doConvert();
converter.getNextImage("C:\\pdftest\\1916 Nokia.png", com.aspose.pdf.kit.ImageType.PNG);
Running this snippet alone will not cause the problem to be noticed. The problem only occurs when the code containing the snippet is running in a separate thread and another thread has already locked AWTTreeLock.
I’m sure that the code still creates the UI component in the constructor, but it shouldn’t since it is not safe.
I forgot to mention that I was using the version from last week: (version 4.5.0) but had also seen the problem in version 4.4.0.
Hi Steven,