[Tips] 스택 트레이스 읽기 에러 콘솔 읽는 법

초보 개발자를 위한 스택트레이스 읽는 법

커뮤니티에서 초보 개발자를 위한 스택 트레이스 읽는 법 이라는 좋은 글이 있어서 소개해드립니다

면접을 볼 때, 질문할 내용을 미리 정해놓지는 않지만 개인적으로 즐겨내는 문제가 있습니다. 널포인터 예외(NullPointerException)의 원인을 찾는 문제인데, 전에 다니던 회사에서는 실제 제품개발 중에 발생한 오류 보고서가 있어서 면접보시는 분들께 해당되는 소스 파일과 함께 제시하고 원인을 찾아보도록 한 적이 있습니다.

처음보는 다른 사람이 짠 소스를 어떻게 분석할 수 있을까 의아할 수 있지만, 실제로 널포인터 예외는 개발중에 매우 흔히 경험하는 오류이고 특성상 정확한 의미만 알고 있다면 거의 대부분 즉시 정확한 원인을 분석할 수 있습니다. 또한 그러기 위해서는 스택트레이스를 읽을 수 있는 능력이 필요합니다.

개인적으로 예외 처리는 초보 개발자가 가장 중요성을 간과하기 쉬운 분야라고 생각합니다. 예외처리라고 하면 단순하게 '그냥 try-catch하면 되는 게 아닌가?'라고 쉽게 생각할 수도 있지만 사실 이야기를 하자면 상당한 설계 차원의 지식이 필요한 문제가 예외처리입니다.

초보 개발자 분들이라면 그렇게 깊게까지 파고들 필요는 없겠지만 최소한 스택트레이스는 정확히 읽을 줄 알아야지만 빠른 디버깅이 가능한 만큼 이 부분에 대해서만은 시간을 투자해서 정확한 지식을 쌓아둘 필요가 있다고 생각합니다.

이번 면접에서 제가 제시한 스택 트레이스는 이렇습니다 :

java.lang.reflect.InvocationTargetException
     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
     at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
     at java.lang.reflect.Method.invoke(Unknown Source)
     at com.mylibrary.ap.xul.builder.handler.MethodCallback.invokeCallback(MethodCallback.java:32)
     at com.mylibrary.ap.xul.builder.handler.ViewHandler.invokeActionResult(ViewHandler.java:581)
     at com.mylibrary.ap.xul.context.impl.ViewContextImpl$2.onActionResult(ViewContextImpl.java:283)
     at com.mylibrary.ap.xul.context.impl.ActionContextImpl.setResult(ActionContextImpl.java:90)
     at com.mylibrary.ap.xul.action.stock.DialogAction.handleDialogClose(DialogAction.java:156)
     at com.mylibrary.ap.xul.action.stock.DialogAction$1.windowClosed(DialogAction.java:142)
     at com.mylibrary.api.Window.fireWindowClosedEvent(Unknown Source)
     at com.mylibrary.api.Window.onClose(Unknown Source)
     at com.mylibrary.api.platform.WindowBase.BaseClose(Native Method)
     at com.mylibrary.api.platform.WindowBase.BaseClose(Unknown Source)
     at com.mylibrary.api.Window.close(Unknown Source)
     at com.mylibrary.ap.xul.ui.MessageDialog.handleButtonClick(MessageDialog.java:145)
     at com.mylibrary.ap.xul.ui.MessageDialog$1.handleClick(MessageDialog.java:134)
     at com.mylibrary.api.ClickableSupport.fireClickEvent(Unknown Source)
     at com.mylibrary.api.ClickableSupport.handleAction(Unknown Source)
     at com.mylibrary.api.Button.actionHook(Unknown Source)
     at com.mylibrary.api.Component.action(Unknown Source)
Caused by: java.lang.NullPointerException
     at com.mycompany.service.impl.PortalManagerImpl.deleteMenuItem(PortalManagerImpl.java:603)
     at com.mycompany.service.impl.PortalManagerImpl.deletePortal(PortalManagerImpl.java:358)
     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
     at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
     at java.lang.reflect.Method.invoke(Unknown Source)
     at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:307)
     at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:182)
     at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
     at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
     at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
     at org.springframework.security.intercept.method.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:66)
     at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
     at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
     at $Proxy54.deletePortal(Unknown Source)
     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
     at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
     at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
     at java.lang.reflect.Method.invoke(Unknown Source)
     at com.mycompany.util.SpringSecurityContextInvocationHandler.invoke(SpringSecurityContextInvocationHandler.java:62)
     at $Proxy84.deletePortal(Unknown Source)
     at com.mycompany.ui.binding.PortalDataProvider.doDelete(PortalDataProvider.java:81)
     at com.mycompany.ui.binding.PortalDataProvider.doDelete(PortalDataProvider.java:12)
     at com.mycompany.ui.binding.AbstractEISDataProvider.delete(AbstractEISDataProvider.java:105)
     at com.mylibrary.ap.xul.binding.dataset.impl.DatasetImpl.doCommit(DatasetImpl.java:90)
     at com.mylibrary.ap.xul.binding.dataset.impl.AbstractDataset.commit(AbstractDataset.java:251)
     at com.mylibrary.ap.xul.binding.dataset.impl.AbstractDataset.deleteRow(AbstractDataset.java:201)
     at com.mylibrary.ap.xul.action.dataset.DeleteDataRowAction.execute(DeleteDataRowAction.java:22)
     at com.mylibrary.ap.xul.context.impl.ViewContextImpl.execute(ViewContextImpl.java:294)
     at com.mycompany.ui.portal.PortalInfoHandler.onPostConfirmDeleteAction(PortalInfoHandler.java:192)
     ... 21 more

상당히 길죠? 제가 본 많은 수의 초보 개발자분들은 이런 로그를 접하면 지례 겁을 먹고 정확하게 트레이스를 읽으려 들지 않습니다.

사실 예외를 읽는 법은 기초 중에서도 가장 중요한 내용이고, 처음 자바 언어를 배우는 모든 개발자가 반드시 숙지해야할 내용인데도 오히려 제대로 아는 초급 개발자를 만나기 힘든 것을 보면 도대체 자바 학원이라는 곳에선 무엇을 가르치는 건가 의아한 생각이 듭니다.

오류가 발생하면 무조건 오류 메시지부터 완벽하게 이해해야합니다. 왜 책에서 본대로 쳤는데 안되나, 왜 어제까지 됐는데 갑자기 안될까, 아니면 인터넷에서 한 번 찾아볼까 등의 생각은 일단 오류부터 제대로 읽어보고 해도 늦지 않습니다.

예외처리를 제대로 작성한 코드라면 거의 대부분의 문제는 스택트레이스 안에 답이 있기 때문입니다.

우선 위의 예의 경우 트레이스가 두 가지 예외 내용을 포함하고 있다는 것을 바로 파악할 수 있어야 하며, 문제의 진정한 원인은 윗쪽의 트레이스가 아니라 'Caused By:'로 표시되는 널포인터 예외 부분임을 인지할 수 있어야 합니다.

일단 문제에 대한 원인이 되는 트레이스를 찾았다면 그 다음은 트레이스를 읽어야 하는데, 이제까지 꽤 많은 수의 초급 개발자들의 면접을 경험했지만 의외로 트레이스 읽는 법을 정확하게 아는 경우가 드물었습니다.

면접시 위의 트레이스를 보여주고 어쩔 줄 몰라할 경우 보통 힌트를 주고 예를들어 널포인터 예외가 찍힌 부분부터 아래쪽으로 단 세줄만 집중해서 무슨 뜻인지 해석해보라고 질문합니다. 즉,

Caused by: java.lang.NullPointerException
     at com.mycompany.service.impl.PortalManagerImpl.deleteMenuItem(PortalManagerImpl.java:603)
     at com.mycompany.service.impl.PortalManagerImpl.deletePortal(PortalManagerImpl.java:358)

이 부분을 보여주고 읽는 방법을 알고 있는지 묻는 질문인데, 이를 정확하게 'com.mycompany.service.impl.PortalManagerImpl' 클래스의 'deletePortal' 메소드 358라인에서 같은 클래스의 'deleteMenuItem'메소드를 호출했는데 해당 메소드 603번 째 줄에서 널포인터 예외가 발생했다'라고 해석할 수 있는 지원자가 많지 않았습니다.

아예 대답을 못하거나 트레이스를 위에서 아래로 해석하려 하거나 심지어 이를 '두 번의 널포인터 예외가 발생했다'로 해석하는 경우까지 있더군요. 이런 로그를 보고 곧바로 해당 클래스의 603번 째 줄을 찾아갈 수 있는 개발자와 '내가 뭘 잘못 쳐서 안되는 거지?' 하는 식으로 막연한 고민으로 시간을 허비하는 개발자를 상상해보시면 스택트레이스를 정확히 아는 것이 얼마나 디버깅과 관련한 개발생산성에 큰 도움을 주는 지 짐작 가능하시리라 생각합니다.

그리고 'PortalManagerImpl' 클래스의 관련된 소스는 다음과 같았습니다:

if (item == null) {
    throw new NullArgumentException("item");}

//중간 생략
List<PortalMenu> children = getMenuItems(item.getPortal().getId(), item.getId()); // 603번째 줄
for (PortalMenu child : children) {
    deleteMenuItem(child);
 }

신기하게도 아직까지 면접을 본 개발자 중에 이런 문제를 보고 곧바로 널포인터 예외의 원인을 짚어내는 지원자는 거의 없었습니다. 글을 읽으시는 분들은 모두 금방 답이 보이시나요?

많은 수의 지원자들이 'children'이나 'item.getId()' 등에 널값이 들어간 것 같다고 답했습니다. 이론적으로 해당 라인에서 널값이 들어갈 수 있는 모든 경우의 수는,

1. children
2. item
3. item.getPortal()
4. item.getPortal().getId()
5. item.getId()

이렇게 다섯 가지가 전부입니다.

이 중 적어도 두 가지, 즉 2번 혹은 3번으로 가능성을 바로 좁히지 못한다면 그것은 널포인터 예외의 의미를 정확하게 파악하지 못하고 있기 때문입니다.

널포인터 예외는 단순하게 변수에 널값이 들어가서 생기는 오류가 아닙니다. 널포인터 예외는 명확하게 객체의 널레퍼런스에 대해 메소드 호출이나 필드 참조 등의 작업을 했을 때 발생하는 문제라는 것을 이해한다면 이런 문제는 곧바로 원인을 좁힐 수 있어야 합니다.

즉, 1번의 경우처럼 단순히 변수에 널값을 할당하는 것만으로는 절대로 널포인터 예외가 날 수 없습니다. 그리고 만일 4 번 'item.getPortal().getId()'이나 5번 'item.getId()'이 널이라면 이는 널 레퍼런스에 대한 호출이 아니라 널값을 'getMenuItems'라는 메소드의 인자로 넘기는 것 뿐이기 때문에 역시 널포인터 예외의 원인이 될 수 없습니다.

물론 'getMenuItem' 메소드 안에서 해당 인자에 대한 널체크 없이 값을 사용하다가 예외가 날 수도 있겠지만 이 경우엔 절대로 트레이스 상에 굵은 글자로 표시된 603번 째에서 예외를 뿌리지 않습니다.

그렇다면 남은 가능성은 2번 'item'이 널이거나 3번 'item.getPortal()'이 널인 경우뿐인데, 'item' 변수는 위에서 널체크를 하기 때문에 603번 째 줄에서 절대로 널값을 가질 수 없습니다. 그렇기 때문에 답은 3번이 되는 것입니다.

너무 문제가 어렵나요? 길게 설명했지만 개발을 하면 매우 흔하게 접할 수 있는 예외이며 따져보면 결코 어려운 내용이 아닙니다. 위와 같은 문제는 이미 스택트레이스를 능숙하게 읽을 수 있고 널포인터 예외를 이해하고 있는 개발자라면 몇 초 안에 곧바로 원인을 파악할 수 있는 문제입니다.

예외만 읽을 줄 알면 단 몇 초만에 깨달을 수 있는 문제를 다른 개발자는 인터넷 검색과 의미없는 무작위 수정, 게시판 질문글 작성등으로 몇 시간씩 허비한다면 두 개발자 사이의 생산성의 차이는 엄청나게 벌어질 것입니다.

디버깅 같은 기본적 부분에서 나쁜 습관을 빨리 고치지 못한다면 시간 낭비도 문제지만 그 만큼 개발자로서 발전도 늦게되고, 나중에는 인터넷이 없으면 아무 것도 못하는 그냥 복사 붙여넣기만 단순 코더가 한계점이 될 수도 있습니다.

그런 점을 감안해서 이 글을 보는 초보 개발자들은 반드시 제대로된 문제 해결 방법을 공부하셨으면 좋겠습니다.

---

출처 : http://okky.kr/article/338405?note=1091903