FusionAuth Bulk 用户创建给出 SQL 超时错误答案

【问题标题】：FusionAuth Bulk user creation giving SQL timeout errorFusionAuth Bulk 用户创建给出 SQL 超时错误
【发布时间】：2019-09-16 20:44:13
【问题描述】：

我正在尝试通过并行 POST /api/user 调用同时创建 50 个用户。获取 sql 超时异常。有没有办法增加超时？有没有更好的解决方案来实现这一点。

AKS 1.14.6 上的 FusionAuth。 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)

【问题讨论】：

标签： sql fusionauth

【解决方案1】：

导入 API 是在一次调用中创建多个用户的最佳解决方案。该 API 记录在这里：

https://fusionauth.io/docs/v1/tech/apis/users#import-users

但是，我很困惑 PostgreSQL 是这样备份并导致 FusionAuth 的数据库连接池超时。通常，超时是由表锁定引起的，因此除非表中已经有大量用户，否则不会遇到任何问题。

如果您的数据库中已经有很多用户，那么您可能会遇到这样一个问题，即用户表（电子邮件和用户名）的唯一键索引无法放入 PostgreSQL 的内存中，并且正在发生到磁盘以确保新记录不违反约束。

您可能需要检查 PostgreSQL 中运行的进程和事务，以了解导致超时的原因。

如果您认为这是一个错误，请随时在 FusionAuth GitHub 问题跟踪器上打开问题并提供尽可能详细的信息。

【讨论】：

我的数据库中只有 150 个用户。无论如何，我们可以增加 fusionauth 配置中的超时时间吗？
@Venky 您可以延长连接池的默认连接超时。我会犹豫将其推荐用于生产场景，正如 Brian 提到的那样，更有可能发生其他事情导致超时发生。如果您无论如何都想弄乱它，要增加超时，请将database.connection-timeout= 添加到fusionauth.properties 文件中。我们默认为 2000 毫秒（2 秒），为了将其增加到 30 秒，例如属性将是 database.connection-timeout= 30000。
2s 的交易真的很高。用户的插入应该需要几毫秒，这意味着您应该能够每秒进行数百次插入。我的猜测是您的数据库或网络有其他原因导致超时。如果这很容易重现，您应该只运行测试，然后开始转储数据库的状态以查看发生了什么。您还可以在数据库中打开日志记录以查看可能导致问题的语句。
事件日志每次插入都会抛出此错误：html : freemarker.core.InvalidReferenceException: The following has evaluated to null or missing: ==> changePasswordId [in nameless template at line 1, column 166]
作为测试，我们为此租户 (1.8.1) 禁用了电子邮件模板。我们在创建用户后立即为用户注册应用程序，但默认为 skipRegistrationVerification。奇怪的是，报告的模板是“无名的”。当 skipRegistrationVerification 设置为 true 时，错误继续。我将打开一个 GitHub 问题。