메아리 저널

버그는 어디에나 있다

오늘 얘기는 랜덤여신의 걸작품 인클봇에 대한 얘깁니다. 인클봇은 IRC를 써 보신 분이라면 아시겠지만 악의 축여기 저기서 돌아 가는 IRC 봇 서비스입니다.

인클봇은 현재 IRC 연결을 제공하는 여러 개의 클라이언트와 실제 작동을 수행하는 하나의 서버로 이루어져 있습니다. 그런데 이 인클봇이라는 게 웬만한 수의 채널에서 돌아 가는 게 아니라서 심심할 때마다 죽고, 어쩔 때는 인클봇 서버가 돌아 가는 서버를 죽여 버리기도 했지요. 그것때문에 루리넷이 완전히 죽어 버려서 재부팅하러 간 적도 몇 번 있습니다. 지금 생각해 보니까 진짜 악의 축 맞네

왜 인클봇이 서버를 죽이는 걸까요? 이 얘기를 하려면 좀 옛날 얘기를 꺼내야 합니다.

슈가큐브와 인클봇

먼 옛날…이라고 하기도 좀 그런데, 하여튼 슈가큐브라는 IRC 봇이 있었습니다. 당시 파이썬으로 짠 봇 중에서 쓸만해서 자주 쓰이던 거고, 예전에 돌리던 토끼냥이라는 봇도 원래는 슈가큐브에 직접 짠 플러그인들을 돌리는 식이었습니다.

슈가큐브는 파이썬으로 IRC 봇을 짜려는 사람들한테 큰 영향을 줬습니다. Tinicube도 그랬고, 인클봇도 슈가큐브의 모듈 형식과 라이브러리 설계를 많이 따랐습니다. 예를 들어서 슈가큐브의 플러그인은 파이썬 모듈 하나와 그 안에 있는 함수들로 이루어져 있는데, 인클봇도 (지금은 약간 다르지만) 같은 방식을 씁니다.

처음에 인클봇이 만들어졌을 때는 다양한 기능을 제공했지만, 가장 많이 쓰는 기능은 수학 계산 기능이었습니다. 계산기 두들기느니 IRC 하면서 계산도 하고 하자는 속셈이었죠.

<아무개> != sin(3)**2 + cos(3)**2
<인클봇> 1.0

이런 계산 기능을 가장 간단하게 구현하는 방법은 수식을 파이썬에서 바로 처리하게 하는 것입니다만, 이런 저런 문제가 많았습니다. 사람들은 이 문제들을 악용해서 인클봇(을 비롯한 여러 IRC 봇들)을 작동 불능한 상태로 만들길 즐겼는데 이를 "봇살"이라고 불렀습니다. 한때 유행하던 봇살의 형태는 다음과 같습니다.

<아무개1> != 2**2**22
<아무개2> != 2**2**22
<아무개3> != 2**2**22
*** 인클봇 님이 퇴장하셨습니다. (Ping timeout)

이러다 보니까 나중에는 인클봇에서 호출할 수 있는 함수에 제한도 걸고, 그래도 2**2**22 같은 코드가 난무해서 계산만은 다른 프로세스에서 돌아 가게 했습니다. 이 코드는 원래 슈가큐브에 있던 것으로 대강 다응과 같은 코드입니다. (에러 처리는 편의상 대부분 생략했습니다.)

def evalrun(code):
    readp, writep = os.pipe()
    pid = os.fork()
    if pid: # parent
        os.close(writep)
        while True:
            pid, status = os.waitpid(pid, 0)
            if os.WIFEXITED(status): return os.read(readp, 8192)
            else: return 'ERROR'
    else: # child
        try:
            signal.alarm(3)
            os.write(writep, eval(code))
        finally:
            os._exit(0)

이렇게 해서 인클봇을 죽이려는 노력은 끝을 맺은듯 보였습니다. 하지만 세상은 그렇게 호락호락한 게 아닙니다.

버그

인클봇은 하나의 독립된 프로그램으로 돌아가는 버전 1, 여러 독립된 봇이 서로 동기화하면서 동작하는 버전 2를 거쳐 중앙 서버와 클라이언트들로 이루어진 버전 3으로 장족의 발전을 거듭했습니다. 하지만 초기에 인클봇 3은 매우 불안정하여 서버가 매일 죽는 것을 반복했습니다.

어느 정도였나고요? 한동안 인클봇 중앙 서버는 루리넷에서 돌아 갔는데, 어느날 루리넷 웹 서버가 죽어 버렸습니다. 용하게도 IRC 클라이언트는 돌아 가고 있길래 서버실에 들어 가서 콘솔로 조작해 보려고 했는데, 콘솔이 키 입력을 받지 않더군요. -_- 결국 재부팅했습니다.

이런 일이 하루가 멀다하고 발생해서 분석을 시도해 봤는데, 누군가가 엄청난 양의 리소스를 먹어서 다른 프로그램들의 실행이 불가능한 상태가 되었다는 것 말고는 얻을 수 있는 게 없었습니다. 루리넷에 돌아 가는 프로그램 중에 리소스를 많이 먹을만한 프로그램은 인클봇 중앙 서버 밖에 없었기 때문에 나중에는 다른 서버로 옮겨 놓고 그 서버도 죽는지 확인을 하기로 했는데, 아니나 다를까 잘 죽더군요. 상황은 인클봇한테 불리하게 돌아 갑니다.

이 버그가 바로 그저께(였나…) 고쳐졌습니다. 랜덤여신이 리소스를 확인하기 위해서 lsof로 열린 파일들의 목록을 보는데 파이프가 수백개 열려 있는 채로 방치되어 있더군요. 뭔가 이상하다고 짐작하고 os.pipe를 쓰는 부분을 뒤지니 계산 기능 뿐. 아하!

def evalrun(code):
    readp, writep = os.pipe()
    pid = os.fork()
    if pid: # parent
        os.close(writep)
        try: # <--
            while True:
                pid, status = os.waitpid(pid, 0)
                if os.WIFEXITED(status): return os.read(readp, 8192)
                else: return 'ERROR'
        finally: # <--
            os.close(readp) # <--
    else: # child
        try:
            signal.alarm(3)
            os.write(writep, eval(code))
        finally:
            os._exit(0)

부모 프로세스에서 파일을 제대로 닫아 주지 않았군요! 허허허… (자식 프로세스는 os._exit를 호출할 때 파일이 자동으로 닫힙니다.)

이 문제점은 슈가큐브에도 마찬가지로 남아 있으며, 3년 반 전에 처음으로 부프로세스가 도입된 이래 한 번도 알려지지 않았습니다. 하지만 인클봇이 코드를 갖다 쓰는 덕분에 문제가 확대되고, 급기야는 죄 없는 제 서버-_-가 죽게 했지요.

버그는 어디에나 있습니다. 아마 우리는 버그를 피할 수 없을 지도 모릅니다. 중요한 것은 그 버그를 어떻게 찾아 내고 고치느냐가 아닐까 싶네요. ;)

이 글은 본래 http://mearie.org/journal/2007/11/bugs-are-everywhere에 썼던 것을 옮겨 온 것입니다.


(rev 1d46270eb038)