회원가입 API 개선하기

Minky·2023년 2월 14일

현재 운영중인 서비스에서, 회원가입시 api 속도가 느려 timeout이 발생하여 회원가입 프로세스가 정상적으로 진행되지 않은 이슈가 발생했다.
마케팅 효과로 클라이언트 인입이 증가함에 따라 뒤늦게라도 발견한 이슈를 개선한 내용을 기록한다.

문제

회원가입 하면서 팀과 멤버 생성 프로세스가 진행되는데, 이때 연속적으로 물리는 데이터들이 많다.
예를 들면, 팀 이나 멤버 생성시 기본적으로 필요한 세팅들 (팀에서 관리할 시간, 역할, 등.. 연관된 테이블이 굉장히 많음)이 존재한다.
이 생명주기가 맞물리는 스키마들을 저장하면서 최적화된 쿼리가 아닌 불필요한 수많은 쿼리들이 날라가게 되면서 속도가 현저하게 느려지고 결국 타임아웃까지 나버리는 상황이었다.
테스트 서버에서 테스트시에는 아예 타임아웃이 나고 .. 운영에서도 27초 정도의 시간이 걸렸다.

원인

불필요한 쿼리 발생

팀 생성시 역할/권한 관련 설정에서 발생되는 쿼리중, 해당 팀에 대한 insert만 발생되어야 하는데 아래의 로그처럼 기존의 데이터들이 모두 delete 되고 전체 재 insert가 나가고 있었다.
(이때 발생되는 쿼리는 대략 40~50개의 로우 x 전체 팀 수 만큼 발생함)

    delete
    from
        `역할/권한 매핑 테이블`
    where
        `권한_id`=?
[2023-02-13 23:25:52.936] [http-nio-8080-exec-1] TRACE o.h.type.descriptor.sql.BasicBinder@bind(65) - binding parameter [1] as [BIGINT] - [13]
[2023-02-13 23:25:52.961] [http-nio-8080-exec-1] DEBUG org.hibernate.SQL@logStatement(94) -
    insert
    into
        `역할/권한 매핑 테이블` (
            `권한_id`, `역할_id`
        )
    values
        (?, ?)
[2023-02-13 23:25:52.962] [http-nio-8080-exec-1] TRACE o.h.type.descriptor.sql.BasicBinder@bind(65) - binding parameter [1] as [BIGINT] - [13]
[2023-02-13 23:25:52.962] [http-nio-8080-exec-1] TRACE o.h.type.descriptor.sql.BasicBinder@bind(65) - binding parameter [2] as [BIGINT] - [3923]
[2023-02-13 23:25:52.962] [http-nio-8080-exec-1] DEBUG org.hibernate.SQL@logStatement(94) -
    insert
    into
        `역할/권한 매핑 테이블` (
            `권한_id`, `역할_id`
        )
    values
        (?, ?)
[2023-02-13 23:25:52.962] [http-nio-8080-exec-1] TRACE o.h.type.descriptor.sql.BasicBinder@bind(65) - binding parameter [1] as [BIGINT] - [13]
[2023-02-13 23:25:52.962] [http-nio-8080-exec-1] TRACE o.h.type.descriptor.sql.BasicBinder@bind(65) - binding parameter [2] as [BIGINT] - [3924]
[2023-02-13 23:25:52.962] [http-nio-8080-exec-1] DEBUG org.hibernate.SQL@logStatement(94) -
    insert
    into
        `역할/권한 매핑 테이블` (
            `권한_id`, `역할_id`
        )
    values
        (?, ?)

select 해오는 쿼리도 단건으로 발생 (n+1)

    select
        .....
    from
        `역할/권한 매핑 테이블` a
    inner join
        `역할` b
            on a.`역할_id`=b.`id`
            and (
                display_status = 'SHOW'
            )
    where
        권한.id =?
[2023-02-13 23:41:19.242] [http-nio-8080-exec-3] TRACE o.h.type.descriptor.sql.BasicBinder@bind(65) - binding parameter [1] as [BIGINT] - [19]
[2023-02-13 23:41:19.282] [http-nio-8080-exec-3] DEBUG org.hibernate.SQL@logStatement(94) -
    select
        .....
    from
        `역할/권한 매핑 테이블` a
    inner join
        `역할` b
            on a.`역할_id`=b.`id`
            and (
                display_status = 'SHOW'
            )
    where
        권한.id =?
[2023-02-13 23:41:19.283] [http-nio-8080-exec-3] TRACE o.h.type.descriptor.sql.BasicBinder@bind(65) - binding parameter [1] as [BIGINT] - [20]
[2023-02-13 23:41:19.323] [http-nio-8080-exec-3] DEBUG org.hibernate.SQL@logStatement(94) -
    select
        .....
    from
        `역할/권한 매핑 테이블` a
    inner join
        `역할` b
            on a.`역할_id`=b.`id`
            and (
                display_status = 'SHOW'
            )
    where
        권한.id =?
[2023-02-13 23:41:19.323] [http-nio-8080-exec-3] TRACE o.h.type.descriptor.sql.BasicBinder@bind(65) - binding parameter [1] as [BIGINT] - [21]
[2023-02-13 23:41:19.358] [http-nio-8080-exec-3] DEBUG org.hibernate.SQL@logStatement(94) -
    select
        .....
    from
        `역할/권한 매핑 테이블` a
    inner join
        `역할` b
            on a.`역할_id`=b.`id`
            and (
                display_status = 'SHOW'
            )
    where
        권한.id =?
[2023-02-13 23:41:19.359] [http-nio-8080-exec-3] TRACE o.h.type.descriptor.sql.BasicBinder@bind(65) - binding parameter [1] as [BIGINT] - [22]
[2023-02-13 23:41:19.392] [http-nio-8080-exec-3] DEBUG org.hibernate.SQL@logStatement(94) -
    select
        .....
    from
        `역할/권한 매핑 테이블` a
    inner join
        `역할` b
            on a.`역할_id`=b.`id`
            and (
                display_status = 'SHOW'
            )
    where
        권한.id =?

1,2 번의 과정을 거치고 최종적으로 insert 역시 단건으로 발생
(로그 이하 생략)

이렇게 각 세팅마다 1,2,3번의 과정이 반복되면서 미친듯한 쿼리 발생과 , 그로 인한 api 속도 지연이 발생되는 원인이 되었다.

해결

1. @ManyToMany의 연관관계 컬렉션을 List > Set으로 변경

    @ManyToMany(mappedBy = "역할엔티티", cascade = CascadeType.ALL)
    private List<권한> 권한 = Lists.newArrayList();

연관된 모든 데이터들이 delete되고 재 insert되는것이 이상하여 엔티티 관계부터 살펴보던중, 다른 엔티티들과 다르게 @ManyToMany에서 List 타입으로 지정하여 관계를 맺고 있었다.

관련해서 찾아보니,
JPA에서 보통 컬렉션 type에 대해서는 list를 주로 사용하는데, (Set의 특징상 중복이 안된다는것은, 결국 중복 제거를 위해 중복 비교가 필요하고.. 이때 컬렉션에 값을 넣게 되면 지연로딩으로 컬렉션을 가져와도 강제로 초기화 되는 문제가 발생하기때문에 성능상 list를 쓴다고 한다.)

하이버네이트는 @ManyToMany에서는 저장시에, 기존에 저장되어있던 (모든관계)를 삭제하고 다시 기존 데이터 및 신규 데이터를 생성한다고한다.

현재 발생하던 이슈와 동일했고, Set으로 변경하자마자 delete와 전부다 다시 insert 시키는 쿼리가 사라졌다!

2. default_batch_fetch_size 옵션 주기

hibernate.default_batch_fetch_size: 100

JPA를 사용하면서 늘 직면할 수 있는 N+1 개선 방법 중 하나인 옵션이다.
하위 엔티티를 로딩할때 size 지정한 숫자만큼 in query로 해주는 옵션이다.
쉽게 말해 .. select 쿼리를 지정한 사이즈만큼 모일때까지 두었다 한방에 날리는 옵션? 이다.
어쩐지 다른 프로젝트에선 이미 잘 사용중인 옵션이였는데, 해당 프로젝트에서는 주석처리가 되어있었다.
(근데 히스토리를 보니 그 범인도 나였다..3년전의 나..)

해당옵션으로 1개씩 날라가는 select 역시 30%이상의 쿼리 발생을 줄였다.

3. jdbcTemplate를 이용하여 bulk insert 하기

현재 엔티티 생성전략은 IDENTITY인 관계로

    @Id
    @Column(nullable = false)
    @GeneratedValue(strategy = GenerationType.IDENTITY)
    private Long id;

JPA batch insert가 의도대로 동작되지 않는다.
따라서 jdbcTemplate bulk insert를 활용하여 단건 insert되는 방식을 변경했다.

        jdbcTemplate.batchUpdate(sql, new BatchPreparedStatementSetter() {
            @Override
            public void setValues(PreparedStatement ps, int i) throws SQLException {
                ps.setLong(1, a...);
                ps.setLong(2, b...);
           }