IdStory Identity Manager

So far, I have tested provisioning of 1000 accounts to end system (via SSH connector) with various speeds of system response (0.5s, 1s, 5.5s) with both synchronous and asynchronous operations.
Raising the number of event executors (from 3 to 30) does not have any big effect on system performace. Importantly, it seems to have a very small positive effect so we probably do not need to fear a performance hit.

Next step is to create scenario with intensive attribute calculation in the IdM to see how it then behaves.
Probably something like this transformation script should be enough:

import java.util.Date;
// cca 9s on my station
// cca 6s on testing server
String megastr = "";
for (int i = 0; i < 10e6; i++) {
    megastr = megastr + i;
    if (megastr.length() > 1000) {
        megastr = megastr.substring(0, 999);
    }
}
return attributeValue;

After testing, I can say that number of event executors does not impact IdM performance either positively or negatively.
This may have two causes (I don't know which one yet):

• During tests, I used mainly non-poolable connector. (This is my tip. But it is a problem, because right now most of our connectors are not poolable.)
• JVM maps event executor threads to only a small number of native (or in effect kernel) threads. This causes event executors to share CPU time no matter how many of them we create. (This may not be true, because CPU time needed for transformation scripts does not affect processing times when the end system's response is very slow. However, JVM could be making some clever desicions in rescheduling Java threads on Native threads... guess this would need a bit more of testing.)

I planned results presentation on Friday 6/9/2019.

I did a whole bunch of tests using LDAP connector. With and without pooling set up. I have results in a google document - PM me if you want to take a look.
Results are funny:

• When using LDAP connector, the pooling seemed to have (dunno how, read on...) a positive effect. AccountMgmt and reprovisioning of 1000 users took 8-10 minutes without pooling and about 5 minutes with pooling (stable).
• Number of event executor threads (3, 15, or 30) did not matter.
• When I added transformation script which slowes provisioning computation by about 5s, I got the same behavior as I saw when using SSH connector. Pooling enabled or not, did not matter. Neither did the number of event executors.

So when looking at Threads competing over some monitor objects, I took a series of thread dumps. In this case IdM had LDAP pooling enabled (min. 1 connection, max. 30 connections), 3 event executors and no slowdown transformation script. Whole reprovisioning took about 5 minutes.
Case 1 (threads waiting on DefaultProvisioningExecutor, looks like they compete for database access):

"event-task-executor-1" - Thread t@298
   java.lang.Thread.State: BLOCKED
        at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor.executeInternal(DefaultProvisioningExecutor.java:151)
        - waiting to lock <1bb9e35c> (a eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor) owned by "event-task-executor-2" t@299
        at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor$$FastClassBySpringCGLIB$$68607120.invoke(<generated>)
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
        at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655)
        at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor$$EnhancerBySpringCGLIB$$e87aff4c.executeInternal(<generated>)

"event-task-executor-2" - Thread t@299
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:171)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:140)

"event-task-executor-3" - Thread t@300
   java.lang.Thread.State: BLOCKED
        at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor.execute(DefaultProvisioningExecutor.java:108)
        - waiting to lock <1bb9e35c> (a eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor) owned by "event-task-executor-2" t@299
        at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor$$FastClassBySpringCGLIB$$68607120.invoke(<generated>)
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
        at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
        at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655)
        at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor$$EnhancerBySpringCGLIB$$e87aff4c.execute(<generated>)
        at eu.bcvsolutions.idm.acc.service.impl.AbstractProvisioningExecutor.doProvisioning(AbstractProvisioningExecutor.java:741)

Case 2 (Threads waiting on DefaultProvisioningExecutor but because LDAP was contacted - this probably should not happen, we should be pooling):

"event-task-executor-3" - Thread t@300
   java.lang.Thread.State: WAITING
        at java.lang.Object.wait(Native Method)
        - waiting on <48b541cc> (a com.sun.jndi.ldap.LdapRequest)
        at java.lang.Object.wait(Object.java:502)
        at com.sun.jndi.ldap.Connection.readReply(Connection.java:493)
        at com.sun.jndi.ldap.LdapClient.processReply(LdapClient.java:881)
        at com.sun.jndi.ldap.LdapClient.modify(LdapClient.java:955)
        at com.sun.jndi.ldap.LdapCtx.c_modifyAttributes(LdapCtx.java:1471)
        at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_modifyAttributes(ComponentDirContext.java:277)
        at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.modifyAttributes(PartialCompositeDirContext.java:192)
        at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.modifyAttributes(PartialCompositeDirContext.java:181)
        at javax.naming.directory.InitialDirContext.modifyAttributes(InitialDirContext.java:167)
        at net.tirasa.connid.bundles.ldap.modify.LdapUpdate.modifyAttributes(LdapUpdate.java:327)
        at net.tirasa.connid.bundles.ldap.modify.LdapUpdate.modifyAttributes(LdapUpdate.java:321)
        at net.tirasa.connid.bundles.ldap.modify.LdapUpdate.update(LdapUpdate.java:131)
        at net.tirasa.connid.bundles.ldap.LdapConnector.update(LdapConnector.java:161)
        at org.identityconnectors.framework.impl.api.local.operations.UpdateImpl.update(UpdateImpl.java:101)
        at sun.reflect.GeneratedMethodAccessor1132.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.identityconnectors.framework.impl.api.local.operations.ConnectorAPIOperationRunnerProxy.invoke(ConnectorAPIOperationRunnerProxy.java:98)
        at com.sun.proxy.$Proxy365.update(Unknown Source)
        at sun.reflect.GeneratedMethodAccessor1132.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.identityconnectors.framework.impl.api.local.operations.ThreadClassLoaderManagerProxy.invoke(ThreadClassLoaderManagerProxy.java:96)
        at com.sun.proxy.$Proxy365.update(Unknown Source)
        at sun.reflect.GeneratedMethodAccessor1132.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.identityconnectors.framework.impl.api.DelegatingTimeoutProxy.invoke(DelegatingTimeoutProxy.java:99)
        at com.sun.proxy.$Proxy365.update(Unknown Source)
        at org.identityconnectors.framework.impl.api.AbstractConnectorFacade.update(AbstractConnectorFacade.java:190)
        at eu.bcvsolutions.idm.ic.connid.service.impl.ConnIdIcConnectorService.updateObject(ConnIdIcConnectorService.java:123)

"event-task-executor-2" - Thread t@299
   java.lang.Thread.State: BLOCKED
        at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor.executeInternal(DefaultProvisioningExecutor.java:151)
        - waiting to lock <1bb9e35c> (a eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor) owned by "event-task-executor-3" t@300
        at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor$$FastClassBySpringCGLIB$$68607120.invoke(<generated>)

"event-task-executor-1" - Thread t@298
   java.lang.Thread.State: BLOCKED
        at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor.execute(DefaultProvisioningExecutor.java:108)
        - waiting to lock <1bb9e35c> (a eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor) owned by "event-task-executor-3" t@300
        at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor$$FastClassBySpringCGLIB$$68607120.invoke(<generated>)

Case 3 (A-OK):

"event-task-executor-3" - Thread t@300
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:171)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:140)

"event-task-executor-2" - Thread t@299
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:171)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:140)

"event-task-executor-1" - Thread t@298
   java.lang.Thread.State: RUNNABLE
        at java.io.DataOutputStream.writeByte(DataOutputStream.java:153)
        at org.identityconnectors.framework.impl.serializer.binary.BinaryObjectEncoder$InternalEncoder.writeByte(BinaryObjectEncoder.java:233)
        at org.identityconnectors.framework.impl.serializer.binary.BinaryObjectEncoder$InternalEncoder.startField(BinaryObjectEncoder.java:180)
        at org.identityconnectors.framework.impl.serializer.binary.BinaryObjectEncoder.writeStringField(BinaryObjectEncoder.java:445)
        at org.identityconnectors.framework.impl.serializer.APIConfigurationHandlers$3.serialize(APIConfigurationHandlers.java:138)
        at org.identityconnectors.framework.impl.serializer.binary.BinaryObjectEncoder$InternalEncoder.writeObject(BinaryObjectEncoder.java:125)
        at org.identityconnectors.framework.impl.serializer.binary.BinaryObjectEncoder.writeObjectContents(BinaryObjectEncoder.java:424)
        at org.identityconnectors.framework.impl.serializer.APIConfigurationHandlers$4.serialize(APIConfigurationHandlers.java:165)
        at org.identityconnectors.framework.impl.serializer.binary.BinaryObjectEncoder$InternalEncoder.writeObject(BinaryObjectEncoder.java:125)
        at org.identityconnectors.framework.impl.serializer.binary.BinaryObjectEncoder.writeObjectField(BinaryObjectEncoder.java:431)
        at org.identityconnectors.framework.impl.serializer.APIConfigurationHandlers$5.serialize(APIConfigurationHandlers.java:205)
        at org.identityconnectors.framework.impl.serializer.binary.BinaryObjectEncoder$InternalEncoder.writeObject(BinaryObjectEncoder.java:125)
        at org.identityconnectors.framework.impl.serializer.binary.BinaryObjectEncoder.writeObject(BinaryObjectEncoder.java:316)
        at org.identityconnectors.framework.common.serializer.SerializerUtil.serializeBinaryObject(SerializerUtil.java:57)
        at org.identityconnectors.framework.common.serializer.SerializerUtil.cloneObject(SerializerUtil.java:159)
        at org.identityconnectors.framework.impl.api.AbstractConnectorInfo.createDefaultAPIConfiguration(AbstractConnectorInfo.java:93)
        at eu.bcvsolutions.idm.ic.connid.service.impl.ConnIdIcConnectorService.getConnectorFacade(ConnIdIcConnectorService.java:291)

Case 4 (another waiting for LDAP reply, blocked in DefaultProvisioningExecutor):

"event-task-executor-3" - Thread t@300
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:171)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:140)

"event-task-executor-2" - Thread t@299
   java.lang.Thread.State: WAITING
        at java.lang.Object.wait(Native Method)
        - waiting on <7e27dd00> (a com.sun.jndi.ldap.LdapRequest)
        at java.lang.Object.wait(Object.java:502)
        at com.sun.jndi.ldap.Connection.readReply(Connection.java:493)

"event-task-executor-1" - Thread t@298
   java.lang.Thread.State: BLOCKED
        at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor.executeInternal(DefaultProvisioningExecutor.java:151)
        - waiting to lock <1bb9e35c> (a eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor) owned by "event-task-executor-2" t@299
        at eu.bcvsolutions.idm.acc.service.impl.DefaultProvisioningExecutor$$FastClassBySpringCGLIB$$68607120.invoke(<generated>)

Next step: Configure slowdown transformation script and take Thread dumps.

As we briefly discussed in person, here is the conclusion. I have to consult it with Zdenda and the product team once more.
The proposed values are my guess on what would make sense, any feedback appreciated.

Base task executors

• Implement rejection policy for LRT queue #1837.
• Default minimal num. base-task-executor threads to #CPU*2.
  • This means having up to 16 LRT threads by default (on 8-core system).
• queueCapacity set to #CPU*2.
  • This causes LRT thread pool to enlarge once there is enough work.
• Default max num. base-task-executor threads to 50.
  • When there is so much work (on say 4-core or 8-core system) that we need 50 LRT threads, the CPU time one thread gets is way under 20% so things will get reeealy slow by this point. Other LRTs can simply wait.

Event task executors

• Resolve suspected thread interlocking as per: #1690#note-5 , #1690#note-6
• Default minimal num. event-task-executor threads to #CPU*2.
  • So that one LRT gets to one event thread on average. Some LRTs do not create events so this gives us a relatively safe margin.
• Default max num. event-task-executor threads to #CPU*4.
• Set scheduler.event.executor.queueCapacity = 25.
  • Currently we have this set to 50 but idm.sec.core.event.asynchronous.batchSize is set to 15. Setting both those values to 25 seems like a good average.
  • This is a blind guess. If you have any data to support deciding this, I'll be glad.
• Set scheduler.event.executor.queueCapacity = idm.sec.core.event.asynchronous.batchSize which means once there is enough work, the pool start to enlarge.
  • We have to do this (or make some implementation change), otherwise the executor pooling does not work.