로그를 남길 때 e와 e.toString()은 다르다

 오늘 테스트 중에 NullPointerException이 발생하는 상황이 있었고, 아래와 같이 로그를 남기고 있었다. 아래는 단순 예시.

이렇게 로그를 남기니 아래와 같은 결과가 있었다.

그런데 NullPointerException이 어디에서 발생하는지 알아야 처리를 할 수 있는데 저 정보만으로는 처리가 어려웠다. 그래서 스택트레이스를 표시해줘야했는데 아래와 같이 변경해서 표시할 수 있었다.

결과는 아래와 같다.

---

 그래서 문득 궁금해졌다. Exception의 최상위인 Throwable은 toString()을 어떻게 정의하고 있는지, 로그에서는 e와 e.toString()을 어떻게 처리하는지. 그래서 코드를 뜯어봤다! 참고로 로그 라이브러리로 logback을 사용하고 있다.

Logger 인터페이스

 위의 메서드를 먼저 살펴봤다.

 Logger 인터페이스를 구현한 Logger 클래스로 타고 가보면 아래와 같은 코드로 연결된다.

여기에서 buildLoggingEventAndAppend의 내부로 이동해보면 아래와 같은 코드를 만날 수 있다.

여기에서는 LoggingEvent를 만들어서 사용하는데, 이 내부를 살펴봐야 한다.

Throwable이 null이 아니기 때문에 LoggingEvent의 throwableProxy에 throwable이 들어가게 된다.

이 ThrowableProxy 생성자 내부를 보게 되면 throwable의 StackTrace를 ThrowableProxy가 갖게 되는 걸 알 수 있다.

이렇게 LoggingEvent가 만들어지고 나면 아래와 같이 로그를 만들 때 ThrowableProxy에서 StackTrace를 꺼내어 사용하게 된다.

String stackTrace = tpc.convert(event); 이 부분에서 tpc는 ThrowableProxyConverter이다. 이때 stackTrace를 보면 아래와 같다.

우리가 로그를 찍어서 확인할 수 있는 스택트레이스가 들어 있다.

 그럼 e.toString() 으로 확인하는 건 어떤 차이가 있는지 보았다.

 이때 제일 마지막에 들어가는 인자가 Throwable인데 보시다시피 null로 들어가고 있다는걸 확인할 수 있다. 이때 우리가 넘기는 e.toString()은 아래처럼 넘어가게 된다.

filterAndLog_1의 내부를 통하면 제일 마지막 buildLoggingEventAndAppend로 통하게 된다.

들어가보면 역시나 LoggingEvent를 만들게 되어 있다.

이때 사용하는 생성자는 Throwable을 넘겼을 때의 LoggingEvent 생성자와 같다.

이때 e를 e가 아닌 e.toString()으로 넣었기 때문에 스택트레이스를 넣어주는 부분을 지나치게 된다.

결국 e.toString()으로 넣으면 애초에 스택트레이스 정보를 넣어주지 않는다는게 된다. 그래서 Throwable의 toString()을 살펴보았다.

Throwable의 클래스 이름(발생한 예외 이름)과 메시지만을 넘겨주고 있다.

---

결과적으로 어디에서 예외가 발생했는지 좀 더 자세하게 확인하고 싶으면 LOGGER.error(e)와 같이, 어떤 예외인지 간단하게 확인하고 싶으면 LOGGER.error({}, e.toString())와 같이 사용하는게 맞겠다.

Throwable로 넘기면 스택트레이스정보를 담고 있는 ThrowableProxy를 이용해서 LoggingEvent를 만들기 때문에 스택트레이스정보까지 출력하고, e.toString()으로 넘기면 예외명과 메시지를 String으로 넘기기 때문에 스택트레이스정보까지는 넘어가지 않는다.