Xerces Parsing and the Dreaded FWK005 Exception

One of the Java/Groovy applications I'm currently works with multiple threads. In each thread, an XML service response is marshalled into an object using a method similar to:

    private def messageObjectFrom(String responseXml) {
        def jaxbElement = (JAXBElement) unmarshaller().unmarshal(readerFor(responseXml))
        (MessageType) jaxbElement.value
    }

Under a reasonable amount of load (several threads), the application would report the following exception during an execution of the method:

    javax.xml.bind.UnmarshalException: null
            at javax.xml.bind.helpers.AbstractUnmarshallerImpl.createUnmarshalException(AbstractUnmarshallerImpl.java:315) ~[na:1.6.0_24]
    ...
    Caused by: org.xml.sax.SAXException: FWK005 parse may not be called while parsing.
            at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source) ~[com.springsource.org.apache.xerces-2.8.1.jar:na]
            at org.apache.xerces.jaxp.SAXParserImpl$JAXPSAXParser.parse(Unknown Source) ~[com.springsource.org.apache.xerces-2.8.1.jar:na]
            at com.sun.xml.bind.v2.runtime.unmarshaller.UnmarshallerImpl.unmarshal0(UnmarshallerImpl.java:211) ~[jaxb-impl-2.1.13.jar:2.1.13]
            ... 43 common frames omitted

I've seen the error in the past when parsing XML in a multi-threaded application using Xerces. Several mailing lists have had questions about this error over the years which point to a concurrency issue in the Xerces parser. In my application, the parser is used inside multiple threads.

Most of the postings suggest synchronizing access to the parser. I attempted to do so by adding the synchronized keyword to the method signature:

    synchronized private def messageObjectFrom(String responseXml) {
        def jaxbElement = (JAXBElement) unmarshaller().unmarshal(readerFor(responseXml))
        (MessageType) jaxbElement.value
    }

This indeed did resolve the issue as I haven't run into a FWK005 error since. Its unfortunate the parser itself is not thread-safe, but this solution will do for me for now.

Hope this may help someone else who runs into a similar situation. Thanks!

Maven JAXB2 Plugin and Configuring Package Names

Several Maven plugins exist for generating classes from a schema definition. One I have yet to try is the Maven JAXB2 Plugin. Below I'll show the minimum setup for using the plugin in your project, as well as a couple of methods for dealing with the package name assigned to the generated classes.

Given the simplistic schema below, placed in src/main/resources of the project:

  <?xml version="1.0" encoding="utf-8"?>
  <xsd:schema xmlns="http://example.org/message/1.0" xmlns:xsd="http://www.w3.org/2001/XMLSchema">
    <xsd:element name="message">
      <xsd:complexType>
        <xsd:sequence>
          <xsd:element name="text" type="xsd:string"/>
        </xsd:sequence>
      </xsd:complexType>    
    </xsd:element>
  </xsd:schema>

We can add the plugin definition to our POM:

  <plugin>
    <groupId>org.jvnet.jaxb2.maven2</groupId>
    <artifactId>maven-jaxb2-plugin</artifactId>
    <version>0.8.0</version>
    <executions>
      <execution>
        <goals>
          <goal>generate</goal>
        </goals>
      </execution>
    </executions>
  </plugin>

The classes generated by the plugin can be found in target/generated-sources/xjc. Below is the single class, Message.java, generated by the plugin (with the imports optimized and comments removed for brevity):

  package generated;

  import javax.xml.bind.annotation.*;

  @XmlAccessorType(XmlAccessType.FIELD)
  @XmlType(name = "", propOrder = {"text"})
  @XmlRootElement(name = "message")
  public class Message {

      @XmlElement(required = true)
      protected String text;

      public String getText() {
          return text;
      }

      public void setText(String value) {
          this.text = value;
      }
  }

The first thing that stands out to me is the package name of generated. This might be ok if I wanted to use the generated classes within a single project, but if I wanted to distribute them, a more useful package name might be helpful.

The user guide for the plugin describes a list of configuration options. The one we're looking for might just be generatePackage, which we can add:

  <plugin>
    <groupId>org.jvnet.jaxb2.maven2</groupId>
    <artifactId>maven-jaxb2-plugin</artifactId>
    <version>0.8.0</version>
    <executions>
      <!-- ... -->
    </executions>
    <configuration>
      <generatePackage>org.example.message</generatePackage>
    </configuration>
  </plugin>

The generated class can now be found in target/generated-sources/xjc/org/example/messsage/Message.java, with the new package name:

  package org.example.message;

  public class Message {
     // ...
  }

There are a couple more options for setting the package name, one is to add an annotation to the schema:

  <?xml version="1.0" encoding="utf-8"?>
  <xsd:schema xmlns="http://example.org/message"
      xmlns:xsd="http://www.w3.org/2001/XMLSchema" 
      xmlns:xjc="http://java.sun.com/xml/ns/jaxb/xjc" 
      xmlns:jaxb="http://java.sun.com/xml/ns/jaxb" 
      jaxb:version="2.0">
    <xsd:annotation>
      <xsd:appinfo>
        <jaxb:schemaBindings>
          <jaxb:package name="org.example.test"/>
        </jaxb:schemaBindings>
      </xsd:appinfo>
    </xsd:annotation>
    <xsd:element name="message">
      <!-- ... -->
    </xsd:element>
  </xsd:schema>

If you find annotating a schema to for something like JAXB impurifies the schema, you could influence to derive a namespace by providing a targetNamespace attribute to the root element of the schema:

  <?xml version="1.0" encoding="utf-8"?>
  <xsd:schema xmlns="http://example.org/message"
      targetNamespace="http://example.org/message" ...>
      <!-- ... -->
  </xsd:schema>

If you have any other suggestions or feel like weighing in on the use of xjc annotations in schema definitions, please feel free to add a comment below.

Logging Thread Names with Log4j

In some applications that start multiple threads to handle some concurrent processing, tracking the activity for a particular thread can be tricky. Take the following log file snippet where a group of JMS messages are sent off all around the same time:

2011-11-15 10:08:25,460 INFO  [JmsMessageSender:?] Sending message to queue: UPDATE.REQ.QUEUE
2011-11-15 10:08:25,460 INFO  [JMSMessageReceiver:47] Using JMS Selector JMSCorrelationID='d6d3278b-7f7d-47f5-9d1f-a67e4100d800'
2011-11-15 10:08:25,461 INFO  [JmsMessageSender:?] Sending message to queue: UPDATE.REQ.QUEUE
2011-11-15 10:08:25,489 INFO  [JMSMessageSender:60] Using replyToQueue UPDATE.RESP.QUEUE
2011-11-15 10:08:25,486 INFO  [JMSMessageReceiver:47] Using JMS Selector JMSCorrelationID='10287b5f-c061-4bba-8d9d-f92dbf6fb239'
2011-11-15 10:08:25,489 INFO  [JMSMessageSender:60] Using replyToQueue UPDATE.RESP.QUEUE
2011-11-15 10:08:25,505 INFO  [JMSMessageReceiver:47] Using JMS Selector JMSCorrelationID='b7892699-8f26-4260-ae36-62fa8b09c9c3'
2011-11-15 10:08:25,517 INFO  [JmsMessageSender:?] Received message from queue UPDATE.RESP.QUEUE
2011-11-15 10:08:25,564 INFO  [JmsMessageSender:?] Received message from queue UPDATE.RESP.QUEUE

With the case above, where many messages are sent and the responses will be eventually dealt with for further processing (which will also be logged), we could filter the log
Message on the thread to help track where something may have gone wrong.

The logging patterns for log4j allow for logging the name of the thread with %t. Here is the pattern used to output the messages above:

log4j.appender.outFile.layout.ConversionPattern=%d{ISO8601} %-5p [%c{1}:%L] %m%n

We can add the %t next to the class (%c):

log4j.appender.outFile.layout.ConversionPattern=%d{ISO8601} %-5p [%t:%c{1}:%L] %m%n

The next run produces similar logging statements with the thread name. As this is a Spring Batch application, the threads are named after the class handling their creation, SimpleAsyncTaskExecutor, with a number appened on as in: SimpleAsyncTaskExecutor-5

2011-11-15 10:57:51,643 INFO  [SimpleAsyncTaskExecutor-5:JMSMessageSender:47] Sending to destination queue UPDATE.REQ.QUEUE
2011-11-15 10:57:51,659 INFO  [SimpleAsyncTaskExecutor-5:JMSMessageSender:60] Using replyToQueue UPDATE.RESP.QUEUE
2011-11-15 10:57:51,665 INFO  [SimpleAsyncTaskExecutor-4:JmsMessageSender:?] Sending message to queue: UPDATE.REQ.QUEUE
2011-11-15 10:57:51,665 INFO  [SimpleAsyncTaskExecutor-4:JMSMessageSender:47] Sending to destination queue UPDATE.REQ.QUEUE
2011-11-15 10:57:51,666 INFO  [SimpleAsyncTaskExecutor-5:JMSMessageReceiver:47] Using JMS Selector JMSCorrelationID='846cc984-84fd-47a5-bfd3-c293da829927'
2011-11-15 10:57:51,687 INFO  [SimpleAsyncTaskExecutor-4:JMSMessageSender:60] Using replyToQueue UPDATE.RESP.QUEUE
2011-11-15 10:57:51,695 INFO  [SimpleAsyncTaskExecutor-4:JMSMessageReceiver:47] Using JMS Selector JMSCorrelationID='d44087e2-bd19-474a-a8d1-71ac0fc618a7'
2011-11-15 10:57:51,827 INFO  [SimpleAsyncTaskExecutor-5:JmsMessageSender:?] Received message from queue UPDATE.RESP.QUEUE
2011-11-15 10:57:51,831 INFO  [SimpleAsyncTaskExecutor-4:JmsMessageSender:?] Received message from queue UPDATE.RESP.QUEUE

Here we can now map request and responses to particular threads if we were to encounter a error (that's logged of course) later in processing.

I'm sure something similar can be done with the newer logging frameworks as well.

Groovy: A Look at Mixins

Groovy's XML support is often cited as one of the bigger attractions of the language. I often find myself writing classes that parse XML messages of the form:

    class MyXmlParser {
        def parse(String response) {
            def parsedXml = parsed(response)
            doSomethingWith(parsedXml)
        }

        def parsed(String response) {
            new XmlSlurper().parseText(response)
        }
        
        // ...
    }

One of the things that bothers me about the above pattern is the duplication in the parsed method that might spread throughout a group of classes. Using an inheritance scheme here might jump out as a possible solution at first, but that doesn't sit so well with me, as although the classes that use the duplicated method all parse XML, they all may not serve a similar substitutable purpose (one may send parsed results to a database, while another transforms the XML into an object, for example).

A newer feature of Groovy that I've been meaning to look into is the Mixin Transformation. Here, I could mixin the parsed method to all my classes that need to parse some XML. I started with the example linked to the left, but ran into a couple problems doing joint-compilation with Maven. Before we take a look at that, I'll demonstrate the mixin approach I used for this case.

The first step to adding mixins is to ensure the class you want to have make use of the mixin implement a common interface:

    package prystasj.groovy.xml

    interface XmlParser {
        def parse(String xml)
    }

    class MyXmlParser implements XmlParser {
        def parse(String response) {
            def parsedXml = parsed(response)
            doSomethingWith(parsedXml)
        }
        // ...
    }

The next step was to define the mixin class using the @Category annotation:

    package prystasj.groovy.xml

    @Category(XmlParser)
    class XmlParsing {
        def parsed(String response) {
            new XmlSlurper().parseText(response)
        }
    }

Finally, we can apply the @Mixin annotation and remove the parsed method for our parser:

    package prystasj.groovy.xml

    @Mixin(XmlParsing)
    class MyXmlParser implements XmlParser {
        def parse(String response) {
            def parsedXml = parsed(response)
            doSomethingWith(parsedXml)
        }
        // ... method parsed(String response) removed ...
    }

The MyXmlParser class now has the parsed method mixed in and no longer needs to define it. Is this a worthwile use of a mixin however, i.e. is the overhead worth having the duplication removed? In a more concrete situation, we might have many more duplicated methods between a group of classes that we would could add to the mixin, improving its worth.

Now back to the compilation problems I referred to earlier. When I went to compile, the GMaven plugin created the stubs required for joint compilation, and the Maven Compiler Plugin stumbled:

    [ERROR] /home/prystasj/.../target/generated-sources/groovy-stubs/main/prystasj/groovy/xml/MyXmlParser.java:[..] cannot find symbol
    [ERROR] symbol: variable XmlParsing

Everything in the stub looked legitimate, so I was rather stumped. I remembered running into a similar problem before, so I went ahead and tried fully qualifying the references inside the annotations:

    package prystasj.groovy.xml

    @Category(prystasj.groovy.xml.XmlParser)
    class XmlParsing {
        def parsed(String response) {
            new XmlSlurper().parseText(response)
        }
    }

    @Mixin(prystasj.groovy.xml.XmlParsing)
    class MyXmlParser implements XmlParser {
        def parse(String response) {
            def parsedXml = parsed(response)
            doSomethingWith(parsedXml)
        }
        // ... method parsed(String response) removed ...
    }

This resolved the issue and the project compile happily. If I'm not missing something, maybe this might be something worthwile to bring up with the GMaven developers? Thoughts? Thanks for reading.

Spring Batch: Deadlock Inserting Job Instances

I have been working on my first Spring Batch project and so far I'm a big fan. I think I'm pretty far along and the only real issue I've had is random occurrences of deadlock when the app tries to create instances of the same job simultaneously in the job database (in table BATCH_JOB_INSTANCE):

  2011-11-13 12:48:18,808 ERROR [AbstractStep:212] Encountered an error executing the step
  org.springframework.dao.DeadlockLoserDataAccessException: PreparedStatementCallback;
  SQL [INSERT into BATCH_JOB_INSTANCE(JOB_INSTANCE_ID, JOB_NAME, JOB_KEY, VERSION) values (?, ?, ?, ?)]; 
  Deadlock found when trying to get lock; try restarting transaction; 
  nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException:
  Deadlock found when trying to get lock; try restarting transaction
        at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:265)
        at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72)
        at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:602)

I'm using MySQL as the database backing the batch app. The Job Repository, I'm using seemed pretty stock and I never had given it much thought:

     <bean id="jobRepository"
           class="org.springframework.batch.core.repository.support.JobRepositoryFactoryBean"
           p:dataSource-ref="dataSource" 
           p:transactionManager-ref="transactionManager" 
           p:lobHandler-ref="lobHandler"/>

One of the properties on the repository that can be set is isolationLevelForCache. I found that setting this value to ISOLATION_READ_UNCOMMITTED helped my deadlock issue.

     <bean id="jobRepository"
           class="org.springframework.batch.core.repository.support.JobRepositoryFactoryBean"
           p:dataSource-ref="dataSource" 
           p:transactionManager-ref="transactionManager" 
           p:isolationLevelForCache="ISOLATION_READ_UNCOMMITTED"
           p:lobHandler-ref="lobHandler"/>

Whether or not this is the solution to use come production time is yet to be seen. For now, I surmise this works because the app is starting enough jobs at the same time, that the framework is ready to proceed with one before the insert to the database table is formally committed.

Maven Tomcat Plugin: Selecting an XML Parser

The Tomcat Maven Plugin is a great tool for quickly working through the cycle of making and verifying changes in a webapp. One such app I was working with included an XML parser from Oracle:

  oracle:oracle_xmlparserv2:jar:10.2.0.3:compile

The inclusion of the parser created a problem as it did not take kindly to a document parsed during startup, causing an error:

  $ mvn tomcat:run 
  ...
  Caused by: oracle.xml.parser.schema.XSDException: Duplicated definition for: 'identifiedType'
          at oracle.xml.parser.schema.XSDBuilder.buildSchema(XSDBuilder.java:731)
          at oracle.xml.parser.schema.XSDBuilder.build(XSDBuilder.java:435)
          at oracle.xml.parser.schema.XSDValidator.processSchemaLocation(XSDValidator.java:879)
          at oracle.xml.parser.schema.XSDValidator.startElement(XSDValidator.java:496)
          at oracle.xml.parser.v2.NonValidatingParser.parseElement(NonValidatingParser.java:1224)
          at oracle.xml.parser.v2.NonValidatingParser.parseRootElement(NonValidatingParser.java:311)
          at oracle.xml.parser.v2.NonValidatingParser.parseDocument(NonValidatingParser.java:278)
         ... 52 more

A colleague of mine at work pointed at that you can select another parser through system properties, so I wanted to share his solution here:

  $ mvn tomcat:run \
    -DXMLPARSER=XERCES \
    -DXSLENGINE=XERCES \
    -Djavax.xml.parsers.DocumentBuilderFactory=org.apache.xerces.jaxp.DocumentBuilderFactoryImpl \
    -Djavax.xml.transform.TransformerFactory=org.apache.xalan.processor.TransformerFactoryImpl \
    -Djavax.xml.parsers.SAXParserFactory=org.apache.xerces.jaxp.SAXParserFactoryImpl

The above selects a JAXP parser from Apache, requiring Xerces and Xalan:

  xerces:xercesImpl:${xercesImpl.version}
  xalan:xalan:${xalan.version}

To avoid having to script the above command or have to remember it, you can add the settings to the plugin definition:

    <plugin>
        <groupId>org.codehaus.mojo</groupId>
        <artifactId>tomcat-maven-plugin</artifactId>
        <version>1.0</version>
        <configuration>
            <port>${tomcatPort}</port>
            <path>/${project.artifactId}-${project.version}</path>
            <systemProperties>
                <env>${env}</env>
                <tomcatPort>${tomcatPort}</tomcatPort>
                <XMLPARSER>XERCES</XMLPARSER>
                <XSLENGINE>XERCES</XSLENGINE>
                <javax.xml.parsers.DocumentBuilderFactory>org.apache.xerces.jaxp.DocumentBuilderFactoryImpl</javax.xml.parsers.DocumentBuilderFactory>
                <javax.xml.transform.TransformerFactory>org.apache.xalan.processor.TransformerFactoryImpl</javax.xml.transform.TransformerFactory>
                <javax.xml.parsers.SAXParserFactory>org.apache.xerces.jaxp.SAXParserFactoryImpl</javax.xml.parsers.SAXParserFactory>
            </systemProperties>
        </configuration>
        <dependencies>
            <dependency>
                <groupId>xerces</groupId>
                <artifactId>xercesImpl</artifactId>
                <version>${xercesImpl.version}</version>
            </dependency>
            <dependency>
                <groupId>xalan</groupId>
                <artifactId>xalan</artifactId>
                <version>${xalan.version}</version>
            </dependency>
        </dependencies>
    </plugin>

Hope this helps anyone else who may run into a similar situation.

Prompted for GNOME Keyring Password During a Subversion Commit

Out of the blue when trying a Subversion commit, I was presented with a prompt for the password to the GNOME Keyring:

  $ svn ci -m"adding module"
  Password for '(null)' GNOME keyring:
  svn: Commit failed (details follow):
  svn: MKACTIVITY of '/svn/projectr/!svn/act/c5d9f7fb-76ee-4900-9a0b-b55928d418f0': authorization failed:
  Could not authenticate to server: rejected Basic challenge (http://svn.myorginazation.org)

In my case, the password for my login took care of the problem. While I do not understand the reasons for the prompt, the same may work for someone else, as by default the login password is what is being asked for.

If anyone understands why the prompt may have occurred (I haven't done much research yet), please leave a comment. Thanks!