MESSAGE=ENGINE-16004 Exception while closing command context: EL1007E: Property or field 'eventName' cannot be found on null

PieterS · October 19, 2021, 9:37pm

Hi there

I have a very basic process which routes to a user Task upon creation.

I also have 5 @EventListener methods running, all specifying different matching criteria.

All 5 listeners start the evaluation with either one of the following conditions:
#delegateExecution.eventName== ....etc
#taskDelegate.eventName== ....etc

When running on our cloud environment, as soon as I start a case via runtimeService.startProcessInstanceByKey, I receive the following error, which I can only conlude is due to the event handlers:
MESSAGE=ENGINE-16004 Exception while closing command context: EL1007E: Property or field 'eventName' cannot be found on null

Some oddities:

The deployed process runs fine for a few days, and then this issue pops up.
Dropping the Camunda database (which then redeploys the process) seems to resolve the issue for a few days
The process is deployed on an Oracle database. When I run locally with identical config, I get no error. The same code running in PCF with identical config and pointing to the same database results in the error occurring.

Camunda: camunda-bpm-spring-boot-starter-webapp-ee 7.15.2
Spring Boot: spring-boot 2.3.10.RELEASE
Oracle: ojdbc 19.3.3.0

Full log below:

LOGGER=org.camunda.bpm.engine.context, CORR=ea6c91fd517f4624bd4898599605cec0, INT_CORR=, X-VCAP-REQUEST-ID=869d9d66-81b1-403d-6deb-9b697ea238ed, MESSAGE=ENGINE-16004 Exception while closing command context: EL1007E: Property or field 'eventName' cannot be found on null
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] org.springframework.expression.spel.SpelEvaluationException: EL1007E: Property or field 'eventName' cannot be found on null
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.ast.PropertyOrFieldReference.readProperty(PropertyOrFieldReference.java:213)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.ast.PropertyOrFieldReference.getValueInternal(PropertyOrFieldReference.java:104)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.ast.PropertyOrFieldReference.access$000(PropertyOrFieldReference.java:51)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.ast.PropertyOrFieldReference$AccessorLValue.getValue(PropertyOrFieldReference.java:406)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.ast.CompoundExpression.getValueInternal(CompoundExpression.java:92)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.ast.OpEQ.getValueInternal(OpEQ.java:42)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.ast.OpEQ.getValueInternal(OpEQ.java:32)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.ast.SpelNodeImpl.getValue(SpelNodeImpl.java:188)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.ast.OpAnd.getBooleanValue(OpAnd.java:57)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.ast.OpAnd.getValueInternal(OpAnd.java:48)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.ast.SpelNodeImpl.getValue(SpelNodeImpl.java:188)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.ast.OpAnd.getBooleanValue(OpAnd.java:57)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.ast.OpAnd.getValueInternal(OpAnd.java:48)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.ast.SpelNodeImpl.getTypedValue(SpelNodeImpl.java:117)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.expression.spel.standard.SpelExpression.getValue(SpelExpression.java:308)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.context.event.EventExpressionEvaluator.condition(EventExpressionEvaluator.java:59)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.context.event.ApplicationListenerMethodAdapter.shouldHandle(ApplicationListenerMethodAdapter.java:286)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.context.event.ApplicationListenerMethodAdapter.processEvent(ApplicationListenerMethodAdapter.java:189)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.context.event.ApplicationListenerMethodAdapter.onApplicationEvent(ApplicationListenerMethodAdapter.java:153)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:172)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:165)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:404)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:374)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.spring.boot.starter.event.PublishDelegateParseListener.lambda$new$1(PublishDelegateParseListener.java:69)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.delegate.ExecutionListener.notify(ExecutionListener.java:28)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.core.instance.CoreExecution.invokeListener(CoreExecution.java:101)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.core.operation.AbstractEventAtomicOperation.execute(AbstractEventAtomicOperation.java:55)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.interceptor.AtomicOperationInvocation.execute(AtomicOperationInvocation.java:99)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.invokeNext(CommandInvocationContext.java:131)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.performNext(CommandInvocationContext.java:118)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext$1.call(CommandInvocationContext.java:102)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext$1.call(CommandInvocationContext.java:100)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.context.ProcessApplicationClassloaderInterceptor.call(ProcessApplicationClassloaderInterceptor.java:48)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.application.AbstractProcessApplication.execute(AbstractProcessApplication.java:121)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.application.AbstractProcessApplication.execute(AbstractProcessApplication.java:132)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.context.Context.executeWithinProcessApplication(Context.java:206)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.performNext(CommandInvocationContext.java:100)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.performOperation(CommandInvocationContext.java:86)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.persistence.entity.ExecutionEntity.performOperation(ExecutionEntity.java:634)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.persistence.entity.ExecutionEntity.performOperation(ExecutionEntity.java:608)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.pvm.runtime.PvmExecutionImpl.start(PvmExecutionImpl.java:288)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.persistence.entity.ExecutionEntity.start(ExecutionEntity.java:460)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.pvm.runtime.PvmExecutionImpl.start(PvmExecutionImpl.java:264)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.cmd.StartProcessInstanceCmd.execute(StartProcessInstanceCmd.java:66)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.cmd.StartProcessInstanceCmd.execute(StartProcessInstanceCmd.java:38)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.interceptor.CommandExecutorImpl.execute(CommandExecutorImpl.java:28)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:110)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.spring.SpringTransactionInterceptor$1.doInTransaction(SpringTransactionInterceptor.java:72)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:70)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.interceptor.ProcessApplicationContextInterceptor.execute(ProcessApplicationContextInterceptor.java:70)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.interceptor.CommandCounterInterceptor.execute(CommandCounterInterceptor.java:35)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:33)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.ProcessInstantiationBuilderImpl.executeWithVariablesInReturn(ProcessInstantiationBuilderImpl.java:166)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.ProcessInstantiationBuilderImpl.execute(ProcessInstantiationBuilderImpl.java:132)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.ProcessInstantiationBuilderImpl.execute(ProcessInstantiationBuilderImpl.java:128)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at org.camunda.bpm.engine.impl.RuntimeServiceImpl.startProcessInstanceByKey(RuntimeServiceImpl.java:118)
2021-10-19T21:29:46.720+01:00 [APP/PROC/WEB/0] [OUT] at com.mycompany.myservice.service.request.service.CamundaService.startProcess(CamundaService.java:30)

PieterS · November 1, 2021, 9:52am

Just in case someone else runs into this, the code snippet below from Camunda Support provides a workaround for the issue.

@Component
@Scope(value = ConfigurableBeanFactory.SCOPE_PROTOTYPE)
public class MyListener implements ....

We had to set the Spring Scope to Prototype for all our Execution and Task listeners.

PieterS · November 12, 2021, 9:11am

The solution above did not solve the issue. As luck would have it, it re-occurred once we deployed to production.

We are now completely avoiding the use of ‘@EventListener’ with Camunda.

Jeremiah_Stones · December 6, 2022, 3:55pm

The error above appears to be a SPEL evaluation error, which occurs in @EventListener conditions when the variable name in the parameter of the event listener method does not match the exact variable name being used in the condition.

Fails with EL1007E error code, Property or field ‘eventName’ cannot be found on null, because the variable name “delegate” does not match the “#taskDelegate…” variable name in condition, which is resolving to “null”.
@EventListener(condition = “#taskDelegate.eventName == ‘MY_TEST_EVENT’”)
public void exampleListenerMethod(TaskDelegate delegate) {
// some logic
}

Succeeds, when both are “taskDelegate” and match:
@EventListener(condition = “#taskDelegate.eventName == ‘MY_TEST_EVENT’”)
public void exampleListenerMethod(TaskDelegate taskDelegate) {
// some logic
}

PieterS · December 8, 2022, 10:26am

Hi - thanks for your response. If this ever comes up again I will definitely try that. We have since completely abandoned the SpEL listeners.

Your solution makes sense, however, it does not explain why it works intermittently:

The deployed process runs fine for a few days, and then this issue pops up.
Dropping the Camunda database (which then redeploys the process) seems to resolve the issue for a few days
Unable to replicate locally - The process is deployed on an Oracle database. When I run locally with identical config, I get no error. The same code running in PCF with identical config and pointing to the same database results in the error occurring.