트랜잭션 재배치로 쿼리 최적화하기

dasd412·2022년 3월 22일
JPA최적화트랜잭션포트폴리오
0

포트폴리오

목록 보기
36/41

문제 상황

하나의 컨트롤러 메서드 호출에 대해서 여러 번의 트랜잭션이 생긴다.
로그를 분석해보면, 최소화할 수 있는 select 쿼리가 많이 있다.
참고 링크는 이전 게시글이다.
(https://velog.io/@dasd412/JPA-Save-%EC%B5%9C%EC%A0%81%ED%99%94-%EC%8B%A4%ED%97%98-batch-insert)

문제 코드

컨트롤러 코드

    @PostMapping("/api/diary/user/diabetes-diary")
    public ApiResult<SecurityDiaryPostResponseDTO> postDiary(@AuthenticationPrincipal PrincipalDetails principalDetails, @RequestBody @Valid SecurityDiaryPostRequestDTO dto) {
        logger.info("post diary with authenticated user");

        Long writerId = principalDetails.getWriter().getId();

        /*JSON 직렬화가 LocalDateTime 에는 적용이 안되서 작성한 코드. */
        DateStringJoiner dateStringJoiner = DateStringJoiner.builder()
                .year(dto.getYear()).month(dto.getMonth()).day(dto.getDay())
                .hour(dto.getHour()).minute(dto.getMinute()).second(dto.getSecond())
                .build();

        LocalDateTime writtenTime = dateStringJoiner.convertLocalDateTime();

        /* 혈당 일지 저장 */
        DiabetesDiary diary = saveDiaryService.saveDiaryOfWriterById(EntityId.of(Writer.class, writerId), dto.getFastingPlasmaGlucose(), dto.getRemark(), writtenTime);

        Long diaryId = diary.getId();

        /* 아침 점심 저녁 식단 저장 */
        Diet breakFast = saveDiaryService.saveDietOfWriterById(EntityId.of(Writer.class, writerId), EntityId.of(DiabetesDiary.class, diaryId), EatTime.BreakFast, dto.getBreakFastSugar());
        Diet lunch = saveDiaryService.saveDietOfWriterById(EntityId.of(Writer.class, writerId), EntityId.of(DiabetesDiary.class, diaryId), EatTime.Lunch, dto.getLunchSugar());
        Diet dinner = saveDiaryService.saveDietOfWriterById(EntityId.of(Writer.class, writerId), EntityId.of(DiabetesDiary.class, diaryId), EatTime.Dinner, dto.getDinnerSugar());

        /* 아침 음식 저장 */
        dto.getBreakFastFoods()
                .forEach(elem -> saveDiaryService.saveFoodAndAmountOfWriterById
                        (EntityId.of(Writer.class, writerId),
                                EntityId.of(DiabetesDiary.class, diaryId),
                                EntityId.of(Diet.class, breakFast.getDietId()),
                                elem.getFoodName(), elem.getAmount(), elem.getAmountUnit()
                        ));
        /* 점심 음식 저장 */
        dto.getLunchFoods()
                .forEach(elem -> saveDiaryService.saveFoodAndAmountOfWriterById
                        (EntityId.of(Writer.class, writerId),
                                EntityId.of(DiabetesDiary.class, diaryId),
                                EntityId.of(Diet.class, lunch.getDietId()),
                                elem.getFoodName(), elem.getAmount(), elem.getAmountUnit()
                        ));
        /* 식단 음식 저장 */
        dto.getDinnerFoods()
                .forEach(elem -> saveDiaryService.saveFoodAndAmountOfWriterById
                        (EntityId.of(Writer.class, writerId),
                                EntityId.of(DiabetesDiary.class, diaryId),
                                EntityId.of(Diet.class, dinner.getDietId()),
                                elem.getFoodName(), elem.getAmount(), elem.getAmountUnit()
                        ));

        return ApiResult.OK(new SecurityDiaryPostResponseDTO(diaryId));
    }

서비스 코드

 @Transactional
    public DiabetesDiary saveDiaryOfWriterById(EntityId<Writer, Long> writerEntityId, int fastingPlasmaGlucose, String remark, LocalDateTime writtenTime) {
        logger.info("saveDiaryOfWriterById");
        checkNotNull(writerEntityId, "writerId must be provided");

        Writer writer = writerRepository.findById(writerEntityId.getId()).orElseThrow(() -> new NoResultException("작성자가 없습니다."));
        DiabetesDiary diary = new DiabetesDiary(getNextIdOfDiary(), writer, fastingPlasmaGlucose, remark, writtenTime);
        writer.addDiary(diary);
        writerRepository.save(writer);
        return diary;
    }

    @Transactional
    public Diet saveDietOfWriterById(EntityId<Writer, Long> writerEntityId, EntityId<DiabetesDiary, Long> diaryEntityId, EatTime eatTime, int bloodSugar) {
        logger.info("saveDietOfWriterById");
        checkNotNull(writerEntityId, "writerId must be provided");
        checkNotNull(diaryEntityId, "diaryEntityId must be provided");

        Writer writer = writerRepository.findById(writerEntityId.getId()).orElseThrow(() -> new NoResultException("작성자가 없습니다."));
        DiabetesDiary diary = diaryRepository.findOneDiabetesDiaryByIdInWriter(writerEntityId.getId(), diaryEntityId.getId()).orElseThrow(() -> new NoResultException("일지가 없습니다."));
        Diet diet = new Diet(getNextIdOfDiet(), diary, eatTime, bloodSugar);
        diary.addDiet(diet);
        writerRepository.save(writer);
        return diet;
    }


    @Transactional
    public void saveFoodAndAmountOfWriterById(EntityId<Writer, Long> writerEntityId, EntityId<DiabetesDiary, Long> diaryEntityId, EntityId<Diet, Long> dietEntityId, String foodName, double amount, AmountUnit amountUnit) {
        logger.info("saveFoodAndAmountOfWriterById");
        checkNotNull(writerEntityId, "writerId must be provided");
        checkNotNull(diaryEntityId, "diaryId must be provided");
        checkNotNull(dietEntityId, "dietId must be provided");

        Writer writer = writerRepository.findById(writerEntityId.getId()).orElseThrow(() -> new NoResultException("작성자가 없습니다."));
        Diet diet = dietRepository.findOneDietByIdInDiary(writerEntityId.getId(), diaryEntityId.getId(), dietEntityId.getId()).orElseThrow(() -> new NoResultException("식단이 없습니다."));
        Food food = new Food(getNextIdOfFood(), diet, foodName, amount, amountUnit);
        diet.addFood(food);
        writerRepository.save(writer);
    }

코드 분석

  1. 컨트롤러에서 하는 일이 너무 많다. 비즈니스 로직은 서비스 레이어가 하는 게 좋다.
  2. 일지 하나를 작성할 때, 연관된 엔티티인 식사와 음식은 다 같이 작성되야 한다. 수정 또한 마찬가지이다.
    즉, 어차피 한 꺼번에 처리해야할 작업이다. 굳이 트랜잭션을 여러 번 해서 성능을 떨어뜨릴 필요가 있을까 싶다. (트랜잭션 생성 및 소멸의 후처리 오버헤드 등...)
  3. 까먹었던 JPA 개념을 들춰보니, 스프링 컨테이너의 기본 전략은 트랜잭션 범위의 영속성 컨텍스트라고 한다.
    즉, 트랜잭션을 시작할 때 영속성 컨텍스트가 시작되고 트랜잭션이 끝날 때 영속성 컨텍스트가 종료된다는 것이다.
    위 코드들의 문제점은 트랜잭션이 여러 번 시작되면서 영속성 컨텍스트 역시 여러번 재시작 되는 것이라고 볼 수 있다.
    왜 세션(@AuthenticationPrincipal)이 있는데, Writer writer = writerRepository.findById(writerEntityId.getId()).orElseThrow(() -> new NoResultException("작성자가 없습니다.")); 라는 코드가 굳이 필요한가?
    다른 엔티티들도 마찬가지이다. 같은 영속성 컨텍스트 범위 내에 있으면, 연관관계를 맺을 엔티티를 다시 db에서 select할 필요가 없다.

Trial

다음은 수행 도중 오류가 발생했던 코드이다.

    @Transactional
    public Long postDiary(PrincipalDetails principalDetails, SecurityDiaryPostRequestDTO dto) {
        logger.info("post diary in service logic");
        checkNotNull(principalDetails, "principalDetails must be provided");

        /* 0. 현재 세션에 담긴 사용자 정보 판별 */
        Writer writer = writerRepository.findById(principalDetails.getWriter().getId()).orElseThrow(() -> new NoResultException("작성자가 없습니다."));

        /* 2-1. LocalDateTime JSON 직렬화 */
        LocalDateTime writtenTime = convertStringToLocalDateTime(dto);

        /* 2-2. 혈당 일지 저장 */
        DiabetesDiary diary = new DiabetesDiary(getNextIdOfDiary(), writer, dto.getFastingPlasmaGlucose(), dto.getRemark(), writtenTime);
        writer.addDiary(diary);
        writerRepository.save(writer);

        /* 3. 아침 점심 저녁 식사 저장 */

        Diet breakFast = new Diet(getNextIdOfDiet(), diary, EatTime.BreakFast, dto.getBreakFastSugar());
        diary.addDiet(breakFast);
        writerRepository.save(writer);

        Diet lunch = new Diet(getNextIdOfDiet(), diary, EatTime.Lunch, dto.getLunchSugar());
        diary.addDiet(lunch);
        writerRepository.save(writer);

        Diet dinner = new Diet(getNextIdOfDiet(), diary, EatTime.Dinner, dto.getDinnerSugar());
        diary.addDiet(dinner);
        writerRepository.save(writer);

        /* 4-1. 아침 음식 저장 */
        dto.getBreakFastFoods().forEach(elem -> {
            Food food = new Food(getNextIdOfFood(), breakFast, elem.getFoodName(), elem.getAmount(), elem.getAmountUnit());
            breakFast.addFood(food);
            writerRepository.save(writer);
        });

        /* 4-2. 점심 음식 저장 */
        dto.getLunchFoods().forEach(elem -> {
            Food food = new Food(getNextIdOfFood(), lunch, elem.getFoodName(), elem.getAmount(), elem.getAmountUnit());
            lunch.addFood(food);
            writerRepository.save(writer);
        });

        /* 4-3. 저녁 음식 저장 */
        dto.getDinnerFoods().forEach(elem -> {
            Food food = new Food(getNextIdOfFood(), dinner, elem.getFoodName(), elem.getAmount(), elem.getAmountUnit());
            dinner.addFood(food);
            writerRepository.save(writer);
        });
        
        return diary.getId();
    }

발생한 오류는 다음과 같다.
org.hibernate.LazyInitializationException: failed to lazily initialize a collection of role
찾아보니 @Transactional을 적용하거나 Eager loading을 사용하라고 한다.
하지만 전자의 경우 이미 적용이 되었고, 후자의 경우는 이미 Lazy Loading과 관련 로직으로 다 작성했는데 바꾸는 건 말이 안된다.

Enhancement

코드

일단, 비즈니스 로직을 서비스 레이어에 옮겼다.

서비스 코드

    @Transactional
    public Long postDiary(PrincipalDetails principalDetails, SecurityDiaryPostRequestDTO dto) {
        logger.info("post diary in service logic");
        checkNotNull(principalDetails, "principalDetails must be provided");

        /* 0. 현재 세션에 담긴 사용자 정보 판별 */
        Writer writer = writerRepository.findById(principalDetails.getWriter().getId()).orElseThrow(() -> new NoResultException("작성자가 없습니다."));

        /* 2-1. LocalDateTime JSON 직렬화 */
        LocalDateTime writtenTime = convertStringToLocalDateTime(dto);

        /* 2-2. 혈당 일지 저장 */
        DiabetesDiary diary = new DiabetesDiary(getNextIdOfDiary(), writer, dto.getFastingPlasmaGlucose(), dto.getRemark(), writtenTime);
        writer.addDiary(diary);

        /* 3. 아침 점심 저녁 식사 저장 */

        Diet breakFast = new Diet(getNextIdOfDiet(), diary, EatTime.BreakFast, dto.getBreakFastSugar());
        diary.addDiet(breakFast);

        Diet lunch = new Diet(getNextIdOfDiet(), diary, EatTime.Lunch, dto.getLunchSugar());
        diary.addDiet(lunch);

        Diet dinner = new Diet(getNextIdOfDiet(), diary, EatTime.Dinner, dto.getDinnerSugar());
        diary.addDiet(dinner);

        /* 4-1. 아침 음식 저장 */
        dto.getBreakFastFoods().forEach(elem -> {
            Food food = new Food(getNextIdOfFood(), breakFast, elem.getFoodName(), elem.getAmount(), elem.getAmountUnit());
            breakFast.addFood(food);
        });

        /* 4-2. 점심 음식 저장 */
        dto.getLunchFoods().forEach(elem -> {
            Food food = new Food(getNextIdOfFood(), lunch, elem.getFoodName(), elem.getAmount(), elem.getAmountUnit());
            lunch.addFood(food);
        });

        /* 4-3. 저녁 음식 저장 */
        dto.getDinnerFoods().forEach(elem -> {
            Food food = new Food(getNextIdOfFood(), dinner, elem.getFoodName(), elem.getAmount(), elem.getAmountUnit());
            dinner.addFood(food);
        });

        writerRepository.save(writer);

        return diary.getId();
    }

Trial 부분과 다른 점은 writerRepository.save(writer);가 마지막에 단 한번 호출되는 것이다. 이렇게 하니, 오류가 발생하지 않았다.
자세히는 분석하지 않았지만, 아마 save() 호출 때 영속성 컨텍스트 내 문제가 발생한 것 같다. 흠... 무엇이 원일일라나..

컨트롤러 코드

반면 컨트롤러 코드는 매우 간소해졌다.

    @PostMapping("/api/diary/user/diabetes-diary")
    public ApiResult<SecurityDiaryPostResponseDTO> postDiary(@AuthenticationPrincipal PrincipalDetails principalDetails, @RequestBody @Valid SecurityDiaryPostRequestDTO dto) {
        logger.info("post diary with authenticated user");

        Long diaryId = saveDiaryService.postDiary(principalDetails, dto);

        return ApiResult.OK(new SecurityDiaryPostResponseDTO(diaryId));
    }

로그

로그를 분석해보자. 사용한 예시는 일지 1개 + 식사 3번 + 식사 당 5개의 음식이다.
원래는 77개의 쿼리가 실행되었다.(https://velog.io/@dasd412/JPA-Save-%EC%B5%9C%EC%A0%81%ED%99%94-%EC%8B%A4%ED%97%98-batch-insert)

하지만 트랜잭션을 하나로 묶음으로써 실행되는 쿼리가 41개로 줄었다. 36개가 줄었으니 약 40% 향상된 것이다. 

2022-03-22 11:44:10.650  INFO 1956 --- [nio-8084-exec-2] .d.r.a.c.s.d.SecurityDiaryRestController : post diary with authenticated user
2022-03-22 11:44:10.652  INFO 1956 --- [nio-8084-exec-2] c.d.r.a.service.domain.SaveDiaryService  : post diary in service logic
Hibernate: select writer0_.writer_id as writer_i1_4_0_, writer0_.email as email2_4_0_, writer0_.name as name3_4_0_, writer0_.password as password4_4_0_, writer0_.profile_id as profile_8_4_0_, writer0_.provider as provider5_4_0_, writer0_.provider_id as provider6_4_0_, writer0_.role as role7_4_0_, profile1_.profile_id as profile_1_3_1_, profile1_.diabetes_phase as diabetes2_3_1_ from writer writer0_ left outer join profile profile1_ on writer0_.profile_id=profile1_.profile_id where writer0_.writer_id=?
Hibernate: select max(diabetesdi0_.diary_id) as col_0_0_ from diabetes_diary diabetesdi0_
Hibernate: select diaries0_.writer_id as writer_i2_0_0_, diaries0_.diary_id as diary_id1_0_0_, diaries0_.diary_id as diary_id1_0_1_, diaries0_.writer_id as writer_i2_0_1_, diaries0_.fpg as fpg3_0_1_, diaries0_.remark as remark4_0_1_, diaries0_.written_time as written_5_0_1_ from diabetes_diary diaries0_ where diaries0_.writer_id=?
Hibernate: insert into diabetes_diary (fpg, remark, written_time, diary_id, writer_id) values (?, ?, ?, ?, ?)
Hibernate: select max(diet0_.diet_id) as col_0_0_ from diet diet0_
Hibernate: insert into diet (blood_sugar, eat_time, diary_id, writer_id, diet_id) values (?, ?, ?, ?, ?)
Hibernate: select max(diet0_.diet_id) as col_0_0_ from diet diet0_
Hibernate: insert into diet (blood_sugar, eat_time, diary_id, writer_id, diet_id) values (?, ?, ?, ?, ?)
Hibernate: select max(diet0_.diet_id) as col_0_0_ from diet diet0_
Hibernate: insert into diet (blood_sugar, eat_time, diary_id, writer_id, diet_id) values (?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
Hibernate: select max(food0_.food_id) as col_0_0_ from food food0_
Hibernate: select food0_.diary_id as diary_id0_2_0_, food0_.writer_id as writer_i0_2_0_, food0_.diet_id as diet_id0_2_0_, food0_.food_id as food_id1_2_0_, food0_.diary_id as diary_id5_2_0_, food0_.writer_id as writer_i6_2_0_, food0_.diet_id as diet_id7_2_0_, food0_.amount as amount2_2_0_, food0_.amount_unit as amount_u3_2_0_, food0_.food_name as food_nam4_2_0_ from food food0_ where food0_.diary_id=? and food0_.writer_id=? and food0_.diet_id=? and food0_.food_id=?
Hibernate: insert into food (amount, amount_unit, food_name, diary_id, writer_id, diet_id, food_id) values (?, ?, ?, ?, ?, ?, ?)
2022-03-22 11:44:10.741  INFO 1956 --- [nio-8084-exec-2] i.StatisticalLoggingSessionEventListener : Session Metrics {
    340300 nanoseconds spent acquiring 1 JDBC connections;
    0 nanoseconds spent releasing 0 JDBC connections;
    2709400 nanoseconds spent preparing 41 JDBC statements;
    28311800 nanoseconds spent executing 41 JDBC statements;
    0 nanoseconds spent executing 0 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    1273500 nanoseconds spent executing 1 flushes (flushing a total of 26 entities and 10 collections);
    33409600 nanoseconds spent executing 19 partial-flushes (flushing a total of 299 entities and 299 collections)
}

향상 이유 분석

@Transactional의 기본 전략은 Required라고 한다.
이 전략은 현재 트랜잭션이 없을 경우 새로 생성하지만, 이미 시작된 트랜잭션이 있으면 새로이 만들지 않고 기존 트랜잭션에 참여하는 것이다.

save()의 경우도 @Transactional이 선언 되어있다.
하지만 더 상위인 서비스 레이어에 @Transactional를 부착하였으므로 서비스 레이어 트랜잭션에 참여하게 된다.

기존에는 트랜잭션이 19개 생성되어 영속성 컨텍스트도 19번 초기화되었었다면, 향상된 코드에는 트랜잭션이 1개 생성되어 해당 트랜잭션 내에서 일지 작성과 관련된 모든 엔티티의 저장 작업이 일어난다.

즉, 트랜잭션 오버헤드랑 영속성 컨텍스트 재초기화 오버헤드가 없어졌다고 볼 수 있다.

물론, 트랜잭션 하나에 모든 작업을 처리해야 해서 그 동안에는 다른 일을 하지 못한다.
하지만 일지 작성의 경우, 연관된 엔티티 모두가 정상 저장되야만 완료했다고 할 수 있는 작업이다. 작업의 완전성을 보장하기 위해서라도 트랜잭션 하나에 위 작업들을 모두 처리하는 것은 문제가 없다고 생각한다.

참고 자료

https://2dongdong.tistory.com/29
https://www.nowwatersblog.com/jpa/ch13/13-1

profile
dasd412
아키텍쳐 설계와 테스트 코드에 관심이 많음.
이전 포스트

JPA Save 최적화 실험 [batch insert]

다음 포스트

how to test JAR file with external secret properties in CI

0개의 댓글