프로그래밍은 지루하지만 그만큼 재미나다. 특히, 옛날 도구를 새롭게 사용하는 방식을 배울 때는 재미가 더해진다. 최근 나는 리눅스(Linux®), 아파치, MySQL 그리고 리눅스, 아파치, MySQL, PHP/펄(LAMP) 기반에다 크고 복잡한 CMS(Content Management System)에서 버그 수십 개를 잡아달라는 요청을 받았다. CMS 아키텍처는 표준 LAMP 모델이고 엔터프라이즈 레드햇 리눅스와 아파치 V2.0을 사용했다. 웹 사이트는 PHP 프로그램이었는데, 몇 백 개에 이르는 PHP 소스 모듈이 (아파치 문서 루트 디렉터리 내) 30여 개가 넘는 하위 디렉터리에 흩어져 있었다. 아파치와 MySQL 부분은 변경할 필요가 없었으므로 버그 색출 작업은 모두 PHP 코드에서 수행할 예정이었다.
CMS가 돌아가는 방식을 파악하고자 상당한 시간을 투자한 끝에 나는 시스템이 우아하게 설계되었다는 사실을 깨달았다. 또한 (대다수 성숙한 프로그래밍 환경이 그렇듯이) 시스템이 소수 PHP 함수만 사용한다는 사실도 깨달았다. (80% 작업은 20% 함수가 수행한다는 80/20 규칙이 드러난다.) 이 기사에서는 복잡한 미지의 시스템을 디버깅하면서 거의 사용하지 않는 함수를 찾아낸 과정을 소개한다. 또한 syslog() 함수가 제공하는 풍부한 기능을 사용해 새로운 지식을 적용하는 방법도 예시한다.
눈여겨 살피기
PHP 프로그래밍 언어에는 수백 가지 함수가 있지만, 이런 기사에서 접하지 않는 한 일부 (혹은 대다수?) 함수는 거의 사용하지 않는다. 기사에서 접하는 방법 외에도 언어를 좀더 심도 있게 배우는 방법은 남이 짠 프로그램을 디버깅하는 방법이다. 나는 코드를 볼 때마다 프로그래머들이 도구를 사용하는 기발한 방식에 늘 감탄한다.
프로그래밍과 마찬가지로 디버깅도 어느 정도는 과학이고 어느 정도는 예술이다. 자신이 짜지 않은 시스템에서 버그를 찾아내려면 대충 어디서 시작할지 감을 잡아야 한다. 수백 개에 이르는 코드 모듈을 다루는 과정에서 가장 좋은 출발점은 버그가 존재한다는 사실을 확실히 보여주는 지점이다. 여기서부터 거슬러 추적하면서 문제를 격리해 나간다.
예를 들어 계산한 값을 출력한 결과가 올바르지 않다면, 값을 출력한 지점부터 거슬러 올라가면서 중간 값을 확인해야 한다. 또 다른 예로 중요한 데이터베이스를 조회한 결과가 올바르지 않다면, 문제 지점을 살펴보기 위해 (MySQL 엔진에서 데이터베이스로 던지는) SQL 문장을 확인해야 한다.
이러한 문자열이나 값을 확인하는 오래된 디버깅 기법 중 하나가 프로그램에 코드를 삽입하여 직접 찍어보는 방법이다. 그러나 PHP나 웹 응용 프로그램에서는 정상적인 출력, 즉 브라우저로 보내는 HTML 코드에 디버깅 정보를 섞는 일이 바람직하지 못하다. 특히나 테스트 환경이 아니라 운영 환경이라면 더욱 피해야 한다.
별도로 로그 파일을 생성해 이곳에 로그 메시지를 기록해도 되지만, 이왕이면 이미 있는 도구를 사용하면 좋지 않을까? 항상 명심하건데 도구를 묻어두지 말지어다. 흔히 사용하는 기능이라 여겨 라이브러리 루틴이나 함수를 뒤지느라 보내는 시간은 결코 낭비가 아니다. 흔히 프로그래머가 언어 패키지에 들어 있으리라 추측하는 기능은 실제로 거의 다 들어 있다.
나는 유닉스(UNIX®)에서 제공하는 syslog와 비슷한 기능이 필요하다는 사실을 깨달았다. PHP 프로그램에서 syslog 함수로 연결할 방법이 있으리라는 추측 아래 재빨리 PHP 문서를 뒤진 결과 PHP syslog() 함수를 찾아냈다! 이번 프로젝트를 맡기 전까지는 PHP에syslog() 함수가 존재한다는 사실을 몰랐다. 이 syslog() 함수 덕택에 실제 환경에서 (syslog 함수를 실행하는 시간 외에) 부수적인 효과를 일으키지 않고서 대다수 버그를 잡아낼 수 있었다.
경험과 기술이 쌓이다 보면 작업은 한 가지이지만 수행하는 방식은 다양하다는 사실을 깨닫는다. 그러다가 종내에는 여러 방식 중 하나가 당연한 방식으로 자리를 잡는다. 하지만 자신에게 당연한 방식이 다른 사람에게도 당연하리라 여겨서는 안 된다. 자신이 간단하다 여기는 방식이 다른 사람들에게 터무니 없이 복잡하게 여겨지기도 한다.
syslog() 함수를 사용하면 복잡한 물밑 작업을 신경쓸 필요가 없다. 그러면서도 syslog.conf라는 환경 설정 파일을 통해 프로그래머가 설정을 다양하게 변경할 수 있다. 예를 들어, 코드에서 SQL 문을 만든 후 syslog()로 기록한 다음 실행을 위해 MySQL로 넘긴다. 나중에 syslog.conf 파일만 살짝 수정하면 출력 문자열을 다른 로그 파일로 보내거나 날려버릴 수 있다. 몇 주 혹은 몇 달 후에 다시 SQL 문을 확인해야 한다면 단순히 syslog.conf만 변경하면 족하다.
위로
syslog
syslog는 유닉스 세상에서 오래되고 찬란한 역사를 자랑한다. 원래는 센드메일 프로젝트 일부로 개발되었으나, 무척이나 유용한 탓에 많은 도구가 syslog를 자체 기능에 포함시켰다. 가장 단순한 아이디어가 때로는 가장 강력하다는 증거라 하겠다.
간단히 설명하자면, syslog는 응용 프로그램이 공통적인 시스템 로그 파일에 태그 있는 메시지를 기록하는 메커니즘을 제공한다. 공통적인 시스템 로그 파일은 프로그래머나 네트워크 관리자가 접근하기 편한 위치에 저장한다. 즉, 필요하다면 웹 서버가 로그 메시지를 다른 서버로 (예를 들면, 보안 방화벽 내 깊숙히 위치하고 네트워크 관리자가 접근하기 편한 서버로) 저장해도 좋다는 뜻이다. 하지만 이 기사에서는 기본 위치인 /var/log 디렉터리를 그대로 사용했다.
syslog 메커니즘은 시스템을 시작하면 자동으로 시작되며, 초기 동작 방식은 syslog.conf 파일에 지정된 규칙을 따른다. syslog.conf 파일을 통해 프로그래머는 기록하려는 자료와 기록하지 않으려는 자료를 세밀하게 가려낼 수 있다. 사용량이 많은 바쁜 서버라면 로그 파일 크기가 매우 커지므로 로그를 적정한 수준으로 조정할 필요가 있다.
각 규칙은 필드 두 개로 이루어진다. 하나는 selector고 다른 하나는 action이다. 기본적으로 selector 필드는 (kern, user, mail, lpr 등) 기록할 대상과 우선순위를 지정한다. 우선순위 필드는 debug, info, notice, warning 등과 같은 키워드를 포함한다. action 필드는 selector 필드에 일치하는 메시지를 처리하는 방식을 지정한다. 규칙에 메시지를 기록할 파일, 메시지를 전송할 시스템, (콘솔 메시지 형식으로) 메시지를 보여줄 사용자 등을 지정할 수 있다.
위로
기록
syslog를 설정하는 방법은 관련 info와 man 페이지에서 자세히 설명한다. 내 경우는 CMS 시스템이 돌아가는 동안 여러 시점에서 PHP 변수 값을 확인하고 싶었다. 또한 일부 변수에서 중간 값도 확인하고, 특정 모듈이 시작하거나 끝나는 시점도 파악하고 싶었다. 기록하려는 내용을 구체적으로 설명하기 전에 먼저 기본 설정 작업부터 수행하자.
애용하는 편집기로 Listing 1과 같은 파일을 생성한 후 test.php라고 명명한다. 이 파일을 아파치 문서 루트 디렉터리 아래 넣는다(내 시스템에서는 /var/www였다).
Listing 1. test.php
<html>
<head>
<title>PHP Test Page</title>
</head>
<body>
<?php
syslog(LOG_NOTICE, "{$_SERVER['REMOTE_ADDR']}:
test.php - PHP Index page accessed.");
echo '<p>PHP Test Page</p>';
?>
</body>
</html>
|
PHP를 설치하고 환경 설정이 끝난 상태여야 한다. 그렇지 않으면 참고자료를 참조해 설정을 진행한다. PHP를 올바로 설치하고 설정했다면 브라우저에서 http://localhost/test.php 페이지를 열었을 때 다음 결과가 뜬다.
다음으로, X 터미널 창을 열어 다음 명령을 입력한다. 아래 명령은 /var/log/messages 파일에 기록된 내용을 출력한다.
여기까지 아무런 문제가 없었다면 파일 마지막에 다음과 같은 행이 들어 있어야 한다.
Jul 23 14:43:42 localhost apache2: 127.0.0.1: test.php - PHP Index page accessed.
|
마지막 행이 위와 같다면 성공이다. 이제 작업 중인 복잡한 시스템을 디버깅할 준비가 모두 갖추어졌다.
PHP/MySQL 호출 시에는 무조건 syslog()를 사용하라고 권한다. 그러면 웹 사이트에 접속할 때마다 페이지를 만들기 위해 방금 데이터베이스로 던진 SQL 조회문을 실시간에 확인할 수 있다. 실시간으로 로그 파일을 확인하려면 여분의 X 터미널 창을 띄운 다음에 아래와 같이 로그 메시지를 보기 위해 tail 명령에 -f 옵션을 사용한다.
tail -f /var/log/messages
|
위로
기록할 내용
syslog 결과를 살펴 로그 메커니즘이 동작한다는 사실을 확인했으니, 이제 syslog를 사용하여 낯선 시스템을 가능한 빠르게 파악하는 방법을 몇 가지 소개한다.
가장 먼저, 나는 각 모듈이 문서에 기록된 내용 외에도 어떤 작업을 수행하는지 파악하고 싶었다. 그래서 모듈 시작과 끝에 로그 메시지를 추가했다. 그런 다음, X 터미널 창에서 tail -f /var/log/messages 명령을 실행한 후 웹 사이트를 탐색했다. 이 방법으로 브라우저가 새 페이지를 띄울 때마다 어떤 모듈이 어떤 순서로 실행되는지 확인할 수 있었다.
또 PHP 코드를 실행하는 중에 다른 프로그램이 호출되는 시점도 기록하고 싶었다. 예를 들어, 데이터베이스를 조회할 목적으로 MySQL 함수를 호출하는 시점이나 데이터 형식을 변환할 목적으로 외부 프로그램(예, XSLT(Extensible Stylesheet Language Transformation) 엔진)을 호출하는 시점을 로그 파일에서 파악하고 싶었다. 그래서 PHP 코드 모듈 내 적절한 위치에다 체계적으로 로그 코드를 삽입했는데, 이 과정에서 모듈 이름과 위치에 친숙해졌다. 그런 다음, 웹 사이트를 탐색하면서 X 터미널에 표시되는 메시지를 살폈다. syslog 코드가 보내는 메시지는 X 터미널에 즉각 표시되므로 시스템이 동작하는 방식을 이해하기가 훨씬 더 쉬워졌다.
위로
결론
syslog는 남이 작성한 프로그램을 디버깅하기에 매우 유용한 도구다. 웹 사이트를 탐색하는 과정에서 실행되는 모듈, 데이터베이스로 던진 SQL 문, 수정되는 변수 값 등을 쉽게 확인할 수 있다. 이러한 정보가 있으면 문제가 있는 모듈을 밝혀내기가 쉬워진다.
참고자료
교육
제품 및 기술 얻기
- DVD나 다운로드 링크를 통해 얻을 수 있는 IBM 평가판 소프트웨어로 다음번 오픈 소스 프로젝트를 진행하기 바란다.
- IBM 제품 평가판 버전을 내려받아 DB2®, Lotus®, Rational®, Tivoli®, WebSphere®와 같은 미들웨어와 응용 프로그램 개발도구를 활용하기 바란다.
토론
필자소개
Bill Zimmerly는 지식 엔지니어이자, 유닉스와 마이크로소프트 윈도우(Microsoft® Windows®) 전문 시스템 프로그래머이자, 논리를 신봉하는 자유 사상가다. 빌은 또한 비(非)이성적인 사람으로도 알려져 있다. 조지 버나드 쇼는 “이성적인 사람들은 자신을 세상에 적응시킨다. 비이성적인 사람들은 세상을 자신에게 적응시키려 한다. 그래서 모든 진보는 비이성적인 사람들에게서 나온다.”라고 했다. 새로운 기술을 창안하고 이에 대한 글을 쓰기가 그의 열정이다. 현재 그는 공기 좋고 경치 좋고 와인이 멋진 미주리 주 힐스보로에 살고 있다. 스톤 힐 브러시(백포도주)를 홀짝거리며 유닉스 셸 스크립트에 대한 기사를 쓰는 시간 만큼 즐거운 한 때는 또 없으리라. 전자편지 주소는 bill@zimmerly.com이다.
