cloud function 호출 시 context의 중요성에 대해 알아보자.

1. url을 통해서 함수를 실행하면 최초 실행 후 일정 시간동안은 몇번을 호출하든 결과가 정상적으로 반환합니다.
2. 하지만 이후 500 에러를 반환하기 시작합니다. 심지어 이 전에 정상적으로 반환했던 url을 그대로 호출해도 500 error를 반환하는 어처구니 없는 모습을 보여줍니다.
3. 게다가 500 에러를 반환하는 경우엔 로그조차 남지 않아서 원인을 지레짐작으로 파악할 수 밖에 없는 상황입니다.
4. 물론 local test시에는 매우 잘 동작합니다.

절망하다가 차츰 화가 나기 시작합니다.

처음에는 에러가 무작위로 발생한다고 생각했지만 여러번의 테스트를 해본 결과, 함수 배포 후 첫 호출 이후 60초 동안은 파라메터가 잘못되지 않는 이상 절대 에러가 발생하지 않았습니다. 이 60초 라는 시간이 대체 어디서 나온 녀석인지 알아보기 위해서 클라우드 콘솔 화면을 여기저기 뒤적이다가 다음과 같은 화면을 발견했습니다.

60초라는 키워드가 등장하는 제한 시간 옵션입니다. 개발자가 별도로 설정하지 않는다면 기본값으로 60초가 할당되는데 문제가 발생하는 기준인 최초 호출 이후 60초라는 제한 시간이 여기서 나왔다고 추측했습니다. 이후 이 값을 10초로 수정 후 테스트를 진행했더니 실제로 10초 뒤에 동일한 에러가 발생하였습니다.

물론 이 사실을 안다고 해서 버그를 수정하는데 직접적으로 도움이 되는건 아니지만 개발자의 직감에 도움이 됩니다. 함수 제한 시간과 관련이 있단 사실을 알고나니 갑자기 context가 원인이지 않을까 싶어서 관련 코드를 좀 살펴보았고, 결과부터 말하자면 context 관련 문제가 맞았습니다.

이제 실제 코드를 살펴봅시다. imagick-cf에서 context 관련 버그를 수정한 커밋은 여기입니다. 어떻게 수정했는지는 커밋내역을 살펴보시고 여기서는 간략하게 일부분만 떼어서 살펴보겠습니다.

1
2
3
4
5
6

func OptimizeImage(w http.ResponseWriter, r *http.Request) {
...
originalImage := bucket.Object(imageName)
originalImageReader, err := originalImage.NewReader(context.Background()) // we have problem.
...
}

1
2
3
4
5
6

func OptimizeImage(w http.ResponseWriter, r *http.Request) {
...
originalImage := bucket.Object(imageName)
originalImageReader, err := originalImage.NewReader(r.Context()) // good!
...
}

직접 띄우는 서버가 아니라 cloud function에서 가볍게 돌아갈 코드라고 너무 대충 작성한 제 과오를 반성합니다. 실제 클라우드 환경에서만, 그것도 로그가 안남는 버그가 발생해서 많이 당황했지만 그래도 아무생각 없이 대충 써왔던 context에 대해서 다시 한번 신경쓰는 계기가 되는 경험이었습니다. 문제를 해결하고 보니 다른 언어를 사용했으면 이런 context 관련 문제는 마주치지 않아도 되지 않았을까 생각했지만 그래도 golang은 여전히 저한테는 매력적인 언어입니다. 언어를 탓하지 않고 제가 짠 코드를 탓하는게 맞겠지요. 아무튼 재미있는 경험이었습니다.

한 줄 요약: http trigger로 호출한 함수 안에서는 context.Background() 대신 request.Context() 를 사용합시다.