나는 Go에서 Error가 발생할 때 Stack Trace를 함께 출력하는 ‘Golang Error Stack Trace와 로깅’ 라는 글을 쓴 적이 있다. 하지만 시스템을 운영하면서 Panic을 Recover한 경우 Error Stack Trace가 출력되지 않는다는 것을 발견했다.

이 글은 ‘Golang Error Stack Trace와 로깅’ 에 이어지는 글로 Panic을 Recover한 경우에도 Stack Trace를 출력하는 방법을 소개한다.

Panic

우선 Go에서는 Java와 같은 Exception이 없다. 명시적으로 Error를 전달하여 처리하며 관용적으로 마지막 반환 값을 사용한다. 아래 코드를 보면 f1 함수를 호출할 때 반환 값의 error가 nil 이 아니면 error가 발생한 것이다.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
func main() {
	result, err := f1(1)
	if err != nil {
		fmt.Println("error", err)
	} else {
		fmt.Println("result", result)
	}
}
func f1(arg int) (int, error) {
	if arg == 42 {
		return -1, errors.New("can't work with 42")
	}
	return arg + 3, nil
}

예상되는 Error는 위와 같이 처리하지만 런타임 상에서 예상치 못하는 에러가 발생하는 경우 어떻게 될까? Panic이 발생한다.

panic은 일반적으로 무언가가 예상치 못하게 잘못되었음을 의미합니다. 패닉의 일반적인 사용은 어떤 함수가 어떻게 처리할지 모르는 (또는 하고 싶지 않은) 에러값을 반환했을때 중단을 하기 위함입니다. https://mingrammer.com/gobyexample/panic/

Panic이 발생하면 프로그램이 즉시 종료된다. 아래 코드를 실행해 보자.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
func main() {
	result, err := f1(42)
	if err != nil {
		fmt.Println("error", err)
	} else {
		fmt.Println("result", result)
	}
}
func f1(arg int) (int, error) {
	if arg == 42 {
		var str *string
		if *str == "test" {
			// ...
		}
		return arg + 4, nil
	}
	return arg + 3, nil
}

실행 결과는 아래와 같다.

1
2
3
4
5
6
7
8
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x2 addr=0x0 pc=0x102756b60]
goroutine 1 [running]:
main.f1(...)
        /Users/yooyoungmo/go/src/article-panic-stack-trace/main.go:19
main.main()
        /Users/yooyoungmo/go/src/article-panic-stack-trace/main.go:8 +0x20
Process finished with the exit code 2

str 포인터 변수에 값을 할당하지 않고 값에 접근했기 때문에 invalid memory address or nil pointer dereference 에러 메시지와 함께 Panic이 발생하여 프로그램이 종료되었다.

Recover

앞서 Panic이 발생하면 프로그램이 즉시 종료된다고 언급했다. 하지만 Panic 이 발생하여도 종료되지 않아야 하는 경우가 있는데 대표적으로 웹 서버 애플리케이션이 있다. 웹 애플리케이션의 특징 상 여러 사용자가 동시에 사용하는데 Panic이 발생했다고 서버가 종료되어서는 안되기 때문이다.

Go에서는 Panic이 발생할 때 Recover라는 복구 방법을 지원한다. Panic이 발생하면 즉시 종료하지 않고 recover 를 통해 Panic을 복구하는 것이다.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
func main() {
	defer func() {
		if err := recover(); err != nil {
			fmt.Println("Recovered. Error:\n", err)
			// panic 복구
			// ...
		}
	}()
	result, err := f1(42)
	if err != nil {
		fmt.Println("error", err)
	} else {
		fmt.Println("result", result)
	}
}
func f1(arg int) (int, error) {
	if arg == 42 {
		var str *string
		if *str == "test" {
			// ...
		}
		return arg + 4, nil
	}
	return arg + 3, nil
}

위의 코드를 실행한 결과는 아래와 같다.

1
2
3
Recovered. Error:
 runtime error: invalid memory address or nil pointer dereference
Process finished with the exit code 0

Rocover 시에 Error Stack Trace 출력하기

recover를 통해 반환받은 Error를 출력해 보면 에러 메시지만 있다. 하지만 이 정보만으로는 어느 코드에서 Panic이 발생한 것인지 알 수 없다.

아래와 같이 debug.Stack()을 추가하면 Error Stack Trace를 확인할 수 있다.

1
2
3
4
5
defer func() {
	if err := recover(); err != nil {
		fmt.Println(fmt.Sprintf("Recovered. Error: %v \n %v", err, string(debug.Stack())))
	}
}()

1
2
3
4
5
6
7
8
9
10
11
12
Recovered. Error: runtime error: invalid memory address or nil pointer dereference 
 goroutine 1 [running]:
runtime/debug.Stack()
        /usr/local/go/src/runtime/debug/stack.go:24 +0x68
main.main.func1()
        /Users/yooyoungmo/go/src/article-panic-stack-trace/main.go:11 +0x38
panic({0x1023c6220, 0x10243d1b0})
        /usr/local/go/src/runtime/panic.go:838 +0x204
main.f1(...)
        /Users/yooyoungmo/go/src/article-panic-stack-trace/main.go:28
main.main()
        /Users/yooyoungmo/go/src/article-panic-stack-trace/main.go:17 +0x3c

Echo 웹 프레임워크로 확장하기

‘Golang Error Stack Trace와 로깅’ 글에서 Echo 웹 프레임워크에서 커스텀 에러 핸들러를 만들어 Stack Trace를 로깅하는 방법을 소개했다.

1
2
3
4
5
6
7
8
9
func customHTTPErrorHandler(err error, c echo.Context) {
  // ...
  if code == http.StatusInternalServerError {
    log.Errorf("%+v", err)
    c.String(code, "Internal Server Error")
  } else {
    c.JSON(code, msg)
  }
}

Panic을 Recover 한 경우 Stack Trace가 출력되지 않기 때문에 아래와 같이 변경하면 Stack Trace를 출력할 수 있다.

1
2
3
4
5
6
7
8
9
func customHTTPErrorHandler(err error, c echo.Context) {
	// ...
	if code == http.StatusInternalServerError {
		log.Errorf("%+v \ndebug stack %v", err, string(debug.Stack()))
		c.String(code, "Internal Server Error")
	} else {
		c.JSON(code, msg)
	}
}