Code Monkey home page Code Monkey logo

my-pay's Introduction

my-pay

my-pay's People

Contributors

f-lab-bot avatar ieunji2 avatar

Watchers

avatar

Forkers

ieunji2

my-pay's Issues

엣지 케이스 데드락 발생(송금 API) 

          머니 송금 -  /money/v1/money/send
  • case1. 사용자 A는 요청 마다 지갑1의 머니를 지갑2로 200원씩 보낸다, 사용자 B는 요청 마다 지갑2의 머니를 지갑1로 100원씩 보낸다
    • locust
      • number of users: 250
      • wait time: between(1, 5)
    • tryLock
      • wait time: 30s
      • lease time: 10s
    • 결과

      • RPS: 0.1

      • Requests: 119

      • Fails: 24

      • 84번과 93번 스레드가 경쟁 상태이다
        image
        image

        => 84번[LOCK:2, LOCK:1]과 93번[LOCK:1, LOCK:2]이 RedissonMultilock의 tryLock()으로 동시에 락 획득을 시도하는데 교착 상태가 발생한 것으로 보인다

Originally posted by @ieunji2 in #17 (comment)

트랜잭션 경계(충전, 송금 API)

my-pay/money-service/src/main/java/com/hello/money/v1/service/MoneyDistributedLockService.java

Lines 49 to 61 in 15c1ad7

@DistributedMultiLock(keys = {"#walletId", "#dto.receiverWalletId()"})
public Wallet sendMoneyWithLock(final SendMoneyServiceDto dto, final Long walletId) {
final Wallet senderWallet = getSenderWallet(dto);
senderWallet.subtractMoney(dto.amount());
final Transaction senderTransaction = getSavedTransaction(senderWallet, dto);
final Wallet receiverWallet = getReceiverWallet(dto);
receiverWallet.addMoney(dto.amount());
final Transaction receiverTransaction = getSavedTransaction(receiverWallet, dto);
try {
transactionService.executeSend(senderWallet, senderTransaction, receiverWallet, receiverTransaction);

  • getSavedTransaction() 메서드가 호출되면 트랜잭션이 커밋 되면서 executeSend() 메서드 호출 이전에 Wallet 엔티티의 업데이트 쿼리가 나간다.
  • sender와 receiver의 변경 사항을 하나의 트랜잭션으로 관리하려는 것과 맞지 않다.
  • 트랜잭션 경계 수정 시 getReceiverWallet() 메서드는 외부 서비스의 API를 호출하는 로직이 포함되어 있으므로 트랜잭션으로 묶이면 안된다.

부하 테스트 진행 및 모니터링 결과

오류 내용

머니 서비스 대상으로 부하 테스트 중 발생한 오류입니다. 크게 2가지 오류로 보입니다.

Running tasks...
:money-service:MoneyApplication.main()
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 67
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 66
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 68
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 69
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 63
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 64
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 65
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 97
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 103
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 104
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 106
org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection [HikariPool-1 - Connection is not available, request timed out after 30006ms.] [n/a]
java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30006ms.
org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection [HikariPool-1 - Connection is not available, request timed out after 30006ms.] [n/a]
java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30006ms.
org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection [HikariPool-1 - Connection is not available, request timed out after 30005ms.] [n/a]
java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30005ms.
org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection [HikariPool-1 - Connection is not available, request timed out after 30006ms.] [n/a]
java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30006ms.
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 109
org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection [HikariPool-1 - Connection is not available, request timed out after 30006ms.] [n/a]
java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30006ms.
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 111
java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 113
...

1. 락 해제 시 오류

java.util.concurrent.CompletionException: java.lang.IllegalMonitorStateException: attempt to unlock lock, not locked by current thread by node id: 6d3c8dbb-2516-4a52-a882-bd3ea1e36395 thread-id: 106
	at org.redisson.RedissonBaseLock.lambda$unlockAsync0$2(RedissonBaseLock.java:294) ~[redisson-3.24.3.jar:3.24.3]
	at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147) ~[na:na]
	at org.redisson.command.CommandBatchService.lambda$executeAsync$7(CommandBatchService.java:371) ~[redisson-3.24.3.jar:3.24.3]
	at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147) ~[na:na]
	at org.redisson.command.CommandBatchService.lambda$execute$9(CommandBatchService.java:486) ~[redisson-3.24.3.jar:3.24.3]
	at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147) ~[na:na]
	at org.redisson.command.RedisExecutor.handleSuccess(RedisExecutor.java:610) ~[redisson-3.24.3.jar:3.24.3]
	at org.redisson.command.RedisCommonBatchExecutor.handleResult(RedisCommonBatchExecutor.java:164) ~[redisson-3.24.3.jar:3.24.3]
	at org.redisson.command.RedisExecutor.checkAttemptPromise(RedisExecutor.java:568) ~[redisson-3.24.3.jar:3.24.3]
	at org.redisson.command.RedisExecutor.lambda$execute$5(RedisExecutor.java:202) ~[redisson-3.24.3.jar:3.24.3]
	at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147) ~[na:na]
	at org.redisson.client.handler.CommandDecoder.decodeCommandBatch(CommandDecoder.java:326) ~[redisson-3.24.3.jar:3.24.3]
	at org.redisson.client.handler.CommandDecoder.decodeCommand(CommandDecoder.java:217) ~[redisson-3.24.3.jar:3.24.3]
	at org.redisson.client.handler.CommandDecoder.decode(CommandDecoder.java:144) ~[redisson-3.24.3.jar:3.24.3]
	at org.redisson.client.handler.CommandDecoder.decode(CommandDecoder.java:120) ~[redisson-3.24.3.jar:3.24.3]
	at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:529) ~[netty-codec-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.handler.codec.ReplayingDecoder.callDecode(ReplayingDecoder.java:366) ~[netty-codec-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:290) ~[netty-codec-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) ~[netty-transport-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[netty-transport-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) ~[netty-transport-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) ~[netty-transport-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440) ~[netty-transport-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) ~[netty-transport-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) ~[netty-transport-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) ~[netty-transport-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788) ~[netty-transport-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724) ~[netty-transport-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650) ~[netty-transport-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562) ~[netty-transport-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) ~[netty-common-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.97.Final.jar:4.1.97.Final]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.97.Final.jar:4.1.97.Final]
	at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]

2. 데이터베이스 커넥션 획득 실패 오류

2024-01-30T13:00:23.567+09:00 DEBUG 85558 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Pool stats (total=20, active=20, idle=0, waiting=30)
2024-01-30T13:00:23.568+09:00 DEBUG 85558 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Fill pool skipped, pool has sufficient level or currently being filled (queueDepth=0).
2024-01-30T13:00:30.829+09:00 DEBUG 85558 --- [o-10000-exec-47] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Timeout failure stats (total=20, active=20, idle=0, waiting=28)
2024-01-30T13:00:30.829+09:00 DEBUG 85558 --- [o-10000-exec-48] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Timeout failure stats (total=20, active=20, idle=0, waiting=28)
2024-01-30T13:00:30.836+09:00  WARN 85558 --- [o-10000-exec-47] o.h.engine.jdbc.spi.SqlExceptionHelper   : SQL Error: 0, SQLState: null
2024-01-30T13:00:30.836+09:00 ERROR 85558 --- [o-10000-exec-47] o.h.engine.jdbc.spi.SqlExceptionHelper   : HikariPool-1 - Connection is not available, request timed out after 30006ms.
2024-01-30T13:00:30.836+09:00  WARN 85558 --- [o-10000-exec-48] o.h.engine.jdbc.spi.SqlExceptionHelper   : SQL Error: 0, SQLState: null
2024-01-30T13:00:30.836+09:00 ERROR 85558 --- [o-10000-exec-48] o.h.engine.jdbc.spi.SqlExceptionHelper   : HikariPool-1 - Connection is not available, request timed out after 30006ms.
2024-01-30T13:00:30.855+09:00 ERROR 85558 --- [o-10000-exec-48] c.h.m.c.e.GlobalExceptionHandler         : handleException

org.springframework.dao.DataAccessResourceFailureException: Unable to acquire JDBC Connection [HikariPool-1 - Connection is not available, request timed out after 30006ms.] [n/a]
	at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:253) ~[spring-orm-6.0.11.jar:6.0.11]
	at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:229) ~[spring-orm-6.0.11.jar:6.0.11]
	at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.translateExceptionIfPossible(AbstractEntityManagerFactoryBean.java:550) ~[spring-orm-6.0.11.jar:6.0.11]
	at org.springframework.dao.support.ChainedPersistenceExceptionTranslator.translateExceptionIfPossible(ChainedPersistenceExceptionTranslator.java:61) ~[spring-tx-6.0.11.jar:6.0.11]
	at org.springframework.dao.support.DataAccessUtils.translateIfNecessary(DataAccessUtils.java:242) ~[spring-tx-6.0.11.jar:6.0.11]
	at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:152) ~[spring-tx-6.0.11.jar:6.0.11]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184) ~[spring-aop-6.0.11.jar:6.0.11]
	at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:135) ~[spring-data-jpa-3.1.3.jar:3.1.3]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184) ~[spring-aop-6.0.11.jar:6.0.11]
	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97) ~[spring-aop-6.0.11.jar:6.0.11]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184) ~[spring-aop-6.0.11.jar:6.0.11]
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:244) ~[spring-aop-6.0.11.jar:6.0.11]
	at jdk.proxy2/jdk.proxy2.$Proxy161.findByAccountId(Unknown Source) ~[na:na]
	at com.hello.money.v1.repository.WalletAdapter.findWalletByAccountId(WalletAdapter.java:22) ~[main/:na]
	at com.hello.money.v1.service.MoneyServiceImpl.sendMoney(MoneyServiceImpl.java:40) ~[main/:na]
	at com.hello.money.v1.controller.MoneyController.sendMoney(MoneyController.java:39) ~[main/:na]
	at jdk.internal.reflect.GeneratedMethodAccessor45.invoke(Unknown Source) ~[na:na]
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
	at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na]
	at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205) ~[spring-web-6.0.11.jar:6.0.11]
	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:150) ~[spring-web-6.0.11.jar:6.0.11]
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:118) ~[spring-webmvc-6.0.11.jar:6.0.11]
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:884) ~[spring-webmvc-6.0.11.jar:6.0.11]
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797) ~[spring-webmvc-6.0.11.jar:6.0.11]
	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-6.0.11.jar:6.0.11]
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1081) ~[spring-webmvc-6.0.11.jar:6.0.11]
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:974) ~[spring-webmvc-6.0.11.jar:6.0.11]
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1011) ~[spring-webmvc-6.0.11.jar:6.0.11]
	at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:914) ~[spring-webmvc-6.0.11.jar:6.0.11]
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:590) ~[tomcat-embed-core-10.1.12.jar:6.0]
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885) ~[spring-webmvc-6.0.11.jar:6.0.11]
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658) ~[tomcat-embed-core-10.1.12.jar:6.0]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:205) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51) ~[tomcat-embed-websocket-10.1.12.jar:10.1.12]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-6.0.11.jar:6.0.11]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.0.11.jar:6.0.11]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-6.0.11.jar:6.0.11]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.0.11.jar:6.0.11]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.springframework.web.filter.ServerHttpObservationFilter.doFilterInternal(ServerHttpObservationFilter.java:109) ~[spring-web-6.0.11.jar:6.0.11]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.0.11.jar:6.0.11]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-6.0.11.jar:6.0.11]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.0.11.jar:6.0.11]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:166) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:482) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:115) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:341) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:391) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:894) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1740) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-10.1.12.jar:10.1.12]
	at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]
Caused by: org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection [HikariPool-1 - Connection is not available, request timed out after 30006ms.] [n/a]
	at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:49) ~[hibernate-core-6.2.7.Final.jar:6.2.7.Final]
	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:56) ~[hibernate-core-6.2.7.Final.jar:6.2.7.Final]
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:108) ~[hibernate-core-6.2.7.Final.jar:6.2.7.Final]
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:94) ~[hibernate-core-6.2.7.Final.jar:6.2.7.Final]
	at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:116) ~[hibernate-core-6.2.7.Final.jar:6.2.7.Final]

부하 테스트

부하 테스트 도구로 locust를 사용했습니다.

모니터링 환경 구축

  • spring boot에서 prometheus actuator 열기
  • prometheus docker로 띄우고 해당 app들 연동하기
  • grafana로 대시보드 살펴보기

예외 처리

Request나 Response는 보통 json으로의 serialize/deserialize이기 때문에 다른 방식으로 깔끔하게 에러처리를 할 수 있을거 같은데 한번 살펴보세요~!
Originally posted by @f-lab-justin in #6 (comment)

  • account-service
  • money-service
  • api-gateway

부하 테스트 시 데이터 불일치(충전, 송금 API) 

          머니 충전 - /money/v1/money/charge

  • case1. (트랜잭션 분리 적용 전)요청 마다 지갑 1의 잔액을 2000원씩 증가시킨다

    • locust
      • number of users: 250
      • wait time: between(1, 5)
    • tryLock
      • wait time: 30s
      • lease time: 1s
    • 결과
      • RPS: 81.6
      • Requests: 20411
      • Fails: 0
      • 기대하는 지갑 1의 잔액: 20411 * 2,000 = 40,822,000
      • DB에 저장된 지갑 1의 잔액: 30,538,000
        image
      • 80번과 91번 스레드가 경쟁 상태이다
        image

  • case2. (트랜잭션 분리 적용 후)요청 마다 지갑 1의 잔액을 2000원씩 증가시킨다

    • locust
      • number of users: 250
      • wait time: between(1, 5)
    • tryLock
      • wait time: 30s
      • lease time: 1s
    • 결과
      • RPS: 83.6
      • Requests: 30163
      • Fails: 0
      • 기대하는 지갑 1의 잔액: 30163 * 2,000 = 60,326,000
      • DB에 저장된 지갑 1의 잔액: 42,858,000
        image
      • 80번과 92번 스레드가 경쟁 상태이다
        image

  • case3. 트랜잭션 로그 살펴보기

    2024-03-01T04:05:18.036+09:00 TRACE 4982 --- [io-10000-exec-1] o.s.t.i.TransactionInterceptor           : No need to create transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findByAccountId]: This method is not transactional.
2024-03-01T04:05:18.036+09:00 TRACE 4982 --- [io-10000-exec-9] o.s.t.i.TransactionInterceptor           : No need to create transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findByAccountId]: This method is not transactional.
2024-03-01T04:05:18.037+09:00  INFO 4982 --- [io-10000-exec-9] c.h.m.config.redis.DistributedLockAop    : 85:LOCK:1 - 1. lock 생성
2024-03-01T04:05:18.037+09:00  INFO 4982 --- [io-10000-exec-9] c.h.m.config.redis.DistributedLockAop    : 85:LOCK:1 - 2. lock 획득 시도
2024-03-01T04:05:18.037+09:00  INFO 4982 --- [io-10000-exec-1] c.h.m.config.redis.DistributedLockAop    : 77:LOCK:1 - 1. lock 생성
2024-03-01T04:05:18.037+09:00  INFO 4982 --- [io-10000-exec-1] c.h.m.config.redis.DistributedLockAop    : 77:LOCK:1 - 2. lock 획득 시도
2024-03-01T04:05:18.038+09:00  INFO 4982 --- [io-10000-exec-9] c.h.m.config.redis.DistributedLockAop    : 85:LOCK:1 - 3. lock 획득 성공
2024-03-01T04:05:18.038+09:00 TRACE 4982 --- [io-10000-exec-9] o.s.t.i.TransactionInterceptor           : No need to create transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findByAccountId]: This method is not transactional.
2024-03-01T04:05:18.038+09:00  INFO 4982 --- [io-10000-exec-9] c.h.m.v.s.MoneyDistributedLockService    : 85:614000 - 충전 시작
2024-03-01T04:05:18.038+09:00 TRACE 4982 --- [io-10000-exec-9] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.039+09:00 TRACE 4982 --- [io-10000-exec-9] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.041+09:00 TRACE 4982 --- [io-10000-exec-9] o.s.t.i.TransactionInterceptor           : Getting transaction for [com.hello.money.v1.service.MoneyTransactionService.executeCharge]
2024-03-01T04:05:18.041+09:00 TRACE 4982 --- [io-10000-exec-9] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.041+09:00 TRACE 4982 --- [io-10000-exec-9] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.041+09:00 TRACE 4982 --- [io-10000-exec-9] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.041+09:00 TRACE 4982 --- [io-10000-exec-9] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.041+09:00 TRACE 4982 --- [io-10000-exec-9] o.s.t.i.TransactionInterceptor           : Completing transaction for [com.hello.money.v1.service.MoneyTransactionService.executeCharge]
2024-03-01T04:05:18.042+09:00  INFO 4982 --- [io-10000-exec-9] c.h.m.v.s.MoneyDistributedLockService    : 85:616000 - 충전 완료
2024-03-01T04:05:18.042+09:00 TRACE 4982 --- [io-10000-exec-9] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findById]
2024-03-01T04:05:18.042+09:00 TRACE 4982 --- [io-10000-exec-9] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findById]
2024-03-01T04:05:18.043+09:00  INFO 4982 --- [io-10000-exec-9] c.h.m.config.redis.DistributedLockAop    : 85:LOCK:1 - 4. lock 해제 성공
2024-03-01T04:05:18.043+09:00  INFO 4982 --- [io-10000-exec-1] c.h.m.config.redis.DistributedLockAop    : 77:LOCK:1 - 3. lock 획득 성공
2024-03-01T04:05:18.043+09:00 TRACE 4982 --- [io-10000-exec-1] o.s.t.i.TransactionInterceptor           : No need to create transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findByAccountId]: This method is not transactional.
2024-03-01T04:05:18.044+09:00  INFO 4982 --- [io-10000-exec-1] c.h.m.v.s.MoneyDistributedLockService    : 77:614000 - 충전 시작
2024-03-01T04:05:18.045+09:00 TRACE 4982 --- [io-10000-exec-1] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.046+09:00 TRACE 4982 --- [io-10000-exec-1] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.047+09:00 TRACE 4982 --- [o-10000-exec-10] o.s.t.i.TransactionInterceptor           : No need to create transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findByAccountId]: This method is not transactional.
2024-03-01T04:05:18.047+09:00 TRACE 4982 --- [io-10000-exec-1] o.s.t.i.TransactionInterceptor           : Getting transaction for [com.hello.money.v1.service.MoneyTransactionService.executeCharge]
2024-03-01T04:05:18.047+09:00 TRACE 4982 --- [io-10000-exec-1] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.047+09:00 TRACE 4982 --- [io-10000-exec-1] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.047+09:00 TRACE 4982 --- [io-10000-exec-1] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.047+09:00 TRACE 4982 --- [io-10000-exec-1] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.047+09:00 TRACE 4982 --- [io-10000-exec-1] o.s.t.i.TransactionInterceptor           : Completing transaction for [com.hello.money.v1.service.MoneyTransactionService.executeCharge]
2024-03-01T04:05:18.047+09:00  INFO 4982 --- [o-10000-exec-10] c.h.m.config.redis.DistributedLockAop    : 86:LOCK:1 - 1. lock 생성
2024-03-01T04:05:18.047+09:00  INFO 4982 --- [o-10000-exec-10] c.h.m.config.redis.DistributedLockAop    : 86:LOCK:1 - 2. lock 획득 시도
2024-03-01T04:05:18.048+09:00  INFO 4982 --- [io-10000-exec-1] c.h.m.v.s.MoneyDistributedLockService    : 77:616000 - 충전 완료
2024-03-01T04:05:18.049+09:00 TRACE 4982 --- [io-10000-exec-1] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findById]
2024-03-01T04:05:18.049+09:00 TRACE 4982 --- [io-10000-exec-1] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findById]
2024-03-01T04:05:18.049+09:00  INFO 4982 --- [io-10000-exec-1] c.h.m.config.redis.DistributedLockAop    : 77:LOCK:1 - 4. lock 해제 성공
2024-03-01T04:05:18.050+09:00  INFO 4982 --- [o-10000-exec-10] c.h.m.config.redis.DistributedLockAop    : 86:LOCK:1 - 3. lock 획득 성공
2024-03-01T04:05:18.050+09:00 TRACE 4982 --- [o-10000-exec-10] o.s.t.i.TransactionInterceptor           : No need to create transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findByAccountId]: This method is not transactional.
2024-03-01T04:05:18.051+09:00  INFO 4982 --- [o-10000-exec-10] c.h.m.v.s.MoneyDistributedLockService    : 86:616000 - 충전 시작
2024-03-01T04:05:18.051+09:00 TRACE 4982 --- [o-10000-exec-10] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.052+09:00 TRACE 4982 --- [o-10000-exec-10] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.053+09:00 TRACE 4982 --- [o-10000-exec-10] o.s.t.i.TransactionInterceptor           : Getting transaction for [com.hello.money.v1.service.MoneyTransactionService.executeCharge]
2024-03-01T04:05:18.053+09:00 TRACE 4982 --- [o-10000-exec-10] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.053+09:00 TRACE 4982 --- [o-10000-exec-10] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.053+09:00 TRACE 4982 --- [o-10000-exec-10] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.053+09:00 TRACE 4982 --- [o-10000-exec-10] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.save]
2024-03-01T04:05:18.053+09:00 TRACE 4982 --- [o-10000-exec-10] o.s.t.i.TransactionInterceptor           : Completing transaction for [com.hello.money.v1.service.MoneyTransactionService.executeCharge]
2024-03-01T04:05:18.054+09:00  INFO 4982 --- [o-10000-exec-10] c.h.m.v.s.MoneyDistributedLockService    : 86:618000 - 충전 완료
2024-03-01T04:05:18.054+09:00 TRACE 4982 --- [o-10000-exec-10] o.s.t.i.TransactionInterceptor           : Getting transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findById]
2024-03-01T04:05:18.054+09:00 TRACE 4982 --- [o-10000-exec-10] o.s.t.i.TransactionInterceptor           : Completing transaction for [org.springframework.data.jpa.repository.support.SimpleJpaRepository.findById]
2024-03-01T04:05:18.055+09:00  INFO 4982 --- [o-10000-exec-10] c.h.m.config.redis.DistributedLockAop    : 86:LOCK:1 - 4. lock 해제 성공
    • 결과

      • 85번, 77번 동시에 들어옴

        77 - findByAccountId 지갑 조회
        85 - findByAccountId 지갑 조회
        85 - 1. lock 생성
        85 - 2. lock 획득 시도
        77 - 1. lock 생성
        77 - 2. lock 획득 시도
        85 - 3. lock 획득 성공
        85 - findByAccountId 지갑조회
        85 - 충전 시작 - 614000
        85 - 충전 완료 - 616000
        85 - 4. lock 해제 성공
        77 - 3. lock 획득성공
        77 - findByAccountId 지갑조회
        77 - 충전 시작 - 614000
        86 - findByAccountId 지갑조회
        86 - 1. lock 생성
        86 - 2. lock 획득 시도
        77 - 충전 완료 - 616000
        77 - 4. lock 해제 성공
        86 - 3. lock 획득 성공
        86 - findByAccountId 지갑조회
        86 - 충전 시작 - 616000
        86 - 충전 완료 - 618000
        86 - 4. lock 해제 성공

        => 락의 키로 walletId를 사용하기 위해 MoneyServiceImpl.java에서 findByAccountId()로 지갑 조회를 먼저 한 번 하는데, 락 획득 이후에 잔액을 가져오기 위해 다시 지갑 조회를 하면 다른 스레드에서 DB에 커밋한 값이 아닌 기존에 조회한 값을 가져오는 것으로 보임

Originally posted by @ieunji2 in #17 (comment)

money-service 기능 구현

  • 내 지갑 생성하기

    • 계정 당 한 개의 지갑만 생성 가능하다.

  • 내 지갑 확인하기

    • 인증 필터를 거쳐 헤더에 셋팅 된 계정 아이디로 지갑 정보를 조회한다.

  • 내 지갑에 머니 충전하기

    • 인증된 계정 정보로 입금할 수 있다.
      • 1. 내 지갑 확인
      • 2. transactions 생성 - transaction_status(요청)
      • 3. 잔액 업데이트
      • 4. transactions 업데이트 - transaction_status(완료/실패)

  • 송금하기

    • 인증된 계정 정보로 송금할 수 있다.
      • 1. 내 지갑 및 잔액 확인
      • 2. 받는 사람 지갑 확인
      • 3. 받는 사람 계정 확인
      • 4. transactions 생성 - transaction_status(요청)
      • 5. 내 잔액 업데이트
      • 6. 받는 사람 잔액 업데이트
      • 7. transactions 업데이트 - transaction_status(완료/실패)

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.