Hyland Connect

christianscheer · ‎04-23-2015

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 Code


taskService.createTaskQuery().taskCandidateUser(userName).processVariableValueEquals(FOERDERFALL_ID_KEY, foerderFallId).list();
‍‍‍

After digging through the stacetrace (see below) and the Activiti Source, i found


  protected List<String> getGroupsForCandidateUser(String candidateUser) {
    // TODO: Discuss about removing this feature? Or document it properly and maybe recommend to not use it
    // and explain alternatives
‍‍‍‍‍

in TaskQueryImpl. So i guess you guys have allready noticed something about this kind of query.
I appreciate any help in switching to a better alternative.
Unfortunally I cannot reproduce this error on my local machine, but i operations told me
the established LDAP connections are fluctuating between 60 and 120 and there is no significant high cpu load or RAM usage. We use Tomcat 8, Java 7 x64.

There is a Custom LdapGroupManager registered, as you can see from the stacktrace. The Exception occures at super.findGroupsByUser(…, so this problem should occure independend of it.


public class CustomLdapGroupManager extends LDAPGroupManager {
    private FoerderFallKundenRolleRepository kundenRollenRepository;
    private RuntimeService runtimeService;
//Constructor with and without LDAPGroupCache ommited

    @Override
    public List<Group> findGroupsByUser(String userId) {
        List<Group> groups = super.findGroupsByUser(userId);

        // Do custom Stuff with groups and kundenRollenRepository and runtimeService
        return groups;
    }
}
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

I attached the processEngineConfiguration and CustomLdapConfigurator/CustomLdapGroupManager below, allthough there is (from my point of view) nothing special in it.

Stacktrace:


2015-04-22 09:31:09,503 ERROR [http-nio-8085-exec-48] com.my_company.project.workflow_webservice.exception_mapping.ProjectExceptionMapper Internal Server Error: 
com.my_company.project.workflow_base.exception.ProjectSystemException: org.apache.ibatis.exceptions.PersistenceException: 
### Error querying database.  Cause: java.lang.NullPointerException
### Cause: java.lang.NullPointerException CallStack:
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]
   at sun.reflect.GeneratedMethodAccessor58.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.project.workflow_webservice.FoerderFallResource.getMoeglicheAktionenByFoerderFallForUser(FoerderFallResource.java:128) ~[workflow-webservice-1.0.0-SNAPSHOT.jar:na]
   at sun.reflect.GeneratedMethodAccessor650.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.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(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: 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_core.impl.WorkflowServiceImpl.getMoeglicheAktionenByFoerderFallForUser(WorkflowServiceImpl.java:60) ~[workflow-core-1.0.0-SNAPSHOT.jar:na]
   at sun.reflect.GeneratedMethodAccessor649.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.project.workflow_base.aop.ServiceLoggingAspect.invoke(ServiceLoggingAspect.java:38) ~[workflow-base-1.0.0-SNAPSHOT.jar:na]
   at sun.reflect.GeneratedMethodAccessor57.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.project.workflow_base.aop.ServiceExceptionMapperAspect.invoke(ServiceExceptionMapperAspect.java:29) ~[workflow-base-1.0.0-SNAPSHOT.jar:na]
   … 63 common frames omitted
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.GeneratedMethodAccessor88.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.ASTChain.getValueBody(ASTChain.java:109) ~[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.ASTGreater.getValueBody(ASTGreater.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]
   … 96 common frames omitted
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

activitiApplicationContext.xml:


<bean id="processEngineConfiguration" class="org.activiti.spring.SpringProcessEngineConfiguration">
    <property name="dataSource" ref="dataSource"/>
    <property name="transactionManager" ref="transactionManager"/>
    <property name="databaseSchemaUpdate" value="true"/>
    <property name="jobExecutorActivate" value="true"/>
    <!– mail server config ommited –>
    <!– pre and postBpmnParseHandlers config ommited –>

    <property name="configurators">
        <list>
            <bean class="com.my_company.project.workflow_core.activiti.CustomLdapConfigurator">
                <property name="server" value="${ldap.EndpointServer.host}"/>
                <property name="port" value="${ldap.EndpointServer.port}"/>
                <property name="user" value="${ldap.EndpointUser}"/>
                <property name="password" value="${ldap.EndpointPassword}"/>

                <property name="baseDn" value="${ldap.BasePath}"/>
                <property name="userBaseDn" value="${ldap.UserBasePath}"/>
                <property name="groupBaseDn" value="${ldap.GroupBasePath}"/>
                <property name="queryUserByUserId" value="(&amp;(objectClass=portalnutzer)(cn={0}))"/>
                <property name="queryGroupsForUser" value="(&amp;(objectClass=nutzergruppe)(member={0}))"/>
                <property name="queryUserByFullNameLike" value="(&amp;(objectClass=inetOrgPerson)(|({0}=*{1}*)({2}=*{3}*)))"/>

                <property name="userIdAttribute" value="cn"/>
                <property name="userFirstNameAttribute" value="cn"/>
                <property name="userLastNameAttribute" value="sn"/>

                <property name="groupIdAttribute" value="cn"/>
                <property name="groupNameAttribute" value="cn"/>
                
                <!– custom repository –>
                <property name="kundenRollenRepository" ref="foerderFallKundenRolleRepositoryImpl"/>
            </bean>
        </list>
    </property>
</bean>
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍


public class CustomLdapConfigurator extends LDAPConfigurator {
    private FoerderFallKundenRolleRepository kundenRollenRepository;

    @Override
    public void configure(ProcessEngineConfigurationImpl processEngineConfiguration) {
        super.configure(processEngineConfiguration);
        Clock clock = processEngineConfiguration.getClock();
        // Replace GroupIdentityManager with own CustomGroupIdentityManager
        CustomLdapGroupManagerFactory groupManagerFactory = new CustomLdapGroupManagerFactory(this, clock,
                kundenRollenRepository, processEngineConfiguration.getRuntimeService());
        processEngineConfiguration.getSessionFactories().put(GroupIdentityManager.class, groupManagerFactory);
    }
    
    //Set custom repository
    public void setKundenRollenRepository(FoerderFallKundenRolleRepository kundenRollenRepository) {
        this.kundenRollenRepository = kundenRollenRepository;
    }
}

public CustomLdapGroupManagerFactory(LDAPConfigurator ldapConfigurator, Clock clock,
                                         FoerderFallKundenRolleRepository kundenRollenRepository,
                                         RuntimeService runtimeService) {
        super(ldapConfigurator, clock);
        this.kundenRollenRepository = kundenRollenRepository;
        this.runtimeService = runtimeService;
    }

    @Override
    public Session openSession() {
        if (ldapGroupCache == null) {
            return new CustomLdapGroupManager(ldapConfigurator, kundenRollenRepository, runtimeService);
        } else {
            return new CustomLdapGroupManager(ldapConfigurator, ldapGroupCache, kundenRollenRepository, runtimeService);
        }
}
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

trademak · ‎04-24-2015

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,

christianscheer · ‎04-24-2015

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>

christianscheer · ‎04-24-2015

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>

christianscheer · ‎04-24-2015

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.

christianscheer · ‎04-27-2015

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

jbarrez · ‎04-28-2015

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.

christianscheer · ‎04-29-2015

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.

jbarrez · ‎05-07-2015

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

christianscheer · ‎05-07-2015

Thanks!

Hyland Connect

NullPointerException in taskService with CandidateUser Query under load