JPA N+1 감지 기능 구현기

N + 1 문제는 JPA를 사용할 때 자주 겪는 성능 문제로, 연관된 엔티티들을 반복적으로 조회하면서 추가적인 쿼리가 발생하는 현상입니다. 이러한 N + 1 문제는 쿼리 수 증가와 메모리 점유율을 높여 성능 저하를 유발할 수 있습니다.

 

프로젝트를 진행하며 N + 1 개념을 모르고, 해결법을 몰라서가 아닌 개발자의 실수로 N + 1 문제가 발생하는 상황을 종종 볼 수 있었습니다. 개발 환경에서 발생되는 쿼리를 보고도 충분히 문제를 방지할 수 있지만 N + 1 문제가 발생하면 로깅을 통해 문제상황을 감지, 개발생산성을 높이고자 하여 기능 개발을 하게 되었습니다.

---

접근 방식

우선, 로깅을 남기기 위해 N+1 문제의 명확한 정의가 필요했습니다. 다음과 같이 정의를 내렸습니다.

1. 즉시 로딩(FetchType.EAGER)으로 설정된 엔티티는 로깅 대상이 아닙니다.
2. 지연 로딩(FetchType.LAZY)으로 설정된 엔티티에 대해 접근이 발생할 때 N+1 문제가 발생합니다.

JPA에서 지연 로딩으로 설정된 엔티티는 실제 데이터를 담고 있는 엔티티가 아닌 프록시 객체로, 엔티티에 접근하는 순간 쿼리를 발생시켜 엔티티가 초기화됩니다.

저는 EntityManager가 엔티티를 초기화하는 내부 구조를 살펴봄으로써 해결 방향을 찾고자 했습니다. 소스 코드를 분석하던 중, 컬렉션 초기화 시 InitializeCollectionEvent 이벤트가 발생하며, 이를 수신할 InitializeCollectionEventListener 인터페이스가 있다는 것을 확인했습니다.

 

---

컬렉션 타입의 지연 로딩 감지 및 로깅

컬렉션 타입의 지연 로딩을 감지하여 로깅하기 위해 InitializeCollectionEventListener의 onInitializeCollection 메서드를 구현했습니다.

 

이 메서드는 컬렉션 정보(CollectionPersister)에서 지연 로딩이 설정된 경우 로깅을 남기도록 합니다.

import lombok.extern.slf4j.Slf4j;
import org.hibernate.Session;
import org.hibernate.collection.spi.PersistentCollection;
import org.hibernate.engine.spi.SessionFactoryImplementor;
import org.hibernate.event.spi.InitializeCollectionEvent;
import org.hibernate.event.spi.InitializeCollectionEventListener;
import org.hibernate.persister.collection.CollectionPersister;

@Slf4j
public class CollectionListener implements InitializeCollectionEventListener {

  @Override
  public void onInitializeCollection(InitializeCollectionEvent event) {
    PersistentCollection<?> collection = event.getCollection();
    Session session = event.getSession();
    SessionFactoryImplementor sessionFactory = (SessionFactoryImplementor) session.getFactory();
    CollectionPersister persister = sessionFactory.getMappingMetamodel()
        .getCollectionDescriptor(collection.getRole());

    if (persister.isLazy()) {
      log.info("Lazy loading detected for collection: " + persister.getRole());
    }
  }
}

 

호출 순서

1. 지연 로딩이 설정된 컬렉션이 초기화될 때 InitializeCollectionEvent 이벤트가 발생합니다.
2. 이 이벤트를 발행하는 주체는 EntityManager이며, Hibernate에서는 이의 기본 구현체인 SessionImpl이 이벤트를 발행하게 됩니다.
3. 구현한 리스너를 SessionFactory에 등록하면, 컬렉션이 초기화될 때 해당 이벤트를 받아 로깅할 수 있습니다.

SessionImpl 의 컬렉션 초기화 소스코드

private void registerCollectionListener(EntityManagerFactory entityManagerFactory) {
    SessionFactoryImpl sessionFactory = entityManagerFactory.unwrap(SessionFactoryImpl.class);

    EventListenerRegistry registry = sessionFactory.getEventEngine().getListenerRegistry();
    registry.getEventListenerGroup(EventType.INIT_COLLECTION)
        .appendListener(new CollectionListener());
  }

 

테스트

Parent 클래스

public class Parent {

  @Id
  @GeneratedValue(strategy = GenerationType.IDENTITY)
  private Long id;

  private String name;

  @OneToMany(mappedBy = "parent", fetch = FetchType.LAZY)
  private List<Child> children;
}

Child 클래스

public class Child {

  @Id
  @GeneratedValue(strategy = GenerationType.IDENTITY)
  private Long id;

  private String name;

  @ManyToOne
  private Parent parent;
}

 

 

간단한 샘플 코드를 통해 애플리케이션을 실행한 결과, 추가 쿼리가 발생하며 로깅이 성공적으로 기록되는 것을 확인할 수 있었습니다.

 

 

 

---

엔티티 타입의 지연 로딩 감지 및 로깅

컬렉션의 경우에는 필요한 리스너가 잘 되어있었기에 어려움 없이 구현을 할 수 있었습니다.

컬렉션에서 사용했던 이벤트가 InitializeCollectionEvent 이었고, 해당 타입의 부모를 타고 가보니 AbstractEvent 라는 이벤트 클래스를 찾을 수 있었습니다. 그리고 해당 이벤트를 상속받고 있는 다양한 이벤트들을 확인할 수 있었고, 그 중에서 LoadEvent를 찾을 수 있었습니다.

아래는 다양한 타입의 이벤트들입니다. 원하는 이벤트를 찾아서 리스너를 구현하여 SessionFactory의 ServiceRegistry에 등록하면 커스터마이징이 가능합니다.

이벤트 타입

 

지연로딩인 객체를 초기화 하는 로직을 알아야 로깅을 정확히 찍을 수 있기에 하이버네이트는 지연로딩일 경우 어떤 식으로 객체를 초기화 하는지 내부 구조를 살펴볼 필요가 있었습니다. 그래서 SessionImpl 의 내부구조를 디버깅하면서 한가지 메서드를 찾을 수 있었습니다.

 

지연로딩으로 설정된 엔티티에 접근할 때 immediateLoad 라는 메서드가 호출되고 있었습니다.

SessionImpl 의 immediateLoad

 

그리고 보시다시피 IMMEDIATE_LOAD 라는 타입으로 LoadEvent 를 발행하고 있었습니다. 그래서 IMMEDIATE_LOAD 타입으로 발행된 LoadEvent 를 잡아서 로깅을 찍으면 되겠다고 생각하여 다음과 같이 구현을 했습니다.

@Slf4j
public class EntityLoadListener implements LoadEventListener {

  @Override
  public void onLoad(LoadEvent event, LoadType loadType) throws HibernateException {
    if(loadType.getName().equals("IMMEDIATE_LOAD")) {
      log.info("lazy : {}", event.getEntityClassName());
    }
  }
}

로그도 잘 출력되고 예상한 대로 잘 동작하고 있었습니다. 하지만 다음과 같은 문제점이 있었습니다.

• 로그를 찍는 시점이 N + 1 문제가 발생한 후가 아닌 전이다.
• 따라서 로그를 찍은 뒤 모종의 이유로 N + 1 문제가 발생하지 않을 수 있다.
• 그렇다면 로그는 신뢰성이 있을까 ?

그래서 지연로딩으로 설정된 엔티티가 초기화가 일어난 후, 즉 N + 1 문제가 발생한 시점에서 로그를 찍는 것을 목표로 다른 방법을 찾았습니다.

 

---

Interceptor

JPA 표준 API 에는 포함되지 않는 하이버네이트가 엔티티의 라이프사이클 이벤트를 처리하기 위해 추가로 제공하는 인터페이스입니다. Interceptor를 구현함으로써 엔티티의 로드, 저장, 삭제 등의 이벤트를 가로채고 특정 로직을 추가할 수 있습니다.

• onSave: 새로운 엔티티가 저장될 때 호출되며, 저장 전후에 특정 로직을 실행할 수 있습니다.
• onFlushDirty: 이미 존재하는 엔티티가 업데이트될 때 호출됩니다. 변경된 상태가 데이터베이스에 플러시되기 전후에 로직을 추가할 수 있습니다.
• onDelete: 엔티티가 삭제될 때 호출됩니다. 삭제 이벤트를 감지하고 필요한 로직을 수행할 수 있습니다.
• onLoad: 엔티티가 로드될 때 호출되며, 엔티티가 데이터베이스에서 조회될 때 특정 로직을 추가하는 데 사용됩니다.
• onCollectionRecreate: 컬렉션이 새로 생성될 때 호출됩니다. 주로 엔티티의 컬렉션 필드가 추가될 때 관련 작업을 수행할 수 있습니다.
• onCollectionRemove: 컬렉션이 삭제될 때 호출됩니다. 컬렉션 삭제 이벤트를 처리하는 데 유용합니다.
• onCollectionUpdate: 컬렉션이 업데이트될 때 호출됩니다. 컬렉션이 수정되면 이 메서드를 통해 관련 로직을 추가할 수 있습니다.
• preFlush: 트랜잭션이 커밋되기 직전에 호출되며, 플러시 작업 전에 수행할 로직을 정의할 수 있습니다.
• postFlush: 플러시 작업이 완료된 후 호출되며, 플러시 이후 처리할 로직을 구현할 수 있습니다.
• isTransient: 엔티티가 새롭게 생성된 상태인지, 즉 영속성이 없는 상태인지 여부를 확인할 수 있습니다.
• findDirty: 엔티티의 상태가 변경되었는지 여부를 확인하여 변경된 속성의 인덱스를 반환합니다.
• instantiate: 새로운 엔티티 인스턴스를 생성할 때 호출됩니다. 기본 생성자를 사용하지 않고 엔티티를 생성해야 할 경우 유용합니다.
• getEntity: 식별자로 엔티티를 직접 가져오는 메서드입니다. 특정 ID로 엔티티를 찾을 수 있습니다.
• afterTransactionBegin: 트랜잭션 시작 시 호출됩니다. 트랜잭션 시작과 관련된 초기화 작업을 수행할 수 있습니다.
• beforeTransactionCompletion: 트랜잭션이 커밋되기 직전에 호출되며, 커밋 전 처리할 작업을 정의할 수 있습니다.
• afterTransactionCompletion: 트랜잭션이 완료된 후 호출되며, 트랜잭션 종료 후 처리할 로직을 추가할 수 있습니다.

저는 이 중에서 OnLoad 를 통해 엔티티가 로드될 때, 해당 엔티티가 지연로딩으로 설정되었었는 지, 초기화가 되었는 지를 판단하여 로그를 찍기로 했습니다.

 

위의 SessionImpl 의 immediateLoad에서 로드할 엔티티의 프록시를 추출한 뒤 초기화를 하는 로직을 확인했고, 해당 내부 코드에서 LazyInitializer 에서 boolean isUninitialized(); 메서드를 확인했습니다. 해당 메서드는 엔티티가 초기화 되지 않았으면 true 를, 초기화 되었다면 false 를 반환하는 메서드입니다.

 

그래서 OnLoad 에서 감지된 엔티티가 HibernateProxy 의 타입인지 확인 후 초기화가 되었는 지를 판단하여 로그를 찍게 했습니다.

  @Override
  public boolean onLoad(Object entity, Object id, Object[] state, String[] propertyNames,
      Type[] types)
      throws CallbackException {
    if (entity instanceof HibernateProxy proxy) {
      if(!proxy.getHibernateLazyInitializer().isUninitialized()) {
        log.info("Lazy loading detected for field: {}", entity.getClass().getName());
      }
    }
    return false;
  }

 

결과는 의도한 대로 초기화 된 이후에 로그를 남기고 있었습니다.

---

 

 

후기

글에는 다 적지 못하였지만 많은 삽질을 하며 공부가 되었습니다.