TNF Needlworks

현재 텍스트큐브의 공지사항은 http://notice.textcube.org/ko/ 이곳을 통해 서비스되고 있습니다. 그런데 아마 아시는 분들은 아시겠지만 여기 접속 속도가 무지 느렸습니다. 페이지 하나 불러오는 데에만 5~15초 넘게 걸렸죠.;; 게다가 공지 블로그는 여러분들이 설치하신 텍스트큐브에서 관리자모드 로그인할 때 보여지도록 12시간마다 동기화되고 있기 때문에 다수의 텍스트큐브 사용자들이 이러한 속도 저하의 영향을 받을 수밖에 없었습니다.

엊그제 정말 딱 한 줄만 고쳐서 평균 접속 속도를 5~8초 가량 걸리던 것을 0.2~0.3초 정도 걸리도록 개선했습니다. 과연 무엇이 문제였을까요?

1. 텍스트큐브 자체의 속도가 느리지 않을까?
가장 먼저 해본 일이 세션 테이블을 비우는 것이었습니다. 서버 쪽에서 수십~수백 군데의 PC로부터 동시에 들어오는 HTTP 요청을 가지고 각자의 PC별로 현재 접속한 사용자를 잘 구분하여 처리하기 위해 세션이라는 것을 사용합니다. 사용자를 구분하는 것 말고도 현재 사용자의 상태에 관한 데이터를 가지고 있기도 하죠. 로그인 상태는 이 세션이 유효한 상태에서만 지속됩니다.

보통 이러한 정보를 파일 또는 데이터베이스 상의 특정 테이블에 저장하게 되는데, HTTP 특성 상 새로운 요청이 들어오지 않는다고 사용자가 웹페이지를 닫은 것인지 아니면 밥 먹으러 간 것인지 알 방법이 없습니다. (그래서 일정 시간이 지나면 개인정보 유출을 방지하기 위해 서버 쪽에서 세션을 만료시켜 자동 로그아웃되도록 해놓는 경우가 많죠) 이 만료 시간을 길게 설정할수록, 사이트의 동시접속자 수가 많을수록 서버가 동시에 유지하고 있어야 하는 세션 개수가 엄청나게 늘어나게 됩니다.

당연히 텍스트큐브 공지사항 블로그는 설치형 텍스트큐브를 설치한 온갖 곳의 서버로부터 공지사항 업데이트를 받고 있으므로 이러한 세션 수가 상당히 높게 유지됩니다. 그래서 혹시 DB가 느려져서 그런 것은 아닐까 했던 것이죠. 주절주절 썼는데 결론은 효과 없었다, 즉 이것이 원인이 아니었다는 겁니다. orz

그래서 텍스트큐브의 PHP 코드 자체가 느린 부분이 있나도 생각해봤습니다만, 같은 서버에서 동작하는 다른 텍스트큐브 및 PHP 기반 웹사이트들은 멀쩡했습니다. 그렇다면 PHP 자체의 속도가 느린 것은 아니었죠.

2. Apache 웹 서버의 속도가 느리지 않을까?
다음으로 살펴본 것은 Apache 웹 서버였습니다. 우선 시간 지연이 어떤 패턴으로 나타나는지 정확히 알아야 했기 때문에 wget, ab, Firebug 등등 온갖 벤치마킹 프로그램을 동원해서 어떤 경우에 그러한 심각한 시간 지연이 나타나는지 조사했습니다.

그 결과, 텍스트큐브가 HTML을 뿌려줄 때, 그리고 몇몇 리소스 파일(자바스크립트와 CSS)을 로딩할 때만 그런 현상이 발생하고, 서버 내에서 서버 자신으로 접속할 때는 그런 지연이 전혀 나타나지 않고 외부에서 접속할 때만 그렇다는 사실을 알아냈습니다. 또한 시간 지연은 매우 일정하게 5초 정도 발생하며, 실제 컨텐츠 전송은 시간 지연이 없으나 전송이 시작되기 전까지 기다리는 시간이 길다는 것을 알 수 있었습니다.

이러한 사실로부터, 이것이 네임서버(DNS)와 관련된 문제라는 것을 직감할 수 있었습니다. 우리가 홈페이지 주소를 입력하면 웹사이트가 뜨는 그 과정에는 홈페이지 주소를 실제 서버의 IP 주소(4자리 숫자로 된 그것)로 변환해야 하는데, 그런 변환 또는 역변환을 하는 서버가 네임서버입니다. 대부분의 웹서버들은 어떤 곳으로부터 접속이 들어왔는지 로그를 남기는데요, 이때 클라이언트의 IP 주소는 바로 알 수 있지만 그 클라이언트가 가진 도메인은 네임서버를 통해 조회해봐야만 알 수 있습니다.

그런데 이 역변환의 경우 네임서버에서 지원하지 않거나 네임서버에서 찾을 수 없는 경우 응답이 아예 돌아오지 않는 경우가 생깁니다. 그러면 웹서버는 일정 시간이 지나 timeout될 때까지 기다리고(그래야 로그를 남긴 후 웹페이지 내용을 전송할 수 있으므로), 클라이언트 PC를 사용하는 사용자 입장에서는 "응답을 기다리는 중" 상태로 그 시간만큼 똑같이 기다리게 됩니다.

그래서 첫번째로 한 것은 Apache 설정에서 네임서버를 이용하지 않도록 하는 것이었습니다. 하나의 IP 주소에서 여러 웹사이트를 서비스하기 위해 virtual host라는 것을 이용하는데 이것을 설정하는 방법에 따라 네임서버 접근이 발생할 수 있었기 때문에 이것도 모두 손보고, 텍스트큐브의 PHP 코드 내에서 자체적으로 네임서버 접근하는 부분이 있는지 검사하고, HostnameLookups 설정변수 및 로그 포맷에서 호스트 이름(도메인)이 들어가는지 모두 확인해서 제거하였습니다.

문제는 그래도 나아지지 않았다는 것이지요. T_T

최후의 수단으로 사용한 것은 strace라는 것입니다. Linux에서 시스템콜을 추적하여 로그로 남겨주는 프로그램인데, 이것을 이용하면 파일 입출력, 소켓 접근 등 운영체제의 도움을 받는 모든 부분을 다 들여다볼 수 있습니다. 네임서버에 접근하기 위해선 소켓을 이용해 인터넷에 접속해야 하므로, 웹서버가 네임서버와 어떻게 상호작용하는지 알 수 있는 것이죠. (아니면 특정 파일을 읽어야 하는데 하드디스크나 운영체제 내부적인 문제로 비정상적으로 오래 걸린다든지 하는 경우, 권한 문제인지 등도 상세히 알 수 있습니다.)

처음 시도했을 땐 웹서버의 구조 상 각각의 동시 요청을 처리하기 위해 여러 개의 프로세스를  만들도록 되어 있었기 때문에 로그가 너무 많이 나와서(간단한 텍스트 파일 하나 보여주기 위해서만도 수백개 이상의 시스템콜이 발생합니다) 분석이 불가능했습니다.

방법을 고민하던 중 니들웍스의 쿨엔지니어님이 프로세스를 한 개만 띄우도록 설정해보라고 조언해주셔서, 다른 웹사이트를 이 서버에서 모두 내리고(...) 딱 1개의 프로세스만 띄워서 얘가 notice.textcube.org에 대한 요청을 처리하도록 설정을 분리한 다음에서야 다음과 같은 데이터를 확인할 수 있었습니다.

socket(PF_FILE, SOCK_STREAM, 0)         = 16 <0.000101>

fcntl(16, F_GETFD)                      = 0 <0.000089>

fcntl(16, F_SETFD, FD_CLOEXEC)          = 0 <0.000090>

connect(16, {sa_family=AF_FILE, path="/var/run/avahi-daemon/socket"}, 110) = 0 <0.000094>

fcntl(16, F_GETFL)                      = 0x2 (flags O_RDWR) <0.000060>

fstat(16, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 <0.000091>

mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5429003000 <0.000092>

lseek(16, 0, SEEK_CUR)                  = -1 ESPIPE (Illegal seek) <0.000099>

write(16, "RESOLVE-ADDRESS ###.###.###.###\n", 31) = 31 <0.000075>

read(16, "-15 Timeout reached\n", 4096) = 20 <5.002403>

close(16)                               = 0 <0.000068>

munmap(0x7f5429003000, 4096)            = 0 <0.000090>

stat("/var/www/needlworks/notice.textcube.org/root/ko", 0x7fffead9e930) = -1 ENOENT (No such file or directory) <0.000065>

stat("/var/www/needlworks/notice.textcube.org/root/rewrite.php", {st_mode=S_IFREG|0644, st_size=535, ...}) = 0 <0.000058>

시스템콜 함수의 이름과 거기에 전달된 인자값들이 무엇인지, 그리고 그 반환값과 수행 시간이 초 단위로 찍혀 있습니다.

맨 윗줄은 TCP 소켓을 만들었다는 뜻이고, 그 다음 connect 함수 부분은 Linux 계열 시스템에서 제공되는 avahi라는 네임서버 접근용 데몬 프로그램이 만들어놓은 파일형태의 소켓과 만든 소켓을 연결하겠다는 뜻입니다. (조금 복잡한데, Linux 계열에서는 모든 시스템 자원을 파일이라는 형태로 접근할 수 있도록 되어 있어서, 다른 프로그램과 상호작용하기 위해 위와 같은 방법을 자주 사용합니다.) 이런저런 설정과 확인을 거친 후, write 함수를 보면 어떤 IP 주소(실제로는 제가 집에서 접속할 때 사용한 유동IP입니다)에 대한 도메인을 가져오라는 내용을 쓰고 있고, 그 결과로 받은 것이 timeout, 그리고 그 결과를 받기까지 정확히 5초가 걸렸음을 보여줍니다.

네... 범인은 이거였습니다. (....)

그렇다면 웹서버가 제 의지와 상관 없이(...) 마음대로 네임서버에 접근하려다 실패하는 걸 계속 반복하고 있다는 뜻인데 왜 그런지 알아야겠지요.

약간의 구글링 끝에 알아낸 단서는, 보안을 위한 것이라지만 실제론 약간 습관적으로 사용하는 Allow from all과 관련이 있었습니다. Allow from all 자체가 이미 모든 곳으로부터의 접속을 받겠다는 뜻인데, Deny from none이라는 설정이 더 있었습니다. 그것도 텍스트큐브 관련 virtual host 설정에만요. 얼핏 보면 같은 뜻이니까 문제 없겠지 싶지만, 알고보니 none이라는 건 존재하지 않는 특수 이름이었습니다.

...그래서 "none"이라는 주소로부터 온 것인지 아닌지 검사하기 위해 모든 접속마다 IP 주소를 도메인으로 변환하려고 시도했던 것입니다. 랄랄랄라라라랄라라라... (참고로 이 일을 하는 mod_access 모듈은 다른 곳의 설정을 몽땅 무시하고 무조건 DNS 확인 절차를 수행한다고 합니다. -_-)
설정에서 Deny from none 한줄 지워주니 모든 문제가 해결되었습니다. 이 서버에서의 텍스트큐브 정상 속도대로 서비스되기 시작한 것이죠.

이상 삽질기 끝이었습니다.

아 허무해 ...ㅠㅠ

2010/08/28 03:00 2010/08/28 03:00