#1373 Docbook graphics extension seems to cause hang in saxon & xalan

[Ian Wienand]

Something seems to have gone wrong with the java extensions and graphics where the following document will hang with both saxon & xalan when "use.extensions" is turned on (and the classpath has the relevant docbook extensions in it)

<?xml version="1.0"?>
<book xmlns="http://docbook.org/ns/docbook" xmlns:xi="http://www.w3.org/2001/XInclude" version="5.0">

  <title>foo</title>

  <chapter xmlns="http://docbook.org/ns/docbook" version="5.0" xml:id="chapter01" xml:base="chapter01/chapter01.xml">

    <info>
      <title>chapter</title>
    </info>

    <section>
      <info>
        <title>section</title>
      </info>

      <figure>
        <info>
        <title>title</title></info>
        <mediaobject>
          <imageobject role="html">
            <imagedata fileref="chapter01/figures/masking.png" format="PNG"/>
          </imageobject>
        </mediaobject>
      </figure>
    </section>
  </chapter>
</book>

What happens is that everything seems to process, but then saxon/xalan just hangs there doing nothing.

$ java -classpath "../xalan/xalan.jar:../xalan/xercesImpl.jar:../xalan/xml-apis.jar:../docbook-xsl-ns-1.79.0/extensions/xalan27.jar" org.ache.xalan.xslt.Process -in  ./in.xml -xsl ../in.xsl -param use.extensions 1
file:///.../docbook-xsl-ns-1.79.0/xhtml/chunker.xsl; Line #106; Column #18; Writing chapter01.html for chapter(chapter01)
file:///.../docbook-xsl-ns-1.79.0/xhtml/chunker.xsl; Line #106; Column #18; Writing index.html for book
<?xml version="1.0" encoding="UTF-8"?>

It seems to be something to do with graphics extensions because it's the "mediaobject" that induces this behaviour. Since it happens with saxon (6.5) and xalan (2.7) the common thing seems to be the docbook extensions.

java version is

$ java -version
java version "1.7.0_91"
OpenJDK Runtime Environment (IcedTea 2.6.3) (7u91-2.6.3-1)
OpenJDK 64-Bit Server VM (build 24.91-b01, mixed mode)

[Robert Stayton]

Hi, I'm not able to duplicate this problem. I used the same xalan command line you provided except for -xsl ../docbook-xsl-ns-1.79.1/xhtml/chunk.xsl (you didn't specify what was in your in.xsl file), and the two chunks are created, the PI is emitted, and the process terminates normally. My java version is:

java version "1.7.0_45"
Java(TM) SE Runtime Environment (build 1.7.0_45-b18)
Java HotSpot(TM) 64-Bit Server VM (build 24.45-b08, mixed mode)

I don't recall any changes to the extension code in either Java or XSL for this release. Did it work for you using 1.78.1? What is in "in.xsl"?

I notice that the two chunks are actually created for you, as well as the PI, so I don't see anything going wrong with the XSL processing itself.

[Ian Wienand]

I've attached what I can use to replicate it

Included is the jstack logs from both saxon & xalan which both looks similar with a seeming unending wait on a conditional?

2015-12-29 21:52:16
Full thread dump OpenJDK 64-Bit Server VM (24.91-b01 mixed mode):

"Attach Listener" daemon prio=10 tid=0x00007faee0001000 nid=0x7716 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"DestroyJavaVM" prio=10 tid=0x00007faf1000a000 nid=0x76e0 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"AWT-EventQueue-0" prio=10 tid=0x00007faf1024d000 nid=0x76f3 waiting on condition [0x00007faee8984000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)

    - parking to wait for  <0x000000078811e0a8> (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.awt.EventQueue.getNextEvent(EventQueue.java:555)
    at java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:211)
    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)

"process reaper" daemon prio=10 tid=0x00007faf10223000 nid=0x76f1 waiting on condition [0x00007faf0403a000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)

    - parking to wait for  <0x000000078811d808> (a java.util.concurrent.SynchronousQueue$TransferStack)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
    at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:359)
    at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:942)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

"Service Thread" daemon prio=10 tid=0x00007faf100ae000 nid=0x76eb runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=10 tid=0x00007faf100ac000 nid=0x76ea waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0x00007faf100a9000 nid=0x76e9 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x00007faf100a7000 nid=0x76e8 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x00007faf1007b800 nid=0x76e7 in Object.wait() [0x00007faf076b3000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)

    - waiting on <0x00000007881105f8> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000007881105f8> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" daemon prio=10 tid=0x00007faf10079800 nid=0x76e6 in Object.wait() [0x00007faf077b4000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)

    - waiting on <0x0000000788110360> (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 <0x0000000788110360> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=10 tid=0x00007faf10075800 nid=0x76e5 runnable 

"GC task thread#0 (ParallelGC)" prio=10 tid=0x00007faf1001f800 nid=0x76e1 runnable 

"GC task thread#1 (ParallelGC)" prio=10 tid=0x00007faf10021800 nid=0x76e2 runnable 

"GC task thread#2 (ParallelGC)" prio=10 tid=0x00007faf10023800 nid=0x76e3 runnable 

"GC task thread#3 (ParallelGC)" prio=10 tid=0x00007faf10025800 nid=0x76e4 runnable 

"VM Periodic Task Thread" prio=10 tid=0x00007faf100b9000 nid=0x76ec waiting on condition 

JNI global references: 250

[Ian Wienand]

I also just tried with 1.78.1 and the same thing happens

[Ian Wienand]

This might be a problem with the jre itself. I installed "openjdk-8-jre", and it seems to work (i.e. exits correctly). This is with

$ java -version
openjdk version "1.8.0_72-internal"
OpenJDK Runtime Environment (build 1.8.0_72-internal-b05)
OpenJDK 64-Bit Server VM (build 25.72-b05, mixed mode)

[Norman Walsh]

Very strange. That does sound like it could be an OpenJDK bug. I guess. I notice that the problem also occurs in sun.misc.Unsafe and I seem to recall that there was some discussion recently about removing that class.

Did you compile the extension functions with that version of the JDK or are you using release jars?

[Ian Wienand]

This was using the extensions from the release jar files

So all signs point to the jdk ... i had no reason to be using 1.7 other than I hadn't upgraded the system to 1.8. Possibly it's a true race condition in the code, only hit on 1.7 for whatever reason. As mentioned, it would seem to be something in the image processing code, as it is the presence of the <mediaobject> tag that caused the hang across both saxon & xalan</mediaobject>