Bug Report: NullPointerException in com.sun.jts.CosTransactions.RecoveryManager / FISH-5851

[chrjohn]

Description

---

Follow-up to https://forum.payara.fish/t/nullpointerexception-in-com-sun-jts-costransactions-recoverymanager-when-restoring-ejb-timers/81

We came across this issue with Payara 5.2020.4. One of our instances threw the following exception during startup:

[2021-09-09 06:03:54,145] [INFO ] [javax.enterprise.system.container.ejb.com.sun.ejb.containers] [Thread-21] [#1] ejb.timer_service_started [2021-09-09 06:03:54,145] [INFO ] [javax.enterprise.system.container.ejb.com.sun.ejb.containers] [Thread-21] [#1] ==> Restoring Timers ...
[2021-09-09 06:03:54,280] [INFO ] [org.eclipse.persistence.session./file:/home/xxx/applications/ejb-timer-service-app/WEB-INF/classes/___EJB__Timer__App] [Thread-21] [#1] EclipseLink, version: Eclipse Persistence Services - 2.7.6.payara-p1
[2021-09-09 06:04:01,096] [WARN ] [javax.enterprise.system.core.transaction.com.sun.jts.CosTransactions] [Thread-21] [#1] jts.unexpected_error_in_begin java.lang.NullPointerException at com.sun.jts.CosTransactions.RecoveryManager.waitForResync(RecoveryManager.java:1465)
    at com.sun.jts.CosTransactions.TransactionFactoryImpl.localCreate(TransactionFactoryImpl.java:180)
    at com.sun.jts.CosTransactions.CurrentImpl.begin(CurrentImpl.java:428)
    at com.sun.jts.jta.TransactionManagerImpl.begin(TransactionManagerImpl.java:296)
    at com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.beginJTS(JavaEETransactionManagerJTSDelegate.java:496)
    at com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.startJTSTx(JavaEETransactionManagerJTSDelegate.java:397)
    at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.startJTSTx(JavaEETransactionManagerSimplified.java:491)
    at com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate.enlistLAOResource(JavaEETransactionManagerJTSDelegate.java:316)
    at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.enlistResource(JavaEETransactionManagerSimplified.java:414)
    at com.sun.enterprise.resource.rm.SystemResourceManagerImpl.enlistResource(SystemResourceManagerImpl.java:103)

There is a race condition around the semaphore resyncInProgress which can be NULLed concurrently after checking for NULL.

Variable is set to null here:

Payara/appserver/transaction/jts/src/main/java/com/sun/jts/CosTransactions/RecoveryManager.java

Lines 695 to 698 in 8761aec

	if (resyncInProgress != null) {
	resyncInProgress.post();
	resyncInProgress = null;
	}

But could be queried e.g. here:

Payara/appserver/transaction/jts/src/main/java/com/sun/jts/CosTransactions/RecoveryManager.java

Lines 1458 to 1465 in 8761aec

	if (resyncInProgress != null) {
	try {
	//
	if (recoveryResynchTimeout == 0) {
	resyncInProgress.waitEvent();
	} else {
	resyncInProgress.waitTimeoutEvent(recoveryResynchTimeout);

In the forum thread @pdudits suggested a possible fix. I will create a corresponding PR.

Expected Outcome

Normal startup.

Current Outcome

Server throws NPE and does not start. We only encountered this once since it seems to be a rare race condition.

Steps to reproduce

We did not find a way to provoke this.

Environment

• Distribution: Payara 5.2020.4
• JDK Version: openjdk version "11.0.10" 2021-01-19
• Operating System: Debian GNU/Linux 11 (bullseye)

[AlanRoth]

Hi @chrjohn,

As you have submitted your own PR to your issue, I have accepted and created a internal ticket FISH-5851 to track your issue.

Thank you,
Alan