トランザクションの再スケジュールによるsaveとupdateのパフォーマンスの最適化


問題の状況


1つのコントローラメソッド呼び出しで複数のトランザクションが生成されます.
分析ログでは、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);
    }

コード解析

  • コントローラでの作業が多すぎます.ビジネスロジックはサービス層が望ましい.
  • ログに記入する場合は、関連エンティティとしての食事と食事を一緒に記入します.修正もそうです.
    つまり、どうせ一度はやらなければならない仕事です.何度も取引をして性能を下げる必要がありますか?(トランザクションの作成と破棄の後処理コストなど...)
  • 忘れたJPA概念から見ると、スプリングコンテナの基本戦略は트랜잭션 범위의 영속성 컨텍스트である.
    すなわち、トランザクションが開始されると、永続コンテキストが開始され、トランザクションが終了すると、永続コンテキストが終了します.
    上記のコードの問題は、トランザクションが複数回起動されるにつれて、永続性コンテキストも複数回再起動されることです.
    コード@AuthenticationPrincipalではなく、セッション(Writer writer = writerRepository.findById(writerEntityId.getId()).orElseThrow(() -> new NoResultException("작성자가 없습니다."));)があるのはなぜですか?
    他のエンティティもそうです.同じ永続性コンテキストの範囲内である場合、dbで関連付けを確立するエンティティを再度選択する必要はありません.
  • 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調べてみましたが、@TransactionalEager 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);は最後に1回のみ呼び出される.こうすれば間違いはない
    詳細な解析はありませんが、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つのトランザクションはすべてのタスクを処理する必要があります.この間、他のことはできません.
    ただし、ログ作成は、関連するすべてのエンティティが正常に保存されている場合にのみ完了します.仕事の完全性を保証するために、1つのトランザクションでこれらのタスクをすべて処理することは問題ないと思います.

    参考資料


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