N + 1 문제 원인

정말 많이 접하는 문제입니다. 왜 발생하고 처리하는 방법은 뭐가 있는지 정리하려 합니다.

우선 왜 이런 문제가 생기는지 정리합니다. 언제나 문제는 원인부터 알아야 올바르게 대처하니까요.

 

포스트(Post)와 댓글(Comment)와의 관계를 예로 작성해 보았습니다.

@Getter@Setter
@AllArgsConstructor(access = AccessLevel.PROTECTED)
@NoArgsConstructor
@Entity
@ToString
public class Post {

    @Id
    @GeneratedValue
    private Long id;

    private String title;

    @OneToMany(mappedBy = "post", cascade = CascadeType.ALL)
    private List<Comment> comments = new ArrayList<>();

}

@Setter@Getter
@AllArgsConstructor(access = AccessLevel.PROTECTED)
@NoArgsConstructor
@Entity
@ToString(exclude = "post")
public class Comment {

    @Id
    @GeneratedValue
    private Long id;

    private String comment;

    @ManyToOne
    private Post post;
}

public interface PostRepository extends JpaRepository<Post, Long> {
}

public interface CommentRepository extends JpaRepository<Comment, Long> {
}

@Slf4j
@Service
public class PostService {

    private final PostRepository postRepository;

    public PostService(PostRepository postRepository) {
        this.postRepository = postRepository;
    }

    @Transactional(readOnly = true)
    public List<String> findAllComments() {
        return getAllComments(postRepository.findAll());
    }

    /**
     * Lazy Load를 실행하기 위해 모든 comment 순회
     */
    private List<String> getAllComments(List<Post> posts) {
        return posts.stream()
                .map(a -> a.getComments().toString())
                .collect(Collectors.toList());
    }
}

 

test code는 junit5을 사용하였습니다.

@SpringBootTest
class PostRepositoryTest {

    @Autowired
    private PostService postService;
    @Autowired
    private PostRepository postRepository;

    @BeforeEach
    public void setup() {
        Post post = new Post();
        post.setTitle("첫 포스트");

        Comment comment1 = new Comment();
        comment1.setComment("첫 댓글~! ");
        comment1.setPost(post);
        post.getComments().add(comment1);

        Comment comment2 = new Comment();
        comment2.setComment("두번째야~");
        post.getComments().add(comment2);
        comment2.setPost(post);

        Post post2 = new Post();
        post2.setTitle("내가 2등~");

        Comment comment3 = new Comment();
        comment3.setComment("좋아요~");
        comment3.setPost(post2);
        post2.getComments().add(comment3);

        Comment comment4 = new Comment();
        comment4.setComment("감사합니다.");
        comment4.setPost(post2);
        post2.getComments().add(comment4);

        Comment comment5 = new Comment();
        comment5.setComment("다음글 기대할께요.");
        comment5.setPost(post2);
        post2.getComments().add(comment5);

        postRepository.save(post);
        postRepository.save(post2);
    }

    @Test
    void testNPlusOne() {
        System.out.println(postService.findAllComments());
    }

Hibernate: 
    select
        post0_.id as id1_3_,
        post0_.title as title2_3_ 
    from
        post post0_
2020-06-05 11:50:15.206 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([id1_3_] : [BIGINT]) - [1]
2020-06-05 11:50:15.210 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([title2_3_] : [VARCHAR]) - [첫 포스트]
2020-06-05 11:50:15.211 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([id1_3_] : [BIGINT]) - [4]
2020-06-05 11:50:15.211 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([title2_3_] : [VARCHAR]) - [내가 2등~]
2020-06-05 11:50:15.218 TRACE 4256 --- [    Test worker] org.hibernate.type.CollectionType        : Created collection wrapper: [com.icatapark.jpa.post.entity.Post.comments#1]
2020-06-05 11:50:15.219 TRACE 4256 --- [    Test worker] org.hibernate.type.CollectionType        : Created collection wrapper: [com.icatapark.jpa.post.entity.Post.comments#4]
Hibernate: 
    select
        comments0_.post_id as post_id3_2_0_,
        comments0_.id as id1_2_0_,
        comments0_.id as id1_2_1_,
        comments0_.comment as comment2_2_1_,
        comments0_.post_id as post_id3_2_1_ 
    from
        comment comments0_ 
    where
        comments0_.post_id=?
2020-06-05 11:50:15.228 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [BIGINT] - [1]
2020-06-05 11:50:15.239 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([id1_2_1_] : [BIGINT]) - [2]
2020-06-05 11:50:15.240 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([comment2_2_1_] : [VARCHAR]) - [첫 댓글~! ]
2020-06-05 11:50:15.240 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([post_id3_2_1_] : [BIGINT]) - [1]
2020-06-05 11:50:15.242 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([post_id3_2_0_] : [BIGINT]) - [1]
2020-06-05 11:50:15.242 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([id1_2_0_] : [BIGINT]) - [2]
2020-06-05 11:50:15.250 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([id1_2_1_] : [BIGINT]) - [3]
2020-06-05 11:50:15.250 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([comment2_2_1_] : [VARCHAR]) - [두번째야~]
2020-06-05 11:50:15.250 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([post_id3_2_1_] : [BIGINT]) - [1]
2020-06-05 11:50:15.251 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([post_id3_2_0_] : [BIGINT]) - [1]
2020-06-05 11:50:15.251 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([id1_2_0_] : [BIGINT]) - [3]
Hibernate: 
    select
        comments0_.post_id as post_id3_2_0_,
        comments0_.id as id1_2_0_,
        comments0_.id as id1_2_1_,
        comments0_.comment as comment2_2_1_,
        comments0_.post_id as post_id3_2_1_ 
    from
        comment comments0_ 
    where
        comments0_.post_id=?
2020-06-05 11:50:15.264 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicBinder      : binding parameter [1] as [BIGINT] - [4]
2020-06-05 11:50:15.266 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([id1_2_1_] : [BIGINT]) - [5]
2020-06-05 11:50:15.267 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([comment2_2_1_] : [VARCHAR]) - [다음글 기대할께요.]
2020-06-05 11:50:15.267 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([post_id3_2_1_] : [BIGINT]) - [4]
2020-06-05 11:50:15.268 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([post_id3_2_0_] : [BIGINT]) - [4]
2020-06-05 11:50:15.268 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([id1_2_0_] : [BIGINT]) - [5]
2020-06-05 11:50:15.269 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([id1_2_1_] : [BIGINT]) - [6]
2020-06-05 11:50:15.270 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([comment2_2_1_] : [VARCHAR]) - [좋아요~]
2020-06-05 11:50:15.270 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([post_id3_2_1_] : [BIGINT]) - [4]
2020-06-05 11:50:15.271 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([post_id3_2_0_] : [BIGINT]) - [4]
2020-06-05 11:50:15.271 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([id1_2_0_] : [BIGINT]) - [6]
2020-06-05 11:50:15.271 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([id1_2_1_] : [BIGINT]) - [7]
2020-06-05 11:50:15.271 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([comment2_2_1_] : [VARCHAR]) - [감사합니다.]
2020-06-05 11:50:15.272 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([post_id3_2_1_] : [BIGINT]) - [4]
2020-06-05 11:50:15.272 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([post_id3_2_0_] : [BIGINT]) - [4]
2020-06-05 11:50:15.272 TRACE 4256 --- [    Test worker] o.h.type.descriptor.sql.BasicExtractor   : extracted value ([id1_2_0_] : [BIGINT]) - [7]
[[Comment(id=2, comment=첫 댓글~! ), Comment(id=3, comment=두번째야~)], [Comment(id=7, comment=감사합니다.), Comment(id=6, comment=좋아요~), Comment(id=5, comment=다음글 기대할께요.)]]

결과를 보면 처음 select 하나만 원했을텐데 이 후로 post의 수 많큼 select * from comment where post_id=1, select * from comment where post_id=4 이렇게 2번더 실행 되었습니다. 그래서 원하는 1번의 query가 아니라 n+1번 실행되어 N+1문제라고 합니다.

 

문제는 하위 entity가 처음 select에서 가져오지 않고 실제 사용될 때  하나씩 하나씩 따로 가져오게되어 N+1 문제가 발생합니다. 실제 변수를 사용하는 시점에 JPA가 해당 변수 하나만을 가져오는 쿼리가 실행이 되는 것이죠.

JPA는 fetchType과 무관하게 그때 그때 JPQL에 맞춰 쿼리를 실행합니다. 그래서 eager든 lazy든 n+1 문제는 동일하게 일어납니다.

 

 

 

 

나는 항상 오늘 하루만 생각을 해... 가 아니라 나는 변수 하나만을 생각해... 지금 그 변수를 당장 가져와야지라고 동작한다고 보시면 됩니다.

다음 포스트는 어떻게 처리할지 알아보겠습니다.