FusionAuth / fusionauth-issues

FusionAuth issue submission project
https://fusionauth.io
90 stars 12 forks source link

[Bug]: DB Connection not available after loading approx 6.7M users #2751

Closed mooreds closed 3 weeks ago

mooreds commented 1 month ago

What happened?

I tried to load 10M users into a FusionAuth cloud large HA deployment in 50k chunks. After about 6.7M users were loaded, I started to see the errors below:

2024-05-17 03:18:09.692 AM ERROR io.fusionauth.api.service.system.DefaultAsyncTaskManager - An exception occurred while managing an async task.
org.apache.ibatis.exceptions.PersistenceException: 
### Error querying database.  Cause: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 2000ms.
### The error may exist in io/fusionauth/api/domain/LockMapper.java (best guess)
### The error may involve io.fusionauth.api.domain.LockMapper.lock
### The error occurred while executing a query
### Cause: java.sql.SQLTransientConnectionException: HikariPool-1 - 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.selectList(DefaultSqlSession.java:156)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:147)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:142)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java:75)
    at jdk.internal.reflect.GeneratedMethodAccessor7.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
    at org.apache.ibatis.session.SqlSessionManager$SqlSessionInterceptor.invoke(SqlSessionManager.java:348)
    at jdk.proxy2/jdk.proxy2.$Proxy54.selectOne(Unknown Source)
    at org.apache.ibatis.session.SqlSessionManager.selectOne(SqlSessionManager.java:164)
    at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:87)
    at org.apache.ibatis.binding.MapperProxy$PlainMethodInvoker.invoke(MapperProxy.java:141)
    at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:86)
    at jdk.proxy2/jdk.proxy2.$Proxy71.lock(Unknown Source)
    at io.fusionauth.api.service.lock.DefaultLockService.acquireLock(DefaultLockService.java:29)
    at io.fusionauth.api.service.system.DefaultAsyncTaskManager._doRun(DefaultAsyncTaskManager.java:95)
    at org.mybatis.guice.transactional.TransactionalMethodInterceptor.invoke(TransactionalMethodInterceptor.java:100)
    at org.mybatis.guice.transactional.TransactionalMethodInterceptor.invoke(TransactionalMethodInterceptor.java:100)
    at org.mybatis.guice.transactional.TransactionalMethodInterceptor.invoke(TransactionalMethodInterceptor.java:100)
    at org.mybatis.guice.transactional.TransactionalMethodInterceptor.invoke(TransactionalMethodInterceptor.java:100)
    at io.fusionauth.api.service.system.DefaultAsyncTaskManager.run(DefaultAsyncTaskManager.java:217)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
    at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 2000ms.
    at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:696)
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:181)
    at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:146)
    at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:100)
    at org.apache.ibatis.transaction.jdbc.JdbcTransaction.openConnection(JdbcTransaction.java:145)
    at org.apache.ibatis.transaction.jdbc.JdbcTransaction.getConnection(JdbcTransaction.java:67)
    at org.apache.ibatis.executor.BaseExecutor.getConnection(BaseExecutor.java:348)
    at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:89)
    at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:64)
    at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:336)
    at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:158)
    at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:110)
    at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:90)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:154)
    ... 26 common frames omitted

Note that 10k chunks with a 2 second wait worked.

Version

1.50.1

Affects Versions

No response

robotdan commented 3 weeks ago

I don't know that this is a bug. It will always be possible to exhaust db resources which could cause FusionAuth to not be able to obtain a connection to the db.

This seems like a performance improvement request and not a bug.

mooreds commented 3 weeks ago

Fair.