Skip to content

[3차 과제] api 별 발생하는 쿼리 개수와 동작하는 트랜잭션 범위 점검하기 #143

@choyeongju

Description

@choyeongju

Image

TODO

  1. 각 API 호출 시 발생하는 SQL 원본 쿼리 확인, 발생하는 쿼리 개수 기록

    → API 을 호출하면서 콘솔에 찍히는 쿼리문을 확인했습니다.

  2. 트랜잭션 시작-종료의 범위 확인

    → application.yml 에 로깅 설정 추가해서 콘솔에서 확인 가능하도록 했습니다.

    logging:
      level:
        org.springframework.orm.jpa: DEBUG
        org.springframework.jdbc.core: DEBUG
        org.hibernate.engine.transaction: DEBUG

기본 개념

💌 트랜잭션

트랜잭션의 시작과 끝

[시작]

스프링 이용 시, 내부적으로 connection 갖고 있는 추상화된 TransactionManager 을 이용하거나
@transactional 어노테이션을 사용합니다.

[종료]

트랜잭션이 종료되는 시점에는 commit() 과 rollback() 의 두 가지가 있습니다.

하나의 트랜잭션이 시작되면 이 두 메서드가 호출될 떄까지가 하나의 트랜잭션으로 묶이게 됩니다.

→ 하나의 트랜잭션은 하나의 connection 이 만들어지고 닫히는 범위 안에 속함.

→ 즉, 트랜잭션이 시작된 후 commit() 또는 rollback() 이 호출될 때까지 같은 연결을 사용하게 됨!

 

트랜잭션 전파 속성(Transaction Propagation)

작업을 하다보면 기존에 트랜잭션이 진행중일 때 추가적인 트랜잭션을 진행해야 하는 경우가 있습니다. 
이미 트랜잭션이 진행중일 때 추가 트랜잭션 진행을 어떻게 할지 결정하는 것이 전파 속성(Propagation)입니다.

@transactional 에서 별도의 옵션을 주지 않는다면 기본적으로 Propagation.REQUIRED 방식을 따릅니다. → 기존 트랜잭션이 있으면 그 트랜잭션에 참여하고, 없으면 새로운 트랜잭션을 생성!

 

💌 JpaTransactionManager

  • JPA 기반의 Spring 애플리케이션에서 트랜잭션을 관리하는 핵심 클래스
    • 트랜잭션 시작/종료 관리 : 트랜잭션의 시작, 커밋, 롤백 등을 책임짐
    • db 연결 관리 : 트랜잭션 범위 내에서 동일한 db 의 커넥션 유지, 트랜잭션 종료 시 연결 close

 

💌 EntityManager

  • 1차 캐시 제공
    • 같은 트랜잭션 범위 내에서 엔티티를 1차 캐시에 저장
    • 즉, 동일한 엔티티를 여러 번 조회할 경우 데이터베이스에 쿼리를 다시 실행하지 않고, 1차 캐시에서 반환
  • 엔티티 상태 관리의 역할
    • 엔티티는 EntityManager에 의해 관리되는 영속 상태(Persistent State) 가 된다!
    • 즉, 트랜잭션 종료 시 변경 사항은 자동으로 db 에 반영됨

실제로 API 를 호출하면서 발생하는 쿼리를 확인해보자 !!!!!!

🔔 모든 API 들에 대해서 쿼리를 복사해오는 것은 의미없다고 생각하여, 임의로 몇 개의 API 에 대해 공부할 지점이 필요한 부분들에 대해서만 정리했습니다.

✅ [PUT]/api/v1/subjects/{subjectId}/{options}

과목명/과목 별 동기부여 메세지 작성 및 수정 API → 3개

  1. 트랜잭션 시작
2025-01-24T04:55:31.516+09:00 DEBUG 43025 --- [nio-8080-exec-2] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(990363061<open>)] for JPA transaction
2025-01-24T04:55:31.516+09:00 DEBUG 43025 --- [nio-8080-exec-2] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
  • JpaTransactionManager가 현재 thread 에 연결된 EntityManager를 찾은 것을 확인할 수 있습니다.
    • 이는, 새로운 트랜잭션을 시작하지 않고, 이미 존재하는 트랜잭션에 참여하고 있다는 의미!
    • 즉, Spring의 디폴트 트랜잭션 전파방식인 Propagation.REQUIRED 에 따라 동작 중인 것을 확인할 수 있습니다.

→ 장점 : 동일한 트랜잭션 아에서 여러 작업을 묶어서 일관성을 보장할 수 있다!

 

  1. SQL 실행 (조회) : 사용자 조회, 과목 정보 조회
Hibernate: 
    select
        u1_0.id,
        u1_0.first_today_tasks_completed_at,
        u1_0.created_at,
        u1_0.escape_badge_1,
        u1_0.escape_badge_aapjam,
        u1_0.escape_barely_badge_1,
        u1_0.escape_barely_badge_2,
        u1_0.escape_barely_badge_3,
        u1_0.first_create_study_count,
        u1_0.first_study_completed_at,
        u1_0.has_mass_baking_bread_badge,
        u1_0.has_preparing_opening_bakery,
        u1_0.inssa_boss_badge_1,
        u1_0.inssa_boss_badge_2,
        u1_0.is_onboarding_complete,
        u1_0.last_study_completed_date,
        u1_0.nickname,
        u1_0.platform,
        u1_0.platform_user_id,
        u1_0.user_point,
        u1_0.today_study_complete_count,
        u1_0.updated_at,
        u1_0.user_level 
    from
        users u1_0 
    where
        u1_0.id=?
Hibernate: 
    select
        s1_0.id,
        s1_0.created_at,
        s1_0.motivation_message,
        s1_0.subject_name,
        s1_0.updated_at,
        s1_0.user_subject_id 
    from
        subject s1_0 
    join
        user_subject us1_0 
            on us1_0.id=s1_0.user_subject_id 
    join
        users u1_0 
            on u1_0.id=us1_0.user_id 
    where
        s1_0.id=? 
        and u1_0.id=?
  1. 트랜잭션 commit 준비
2025-01-24T04:55:31.573+09:00 DEBUG 43025 --- [nio-8080-exec-2] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
2025-01-24T04:55:31.573+09:00 DEBUG 43025 --- [nio-8080-exec-2] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(990363061<open>)]
2025-01-24T04:55:31.574+09:00 DEBUG 43025 --- [nio-8080-exec-2] o.h.e.t.internal.TransactionImpl         : committing
  • JPA EntityManager 가 현재 트랜잭션 범위 내에서 변경된 데이터를 db 에 반영하기 위해서 준비중인 상태입니다.
  1. SQL 실행 (업데이트) : 과목 정보 업데이트
Hibernate: 
    update
        subject 
    set
        motivation_message=?,
        subject_name=?,
        updated_at=?,
        user_subject_id=? 
    where
        id=?
  1. 트랜잭션 commit 완료
2025-01-24T04:55:31.584+09:00 DEBUG 43025 --- [nio-8080-exec-2] o.s.orm.jpa.JpaTransactionManager        : Not closing pre-bound JPA EntityManager after transaction
  • 트랜잭션의 종료 → 모든 작업이 db 에 영구적으로 저장 !!
  • But, EntityManager 은 닫히지 않았음.
    • OpenEntityManagerInViewInterceptor 에 의해서 EntityManager 가 열려 있는 상태를 유지하기 때문
    • → 클라이언트 요청이 완료될 때까지 EntityManager를 열어 둠으로써 Lazy loading 을 지원!
    • → Lazy loading 이 필요한 경우, 트랜잭션 범위를 넘어서 요청 응답 동안에도 데이터 가져올 수 있음
  1. EntityManager 종료
2025-01-24T04:55:31.594+09:00 DEBUG 43025 --- [nio-8080-exec-2] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor
  • 요청 처리 완료되면서, OpenEntityManagerInViewInterceptor가 EntityManager를 닫음

 

✅ [POST]/api/v1/studies

공부 범위(교재) 추가하기 API → 9개

🫢 쿼리가 왜 이만큼 밖에 실행이 안되었나?!

  • Spring Boot 에서는 위에서 봤듯이 OpenEntityManagerViewInterceptor 가 활성화되어 있다!

🫢 그래서 이게 무슨 역할인데?

  • HTTP 요청 시 → JPA 의 EntityManager가 열린다.
  • 요청 종료 시까지 EntityManager 가 유지! → 동일한 영속성 컨텍스트 내에서 엔티티 조회 및 관리가 이루어짐
  • 따라서… 같은 트랜잭션 내에서 동일한 엔티티를 다시 조회하면 1차 캐시에서 가져오므로 쿼리가 실행되지 않음!

→ 즉, JPA 1차 캐시에 저장된 사용자 엔티티를 이후 동일 트랜잭션 내에서 재사용중~

📝 결론

  • 이 API는 OpenEntityManagerInViewInterceptor와 JPA 1차 캐시를 활용해 효율적으로 쿼리를 줄이고 데이터를 처리한 것임

  • 9개의 쿼리는 캐시 덕분에 쿼리의 개수가 최소화된 결과임

  • OpenEntityManagerInViewInterceptor 가 요청 범위 동안 EntityManager를 열어두어 데이터베이스 조회 성능이 최적화 된 것!

  • 원본 쿼리 목록

    2025-01-24T07:32:43.555+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.j.s.OpenEntityManagerInViewInterceptor : Opening JPA EntityManager in OpenEntityManagerInViewInterceptor
    2025-01-24T07:32:43.567+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(436268816<open>)] for JPA transaction
    2025-01-24T07:32:43.567+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.s.orm.jpa.JpaTransactionManager        : Creating new transaction with name [com.sopt.bbangzip.domain.study.service.StudyService.createStudy]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
    2025-01-24T07:32:43.568+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.h.e.t.internal.TransactionImpl         : On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
    2025-01-24T07:32:43.568+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.h.e.t.internal.TransactionImpl         : begin
    2025-01-24T07:32:43.568+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.s.orm.jpa.JpaTransactionManager        : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@103792d5]
    Hibernate: 
        select
            s1_0.id,
            s1_0.created_at,
            s1_0.motivation_message,
            s1_0.subject_name,
            s1_0.updated_at,
            s1_0.user_subject_id 
        from
            subject s1_0 
        join
            user_subject us1_0 
                on us1_0.id=s1_0.user_subject_id 
        join
            users u1_0 
                on u1_0.id=us1_0.user_id 
        where
            s1_0.id=? 
            and u1_0.id=?
    2025-01-24T07:32:43.571+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(436268816<open>)] for JPA transaction
    2025-01-24T07:32:43.571+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
    Hibernate: 
        insert 
        into
            exam
            (created_at, exam_date, exam_name, subject_id) 
        values
            (?, ?, ?, ?)
    2025-01-24T07:32:43.574+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(436268816<open>)] for JPA transaction
    2025-01-24T07:32:43.574+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
    Hibernate: 
        insert 
        into
            study
            (created_at, exam_id, study_contents) 
        values
            (?, ?, ?)
    2025-01-24T07:32:43.577+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.s.orm.jpa.JpaTransactionManager        : Found thread-bound EntityManager [SessionImpl(436268816<open>)] for JPA transaction
    2025-01-24T07:32:43.577+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.s.orm.jpa.JpaTransactionManager        : Participating in existing transaction
    Hibernate: 
        insert 
        into
            piece
            (created_at, deadline, finish_page, is_finished, is_visible, page_amount, piece_number, start_page, study_id, updated_at) 
        values
            (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
    Hibernate: 
        insert 
        into
            piece
            (created_at, deadline, finish_page, is_finished, is_visible, page_amount, piece_number, start_page, study_id, updated_at) 
        values
            (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
    Hibernate: 
        select
            us1_0.id,
            us1_0.semester,
            us1_0.user_id,
            us1_0.year 
        from
            user_subject us1_0 
        where
            us1_0.id=?
    Hibernate: 
        select
            u1_0.id,
            u1_0.first_today_tasks_completed_at,
            u1_0.created_at,
            u1_0.escape_badge_1,
            u1_0.escape_badge_aapjam,
            u1_0.escape_barely_badge_1,
            u1_0.escape_barely_badge_2,
            u1_0.escape_barely_badge_3,
            u1_0.first_create_study_count,
            u1_0.first_study_completed_at,
            u1_0.has_mass_baking_bread_badge,
            u1_0.has_preparing_opening_bakery,
            u1_0.inssa_boss_badge_1,
            u1_0.inssa_boss_badge_2,
            u1_0.is_onboarding_complete,
            u1_0.last_study_completed_date,
            u1_0.nickname,
            u1_0.platform,
            u1_0.platform_user_id,
            u1_0.user_point,
            u1_0.today_study_complete_count,
            u1_0.updated_at,
            u1_0.user_level 
        from
            users u1_0 
        where
            u1_0.id=?
    Hibernate: 
        select
            count(p1_0.id) 
        from
            piece p1_0 
        join
            study s1_0 
                on s1_0.id=p1_0.study_id 
        join
            exam e1_0 
                on e1_0.id=s1_0.exam_id 
        join
            subject s2_0 
                on s2_0.id=e1_0.subject_id 
        join
            user_subject us1_0 
                on us1_0.id=s2_0.user_subject_id 
        where
            p1_0.is_visible=true 
            and p1_0.is_finished=false 
            and e1_0.exam_date>=current_date 
            and us1_0.user_id=?
    Hibernate: 
        select
            count(p1_0.id) 
        from
            piece p1_0 
        join
            study s1_0 
                on s1_0.id=p1_0.study_id 
        join
            exam e1_0 
                on e1_0.id=s1_0.exam_id 
        join
            subject s2_0 
                on s2_0.id=e1_0.subject_id 
        join
            user_subject us1_0 
                on us1_0.id=s2_0.user_subject_id 
        where
            p1_0.is_visible=true 
            and p1_0.is_finished=true 
            and us1_0.user_id=? 
            and e1_0.exam_date>=current_date
    2025-01-24T07:32:43.588+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.s.orm.jpa.JpaTransactionManager        : Initiating transaction commit
    2025-01-24T07:32:43.588+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.s.orm.jpa.JpaTransactionManager        : Committing JPA transaction on EntityManager [SessionImpl(436268816<open>)]
    2025-01-24T07:32:43.588+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.h.e.t.internal.TransactionImpl         : committing
    2025-01-24T07:32:43.591+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.s.orm.jpa.JpaTransactionManager        : Not closing pre-bound JPA EntityManager after transaction
    2025-01-24T07:32:43.593+09:00 DEBUG 43025 --- [nio-8080-exec-4] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor
    

Metadata

Metadata

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions