users@glassfish.java.net

[gf-users] Re: _at_Schedule job being killed

From: Steven Siebert <smsiebe_at_gmail.com>
Date: Fri, 12 Jun 2015 17:08:08 -0400

I only ask this because I didn't see you address it in your post, and your
stack traces doesn't hint towards it: what does your job do?...does it
directly (ie using a JPA entity manager) or indirectly (ie by a container
managed EJB method) access Postgres?

First thought that crossed my mind was that your job is, through a
container managed method, interacting with the database and (since you
mentioned it's not using an XA connector itself) some other enterprise
resource connector with an XA connector setup (perhaps something like JMS)
- the PSQLException thrown during commit from a closed connection, being
caught by the container and when the commit gets to the XAResource fails
commit because of the previous commit failure, rolling back the tx and
throwing a LocalTransactionException. The EJB timer should try to execute
this 3 times by default (IIRC) and if getting an exception all 3 times kill
that job.

The closed PG connection could, for instance, result from a long-running
job with a low connection timeout: Your EJB injects the entity manager on
PostConstruct, does a query...does some long-running operation on the
results, attempts to do something else with the db/commit after the
configured connection timeout, and gets no love. The JDBC pool will only
check the connection (if configured to do so) prior to injection -- it
doesn't do anything fancy like provide a proxied connection to handle
connection failures that may occur between the time it is retrieved from
the pool and the time it is used by that code...though there are of course
some things you can do both with JDBC config as well as the postgres
proprietary driver config...

Perhaps a longer stack trace would help....

On Fri, Jun 12, 2015 at 4:35 PM, Will Hartung <willh_at_mirthcorp.com> wrote:

> GF 3.1.2.2
>
> We have a @Schedule annotated job that runs regularly, every 15s or so.
>
> Occsionally, we get this exception:
>
>
> [#|2015-06-12T12:30:05.015-0700|SEVERE|glassfish3.1.2|javax.enterprise.resource.resourceadapter.com.sun.enterprise.resource|_ThreadID=569;_ThreadName=Thread-2;|RAR5031:System
> Exception
> javax.resource.spi.LocalTransactionException: This connection has been
> closed.
> at
> com.sun.gjc.spi.LocalTransactionImpl.commit(LocalTransactionImpl.java:112)
> at
> com.sun.enterprise.resource.ConnectorXAResource.commit(ConnectorXAResource.java:124)
> at
> com.sun.enterprise.transaction.JavaEETransactionImpl.commit(JavaEETransactionImpl.java:501)
> at
> com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:855)
> at
> com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5136)
> at
> com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4901)
> at
> com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2045)
> at
> com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1994)
> at
> com.sun.ejb.containers.BaseContainer.callEJBTimeout(BaseContainer.java:4088)
> at
> com.sun.ejb.containers.EJBTimerService.deliverTimeout(EJBTimerService.java:1832)
> at
> com.sun.ejb.containers.EJBTimerService.access$100(EJBTimerService.java:108)
> at
> com.sun.ejb.containers.EJBTimerService$TaskExpiredWork.run(EJBTimerService.java:2646)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: org.postgresql.util.PSQLException: This connection has been
> closed.
> at
> org.postgresql.jdbc2.AbstractJdbc2Connection.checkClosed(AbstractJdbc2Connection.java:822)
> at
> org.postgresql.jdbc2.AbstractJdbc2Connection.commit(AbstractJdbc2Connection.java:810)
> at
> com.sun.gjc.spi.LocalTransactionImpl.commit(LocalTransactionImpl.java:106)
> ... 16 more
> |#]
>
> Once we get this, the job is dead and will never run again until we
> restart the server or redeploy the application.
>
> Our EJBTimer pool is the standard, Glassfish default running against
> Derby, so I'm puzzled why Postgres (which is our normal DB) is
> involved in this at all.
>
> I briefly considered that maybe the EJB Timer DB connections are
> enlisted in to an XA transaction with the standard EJB transaction.
> But that makes no sense. First, our PG Driver is not configured for
> XA, second, why would the transaction that manages the EJBTimer be at
> all dependent on the status of the logic transaction that the timer is
> running.
>
> It also makes no sense that it's dealing with a closed PG connection.
>
> Any insight in to how this is happening is welcome frustrating to have
> to restart the server for this. More frustrating was that we had to
> add monitoring code to your application to ensure that this job was
> continually running and had not stopped.
>
> Thanks!
>
> Regards,
>
> Will Hartung
> (willh_at_mirthcorp.com)
>
> --
> This message, and any documents attached hereto, may contain confidential
> or proprietary information intended only for the use of the addressee(s)
> named above or may contain information that is legally privileged. If you
> are not the intended addressee, or the person responsible for delivering it
> to the intended addressee, you are hereby notified that reading,
> disseminating, distributing or copying this message is strictly prohibited.
> If you have received this message by mistake, please immediately notify us
> by replying to the message and delete the original message and any copies
> immediately thereafter. Thank you for your cooperation.
>