topic Re: NullPointerException in taskService with CandidateUser Query under load in Alfresco Archive

NullPointerException in taskService with CandidateUser Query under load

christianscheer — Thu, 23 Apr 2015 10:40:09 GMT

Hi. Under load (about 20 requests per second) i get NullPointerExceptions when i query the taskService with candidate Users against LDAP. There is no problem at a low load or with single requests.Sample CodetaskService.createTaskQuery().taskCandidateUser(userName).processVariableValueEquals(FOERDERF

Re: NullPointerException in taskService with CandidateUser Query under load

trademak — Fri, 24 Apr 2015 13:06:17 GMT

Hi,

What's happening exactly on these lines?

com.my_company.project.workflow_core.impl.WorkflowServiceImpl.getMoeglicheAktionenByFoerderFallForUser(100738,testUser27)

at com.my_company.project.workflow_base.aop.ServiceExceptionMapperAspect.invoke(ServiceExceptionMapperAspect.java:37) ~[workflow-base-1.0.0-SNAPSHOT.jar:na]

Because the NPE is raised there.

Best regards,

Re: NullPointerException in taskService with CandidateUser Query under load

christianscheer — Fri, 24 Apr 2015 14:55:10 GMT

Hi,
this is the method in question:
<java>
@Inject
private TaskService taskService;

@Override
public List<WsAktion> getMoeglicheAktionenByFoerderFallForUser(String foerderFallId,
        String userName) {
    // Tasks holen, die mit "aktion-" starten
    List<Task> tasks =
            taskService.createTaskQuery()
                    .taskDefinitionKeyLike("aktion-%")
                    .processVariableValueEquals("foerderFallId", foerderFallId)
                    .taskCandidateUser(userName).list();

    // Convert to Aktionsmöglichkeiten
    List<WsAktion> aktionsMoeglichkeiten = new ArrayList<>();
    for (Task task : tasks) {
        WsAktion am = createAktionsMoeglichkeit(task);
        aktionsMoeglichkeiten.add(am);
    }
    return aktionsMoeglichkeiten;
}

private static final Pattern AKTIONS_MOEGLICHKEITS_TYP_PATTERN = Pattern.compile("aktion-([^-]*).*");

private WsAktion createAktionsMoeglichkeit(Task task) {
    WsAktion am = new WsAktion();
    am.setId(task.getId());
    am.setBeschreibung(task.getDescription());

    // Extract Type. Pattern: aktion-<typ>[-foo-bar]
    Matcher typMatcher = AKTIONS_MOEGLICHKEITS_TYP_PATTERN.matcher(task.getTaskDefinitionKey());
    if (typMatcher.matches()) {
        am.setTyp(typMatcher.group(1));
    }
    return am;
}
</java>

Re: NullPointerException in taskService with CandidateUser Query under load

christianscheer — Fri, 24 Apr 2015 21:00:22 GMT

I was finally able to reproduce the error on my machine by focusing the load test on the queries that use taskCandidateUser. Allthough i needed a much higher load than the production system.
I then created a resource (jersey 2 webservice) with a method to directly test the critical query.
<java>
@Inject
private TaskService taskService;

@GET
@Path("/candidate")
@Produces(MediaType.APPLICATION_XML)
public String getTasksByCandidate(@QueryParam("user") String user) {
    if (StringUtils.isEmpty(user)) {
        throw ResourceHelper.createErrorResponseException(Response.Status.BAD_REQUEST,
                "username cannot be empty");
    }
    List<Task> tasks = taskService.createTaskQuery().taskCandidateUser(user).list();
    return StringUtils.join(tasks, ",");
}
</java>

20 Threads in jMeter rigorously shooting queries at that resource without any break lead to an error very similar to above:
<code>
2015-04-24 22:25:25,563 ERROR [http-nio-8081-exec-17] com.my_company.project.workflow_webservice.exception_mapping.TabExceptionMapper Internal Server Error:
org.apache.ibatis.exceptions.PersistenceException:
### Error querying database. Cause: java.lang.NullPointerException
### Cause: java.lang.NullPointerException
at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:23) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:107) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:98) ~[mybatis-3.2.5.jar:3.2.5]
at org.activiti.engine.impl.db.DbSqlSession.selectListWithRawParameter(DbSqlSession.java:423) ~[activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.db.DbSqlSession.selectList(DbSqlSession.java:414) ~[activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.persistence.entity.TaskEntityManager.findTasksByQueryCriteria(TaskEntityManager.java:121) ~[activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.TaskQueryImpl.executeList(TaskQueryImpl.java:1143) ~[activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.AbstractQuery.execute(AbstractQuery.java:158) ~[activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.interceptor.CommandInvoker.execute(CommandInvoker.java:24) ~[activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:57) ~[activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.spring.SpringTransactionInterceptor$1.doInTransaction(SpringTransactionInterceptor.java:47) ~[activiti-spring-5.16.4.jar:5.16.4]
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:131) ~[spring-tx-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.activiti.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:45) ~[activiti-spring-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:31) ~[activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:40) ~[activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:35) ~[activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.AbstractQuery.list(AbstractQuery.java:132) ~[activiti-engine-5.16.4.jar:5.16.4]
at com.my_company.project.workflow_webservice.TestResource.getTasksByCandidate(TestResource.java:77) ~[workflow-webservice-1.0.0-SNAPSHOT.jar:na]
at sun.reflect.GeneratedMethodAccessor119.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_75]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_75]
at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) ~[jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:143) ~[jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:160) ~[jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:203) ~[jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:97) ~[jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) ~[jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) ~[jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) ~[jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:303) ~[jersey-server-2.16.jar:na]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [jersey-common-2.16.jar:na]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [jersey-common-2.16.jar:na]
at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [jersey-common-2.16.jar:na]
at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [jersey-common-2.16.jar:na]
at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [jersey-common-2.16.jar:na]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [jersey-common-2.16.jar:na]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:286) [jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1072) [jersey-server-2.16.jar:na]
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:399) [jersey-container-servlet-core-2.16.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:381) [jersey-container-servlet-core-2.16.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.doFilter(ServletContainer.java:534) [jersey-container-servlet-core-2.16.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.doFilter(ServletContainer.java:482) [jersey-container-servlet-core-2.16.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.doFilter(ServletContainer.java:419) [jersey-container-servlet-core-2.16.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [catalina.jar:8.0.21]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.21]
at com.my_company.project.workflow_webservice_war.CacheControlFilter.doFilter(CacheControlFilter.java:45) [CacheControlFilter.class:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [catalina.jar:8.0.21]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.21]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) [catalina.jar:8.0.21]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106) [catalina.jar:8.0.21]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502) [catalina.jar:8.0.21]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142) [catalina.jar:8.0.21]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79) [catalina.jar:8.0.21]
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:610) [catalina.jar:8.0.21]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88) [catalina.jar:8.0.21]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:518) [catalina.jar:8.0.21]
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1091) [tomcat-coyote.jar:8.0.21]
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:668) [tomcat-coyote.jar:8.0.21]
at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) [tomcat-coyote.jar:8.0.21]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1517) [tomcat-coyote.jar:8.0.21]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1474) [tomcat-coyote.jar:8.0.21]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_75]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_75]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:8.0.21]
at java.lang.Thread.run(Thread.java:745) [na:1.7.0_75]
Caused by: java.lang.NullPointerException: null
at org.activiti.ldap.LDAPQueryBuilder$1.executeInContext(LDAPQueryBuilder.java:63) ~[activiti-ldap-5.16.4.jar:5.16.4]
at org.activiti.ldap.LDAPQueryBuilder$1.executeInContext(LDAPQueryBuilder.java:56) ~[activiti-ldap-5.16.4.jar:5.16.4]
at org.activiti.ldap.LDAPTemplate.execute(LDAPTemplate.java:44) ~[activiti-ldap-5.16.4.jar:5.16.4]
at org.activiti.ldap.LDAPQueryBuilder.buildQueryGroupsForUser(LDAPQueryBuilder.java:56) ~[activiti-ldap-5.16.4.jar:5.16.4]
at org.activiti.ldap.LDAPGroupManager$1.executeInContext(LDAPGroupManager.java:120) ~[activiti-ldap-5.16.4.jar:5.16.4]
at org.activiti.ldap.LDAPGroupManager$1.executeInContext(LDAPGroupManager.java:116) ~[activiti-ldap-5.16.4.jar:5.16.4]
at org.activiti.ldap.LDAPTemplate.execute(LDAPTemplate.java:44) ~[activiti-ldap-5.16.4.jar:5.16.4]
at org.activiti.ldap.LDAPGroupManager.findGroupsByUser(LDAPGroupManager.java:116) ~[activiti-ldap-5.16.4.jar:5.16.4]
at com.my_company.project.workflow_core.activiti.CustomLdapGroupManager.findGroupsByUser(CustomLdapGroupManager.java:74) ~[workflow-core-1.0.0-SNAPSHOT.jar:na]
at org.activiti.engine.impl.TaskQueryImpl.getGroupsForCandidateUser(TaskQueryImpl.java:1007) ~[activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.TaskQueryImpl.getCandidateGroups(TaskQueryImpl.java:997) ~[activiti-engine-5.16.4.jar:5.16.4]
at sun.reflect.GeneratedMethodAccessor76.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_75]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_75]
at org.apache.ibatis.reflection.invoker.MethodInvoker.invoke(MethodInvoker.java:37) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.reflection.wrapper.BeanWrapper.getBeanProperty(BeanWrapper.java:151) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.reflection.wrapper.BeanWrapper.get(BeanWrapper.java:45) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.reflection.MetaObject.getValue(MetaObject.java:113) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.DynamicContext$ContextMap.get(DynamicContext.java:94) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.DynamicContext$ContextAccessor.getProperty(DynamicContext.java:113) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.OgnlRuntime.getProperty(OgnlRuntime.java:1657) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.ASTProperty.getValueBody(ASTProperty.java:92) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:170) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.getValue(SimpleNode.java:210) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.ASTNotEq.getValueBody(ASTNotEq.java:49) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:170) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.getValue(SimpleNode.java:210) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.ASTAnd.getValueBody(ASTAnd.java:56) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:170) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.getValue(SimpleNode.java:210) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.Ognl.getValue(Ognl.java:333) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.Ognl.getValue(Ognl.java:413) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.Ognl.getValue(Ognl.java:395) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.OgnlCache.getValue(OgnlCache.java:45) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.ExpressionEvaluator.evaluateBoolean(ExpressionEvaluator.java:29) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.IfSqlNode.apply(IfSqlNode.java:30) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.MixedSqlNode.apply(MixedSqlNode.java:29) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.IfSqlNode.apply(IfSqlNode.java:31) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.MixedSqlNode.apply(MixedSqlNode.java:29) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.TrimSqlNode.apply(TrimSqlNode.java:51) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.MixedSqlNode.apply(MixedSqlNode.java:29) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.DynamicSqlSource.getBoundSql(DynamicSqlSource.java:37) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.mapping.MappedStatement.getBoundSql(MappedStatement.java:275) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:79) ~[mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:104) ~[mybatis-3.2.5.jar:3.2.5]
… 63 common frames omitted
</code>

Re: NullPointerException in taskService with CandidateUser Query under load

christianscheer — Fri, 24 Apr 2015 21:06:51 GMT

After playing around with the loglevels i finally found a hidden exception logged at INFO:

2015-04-24 22:25:24,960 INFO [http-nio-8081-exec-17] org.activiti.ldap.LDAPTemplate Could not create LDAP connection : Could not create InitialDirContext for LDAP connection : localhost:10389
org.activiti.engine.ActivitiException: Could not create InitialDirContext for LDAP connection : localhost:10389
at org.activiti.ldap.LDAPConnectionUtil.createDirectoryContext(LDAPConnectionUtil.java:56) ~[activiti-ldap-5.16.4.jar:5.16.4]
at org.activiti.ldap.LDAPConnectionUtil.creatDirectoryContext(LDAPConnectionUtil.java:35) ~[activiti-ldap-5.16.4.jar:5.16.4]
at org.activiti.ldap.LDAPTemplate.execute(LDAPTemplate.java:40) ~[activiti-ldap-5.16.4.jar:5.16.4]
at org.activiti.ldap.LDAPGroupManager.findGroupsByUser(LDAPGroupManager.java:116) [activiti-ldap-5.16.4.jar:5.16.4]
at com.my_company.project.workflow_core.activiti.CustomLdapGroupManager.findGroupsByUser(CustomLdapGroupManager.java:74) [workflow-core-1.0.0-SNAPSHOT.jar:na]
at org.activiti.engine.impl.TaskQueryImpl.getGroupsForCandidateUser(TaskQueryImpl.java:1007) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.TaskQueryImpl.getCandidateGroups(TaskQueryImpl.java:997) [activiti-engine-5.16.4.jar:5.16.4]
at sun.reflect.GeneratedMethodAccessor76.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_75]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_75]
at org.apache.ibatis.reflection.invoker.MethodInvoker.invoke(MethodInvoker.java:37) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.reflection.wrapper.BeanWrapper.getBeanProperty(BeanWrapper.java:151) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.reflection.wrapper.BeanWrapper.get(BeanWrapper.java:45) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.reflection.MetaObject.getValue(MetaObject.java:113) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.DynamicContext$ContextMap.get(DynamicContext.java:94) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.DynamicContext$ContextAccessor.getProperty(DynamicContext.java:113) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.OgnlRuntime.getProperty(OgnlRuntime.java:1657) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.ASTProperty.getValueBody(ASTProperty.java:92) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:170) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.getValue(SimpleNode.java:210) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.ASTNotEq.getValueBody(ASTNotEq.java:49) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:170) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.getValue(SimpleNode.java:210) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.ASTAnd.getValueBody(ASTAnd.java:56) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:170) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.getValue(SimpleNode.java:210) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.Ognl.getValue(Ognl.java:333) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.Ognl.getValue(Ognl.java:413) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.Ognl.getValue(Ognl.java:395) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.OgnlCache.getValue(OgnlCache.java:45) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.ExpressionEvaluator.evaluateBoolean(ExpressionEvaluator.java:29) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.IfSqlNode.apply(IfSqlNode.java:30) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.MixedSqlNode.apply(MixedSqlNode.java:29) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.IfSqlNode.apply(IfSqlNode.java:31) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.MixedSqlNode.apply(MixedSqlNode.java:29) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.TrimSqlNode.apply(TrimSqlNode.java:51) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.MixedSqlNode.apply(MixedSqlNode.java:29) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.DynamicSqlSource.getBoundSql(DynamicSqlSource.java:37) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.mapping.MappedStatement.getBoundSql(MappedStatement.java:275) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:79) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:104) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:98) [mybatis-3.2.5.jar:3.2.5]
at org.activiti.engine.impl.db.DbSqlSession.selectListWithRawParameter(DbSqlSession.java:423) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.db.DbSqlSession.selectList(DbSqlSession.java:414) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.persistence.entity.TaskEntityManager.findTasksByQueryCriteria(TaskEntityManager.java:121) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.TaskQueryImpl.executeList(TaskQueryImpl.java:1143) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.AbstractQuery.execute(AbstractQuery.java:158) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.interceptor.CommandInvoker.execute(CommandInvoker.java:24) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:57) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.spring.SpringTransactionInterceptor$1.doInTransaction(SpringTransactionInterceptor.java:47) [activiti-spring-5.16.4.jar:5.16.4]
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:131) [spring-tx-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.activiti.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:45) [activiti-spring-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:31) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:40) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:35) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.AbstractQuery.list(AbstractQuery.java:132) [activiti-engine-5.16.4.jar:5.16.4]
at com.my_company.project.workflow_webservice.TestResource.getTasksByCandidate(TestResource.java:77) [workflow-webservice-1.0.0-SNAPSHOT.jar:na]
at sun.reflect.GeneratedMethodAccessor119.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_75]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_75]
at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) [jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:143) [jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:160) [jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:203) [jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:97) [jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) [jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) [jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) [jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:303) [jersey-server-2.16.jar:na]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [jersey-common-2.16.jar:na]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [jersey-common-2.16.jar:na]
at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [jersey-common-2.16.jar:na]
at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [jersey-common-2.16.jar:na]
at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [jersey-common-2.16.jar:na]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [jersey-common-2.16.jar:na]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:286) [jersey-server-2.16.jar:na]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1072) [jersey-server-2.16.jar:na]
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:399) [jersey-container-servlet-core-2.16.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:381) [jersey-container-servlet-core-2.16.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.doFilter(ServletContainer.java:534) [jersey-container-servlet-core-2.16.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.doFilter(ServletContainer.java:482) [jersey-container-servlet-core-2.16.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.doFilter(ServletContainer.java:419) [jersey-container-servlet-core-2.16.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [catalina.jar:8.0.21]
at com.my_company.project.workflow_webservice_war.CacheControlFilter.doFilter(CacheControlFilter.java:45) [CacheControlFilter.class:na]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.21]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [catalina.jar:8.0.21]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.21]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) [catalina.jar:8.0.21]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106) [catalina.jar:8.0.21]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502) [catalina.jar:8.0.21]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142) [catalina.jar:8.0.21]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79) [catalina.jar:8.0.21]
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:610) [catalina.jar:8.0.21]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88) [catalina.jar:8.0.21]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:518) [catalina.jar:8.0.21]
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1091) [tomcat-coyote.jar:8.0.21]
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:668) [tomcat-coyote.jar:8.0.21]
at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) [tomcat-coyote.jar:8.0.21]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1517) [tomcat-coyote.jar:8.0.21]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1474) [tomcat-coyote.jar:8.0.21]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_75]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_75]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:8.0.21]
at java.lang.Thread.run(Thread.java:745) [na:1.7.0_75]
Caused by: javax.naming.CommunicationException: localhost:10389
at com.sun.jndi.ldap.Connection.<init>(Connection.java:226) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapClient.<init>(LdapClient.java:136) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapClient.getInstance(LdapClient.java:1608) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapCtx.connect(LdapCtx.java:2698) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapCtx.<init>(LdapCtx.java:316) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(LdapCtxFactory.java:193) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(LdapCtxFactory.java:211) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(LdapCtxFactory.java:154) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(LdapCtxFactory.java:84) ~[na:1.7.0_75]
at javax.naming.spi.NamingManager.getInitialContext(NamingManager.java:684) ~[na:1.7.0_75]
at javax.naming.InitialContext.getDefaultInitCtx(InitialContext.java:307) ~[na:1.7.0_75]
at javax.naming.InitialContext.init(InitialContext.java:242) ~[na:1.7.0_75]
at javax.naming.InitialContext.<init>(InitialContext.java:216) ~[na:1.7.0_75]
at javax.naming.directory.InitialDirContext.<init>(InitialDirContext.java:101) ~[na:1.7.0_75]
at org.activiti.ldap.LDAPConnectionUtil.createDirectoryContext(LDAPConnectionUtil.java:54) ~[activiti-ldap-5.16.4.jar:5.16.4]
… 103 common frames omitted
Caused by: java.net.SocketException: No buffer space available (maximum connections reached?): connect
at java.net.DualStackPlainSocketImpl.connect0(Native Method) ~[na:1.7.0_75]
at java.net.DualStackPlainSocketImpl.socketConnect(DualStackPlainSocketImpl.java:79) ~[na:1.7.0_75]
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) ~[na:1.7.0_75]
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) ~[na:1.7.0_75]
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) ~[na:1.7.0_75]
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:172) ~[na:1.7.0_75]
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[na:1.7.0_75]
at java.net.Socket.connect(Socket.java:579) ~[na:1.7.0_75]
at java.net.Socket.connect(Socket.java:528) ~[na:1.7.0_75]
at java.net.Socket.<init>(Socket.java:425) ~[na:1.7.0_75]
at java.net.Socket.<init>(Socket.java:208) ~[na:1.7.0_75]
at com.sun.jndi.ldap.Connection.createSocket(Connection.java:368) ~[na:1.7.0_75]
at com.sun.jndi.ldap.Connection.<init>(Connection.java:203) ~[na:1.7.0_75]
… 117 common frames omitted

This can easily be a limitation of my system (oracle db in virtualbox, apache ds, jmeter, tomcat all running on it), but i will definetly request another test with Loglevel Info for org.activiti.ldap on the production system on monday.

Re: NullPointerException in taskService with CandidateUser Query under load

christianscheer — Mon, 27 Apr 2015 10:51:59 GMT

Follow Up: There is a different root Exception on the production system "Caused by: javax.naming.NamingException: LDAP response read timed out, timeout used:-1ms."

From https://docs.oracle.com/javase/tutorial/jndi/newstuff/readtimeout.html
" The integer should be greater than zero. An integer less than or equal to zero means no read timeout is specified which is equivalent to waiting for the response infinitely until it is received which defaults to the original behavior."

I will configure connection pooling and the timeout and observe this. My point is, that this exception should not be logged on INFO.

Full Stacktrace:

2015-04-27 11:03:13,620 INFO [http-nio-8085-exec-38] org.activiti.ldap.LDAPTemplate Could not create LDAP connection : Could not create InitialDirContext for LDAP connection : LDAP response read timed out, timeout used:-1ms.
org.activiti.engine.ActivitiException: Could not create InitialDirContext for LDAP connection : LDAP response read timed out, timeout used:-1ms.
at org.activiti.ldap.LDAPConnectionUtil.createDirectoryContext(LDAPConnectionUtil.java:56) ~[activiti-ldap-5.16.4.jar:5.16.4]
at org.activiti.ldap.LDAPConnectionUtil.creatDirectoryContext(LDAPConnectionUtil.java:35) ~[activiti-ldap-5.16.4.jar:5.16.4]
at org.activiti.ldap.LDAPTemplate.execute(LDAPTemplate.java:40) ~[activiti-ldap-5.16.4.jar:5.16.4]
at org.activiti.ldap.LDAPGroupManager.findGroupsByUser(LDAPGroupManager.java:116) [activiti-ldap-5.16.4.jar:5.16.4]
at com.my_company.e_cohesion.workflow_core.activiti.CustomLdapGroupManager.findGroupsByUser(CustomLdapGroupManager.java:74) [workflow-core-1.0.0-SNAPSHOT.jar:na]
at org.activiti.engine.impl.TaskQueryImpl.getGroupsForCandidateUser(TaskQueryImpl.java:1007) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.TaskQueryImpl.getCandidateGroups(TaskQueryImpl.java:997) [activiti-engine-5.16.4.jar:5.16.4]
at sun.reflect.GeneratedMethodAccessor521.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:1.7.0_75]
at java.lang.reflect.Method.invoke(Unknown Source) ~[na:1.7.0_75]
at org.apache.ibatis.reflection.invoker.MethodInvoker.invoke(MethodInvoker.java:37) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.reflection.wrapper.BeanWrapper.getBeanProperty(BeanWrapper.java:151) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.reflection.wrapper.BeanWrapper.get(BeanWrapper.java:45) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.reflection.MetaObject.getValue(MetaObject.java:113) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.DynamicContext$ContextMap.get(DynamicContext.java:94) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.DynamicContext$ContextAccessor.getProperty(DynamicContext.java:113) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.OgnlRuntime.getProperty(OgnlRuntime.java:1657) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.ASTProperty.getValueBody(ASTProperty.java:92) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:170) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.getValue(SimpleNode.java:210) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.ASTNotEq.getValueBody(ASTNotEq.java:49) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:170) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.getValue(SimpleNode.java:210) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.ASTAnd.getValueBody(ASTAnd.java:56) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:170) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.SimpleNode.getValue(SimpleNode.java:210) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.Ognl.getValue(Ognl.java:333) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.Ognl.getValue(Ognl.java:413) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.ognl.Ognl.getValue(Ognl.java:395) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.OgnlCache.getValue(OgnlCache.java:45) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.ExpressionEvaluator.evaluateBoolean(ExpressionEvaluator.java:29) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.IfSqlNode.apply(IfSqlNode.java:30) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.MixedSqlNode.apply(MixedSqlNode.java:29) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.IfSqlNode.apply(IfSqlNode.java:31) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.MixedSqlNode.apply(MixedSqlNode.java:29) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.TrimSqlNode.apply(TrimSqlNode.java:51) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.MixedSqlNode.apply(MixedSqlNode.java:29) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.scripting.xmltags.DynamicSqlSource.getBoundSql(DynamicSqlSource.java:37) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.mapping.MappedStatement.getBoundSql(MappedStatement.java:275) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:79) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:104) [mybatis-3.2.5.jar:3.2.5]
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:98) [mybatis-3.2.5.jar:3.2.5]
at org.activiti.engine.impl.db.DbSqlSession.selectListWithRawParameter(DbSqlSession.java:423) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.db.DbSqlSession.selectList(DbSqlSession.java:414) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.persistence.entity.TaskEntityManager.findTasksByQueryCriteria(TaskEntityManager.java:121) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.TaskQueryImpl.executeList(TaskQueryImpl.java:1143) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.AbstractQuery.execute(AbstractQuery.java:158) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.interceptor.CommandInvoker.execute(CommandInvoker.java:24) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:57) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.spring.SpringTransactionInterceptor$1.doInTransaction(SpringTransactionInterceptor.java:47) [activiti-spring-5.16.4.jar:5.16.4]
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:131) [spring-tx-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.activiti.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:45) [activiti-spring-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:31) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:40) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:35) [activiti-engine-5.16.4.jar:5.16.4]
at org.activiti.engine.impl.AbstractQuery.list(AbstractQuery.java:132) [activiti-engine-5.16.4.jar:5.16.4]
at com.my_company.e_cohesion.workflow_core.impl.WorkflowServiceImpl.getMoeglicheAktionenByFoerderFallForUser(WorkflowServiceImpl.java:60) [workflow-core-1.0.0-SNAPSHOT.jar:na]
at sun.reflect.GeneratedMethodAccessor748.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:1.7.0_75]
at java.lang.reflect.Method.invoke(Unknown Source) ~[na:1.7.0_75]
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at com.my_company.e_cohesion.workflow_base.aop.ServiceLoggingAspect.invoke(ServiceLoggingAspect.java:38) [workflow-base-1.0.0-SNAPSHOT.jar:na]
at sun.reflect.GeneratedMethodAccessor70.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:1.7.0_75]
at java.lang.reflect.Method.invoke(Unknown Source) ~[na:1.7.0_75]
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at com.my_company.e_cohesion.workflow_base.aop.ServiceExceptionMapperAspect.invoke(ServiceExceptionMapperAspect.java:29) [workflow-base-1.0.0-SNAPSHOT.jar:na]
at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:1.7.0_75]
at java.lang.reflect.Method.invoke(Unknown Source) ~[na:1.7.0_75]
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:96) [spring-tx-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:260) [spring-tx-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:94) [spring-tx-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204) [spring-aop-3.2.13.RELEASE.jar:3.2.13.RELEASE]
at com.sun.proxy.$Proxy75.getMoeglicheAktionenByFoerderFallForUser(Unknown Source) [na:na]
at com.my_company.e_cohesion.workflow_webservice.FoerderFallResource.getMoeglicheAktionenByFoerderFallForUser(FoerderFallResource.java:128) [workflow-webservice-1.0.0-SNAPSHOT.jar:na]
at sun.reflect.GeneratedMethodAccessor746.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:1.7.0_75]
at java.lang.reflect.Method.invoke(Unknown Source) ~[na:1.7.0_75]
at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) [jersey-server-2.7.jar:na]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:151) [jersey-server-2.7.jar:na]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:171) [jersey-server-2.7.jar:na]
at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:195) [jersey-server-2.7.jar:na]
at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:104) [jersey-server-2.7.jar:na]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:406) [jersey-server-2.7.jar:na]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:350) [jersey-server-2.7.jar:na]
at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:106) [jersey-server-2.7.jar:na]
at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:259) [jersey-server-2.7.jar:na]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [jersey-common-2.7.jar:na]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [jersey-common-2.7.jar:na]
at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [jersey-common-2.7.jar:na]
at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [jersey-common-2.7.jar:na]
at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [jersey-common-2.7.jar:na]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:320) [jersey-common-2.7.jar:na]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:236) [jersey-server-2.7.jar:na]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1028) [jersey-server-2.7.jar:na]
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:373) [jersey-container-servlet-core-2.7.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:381) [jersey-container-servlet-core-2.7.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.doFilter(ServletContainer.java:534) [jersey-container-servlet-core-2.7.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.doFilter(ServletContainer.java:482) [jersey-container-servlet-core-2.7.jar:na]
at org.glassfish.jersey.servlet.ServletContainer.doFilter(ServletContainer.java:419) [jersey-container-servlet-core-2.7.jar:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [catalina.jar:8.0.21]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.21]
at com.my_company.e_cohesion.workflow_webservice_war.CacheControlFilter.doFilter(CacheControlFilter.java:45) [CacheControlFilter.class:na]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) [catalina.jar:8.0.21]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:8.0.21]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) [catalina.jar:8.0.21]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106) [catalina.jar:8.0.21]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502) [catalina.jar:8.0.21]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142) [catalina.jar:8.0.21]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79) [catalina.jar:8.0.21]
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:610) [catalina.jar:8.0.21]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88) [catalina.jar:8.0.21]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:518) [catalina.jar:8.0.21]
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1091) [tomcat-coyote.jar:8.0.21]
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:668) [tomcat-coyote.jar:8.0.21]
at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) [tomcat-coyote.jar:8.0.21]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1517) [tomcat-coyote.jar:8.0.21]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1474) [tomcat-coyote.jar:8.0.21]
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [na:1.7.0_75]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [na:1.7.0_75]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:8.0.21]
at java.lang.Thread.run(Unknown Source) [na:1.7.0_75]
Caused by: javax.naming.NamingException: LDAP response read timed out, timeout used:-1ms.
at com.sun.jndi.ldap.Connection.readReply(Unknown Source) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapClient.ldapBind(Unknown Source) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapClient.authenticate(Unknown Source) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapCtx.connect(Unknown Source) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapCtx.<init>(Unknown Source) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(Unknown Source) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(Unknown Source) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(Unknown Source) ~[na:1.7.0_75]
at com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(Unknown Source) ~[na:1.7.0_75]
at javax.naming.spi.NamingManager.getInitialContext(Unknown Source) ~[na:1.7.0_75]
at javax.naming.InitialContext.getDefaultInitCtx(Unknown Source) ~[na:1.7.0_75]
at javax.naming.InitialContext.init(Unknown Source) ~[na:1.7.0_75]
at javax.naming.InitialContext.<init>(Unknown Source) ~[na:1.7.0_75]
at javax.naming.directory.InitialDirContext.<init>(Unknown Source) ~[na:1.7.0_75]
at org.activiti.ldap.LDAPConnectionUtil.createDirectoryContext(LDAPConnectionUtil.java:54) ~[activiti-ldap-5.16.4.jar:5.16.4]
… 136 common frames omitted

Re: NullPointerException in taskService with CandidateUser Query under load

jbarrez — Tue, 28 Apr 2015 18:47:09 GMT

Okay, that was a lot of text to follow. So my hunch at the beginning of the thread was that is was around LDAP connection pooling … which seems to be validated by you in your last post.

Can you confirm this?

Also: the log level does seem to be wrong, can you also confirm that?

I know that Spring-ldap has some Ldap connection poolings improvements vs the direct intialcontext lookup, but i don't think you can straight away plug that straight away into Activiti as-is with the current LdapConfigurator.

Re: NullPointerException in taskService with CandidateUser Query under load

christianscheer — Wed, 29 Apr 2015 06:40:52 GMT

I monitored the JVM and the opened Ldap connections alot. Without Pooling, it seemed to me that Ldap Connectionts remained established until the garbage collector ran. Which led to a lot of open connections and ultimatly the hidden exception from above. Maybe this is something you can have a look at.

After i found the hidden exception from above i tried to use Connection Pooling. It did not help, because connections where not given back to the pool. Maybe there is a connection to the observation above and the connections are given back after garbage collection.

I was able to solve my issue with the LdapGroupCache, which significantly reduced the ammount of Ldap lookups.

>Also: the log level does seem to be wrong, can you also confirm that?
Absolutly, the "Could not create InitialDirContext for LDAP connection" Exception should not be logged on INFO.

Re: NullPointerException in taskService with CandidateUser Query under load

jbarrez — Thu, 07 May 2015 13:39:51 GMT

I added an extra line of logging: https://github.com/Activiti/Activiti/commit/fa486b09cfc0bebfb1bc2064d343719201115b9a

Re: NullPointerException in taskService with CandidateUser Query under load

christianscheer — Thu, 07 May 2015 14:23:00 GMT

Thanks!