Glassfish, XA Transactions, and PostgreSQL

The other night I was working on the source for ActionBazaar (EJB 3.2 in Action) when I ran into a new problem. In the code that I was writing I was both submitting a message to a JMS queue and also creating a user in a database within stateless session bean. This obviously would use a two-phase commit. When I had setup the JDBC connection pool in Glassfish, I had created it as an XADataSource. Apparently my PostgreSQL setup wasn’t quite setup to handle this as I immediately got this exception:

Exception [java.lang.RuntimeException: org.postgresql.xa.PGXAException: Error preparing transaction] on Resource [prepare] operation.|#]

[#|2012-02-08T23:37:21.962-0500|WARNING|glassfish3.1.1|javax.enterprise.system.core.transaction.com.sun.jts.jtsxa|_ThreadID=22;_ThreadName=Thread-4;|JTS5068: Unexpected error occurred in rollback
org.postgresql.xa.PGXAException: Error rolling back prepared transaction
	at org.postgresql.xa.PGXAConnection.rollback(PGXAConnection.java:406)
	at com.sun.gjc.spi.XAResourceImpl.rollback(XAResourceImpl.java:195)
	at com.sun.jts.jta.TransactionState.rollback(TransactionState.java:193)
	at com.sun.jts.jtsxa.OTSResourceImpl.rollback(OTSResourceImpl.java:333)
	at com.sun.jts.CosTransactions.RegisteredResources.distributeRollback(RegisteredResources.java:1038)
	at com.sun.jts.CosTransactions.TopCoordinator.rollback(TopCoordinator.java:2290)
	at com.sun.jts.CosTransactions.CoordinatorTerm.commit(CoordinatorTerm.java:420)
	at com.sun.jts.CosTransactions.TerminatorImpl.commit(TerminatorImpl.java:250)
	at com.sun.jts.CosTransactions.CurrentImpl.commit(CurrentImpl.java:623)
	at com.sun.jts.jta.TransactionManagerImpl.commit(TransactionManagerImpl.java:323)
	at com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.commitDistributedTransaction(JavaEETransactionManagerJTSDelegate.java:186)
	at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:858)
	at com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5114)
	at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4879)
	at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2039)
	at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1990)
	at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:222)
	at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:88)
	at $Proxy310.createUser(Unknown Source)
	at com.actionbazaar.controller.BidderAccountController.create(BidderAccountController.java:396)
	at com.actionbazaar.controller.org$jboss$weld$bean-actionbazaar-ManagedBean-class_com$actionbazaar$controller$BidderAccountController_$$_WeldClientProxy.create(org$jboss$weld$bean-actionbazaar-ManagedBean-class_com$actionbazaar$controller$BidderAccountController_$$_WeldClientProxy.java)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at com.sun.el.parser.AstValue.invoke(AstValue.java:234)
	at com.sun.el.MethodExpressionImpl.invoke(MethodExpressionImpl.java:297)
	at org.jboss.weld.util.el.ForwardingMethodExpression.invoke(ForwardingMethodExpression.java:43)
	at org.jboss.weld.el.WeldMethodExpression.invoke(WeldMethodExpression.java:56)
	at com.sun.faces.facelets.el.TagMethodExpression.invoke(TagMethodExpression.java:105)
	at javax.faces.component.MethodBindingMethodExpressionAdapter.invoke(MethodBindingMethodExpressionAdapter.java:88)
	at com.sun.faces.application.ActionListenerImpl.processAction(ActionListenerImpl.java:102)
	at javax.faces.component.UICommand.broadcast(UICommand.java:315)
	at javax.faces.component.UIViewRoot.broadcastEvents(UIViewRoot.java:794)
	at javax.faces.component.UIViewRoot.processApplication(UIViewRoot.java:1259)
	at com.sun.faces.lifecycle.InvokeApplicationPhase.execute(InvokeApplicationPhase.java:81)
	at com.sun.faces.lifecycle.Phase.doPhase(Phase.java:101)
	at com.sun.faces.lifecycle.LifecycleImpl.execute(LifecycleImpl.java:118)
	at javax.faces.webapp.FacesServlet.service(FacesServlet.java:593)
	at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1539)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:343)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:217)
	at com.ocpsoft.pretty.PrettyFilter.doFilter(PrettyFilter.java:118)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:256)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:217)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:279)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
	at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:655)
	at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:595)
	at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:98)
	at com.sun.enterprise.web.PESessionLockingStandardPipeline.invoke(PESessionLockingStandardPipeline.java:91)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:162)
	at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:330)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:231)
	at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:174)
	at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:828)
	at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:725)
	at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1019)
	at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:225)
	at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)
	at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)
	at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)
	at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79)
	at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)
	at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:59)
	at com.sun.grizzly.ContextTask.run(ContextTask.java:71)
	at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:532)
	at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:513)
	at java.lang.Thread.run(Thread.java:680)
Caused by: org.postgresql.util.PSQLException: ERROR: prepared transaction with identifier "4871251_CwAAAMWkX2BCZWFnbGUsc2VydmVyLFAzNzAw_QmVhZ2xlLHNlcnZlcixQMzcwMCwA" does not exist
	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2102)
	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1835)
	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:257)
	at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:500)
	at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:374)
	at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:302)
	at org.postgresql.xa.PGXAConnection.rollback(PGXAConnection.java:396)
	... 68 more
|#]

Digging into it, I discovered that I had to set set max_prepared_transactions and also lower the shared_buffers. The value set the value for max_prepared_transaction to 20 which is the same as max_connections. These changes were made to postgresql.conf. Changing this file of course required a restart of PostgreSQL – no restart of Glassfish was required. Obviously my database isn’t optimized and this was just a hack to get things operational. In a real production environment a little more tuning would be required.

JavaOne Presentations Accepted!

I am happy to announce that several of my presentations for JavaOne have been accepted:

  • Building a Home Security System with Java
  • NetBeans Project Management

I will also be co-presenting with Reza Rahman:

  • Patterns and Best Practices for CDI

The following presentation has been accepted as alternate presentations:

  • Building Sophisticated Text Components

I’ll post links to the abstracts shortly!

Profiling Windows Services

Netbeans ships with a robust profiler which is easy to use and minimally invasive. You don’t even have to be using Netbeans as your development environment (I use IntelliJ) or even be on the same machine running the VM you want to profile. Thus you can troubleshoot a production environment from afar. Yesterday I figured out how to profile a java process running as a Windows’ service via The Java Service Wrapper. The instructions below assume Java 5 on both Mac and the windows machine as well as Netbeans 6.5+.

To get started, launch Netbeans and select Attach Profiler from the Profile menu.

Launching NetBeans Profiler

This will bring up the Attach Wizard. Pick the target type as an Application and the attach method as being remote.

The next screen will prompt you for the remote host name as well as operating system.

Remote Machine

The next screen just confirms your settings.

Confirm Settings

On this screen you will want to Generate Remote Pack before clicking finish. Clicking the remote pack button will generate a zip file that you will deploy on your windows box. It contains two jar files and a platform specific DLL. By default Netbeans saves the remote pack to an obscure directory under /tmp. I recommend picking a location that is easier to find.

Generating Remote Pack

If you expand the pack you will see the files below. Running the bat files on windows assumes that java.exe is in your path and that JAVA_HOME is set. To profile an application with a 1.5 JVM you would use the profile-15.bat. To profile with 1.6 you would obviously use the profile-16.bat file. You use the bat files as a replacement for typing java at the command line. So to profile foo in bar.jar you would type profile-15.bat -classpath bar.jar foo.

File Structure

On Windows I expanded the zip file at the root of the C volume and changed the name of the directory from profiler-server-win to profiler. Then add the following snippet to your wrapper.conf file:

wrapper.java.additional.1=-agentpath:"C:\profiler\lib\deployed\jdk15\windows\profilerinterface.dll"="C:\profiler\lib",5140
# Disable the pings so wrapper doesn’t kill the JVM while waiting for the profiler.
wrapper.startup.timeout=0
wrapper.ping.timeout=0

When you start the service, the service will pause waiting for the profiler to connect.

Wrapper Waiting

Click attach in Netbeans – now you can start digging through the VM!
Note: With remote profiling you cannot generate heap dumps.

Profiler in Action

Detecting Memory Leaks

Troubleshooting a problem over last weekend I ran into a classic memory leak. Yes, you can have memory leaks in Java! If you hold onto references to objects than the Java virtual machine cannot reclaim those objects. In my case, I was processing millions of records but not giving yielding and allowing an object cache to purge itself (my fault – IDE evidently didn’t copy over an updated config file because I didn’t make a code change). This problem led me to dig into Netbeans and profiling Java processes running as Windows’ services. While Netbeans is a great tool, it does a negative impact upon performance. Obviously a less intrusive tool is needed initially. Java 5 ships with jconsole which drills into a JVM and reports back on heap utilization, thread activity etc. JConsole connects to either local JVM or one on a remote machine. I have also used JConsole to track down a renegade thread that was caught in an IO loop as a result of security software checking for a buffer overrun.

To enable jconsole connectivity for an application simply adding the following VM parameters:

-Dcom.sun.management.jmxremote.port=8999
-Dcom.sun.management.jmxremote.ssl=false
-Dcom.sun.management.jmxremote.authenticate=false

Launch your application and then launch jconsole (jconsole should be in your path).
Below you can see screenshots from my ‘classic’ leak:

Classic Memory Leak


Classic Memory Leak

Launching Tomcat with Launchd

With the release of MacOS 10.4 (aka Tiger) Apple rolled out launchd which is a system startup program that replaces cron, xinetd, init, etc. It also replaces /Library/StartupItems which I have typically used in the last for launching Tomcat and Postgresql. To run Tomcat on my Mac Mini I decided to finally figure out launchd. Below is my launchd script file.
Save the following file as org.apache.tomcat.plist in your home directory

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple Computer//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
  <dict>
  <key>Debug</key>
   <true/>
    <key>GroupName</key>
    <string>staff</string>
    <key>Label</key>
    <string>org.apache.tomcat</string>
    <key>UserName</key>
    <string>rcuprak</string>
    <key>RunAtLoad</key>
    <true/>
    <key>Program</key>
    <string>/usr/bin/java</string>
    <key>ProgramArguments</key>
    <array>
     <string>-Djava.endorsed.dirs=/Applications/apache-tomcat-6.0.14/endorsed</string>
     <string>-Dcatalina.base=/Applications/apache-tomcat-6.0.14</string>
     <string>-Dcatalina.home=/Applications/apache-tomcat-6.0.14</string>
     <string>-Djava.io.tmpdir=/Applications/apache-tomcat-6.0.14/tmp</string>
     <string>-classpath</string>
     <string>/Applications/apache-tomcat-6.0.14/bin/tomcat-juli.jar:/Applications/apache-tomcat-6.0.14/bin/commons-daemon.jar:/Applications/apache-tomcat-6.0.14/bin/commons-logging-api.jar:/Applications/apache-tomcat-6.0.14/bin/bootstrap.jar</string>
     <string>org.apache.catalina.startup.Bootstrap</string>
    </array>
    <key>WorkingDirectory</key>
    <string>/Applications/apache-tomcat-6.0.14</string>
   </dict>
</plist>

You made need to adjust the paths to reflect the version of Tomcat that you are using as well as the username under which to run tomcat.
Perform the following operations from the command line:

sudo bash
cd /Library/LaunchDaemons
cp /Users/<your username>/org.apache.tomcat.plist .
launchctl load org.apache.tomcat.plist
launchctl start org.apache.tomcat

Tomcat should startup and will auto start next time the machine is restarted. Any errors will be recorded to syslog and visible if you run the Console application.

The paths to tomcat may need to be adjusted depending upon your version of tomcat.

Save this file to /Library/LaunchDaemons. You must first authenticate as root (sudo bash) before saving the file.

When the machine shuts down I believe launchd sends a kill signal at the process. There aren’t any hooks for invoking a shutdown logic from what I’ve seen thus far.