삽질기 - Could not write JSON: failed to lazily initialize a collection of role

삽질의 여정

 이번 삽질의 여정은 다음과 같다.

1. 에러 발생 - 지연 로딩
2. 삽질 (1) 디버깅 - PersistentBag
3. 삽질 (2) 로그 찍기 - 지연 로딩 꼼수
4. 삽질의 종착지 - OSIV(Open Session In View)
5. 마무리

 이번 글에서는 지연 로딩에 관한 삽질기지만, 지연 로딩을 자세하게 다루지는 않겠다.

 

에러 발생 - 지연 로딩

 서비스의 Restful API를 개발하고 있었다. Schedule 엔티티의 정보를 수정을 API로, 응답 값으로 수정된 Schedule를 내려줘야했다. MVC 패턴으로 개발하고 있었기에 다음과 같은 순서로 로직이 처리됐다.

1. 컨트롤러 단에서 요청을 받는다.
2. 컨트롤러가 서비스 단으로 파라미터를 전달한다.
3. 서비스가 수정 로직을 처리한다.
4. 서비스가 수정된 Schedule 엔티티를 컨트롤러로 반환한다.
5. 컨트롤러는 ResponseEntity 객체에 수정된 Schedule을 담아 응답한다.

 그런데 이 평화로운 흐름에 갑자기 500 에러가 터졌다. 서버 내부에서 에러가 발생한 것인데, 로그를 보면 4번의 수정까지 잘 된 것을 확인할 수 있었다.

update 로그 까지 잘 찍혔는데..

 그리고 DisptcherServlet이 에러 로그를 뱉기 전에 수상한 WARN 로그가 찍혀있었다. (첫 번째 줄)

2019-08-10 14:49:38.625  WARN 4925 --- [nio-8077-exec-1] .w.s.m.s.DefaultHandlerExceptionResolver : Resolved [org.springframework.http.converter.HttpMessageNotWritableException: Could not write JSON: failed to lazily initialize a collection of role: path.to.jobParameters, could not initialize proxy - no Session; nested exception is com.fasterxml.jackson.databind.JsonMappingException: failed to lazily initialize a collection of role: path.to.jobParameters, could not initialize proxy - no Session (through reference chain: path.to.Schedule["jobParameters"])]
2019-08-10 14:49:38.625 DEBUG 4925 --- [nio-8077-exec-1] o.s.web.servlet.DispatcherServlet        : Completed 500 INTERNAL_SERVER_ERROR
2019-08-10 14:49:38.634 DEBUG 4925 --- [nio-8077-exec-1] o.s.web.servlet.DispatcherServlet        : "ERROR" dispatch for PUT "/error", parameters={}
2019-08-10 14:49:38.644 DEBUG 4925 --- [nio-8077-exec-1] o.s.web.servlet.DispatcherServlet        : Exiting from "ERROR" dispatch, status 500

 WARN 로그 내용을 보면, 지연 로딩이 되어야 하는 컬렉션인 JobParamter의 프록시가 초기화되지 않았다고 한다. 즉, 5번에서 Schedule 엔티티를 Json 형태로 변환하는 과정에서 JobParameter가 로딩(초기화)되지 않은 상태여서 에러가 발생한 것이다.

잠시 엔티티 정보를 살펴보자면...

 엔티티인 Schedule 은 식별자와 등록자, Cron 정보와 함께 파라미터 정보를 담는 JobParameter 객체의 리스트를 가지고 있다.

@ElementCollection을 사용했다.

JobParameter의 리스트 즉, jobParamters는 기본 로딩 전략인 지연 로딩 방식으로 로딩된다. 앞서 언급한 것과 같이 지연 로딩 방식에서는 설명하지 않겠다.

삽질 (1) 디버깅 - PersistentBag

 에러가 발생하면 디버깅을 하는 것이 개발자의 기본 아닌가!? 그래서 디버깅을 해봤더니, 분명 List 타입 여야 하는 jobParameters가 PersistentBag으로 나타났다.

 이건 뭔가 단단히 잘못된 것이다.(라고 생각했었다.)

처음 보는 놈인데..

PersistentBag?

 속성의 설정을 뭔가 잘못했나? 하면서 코드를 몇 번쯤 더 다시 본 후에야 PersistentBag에 관해서 찾아보기로 했다. 결론부터 정리하면 PersistentBag은 Hibernate 가 엔티티의 컬렉션 속성에 관한 영속성을 관리하기 위해 제공하는 래퍼 클래스이다.

 테이블 간 관계는 보통 일대다, 다대일, 다대다 관계를 가진다. 이러한 관계를 객체로 표현하게 되면, Collection, List, Set 등으로 나타낼 수 있다. JPA의 기본 구현체인 Hibernate는 이러한 컬렉션 속성들의 영속성을 추적하고 관리하기 위해 Collection Wrapper를 제공한다. 컬렉션 래퍼는 순서 보장(List), 중복 방지(Set) 등과 같은 컬렉션 타입에 따라 컬렉션을 감싼다. 여기서 jobParameters는 List 타입이기에 PersistentBag으로 감싸진 것이다.

 컬렉션 래퍼는 컬렉션 속성의 영속성을 관리한다. 즉, 컬렉션의 지연 로딩을 관리하는 것도 이 컬렉션 래퍼가 한다. 그렇다면 PersistentBag 객체를 통해 강제적으로 초기화하면 되지 않을까?

크으.. 뭔가 깊게 알아가는 느낌이었다.

 위 코드를 통해 초기화가 되었기 때문에 에러가 발생하지 않았다. 그런데 이상했다. 이전 프로젝트에서도 지연 로딩을 안 쓴 것도 아니고, 다른 프로젝트에서도 이 PersistentBag에 관한 코드를 본 적이 없었다. 그렇다. 뭔가 잘못된 접근인 것이다.

삽질 (2) 로그 찍기 - 지연 로딩 꼼수

 지연 로딩이 적용된 속성이 초기화되는 시점은 해당 속성에 getXXX()와 같이 접근했을 경우이다. Lombok을 사용하고 있었고, 해당 엔티티에는 @ToString을 적용해놨다. 여기서 나의 꼼수 회로가 다음과 같이 정신 승리의 과정을 거쳤다.

1. 그래 어차피 로그를 찍어야 돼!!
2. 로그를 찍으면 toString()를 통해 속성에 접근할거고, 초기화가 될 거야!
3. PersistentBag을 보지 못한 것은 다들 로그를 찍었기 때문일 거야..
4. 강제 초기화 코드보다 더 심플하잖아?!

이것도 분명 뭔가 잘못됐다.

삽질의 종착지 - OSIV(Open Session In View)

 나는 뭔가 잘못된 느낌과 함께 깊은 고민에 빠졌다.

• (1) 방식으로 강제 초기화를 할 것인가?
• (2) 방식으로 꼼수를 부릴 것인가?

 나 혼자 판단하는 것은 답이 나올 것 같지 않았다. 그래서 옆자리에 계신 수석님께 여쭤봤다. 수석님은 딱 이 표정이셨다.

강제 초기화? 로그를 찍어? 뭔소리야...

 결론은 스프링에서 제공하는 옵션인 OSIV(Open Session In View)을 사용하는 것이었다. OSIV 옵션은 말 그래도 세션을 뷰 영역까지 가져가는 것이다.

 Hibernate는 DB와 연결을 관리를 위해 Session 객체를 사용한다. 이 세션 객체는 트랜젝션 영역에 들어가고 나감에 따라 커넥션을 열고 닫으면서 영속성을 관리한다. 즉, 트랜젝션 영역에 들어가며 필요에 따라 영속화하고, 트랜젝션 영역을 나가면서 변경사항을 flush 하고 커넥션을 종료한다. 일반적인 트랜젝션 영역은 영속성과 관련된 처리를 담당하는 서비스 영역이며, 이번 프로젝트에서는 @Transactional이 적용된 서비스 영역이었다.

OSIV를 사용 안 했을 때.

 OSIV 옵션은 기본적으로 false이다. 그렇기 때문에 서비스 영역에서 반환되어 컨트롤러 영역으로 넘어온 객체는 더 이상 hibernate가 영속성을 관리하지 않는다. 그렇기 때문에 초기화되지 않은 PersistentBag은 프록시 형태로만 존재하고, 더 이상 hibernate를 통해 초기화될 수도 없기 때문에 지연 로딩과 관련된 에러를 뱉은 것이다.

OSIV를 사용하면?

 OSIV 옵션을 사용하면 세션이 컨트롤러 영역에서도 열려있는다. 즉, 서비스 영역에서 트랜잭션이 끝나도 DB 와의 커넥션이 살아있으며, hibernate가 이 세션을 통해 PersistentBag을 초기화할 수 있다. 결국 컨트롤러 영역에서 최종적으로 객체를 Json으로 맵핑하는 과정에서 ObjectMapper가 jobParameters에 getter로 접근하는데, 세션이 아직 열려있기 때문에 hibernate가 이 과정에서 DB에 접근하여 초기화할 수 있는 것이다.

 다른 프로젝트에서는 다들 이 옵션을 사용했기 때문에 강제 초기화든, 로그든, 신경 쓸 필요가 없었던 것이다.

OSIV의 치명적인 단점

 OSIV를 적용하면 트랜젝션은 종료되지만 세션은 열려있는다. 즉, 트랜젝션 종료 시점과 flush 가 되는 시점과 같지 않다는 것이다. 이는 다음과 같은 상황에서 치명적인 단점을 가진다. 회원 정보를 나타내는 상황을 가정해보자.

1. 컨트롤러에서 요청을 받는다.
2. 서비스 영역에서 회원 정보를 가져온다. (트랜젝션 종료)
3. 컨트롤러에서 민감한 정보인 회원 주민등록번호를 setter를 통해 `1****`로 변환한다.
4. 서비스 영역에 다시 접근하여 어떤 로직을 처리한다. (트랜젝션 재 생성 및 종료)
5. 컨트롤러에서 반환한다.

 위와 같은 단계로 처리되면 응답과 함께 flush가 되며 DB에 저장된 회원의 주민등록번호는 1******로 변환되게 된다. 4번에서 트랜젝션을 다시 시작하고 종료될 때, 이 과정에서 3번을 통한 엔티티 객체가 다시 영속성을 가지게 되고 setter로 처리했던 작업이 5번에서 함께 flush 되기 때문이다. 이러한 부작용을 피하기 위해선 다음과 같이 3, 4번 과정을 바꿔야 한다.

1. 컨트롤러에서 요청을 받는다.
2. 서비스 영역에서 회원 정보를 가져온다. (트랜젝션 종료)
3. 서비스 영역에 다시 접근하여 어떤 로직을 처리한다. (트랜젝션 재 생성 및 종료)
4. 컨트롤러에서 민감한 정보인 회원 주민등록번호를 setter를 통해 1******로 변환한다.
5. 컨트롤러에서 반환한다.

 즉, OSIV 옵션을 사용하게 되면 영속성과 트랜젝션 관리에 조금 더 신경을 써야 한다. 쉽고 강력한 옵션인 만큼 염두해야 하는 사항이 꽤나 무겁다.

마무리

 뭔가 쌔한 느낌을 많이 받은 삽질기였다. 이번 삽질을 통해 Collection Wrapper에 관해 새로 배울 수 있었으며, 이전에 배웠던 OSIV 옵션에 관해 다시 복습할 수 있었다.