Spring Data Jpa에서 데이터베이스별 lock timeout 설정 테스트

특정 업무의 동시성 이슈를 해결하기 위해서 비관적 락(Pessimistic Lock)을 사용하여 select for update로 조회를 하는 경우가 있다.

이는 여러 쓰레드의 경합이 발생하는 경우에 DB 차원에서 단일 쓰레드에 락을 거는 방법이다.

spring data jpa에서 비관적 락을 사용하려면 아래와 같이 @Lock을 추가하면 된다.

@Lock(LockModeType.PESSIMISTIC_WRITE)
ProductJpo findProductJpoById(long id);

이렇게 추가되면 실행되는 SQL에 for update가 붙어서 실행된다.

SELECT * FROM product_jpo WHERE id = 1 FOR UPDATE

이런 경우에, 2개의 쓰레드가 동시에 요청을 하면 첫 번째 락을 획득한 쓰레드가 실행이 되고 두 번째 요청한 쓰레드는 첫 번째 쓰레드의 실행이 완료되기 전까지는 대기상태가 되고 첫 번째 실행이 종료되고 나서 실행이 된다.

하지만 두 번째 실행되는 쓰레드가 무한정 기다릴 수 없으니 대기 시간을 따로 설정을 할 수도 있다. 대기 시간 설정을 위해 아래와 같이 QueryHint를 주면 된다.

@Lock(LockModeType.PESSIMISTIC_WRITE)
@QueryHints({
    @QueryHint(name = "javax.persistence.lock.timeout", value = "2000")
})
ProductJpo findProductJpoById(long id);

위의 경우는 2초 동안 대기 후에 락을 획득하지 못하면 LockTimeoutException이 발생하도록 하는 것이다.

javax.persistence.lock.timeout 이 트랜잭션의 최대 실행시간이 아니다. Lock이 걸린 데이터에 다른 쓰레드가 진입할 때의 대기 시간임을 알아야 한다. 두 번째 쓰레드가 락을 얻기 위해 대기하는 최대 시간이다.

이 설정이 여러 가지 DB에서 정상적으로 동작하는 지 궁금점이 생겨서 테스트 해보았다.

1. H2
2. mysql (8.x)
3. oracle (11)
4. postgresql

테스트 시나리오

• 특정 상품을 수정하는 api
• 특정 상품을 수정하는 시간은 5초가 걸린다.
• 두 개의 쓰레드가 동시에 수정을 실행한다.
• 두 번째 실행되는 쓰레드가 LockTimeoutException이 발생하는 지 확인

소스

서비스 메소드

// 수정 메소드
@Transactional
public long update(long id) {
    Product product = findForUpdate(id); // select for update
    product.buy();

    sleep(5000); // 5초간 대기

    productRepository.save(new ProductJpo(product));

    return product.getStock();
}

Repository

@Lock(LockModeType.PESSIMISTIC_WRITE) 으로 비관적 락 어노테이션 추가

@Repository
public interface ProductRepository extends JpaRepository<ProductJpo, Long> {

    @Lock(LockModeType.PESSIMISTIC_WRITE)
    ProductJpo findProductJpoById(long id);
}

테스트 코드

@SpringBootTest
public class LockTimeoutTest {

    private static final ExecutorService executorService = Executors.newFixedThreadPool(2);

    @Autowired
    private ProductService productService;

    @BeforeEach
    public void prepare() {
        productService.register(new Product(1, "아이패드", 100));
    }

    @Test
    public void lockTimeoutTest() throws InterruptedException {
        int threadCount = 2;
        ExecutorService executorService = Executors.newFixedThreadPool(threadCount);

        CountDownLatch latch = new CountDownLatch(threadCount);
        for (int i=0; i < threadCount; i++) {
            executorService.execute(() -> {
                productService.update(1);
                latch.countDown();
            });
        }
        latch.await();
    }
}

2개의 쓰레드로 상품을 동시에 수정하도록 실행한다.

실행방법

실행은 기본 케이스와 lock timeout 케이스 두 가지로 실행한다.

• 기본 케이스

  • @Lock(LockModeType.PESSIMISTIC_WRITE)
    ProductJpo findProductJpoById(long id);

• lock timeout 케이스 (2초)

  • @Lock(LockModeType.PESSIMISTIC_WRITE)
    @QueryHints({
        @QueryHint(name = "javax.persistence.lock.timeout", value = "2000") // 2초간 대기
    })
    ProductJpo findProductJpoById(long id);

1. H2 테스트

application.yml

spring:
  datasource:
    url: jdbc:h2:~/jpa-lock-timeout-test-app;AUTO_SERVER=TRUE;
    username: sa
    password:
    driverClassName: org.h2.Driver

기본 케이스 실행

2023-09-08 08:31:18.088 DEBUG 16721 --- [pool-2-thread-2] org.hibernate.SQL                        : select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update
2023-09-08 08:31:18.088 DEBUG 16721 --- [pool-2-thread-1] org.hibernate.SQL                        : select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update
2023-09-08 08:31:22.095  WARN 16721 --- [pool-2-thread-1] com.zaxxer.hikari.pool.ProxyConnection   : HikariPool-1 - Connection conn2: url=jdbc:h2:~/jpa-lock-timeout-test-app user=SA marked as broken because of SQLSTATE(HYT00), ErrorCode(50200)

org.h2.jdbc.JdbcSQLTimeoutException: Timeout trying to lock table {0}; SQL statement:
select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update [50200-214]
    at org.h2.message.DbException.getJdbcSQLException(DbException.java:560) ~[h2-2.1.214.jar:2.1.214]
    at org.h2.message.DbException.getJdbcSQLException(DbException.java:477) ~[h2-2.1.214.jar:2.1.214]
....

2023-09-08 08:31:23.100 DEBUG 16721 --- [pool-2-thread-2] org.hibernate.SQL                        : update product_jpo set name=?, stock=? where id=?

결과: 실패

두 번째 쓰레드가 대기해야 하는데, 2초 후에 LockTimeoutException이 발생했다.

H2에서는 lock.timeout 기본값이 2초로 설정되어 있음

lock timeout 케이스 실행: 2초로 설정

결과: 비정상 (X) - lock timeout이 발생하지 않음

먼저 실행된 쓰레드는 정상적으로 실행이 되고 두 번째 실행된 쓰레드는 아래의 오류를 발생한다.

org.h2.jdbc.JdbcSQLTimeoutException: Timeout trying to lock table {0}; SQL statement:
select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update [50200-214]
    at org.h2.message.DbException.getJdbcSQLException(DbException.java:560) ~[h2-2.1.214.jar:2.1.214]
    at org.h2.message.DbException.getJdbcSQLException(DbException.java:477) ~[h2-2.1.214.jar:2.1.214]

정상적으로 실행된 것으로 보이겠지만, 실제로는 제대로 동작하지 않은 것이다.

시간을 10초로 변경하고 실행해보자.

@QueryHint(name = "javax.persistence.lock.timeout", value = "10000")

그래도 동일하게 2초 후에 LockTimeoutException이 발생한다.

H2에서 lock time이 QueryHint로 동작하지 않고 url에 파라미터에 LOCK_TIMEOUT으로 설정으로 사용해야 한다.

아래는 lock.timeout을 2초로 설정

url: jdbc:h2:~/jpa-lock-timeout-test-app;AUTO_SERVER=TRUE;LOCK_TIMEOUT=10000;

위와 같이 LOCK_TIMEOUT=10000을 넣고 실행하니 정상적으로 잘 실행이 된다.

2. mysql 테스트

기본 케이스 실행

결과: 정상

2023-09-07 16:02:42.968 DEBUG 99369 --- [pool-2-thread-2] org.hibernate.SQL                        : select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update
2023-09-07 16:02:42.968 DEBUG 99369 --- [pool-2-thread-1] org.hibernate.SQL                        : select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update
2023-09-07 16:02:47.977 DEBUG 99369 --- [pool-2-thread-1] org.hibernate.SQL                        : update product_jpo set name=?, stock=? where id=?
2023-09-07 16:02:53.001 DEBUG 99369 --- [pool-2-thread-2] org.hibernate.SQL                        : update product_jpo set name=?, stock=? where id=?

순차대로 실행이 된다. (두 번째 쓰레드 대기 후 실행)

lock timeout 케이스 실행: 2초로 설정

결과: 비정상 (X) - lock timeout이 발생하지 않음

2023-09-07 16:03:18.407 DEBUG 99521 --- [pool-2-thread-2] org.hibernate.SQL                        : select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update
2023-09-07 16:03:18.407 DEBUG 99521 --- [pool-2-thread-1] org.hibernate.SQL                        : select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update
2023-09-07 16:03:23.419 DEBUG 99521 --- [pool-2-thread-1] org.hibernate.SQL                        : update product_jpo set name=?, stock=? where id=?
2023-09-07 16:03:28.444 DEBUG 99521 --- [pool-2-thread-2] org.hibernate.SQL                        : update product_jpo set name=?, stock=? where id=?

lock timeout을 설정해도 [기본]과 동일하게 실행이 된다. 즉 timeout이 발생하지 않는다는 것이다.

찾아보니 mysql의 경우 lock의 시간설정이 global 영역에 정의된 값으로 timeout이 실행되고 쿼리별로는 안되는 듯 하다. (기본: 50초)

select @@global.innodb_lock_wait_timeout;

+-----------------------------------+
| @@global.innodb_lock_wait_timeout |
+-----------------------------------+
|                                50 |
+-----------------------------------+
1 row in set (0.00 sec)

mysql 8.0에서는 기본, skip locked, nowait의 3가지 유형의 lock을 지원하는 듯 하다.

• 기본: innodb_lock_wait_timeout 시간만큼 대기
• skip locked: lock이 걸린 row에 대해 skip하고 읽음
• nowait: 대기하지 않음

특정 쿼리에 대한 timeout을 설정하는 값은 없는 듯 하다.

3. oracle 테스트

기본 케이스 실행

결과: 정상

2023-09-07 16:05:18.299 DEBUG 99570 --- [pool-2-thread-1] org.hibernate.SQL                        : select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update
2023-09-07 16:05:18.299 DEBUG 99570 --- [pool-2-thread-2] org.hibernate.SQL                        : select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update
2023-09-07 16:05:23.308 DEBUG 99570 --- [pool-2-thread-2] org.hibernate.SQL                        : update product_jpo set name=?, stock=? where id=?
2023-09-07 16:05:28.323 DEBUG 99570 --- [pool-2-thread-1] org.hibernate.SQL                        : update product_jpo set name=?, stock=? where id=?

순차대로 실행이 된다.

lock timeout 케이스 실행: 2초로 설정

결과: 정상

2023-09-07 16:04:01.145 DEBUG 99535 --- [pool-2-thread-2] org.hibernate.SQL                        : select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update wait 2
2023-09-07 16:04:01.145 DEBUG 99535 --- [pool-2-thread-1] org.hibernate.SQL                        : select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update wait 2
2023-09-07 16:04:03.176  WARN 99535 --- [pool-2-thread-1] o.h.engine.jdbc.spi.SqlExceptionHelper   : SQL Error: 30006, SQLState: 99999
2023-09-07 16:04:03.176 ERROR 99535 --- [pool-2-thread-1] o.h.engine.jdbc.spi.SqlExceptionHelper   : ORA-30006: 리소스 사용 중. WAIT 시간 초과로 획득이 만료됨
Exception in thread "pool-2-thread-1" org.springframework.dao.CannotAcquireLockException: could not extract ResultSet; SQL [n/a]; nested exception is org.hibernate.exception.LockTimeoutException: could not extract ResultSet
...

2023-09-07 16:04:06.175 DEBUG 99535 --- [pool-2-thread-2] org.hibernate.SQL                        : update product_jpo set name=?, stock=? where id=?

예상한 대로 2초 후에 LockTimeoutException이 발생한다.

023-09-07 14:57:52.789 ERROR 96813 --- [pool-2-thread-1] o.h.engine.jdbc.spi.SqlExceptionHelper   : ORA-30006: 리소스 사용 중. WAIT 시간 초과로 획득이 만료됨

Exception in thread "pool-2-thread-1" org.springframework.dao.CannotAcquireLockException: could not extract ResultSet; SQL [n/a]; nested exception is org.hibernate.exception.LockTimeoutException: could not extract ResultSet
    at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:267)

실행되는 쿼리를 보면 wait 2 (2초)가 붙어서 실행되는 것을 알 수 있다.

select * for update wait 2

4. postgresql 테스트

기본 케이스 실행

결과: 정상

순차대로 실행이 된다.

2023-09-07 16:06:11.961 DEBUG 99602 --- [pool-2-thread-1] org.hibernate.SQL                        : select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update of productjpo0_
2023-09-07 16:06:11.961 DEBUG 99602 --- [pool-2-thread-2] org.hibernate.SQL                        : select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update of productjpo0_
2023-09-07 16:06:16.978 DEBUG 99602 --- [pool-2-thread-2] org.hibernate.SQL                        : update product_jpo set name=?, stock=? where id=?
2023-09-07 16:06:21.998 DEBUG 99602 --- [pool-2-thread-1] org.hibernate.SQL                        : update product_jpo set name=?, stock=? where id=?

lock timeout 케이스 실행: 2초로 설정

결과: 비정상 (X) - lock timeout이 발생하지 않음

2023-09-07 16:06:40.161 DEBUG 99615 --- [pool-2-thread-1] org.hibernate.SQL                        : select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update of productjpo0_
2023-09-07 16:06:40.161 DEBUG 99615 --- [pool-2-thread-2] org.hibernate.SQL                        : select productjpo0_.id as id1_0_, productjpo0_.name as name2_0_, productjpo0_.stock as stock3_0_ from product_jpo productjpo0_ where productjpo0_.id=? for update of productjpo0_
2023-09-07 16:06:45.177 DEBUG 99615 --- [pool-2-thread-2] org.hibernate.SQL                        : update product_jpo set name=?, stock=? where id=?
2023-09-07 16:06:50.192 DEBUG 99615 --- [pool-2-thread-1] org.hibernate.SQL                        : update product_jpo set name=?, stock=? where id=?

설정이 적용되지 않는다.

postgresql도 select for update wait x로 시간을 설정하지 않고 SET LOCAL lock_timeout = '3s';로 lock 시간을 설정하는 것으로 보여 hibernate에서 아직 postgresql용 lock timeout이 아직 지원하지 않는 듯 하다.

결론

Lock timeout을 위해 QueryHint로 javax.persistence.lock.timeout 설정을 하는 경우 동작 여부는 아래와 같다.

• H2 : 비정상 (lock timeout이 발생하지 않음)
• Mysql: 비정상 (lock timeout이 발생하지 않음)
• Oracle: 정상
• Postgresql: 비정상 (lock timeout이 발생하지 않음)

DBMS 별 lock timeout 설정 방법

DBMS별 lock timeout 설정 방법

[h2]

url: jdbc:h2:~/jpa-lock-timeout-test-app;AUTO_SERVER=TRUE;LOCK_TIMEOUT=3000;

// lock 확인
select lock_timeout(); // 기본 2초

[oracle]

select … for update wait 3;

[mysql]

select @@global.innodb_lock_wait_timeout;

+-----------------------------------+
| @@global.innodb_lock_wait_timeout |
+-----------------------------------+
|                                50 |
+-----------------------------------+
1 row in set (0.00 sec)

> SET innodb_lock_wait_timeout = 10000; // 10로 설정

[postgresql]

SET LOCAL lock_timeout = '3s';