1000번에 1번 발생하는 버그는 어떻게 해결할 것인가 (Core dump, 코어덤프, 예시 포함)

 개발 과정에서 아주 간헐적으로 발생하는 버그를 해결하기 위해 코어덤프를 활용했는데, 코어덤프가 왜 필요했는지를 설명하기 위해 삽질의 과정을 포함했다. 코어덤프가 어떤 것인지 궁금한 독자들은 바로 코어덤프(Core Dump) 부분을 확인하길 바란다.

삽질의 과정

 사내 라이브러리를 개발하는 과정에서 유닛테스트가 간헐적으로 실패하는 것을 발견했다. "10번에 1번", "30번에 1번"을 거쳐, 결국 "1000번에 1번" Segmentation Fault가 발생하는 라이브러리 유닛테스트를 구현하게 되었다.

 

 1000번에 1번 에러가 발생한다는 것을 증명하는 것은 생각보다 간단했다. Shell 스크립트를 작성해서 1000번 반복하게 하고, process의 return값이 0이 아닌 경우가 있으면 그대로 멈추도록 하면 됐다. 하지만, 에러가 존재한다는 것을 확인하는 것과 에러를 어떻게 찾을 것이냐는 또 다른 문제였다. std::exception에 의한 에러의 경우, 프로그램 에러 출력에서 어떤 문제가 발생했는지 알 수 있지만 Segmentation fault의 경우 어떤 문제가 발생했는지 직관적으로 알기는 어려웠다.

 

 지나고 보니 실수에 가깝지만, 가장 쉬운 방법으로는 로그를 남겨서 어느 부분에서 발생했는지를 찾으려는 시도도 해보았다. 하지만, 로그를 추가하니 에러가 사라지고 로그를 지우니 에러가 다시 발생하는 상황이었다. 타이밍이 중요한 에러여서 로그로는 파악이 어려운 이슈임을 확인했고, 기존에 gdb를 통해 segmentation fault는 쉽게 잡을 수 있었으니 그거와 script를 결합해야겠다는 생각을 하게 됐다. (정확한 라인 파악을 위해, 로그와 fflush(stdout) 명령어를 같이 넣었기 때문에 타이밍 이슈가 없어졌을 거로 예상한다)

 

 gdb를 반복시키는 것을 서베이 해보니, 가능은 하지만 gdb를 반복 실행하는 건 속도가 느릴 것임이 예상됐고 어렴풋하게 알고 있던 코어덤프라는 것을 활용해야겠다는 결정을 하였다.

코어덤프(Core Dump)

코어덤프는 보통 코어덤프 파일을 의미하고, 커널에서 프로세스가 특정 시그널들에 의해 종료되었을 때의 해당 프로세스의 메모리를 저장한 파일을 말한다.([1], [2]) 일종의 프로세스 에러 발생 시 스냅샷을 남긴다고 이해하면 된다. 추가로, 여기서 특정 시그널들에는 우리가 익히 알고 있는 SIGABRT, SIGSEGV가 포함된다.

 

이 코어덤프 파일들은 gdb를 이용해서 분석하면 된다. gdb를 통해 프로그램을 실행시키고 어디서 Segmentation Fault가 발생했는지를 찾는 것과 비슷한 효과를 볼 수 있다.

코어덤프 파일 생성 및 분석 예시

Ubuntu 환경에서 진행하였고, 에러 분석을 위해 아래 4가지 작업을 수행하였다.

 

1. 코어덤프 패턴 변경

 이 작업은 시스템에 한 번 덮어씌우면 계속 유지되는 것이기 때문에, 원래 설정으로 돌릴 것을 고려한다면 덮어씌우기 전에 기존 파일을 백업하기 바란다. 코어덤프 파일을 현재 디렉토리에 core.{process_id}의 파일명으로 저장하겠다는 명령어이다.

echo "core.%p" > /proc/sys/kernel/core_pattern
# echo "core.%p" | sudo tee /proc/sys/kernel/core_pattern

 

2. 코어덤프 파일 생성 활성화

 이 명령어는 저장하는 코어덤프 파일 크기 제한을 없애주는 명령어이다. 터미널 세션마다 적용되는 것이므로, 터미널을 바꿀 때마다 실행해주어야 한다.

ulimit -c unlimited

 

3. 프로그램 반복 실행 및 에러 탐지

 다음 스크립트를 작성하고 실행하였다. 내 경우에는 1000번을 반복하는 것을 의도하여 작성하였다.

#!/bin/bash

EXECUTABLE="./xxx_unit_test"

echo "Starting advanced crash search loop for: ${EXECUTABLE}"

for i in $(seq 1 1000)
do
    echo -ne "--- Run #$i of 1000 ---\r"

    # 실행 파일의 출력을 변수에 저장하여, 실패 시 원인 분석에 사용
    OUTPUT=$(${EXECUTABLE} 2>&1)
    EXIT_CODE=$?

    # 종료 코드가 0이 아니면 실패로 간주
    if [ $EXIT_CODE -ne 0 ]; then
        echo -e "\n\n!!! FAILURE DETECTED on run #$i !!!"
        echo "Exit code: ${EXIT_CODE}"

        # 리눅스에서 시그널로 종료된 프로세스는 128보다 큰 종료 코드를 가짐
        # (종료 코드 = 128 + 시그널 번호)
        if [ $EXIT_CODE -gt 128 ]; then
            SIGNAL_NUM=$((EXIT_CODE - 128))
            SIGNAL_NAME=$(kill -l ${SIGNAL_NUM}) # 시그널 번호를 이름으로 변환 (예: 11 -> SIGSEGV)

            echo "Type: CRASH (Terminated by signal ${SIGNAL_NAME})"
            echo "A 'core' file should have been generated."
            echo "You can now analyze it with: gdb ${EXECUTABLE} core.<pid>"
        else
            echo "Type: TEST ASSERTION FAILURE (or other non-signal error)"
            echo "No core dump file will be generated for this type of failure."
            echo "Displaying captured output to see the assertion error:"
            echo "-------------------- CAPTURED LOG --------------------"
            echo "${OUTPUT}"
            echo "------------------------------------------------------"
        fi

        break # 실패 원인을 찾았으므로 루프를 중단합니다.
    fi
done

# 1000번 동안 문제가 없었을 경우
if [ $i -eq 1000 ] && [ $EXIT_CODE -eq 0 ]; then
    echo -e "\n\nFinished 1000 runs without any failures."
fi

 

4. 코어덤프 파일 디버깅

 gdb를 통해 분석하였고, gdb 사용법에 대한 가이드는 구글에서 좋은 레퍼런스들이 많이 있으니 참고하길 바란다. 내 경우에는 backtrace를 보는 bt와 info threads 명령어를 사용해서 버그를 분석하였다.

gdb ./xxx_unit_test core.xxxx

Reference

[1]https://manpages.ubuntu.com/manpages/lunar/man5/core.5.html

[2]https://manpages.ubuntu.com/manpages/lunar/man7/signal.7.html