I am trying to create 50 users simultaneously through parallel POST /api/user calls. Getting sql timeout exception. Is there any way to increase timeout ? Is there any better solution to achieve this.
FusionAuth on AKS 1.14.6. Enough hardware resources available on Node.
Postgres 9.6
Sep 16, 2019 8:23:12.859 PM ERROR io.fusionauth.app.primeframework.error.ExceptionExceptionHandler - An unhandled exception was thrown
org.apache.ibatis.exceptions.PersistenceException:
### Error updating database. Cause: java.sql.SQLTransientConnectionException: HikariPool-2 - Connection is not available, request timed out after 2000ms.
### Cause: java.sql.SQLTransientConnectionException: HikariPool-2 - Connection is not available, request timed out after 2000ms.
at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:200)
at org.apache.ibatis.session.defaults.DefaultSqlSession.insert(DefaultSqlSession.java:185)
at sun.reflect.GeneratedMethodAccessor73.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.apache.ibatis.session.SqlSessionManager$SqlSessionInterceptor.invoke(SqlSessionManager.java:350)
at com.sun.proxy.$Proxy79.insert(Unknown Source)
at org.apache.ibatis.session.SqlSessionManager.insert(SqlSessionManager.java:236)
at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:58)
at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:59)
at com.sun.proxy.$Proxy114.create(Unknown Source)
at io.fusionauth.api.service.user.DefaultUserService.create(DefaultUserService.java:256)
at org.mybatis.guice.transactional.TransactionalMethodInterceptor.invoke(TransactionalMethodInterceptor.java:96)
at org.mybatis.guice.transactional.TransactionalMethodInterceptor.invoke(TransactionalMethodInterceptor.java:96)
at org.mybatis.guice.transactional.TransactionalMethodInterceptor.invoke(TransactionalMethodInterceptor.java:96)
at org.mybatis.guice.transactional.TransactionalMethodInterceptor.invoke(TransactionalMethodInterceptor.java:96)
at io.fusionauth.app.action.api.UserAction.post(UserAction.java:115)
at sun.reflect.GeneratedMethodAccessor180.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.primeframework.mvc.util.ReflectionUtils.invoke(ReflectionUtils.java:436)
at org.primeframework.mvc.action.DefaultActionInvocationWorkflow.execute(DefaultActionInvocationWorkflow.java:84)
at org.primeframework.mvc.action.DefaultActionInvocationWorkflow.perform(DefaultActionInvocationWorkflow.java:64)
at org.primeframework.mvc.workflow.SubWorkflowChain.continueWorkflow(SubWorkflowChain.java:43)
at org.primeframework.mvc.validation.DefaultValidationWorkflow.perform(DefaultValidationWorkflow.java:47)
at org.primeframework.mvc.workflow.SubWorkflowChain.continueWorkflow(SubWorkflowChain.java:43)
at org.primeframework.mvc.security.DefaultSecurityWorkflow.perform(DefaultSecurityWorkflow.java:81)
at org.primeframework.mvc.workflow.SubWorkflowChain.continueWorkflow(SubWorkflowChain.java:43)
at org.primeframework.mvc.parameter.DefaultPostParameterWorkflow.perform(DefaultPostParameterWorkflow.java:50)
at org.primeframework.mvc.workflow.SubWorkflowChain.continueWorkflow(SubWorkflowChain.java:43)
at org.primeframework.mvc.content.DefaultContentWorkflow.perform(DefaultContentWorkflow.java:52)
at org.primeframework.mvc.workflow.SubWorkflowChain.continueWorkflow(SubWorkflowChain.java:43)
at org.primeframework.mvc.parameter.DefaultParameterWorkflow.perform(DefaultParameterWorkflow.java:57)
at org.primeframework.mvc.workflow.SubWorkflowChain.continueWorkflow(SubWorkflowChain.java:43)
at org.primeframework.mvc.parameter.DefaultURIParameterWorkflow.perform(DefaultURIParameterWorkflow.java:102)
at org.primeframework.mvc.workflow.SubWorkflowChain.continueWorkflow(SubWorkflowChain.java:43)
at org.primeframework.mvc.scope.DefaultScopeRetrievalWorkflow.perform(DefaultScopeRetrievalWorkflow.java:58)
at org.primeframework.mvc.workflow.SubWorkflowChain.continueWorkflow(SubWorkflowChain.java:43)
at org.primeframework.mvc.message.DefaultMessageWorkflow.perform(DefaultMessageWorkflow.java:45)
at org.primeframework.mvc.workflow.SubWorkflowChain.continueWorkflow(SubWorkflowChain.java:43)
at org.primeframework.mvc.action.DefaultActionMappingWorkflow.perform(DefaultActionMappingWorkflow.java:126)
at org.primeframework.mvc.workflow.SubWorkflowChain.continueWorkflow(SubWorkflowChain.java:43)
at org.primeframework.mvc.workflow.StaticResourceWorkflow.perform(StaticResourceWorkflow.java:97)
at org.primeframework.mvc.workflow.SubWorkflowChain.continueWorkflow(SubWorkflowChain.java:43)
at org.primeframework.mvc.parameter.RequestBodyWorkflow.perform(RequestBodyWorkflow.java:89)
at org.primeframework.mvc.workflow.SubWorkflowChain.continueWorkflow(SubWorkflowChain.java:43)
at org.primeframework.mvc.security.DefaultSavedRequestWorkflow.perform(DefaultSavedRequestWorkflow.java:57)
at org.primeframework.mvc.workflow.SubWorkflowChain.continueWorkflow(SubWorkflowChain.java:43)
at io.fusionauth.api.primeframework.CORSFilter.handleNonCORS(CORSFilter.java:317)
at io.fusionauth.api.primeframework.CORSFilter.doFilter(CORSFilter.java:278)
at io.fusionauth.api.primeframework.CORSRequestWorkflow.perform(CORSRequestWorkflow.java:48)
at org.primeframework.mvc.workflow.SubWorkflowChain.continueWorkflow(SubWorkflowChain.java:43)
at io.fusionauth.api.primeframework.FusionAuthMVCWorkflow.perform(FusionAuthMVCWorkflow.java:87)
at org.primeframework.mvc.workflow.DefaultWorkflowChain.continueWorkflow(DefaultWorkflowChain.java:44)
at org.primeframework.mvc.servlet.FilterWorkflowChain.continueWorkflow(FilterWorkflowChain.java:50)
at org.primeframework.mvc.servlet.PrimeFilter.doFilter(PrimeFilter.java:84)
at com.inversoft.maintenance.servlet.MaintenanceModePrimeFilter.doFilter(MaintenanceModePrimeFilter.java:59)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.inversoft.servlet.UTF8Filter.doFilter(UTF8Filter.java:27)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:137)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:798)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:808)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTransientConnectionException: HikariPool-2 - Connection is not available, request timed out after 2000ms.
at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:602)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:195)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:145)
at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:85)
at org.apache.ibatis.transaction.jdbc.JdbcTransaction.openConnection(JdbcTransaction.java:139)
at org.apache.ibatis.transaction.jdbc.JdbcTransaction.getConnection(JdbcTransaction.java:61)
at org.apache.ibatis.executor.BaseExecutor.getConnection(BaseExecutor.java:338)
at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:84)
at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:49)
at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:117)
at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:76)
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:198)
The Import API is the best solution for creating multiple users in a single call. This API is documented here:
https://fusionauth.io/docs/v1/tech/apis/users#import-users
However, I'm confused that PostgreSQL was backing up like that and causing timeouts in FusionAuth's database connection pool. Normally, timeouts are caused by table locking, so unless you have tons of users in the table already, you shouldn't run into any issues.
If you do have a bunch of users in the database already, then you could be hitting an issue where the unique key indexes for the users table (email and username) are not able to fit in memory in PostgreSQL and it is going to disk to ensure that new records don't violate constraints.
You might want to check the processes and transaction that are running inside PostgreSQL to see what is causing the timeouts.
If you think this is a bug, feel free to open an issue on the FusionAuth GitHub Issue tracker and provide as much detail as possible.