Increasing the JDBC connection pool size
In the event of performing load and stress tests on OpenIAM with OpenIAM API /idp/rest/api/auth/public/login, you might run into an error indicating the pool size for connector is too small.
Problem
For instance, you use 4 rProxys that balance their respective openiam-uis and connect to 3 OpenIAM (backends) machines. When using the JMeter tool pointing to the F5 that balances the 4 rProxys. When carrying about 5000 requests/second, several database errors might occur and cause connections to fail giving the following error.
Unable to acquire JDBC Connection
javax.xml.ws.soap.SOAPFaultException: Could not open JPA EntityManager for transaction; nested exception is org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connectionat org.apache.cxf.jaxws.JaxWsClientProxy.mapException(JaxWsClientProxy.java:195) ~[cxf-rt-frontend-jaxws-3.3.6.jar:3.3.6]at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy. java:145) ~[cxf-rt-frontend-jaxws-3.3.6.jar:3.3.6]at com.sun.proxy.$Proxy244.getLoginByManagedSys(Unknown Source) ~[?:?]at org.openiam.ui.rest.api.mvc.AuthenticationRestController.loginPost(AuthenticationRestController. java:332) ~[classes/:?]at org.openiam.ui.rest.api.mvc.AuthenticationRestController$$$FastClassBySpringCGLIB$$1e6d3f3d.invoke(<generated>) ~[classes/:?]at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy. java:218) ~[spring-core-5.3.18.jar:5.3.18]at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:783) ~[spring-aop-5.3.18.jar:5.3.18]at org.springframework.aop.framework. ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.18.jar:5.3.18]at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:753) ~[spring-aop-5.3.18. jar:5.3.18]at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:89) ~[spring-aop-5.3.18.jar:5.3.18]at org.openiam.ui.audit.AuditPointcut.processAuditLog(AuditPointcut. java:86) ~[openiam-ui-intf-4.2.1.13.jar:?]at jdk.internal.reflect.GeneratedMethodAccessor990.invoke(Unknown Source) ~[?:?]at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]at java.lang.reflect.Method. invoke(Method.java:566) ~[?:?]at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:634) ~[spring-aop-5.3.18.jar:5.3.18]
Solution
The problem may occur since the default property value is org.openiam.jdbc.connection.pool.size.max=20.
To resolve it, increase the value calculating based on following formula:
Concurrent users: XTPS per user: 1.5Avg query time: 0.5 secondsPool Size = (X * 1.5 * 0.5) * 1.2
Once you calculated proper max pool size, you need override this property for openiam-esb, openiam-auth, and workflow services - as these services use DB connection.
RPM environment
How to override default max pool size, which is 20 by default:
- Add one more property -
-Dspring.config.location=$HOME_DIR/conf/application.esb.properties- intoservices/start_esb.shalong with existing-Dproperties. - Create file with following content.
org.openiam.jdbc.connection.pool.size.max=25
- Restart service, make sure that old process is stopped and new is the only one running.
- Additionally, you can add the
logging.level.com.zaxxer.hikari=DEBUGline into the file as it will help to monitor connections.
Once you restart service you should see following logs.
2024-01-19 06:21:58.841 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : Driver class com.mysql.cj.jdbc.Driver found in Thread context class loader org.springframework.boot.loader.LaunchedURLClassLoader@4c70fda82024-01-19 06:21:58.863 WARN 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : HikariPool-1 - idleTimeout has been set but has no effect because the pool is operating as a fixed size pool.2024-01-19 06:21:58.863 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : HikariPool-1 - configuration:2024-01-19 06:21:58.866 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : allowPoolSuspension.............false2024-01-19 06:21:58.867 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : autoCommit......................true2024-01-19 06:21:58.867 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : catalog.........................none2024-01-19 06:21:58.868 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : connectionInitSql...............none2024-01-19 06:21:58.868 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : connectionTestQuery.............none2024-01-19 06:21:58.868 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : connectionTimeout...............300002024-01-19 06:21:58.869 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : dataSource......................none2024-01-19 06:21:58.869 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : dataSourceClassName.............none2024-01-19 06:21:58.869 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : dataSourceJNDI..................none2024-01-19 06:21:58.870 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : dataSourceProperties............{password=<masked>, prepStmtCacheSqlLimit=2048, cachePrepStmts=true, prepStmtCacheSize=250}2024-01-19 06:21:58.871 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : driverClassName................."com.mysql.cj.jdbc.Driver"2024-01-19 06:21:58.871 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : exceptionOverrideClassName......none2024-01-19 06:21:58.871 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : healthCheckProperties...........{}2024-01-19 06:21:58.872 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : healthCheckRegistry.............none2024-01-19 06:21:58.872 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : idleTimeout.....................3000002024-01-19 06:21:58.873 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : initializationFailTimeout.......12024-01-19 06:21:58.873 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : isolateInternalQueries..........false2024-01-19 06:21:58.874 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : jdbcUrl.........................jdbc:mysql://localhost:3306/activiti?autoReconnect=true&useUnicode=true&characterEncoding=utf8&connectionCollation=utf8_general_ci&serverTimezone=UTC2024-01-19 06:21:58.874 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : leakDetectionThreshold..........02024-01-19 06:21:58.874 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : maxLifetime.....................6000002024-01-19 06:21:58.874 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : maximumPoolSize.................252024-01-19 06:21:58.875 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : metricRegistry..................none2024-01-19 06:21:58.875 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : metricsTrackerFactory...........none2024-01-19 06:21:58.875 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : minimumIdle.....................252024-01-19 06:21:58.875 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : password........................<masked>2024-01-19 06:21:58.876 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : poolName........................"HikariPool-1"2024-01-19 06:21:58.876 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : readOnly........................false2024-01-19 06:21:58.876 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : registerMbeans..................false2024-01-19 06:21:58.876 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : scheduledExecutor...............none2024-01-19 06:21:58.877 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : schema..........................none2024-01-19 06:21:58.877 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : threadFactory...................internal2024-01-19 06:21:58.877 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : transactionIsolation............default2024-01-19 06:21:58.877 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : username........................"activiti"2024-01-19 06:21:58.878 DEBUG 2662251 --- [ main] com.zaxxer.hikari.HikariConfig : validationTimeout...............50002024-01-19 06:21:58.880 INFO 2662251 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...2024-01-19 06:21:59.452 DEBUG 2662251 --- [ main] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Added connection com.mysql.cj.jdbc.ConnectionImpl@29a1505c2024-01-19 06:21:59.456 INFO 2662251 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed.2024-01-19 06:21:59.556 DEBUG 2662251 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Pool stats (total=1, active=0, idle=1, waiting=0)
Docker environment
To override the required property in Docker, navigate to docker-compose.yaml file. Here, you can set the JavaOpts for each service, including to solve the mentioned problem by making changes in section below.
OPENIAM_JAVA_OPT_ARGS: "-Dlogging.level.root=${LOGGING_LEVEL} -Dlogging.level.org.elasticsearch.client=ERROR"
After making the respective changes, shutdown OpenIAm with shutdown.sh and start it again with startup.sh.
Kubernetes environment
To perform the same in Kubernetes environment, you will also need to change JavaOpts for the service in terraform.tfvars file. JavaOpts section for all services is the
javaOpts = {
Set the required parameter and run
terraform apply