[Connect Plc to Server] N + 1 Problem 해결 사례

 

날짜 별 로그 작업을 하던 중 로그를 확인 해보니, 한번의 API에서 회원 수 만큼
Query가 발생하고 있었습니다. 흔히 알고 있는 N+1 문제로 인식하고 해결을 하였습니다.

 

Query Log

INFO  22-12-07 13:48:39[http-nio-8080-exec-3] [sqltiming:373] - select account0_.id as id1_0_, account0_.account_roles as account_5_0_, account0_.user_id as 
user_id2_0_, account0_.user_name as user_nam3_0_, account0_.user_pw as user_pw4_0_ from account 
account0_ 
 {executed in 1 msec}
INFO  22-12-07 13:48:39[http-nio-8080-exec-3] [sqltiming:373] - select accountrol0_.id as id1_1_0_, accountrol0_.authority as authorit2_1_0_, accountrol0_.normal 
as normal3_1_0_, accountrol0_.vip as vip4_1_0_ from account_roles accountrol0_ where accountrol0_.id=1 
 {executed in 1 msec}
INFO  22-12-07 13:48:39[http-nio-8080-exec-3] [sqltiming:373] - select accountrol0_.id as id1_1_0_, accountrol0_.authority as authorit2_1_0_, accountrol0_.normal 
as normal3_1_0_, accountrol0_.vip as vip4_1_0_ from account_roles accountrol0_ where accountrol0_.id=2 
 {executed in 1 msec}
INFO  22-12-07 13:48:39[http-nio-8080-exec-3] [sqltiming:373] - select accountrol0_.id as id1_1_0_, accountrol0_.authority as authorit2_1_0_, accountrol0_.normal 
as normal3_1_0_, accountrol0_.vip as vip4_1_0_ from account_roles accountrol0_ where accountrol0_.id=3 
 {executed in 0 msec}
INFO  22-12-07 13:48:39[http-nio-8080-exec-3] [sqltiming:373] - select accountrol0_.id as id1_1_0_, accountrol0_.authority as authorit2_1_0_, accountrol0_.normal 
as normal3_1_0_, accountrol0_.vip as vip4_1_0_ from account_roles accountrol0_ where accountrol0_.id=4 
 {executed in 1 msec}
INFO  22-12-07 13:48:39[http-nio-8080-exec-3] [LogUtil:70] - 
[REQUEST] GET - /api/account/list 200 - 0.016
ClientIP : 0:0:0:0:0:0:0:1
RequestBody :  [] 
Response : {
  "timestamp" : "2022-12-07 13:48",
  "path" : "/api/account/list [GET]",
  "status" : "OK",
  "code" : 200,
  "isSuccess" : true,
  "message" : "전체 회원 목록이 조회되었습니다.",
  "responseData" : [ {} ]
}

API는 전체 회원을 조회하는 기능으로, Response에서 Entity를 그대로 반환하고 있었습니다. 항상 이러한 문제가 발생할 수 있기 때문에 DTO를 통해 반환하는 것을 알고 있었으나, 무슨 이유에서인지 Entity를 그대로 반환하고 있었습니다. 그래서 빠르게 수정을 하였습니다.

 

오류 해결

Query가 발생하고 있던 accountRoles 부분에 LAZY 전략을 적용하였습니다.
LAZY: 지연 로딩으로 Proxy객체로 가지고 있다가, accountRoles에 접근을 했을 때 Query를 실행하여 데이터를 가져옵니다.

@OneToOne(optional = false, cascade = CascadeType.ALL, fetch = FetchType.LAZY)
@JoinColumn(name = "accountRoles")
private AccountRoles accountRoles;

 

그리고 다음과 같은 DTO를 생성하여 Return 해주는 코드로 변경하였습니다.

ListAccountResponseDto.class

@Getter
@NoArgsConstructor(access = AccessLevel.PROTECTED)
public static class ListAccountResponseDto {
    private Long id;
    private String userId;
    private String userName;

    @Builder
    public ListAccountResponseDto(Long id, String userId, String userName) {
        this.id = id;
        this.userId = userId;
        this.userName = userName;
    }
}

---

AccountService.class

@Slf4j
@Service
@RequiredArgsConstructor
public class AccountService {
    public List<ListAccountResponseDto> listAccount() {
        List<ListAccountResponseDto> response = new ArrayList<>();

        List<Account> accounts = accountRepository.findAll();
        for (Account account : accounts)
            response.add(buildListAccountResponseDto(account));

        return response;
    }

    private static ListAccountResponseDto buildListAccountResponseDto(Account account) {
        return ListAccountResponseDto.builder().id(account.getId()).userId(account.getUserId()).userName(account.getUserName()).build();
    }
}

 

결과 화면

INFO  22-12-07 13:56:33[http-nio-8080-exec-2] [sqltiming:373] - select account0_.id as id1_0_, account0_.account_roles as account_5_0_, account0_.user_id as 
user_id2_0_, account0_.user_name as user_nam3_0_, account0_.user_pw as user_pw4_0_ from account 
account0_ 
 {executed in 1 msec}

Query가 다음과 같이 수정되었습니다. 현재는 회원 수가 많지 않아서 괜찮지만 몇백만명이 됬었다면 성능 이슈가 발생했을 것입니다.

 

 

마무리

다음과 같은 실수는 다시는 없어야 할 것입니다.
지금은 배포전이라서 사용자가 없지만,
사용자가 있었다면 이는 바로 성능 문제로 이어졌을 것입니다.

다음에는 이런 실수를 하지 않도록 코딩을 할 것입니다.