[Java] 스택 트레이스(Stack Trace) 제대로 알고 읽기
본 내용은 OKKY에서 활동하시는 fender 님의 게시물을 참고하여 작성하였습니다.
https://okky.kr/articles/338405
스택 트레이스란?
스택 트레이스는 프로그램이 시작된 시점부터 현재 위치까지의 메서드 호출 목록이다.
스택 트레이스는 예외가 발생할 경우 JVM이 어디서 예외가 발생했는지 알려주는 역할을 한다.
스택 트레이스 예시
다음 코드는 강제로 NPE(NullPoniterException)를 발생시키는 코드이다.
대체로 개발을 하게 되면 여러 클래스를 참조하며, 외부 클래스의 메서드를 호출하면서 예외가 발생하기 때문에 다음과 같이 작성했다.
public class StackTraceTest {
public static void main(String[] args) {
Class1.method1();
}
static class Class1 {
public static void method1() {
Class2.method2();
}
}
static class Class2 {
public static void method2() {
Class3.method3();
}
}
static class Class3 {
public static void method3() {
throw new NullPointerException();
}
}
}
Exception in thread "main" java.lang.NullPointerException
at hello.jdbc.exception.basic.StackTraceTest$Class3.method3(StackTraceTest.java:23)
at hello.jdbc.exception.basic.StackTraceTest$Class2.method2(StackTraceTest.java:17)
at hello.jdbc.exception.basic.StackTraceTest$Class1.method1(StackTraceTest.java:11)
at hello.jdbc.exception.basic.StackTraceTest.main(StackTraceTest.java:6)
스택 트레이스는 예외가 발생한 시점부터 시작하여 프로그램이 시작하는 곳까지 출력한다.
따라서 규모가 큰 코드일수록 스택 트레이스는 길어지며 분석하기 힘들다고 느끼기 쉽다.
스택 트레이스를 볼 줄 알아야 하는 이유
https://okky.kr/articles/338405
위 링크의 내용에 의하면 다른 사람이 짠 소스 코드에서 문제가 발생했을 경우, 코드 전체를 분석하지 않더라도 스택 트레이스를 잘 읽을 줄만 안다면 해당 코드의 문제 원인을 분석할 수 있다고 한다.
스택 트레이스를 분석하는 능력은 실무에서도 중요하게 여겨지며 개발자의 필수 역량이다.
나 또한 예외가 발생했을 경우 스택 트레이스를 분석하고 원인을 찾아 해결하는 것이 아닌 코드만 바라보며 많은 시간을 허비한 경험이 많다.
스택 트레이스 분석하기
대부분의 스택 트레이스는 다음과 같이 상당히 길게 출력하는 경우가 많아 다가가기 힘들다고 느끼기 쉽다. 하지만 해당 코드를 분석하여 문제의 원인을 파악해 보자.
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
위 스택 트레이스는 두 가지 예외에 대한 내용을 포함하고 있다.
java.lang.reflect.InvocationTargetException
...
Caused by: java.lang.NullPointerException
...
- InvocationTargetException
- NullPointerException
먼저, 위 문제에서 집중해야 할 곳은 InvocationTargetException이 아닌 NullPointerException이다.
Caused by:에 표시되는 NPE부분을 자세히 들여다보자.
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)
...
- com.mycompany.service.impl 경로에 존재하는
- PortalManagerImpl 클래스의
- deletePortal() 메서드의 358번째 줄을 실행하던 중,
- com.mycompany.service.impl. 경로에 존재하는
- PortalManagerImpl 클래스의
- deleteMenuItem() 메서드의 603번째 줄에서 NPE가 발생했다.
PortalManagerImpl 클래스의 예외와 관련된 코드 부분은 다음과 같다.
if (item == null) {
throw new NullArgumentException("item");
}
//중간 생략
List<PortalMenu> children = getMenuItems(item.getPortal().getId(), item.getId()); // 603번째 줄
for (PortalMenu child : children) {
deleteMenuItem(child);
}
위 코드에서 NPE가 발생할 수 있는 경우의 수는 다음과 같다.
- children
- item
- item.getPortal()
- item.getPortal().getId()
- item.getId()
1 : children
children 변수에 null값이 할당되었다고 해서 NPE가 발생할 수 없다.
NPE는 명확하게 객체의 널값 참조에 메서드 호출이나 필드 참조 등의 작업을 했을 때 발생하는 문제이기 때문이다.
4, 5 : item.getPortal().getId(), item.getId()
만약 item.getPortal().getId()와 item.getId()이 null이라면 이는 null값 참조에 대한 호출이 아닌 널값을 getMenuItems 메서드의 인자로 넘기는 것뿐이기 때문에 NPE가 발생하는 원인이 될 수 없다.
따라서, 해당 코드의 원인은 2번 또는 3번인 item과 item.getPortal() 둘 중 하나이다.
2 : item
다시 NPE 스택 트레이스를 보면, 603번째 줄에서 예외가 발생한다고 되어 있다.
코드상에서 item 변수는 위에서 널 체크를 하기 때문에 603번째 줄에서 널값을 가질 수 없다.
if (item == null) {
throw new NullArgumentException("item");
}
따라서 정답은 3번인 item.getPortal()이 된다.
스택 트레이스를 분석하는 것은 한 번에 되는 것이 아니다.
꾸준히 반복하여 스택 트레이스를 분석하여 문제를 해결하는 경험이 필요하다.
스택 트레이스를 피하지 않고 계속해서 들여다본다면 문제의 발생 원인을 쉽게 찾을 수 있을 것이고, 문제 해결하는 시간이 줄어들게 될 것이다.
뿐만 아니라 다른 사람이 작성한 코드에서 문제가 발생하더라도 전체적인 코드를 분석하지 않고 원인만 찾아내어 해결할 수 있는 능력이 생길 것이다.