Debugging(1) - 콜스택을 이용한 디버깅(누가 내 치즈를 옮겼을까?)

안녕하세요

이번엔 디버깅에 대해서 이야기 해보고자 합니다.

초급 개발자라면 대부분 대해서 개발중 디버깅에 상당한 시간이 소요될거라 봅니다.

물론 개발 능력이 뛰어난 개발자가 혼자 개발하는 경우, 검증이 많이 필요치 않는 경우는 제외하고 가겠습니다ㅋ

하지만 본인이 뛰어난 개발자라도, 프로젝트의 규모가 커지고 여러사람이 투입되어 동시에 개발하는 경우에는 다른 사람이 만들어 놓은 부분에 대해서는 디버깅이 필요 할 수 밖에 없습니다.

이 카테고리에서는 개발을 하면서 가장 많이 하는 디버깅할때 유용한 팁을 몇가지 소개하고자 합니다

그 첫번째로 콜스택을 이용한 디버깅 방법에 대해서 소개 하겠습니다

예를 들어 C라는 스트링을 받아서 숫자로 바꾸는 함수가 있다고 생각해보겠습니다

그리고 C를 호출하는 경우가 아래와 같이 여러 경로가 있을수 있습니다.

void A(boolean callB) {
    if (callB) {
        B();
    } else {
        D();
    }
}

void B() {
    C("1");
}

void D() {
    C(null);
}

void C(String value) {
     Integer.parseInt(value);
}

위의 경우 다음과 같이 호출이 될수가 있습니다

1) A -> B -> C

2) A -> D -> C

2번의 경로로 호출이 되면 NumberFormatException이 발생하면 다음과 같은 콜스택이 로그에 찍히게 됩니다

Caused by: java.lang.NumberFormatException: s == null
at java.lang.Integer.parseInt(Integer.java:577)
at java.lang.Integer.parseInt(Integer.java:650)
at com.test.myapplication.MainActivity.C(MainActivity.java:37)
at com.test.myapplication.MainActivity.D(MainActivity.java:33)
at com.test.myapplication.MainActivity.A(MainActivity.java:24)

위처럼 exception이 발생하면 우리는 A -> D -> C 순서대로 호출이 되고 C의 첫번째가 아닌 두번째에서 호출 되었다고 알수 있고 잘못된 부분을 찾아 가서 오류를 수정 할 수 있을겁니다.

그런데요. 만약 exception이 발생하지 않는 경우에는 어떻게 분석을 해야 할까요?

누군가가 값을 바꿨을 경우에는 어떻게 분석을 해야 할까요? 

D가 C를 호출할때 C(null)이 아닌 C("10")을 호출하고 10을 호출하는 함수를 찾으려면 어떻게 해야 할까요?

우선 쉽게 생각되는 방법은 C를 호출하는 B,D에 로그를 넣고, B와 D를 호출하는 A에 로그를 넣고 테스트를 해보면 알수 있겠죠?

하지만 만약 C를 호출하는 함수가 한 두개가 아닌 훨씬 많은 경우나 특정 값에 의해 달라지게 호출되는 경우는 어떻게 해야 할지 고민이 됩니다

이런 경우에 사용할수 있는 방식이 위와 같은 CallStack을 강제로 출력하게 하여 디버깅을 할 수 있습니다

Thread.currentThread().getStackTrace()

Thread (Java Platform SE 7 )

  

해당 함수를 얻어와서 로그를 찍어 보는 함수를 만들어보겠습니다

void C(String value) {
        showCallStack();
        Integer.parseInt(value);
    }

void showCallStack() {
    StackTraceElement[] stackTraceElements = Thread.currentThread().getStackTrace();
    for (StackTraceElement element : stackTraceElements) {
        Log.d("showCallStack", element.getClassName() + "." + element.getMethodName() + ":" + element.getLineNumber());
    }
}

해당 결과값은 아래와 같이 출력됩니다

com.test.myapplication D/showCallStack: dalvik.system.VMStack.getThreadStackTrace:-2
com.test.myapplication D/showCallStack: java.lang.Thread.getStackTrace:1538
com.test.myapplication D/showCallStack: com.test.myapplication.MainActivity.showCallStack:43
com.test.myapplication D/showCallStack: com.test.myapplication.MainActivity.C:38
com.test.myapplication D/showCallStack: com.test.myapplication.MainActivity.D:34
com.test.myapplication D/showCallStack: com.test.myapplication.MainActivity.A:25
com.test.myapplication D/showCallStack: com.test.myapplication.MainActivity.onCreate:60
com.test.myapplication D/showCallStack: android.app.Activity.performCreate:7136
com.test.myapplication D/showCallStack: android.app.Activity.performCreate:7127
com.test.myapplication D/showCallStack: android.app.Instrumentation.callActivityOnCreate:1271
com.test.myapplication D/showCallStack: android.app.ActivityThread.performLaunchActivity:2893
com.test.myapplication D/showCallStack: android.app.ActivityThread.handleLaunchActivity:3048
com.test.myapplication D/showCallStack: android.app.servertransaction.LaunchActivityItem.execute:78
com.test.myapplication D/showCallStack: android.app.servertransaction.TransactionExecutor.executeCallbacks:108
com.test.myapplication D/showCallStack: android.app.servertransaction.TransactionExecutor.execute:68
com.test.myapplication D/showCallStack: android.app.ActivityThread$H.handleMessage:1808
com.test.myapplication D/showCallStack: android.os.Handler.dispatchMessage:106
com.test.myapplication D/showCallStack: android.os.Looper.loop:193
com.test.myapplication D/showCallStack: android.app.ActivityThread.main:6669
com.test.myapplication D/showCallStack: java.lang.reflect.Method.invoke:-2
com.test.myapplication D/showCallStack: com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run:493
com.test.myapplication D/showCallStack: com.android.internal.os.ZygoteInit.main:858

위의 함수를 단순히 호출하면 위와 같이 로그를 확인할수 있습니다

위 함수를 조금더 가다듬어 보면 원하는 결과를 만들어 낼수 있습니다

자기 자신을 스택출력에서 제거할수도 있고, 호출되는 stack 의 사이즈를 조절 할 수도 있습니다.

    void showCallStack() {
        StackTraceElement[] stackTraceElements = Thread.currentThread().getStackTrace();
        int stackSize = stackTraceElements.length;
        if (stackSize > 0) {
            int startIndex;
            for (startIndex = 0; startIndex < stackSize; startIndex++) {
                if ("showCallStack".equals(stackTraceElements[startIndex].getMethodName())) {
                    //new Object() {}.getClass().getEnclosingMethod().getName()
                    startIndex = startIndex + 1;
                    break;
                }
            }
            int endIndex = startIndex + 4;
            while (startIndex < stackSize) {
                if (startIndex == endIndex) {
                    break;
                }
                Log.d("showCallStack", stackTraceElements[startIndex].getClassName() + "." + stackTraceElements[startIndex].getMethodName() + ":" + stackTraceElements[startIndex].getLineNumber());
                startIndex++;
            }
        }
    }

결과 값 :

com.test.myapplication D/showCallStack: com.test.myapplication.MainActivity.C:38
com.test.myapplication D/showCallStack: com.test.myapplication.MainActivity.D:34
com.test.myapplication D/showCallStack: com.test.myapplication.MainActivity.A:25
com.test.myapplication D/showCallStack: com.test.myapplication.MainActivity.onCreate:60

위 callStack을 호출하는 경우가 만능은 아닙니다

가령 message handler를 통해 메세지로 보내서 함수를 호출하는 경우, handler를 호출하는 함수는 나오지 않고 handler에서 호출되는 함수부터 나오게 되므로 원하는 결과를 얻어낼수가 없을 수도 있습니다.

하지만 여러곳에서 호출하는 함수를 디버깅할때, 순차적으로 호출되는 flow를 확인하고자 할때,

부제로 정해놓은 말처럼 "누가 내 치즈를 훔쳤을까"를 에 해답을 얻을 수 있는 실마리를 얻을수 있지 않을까 싶습니다

참고로 위 스택을 알아내는 함수는 오버헤드가 있어 디버깅 용도로만 사용하시기 바랍니다

감사합니다