PostgreSQL 서버 로그 실시간 감시

시작하며

PostgreSQL의 서버 로그에 대한 기능이 막강한 것은 써본 사람은 대부분 동의할 것입니다. 
일반적으로 서버 로그는 일반 텍스트 파일에 저장하고, 로그를 분석해야 하는 상황에서는 대부분 유닉스 텍스트 파일 도구(cat, grep, sed, perl, awk ....)들을 이용해서 분석합니다. 
즉, 이런 텍스트 파일 분석하는 도구들을 잘 다루는 이들에게는 전혀 불편함을 느끼지 못하지만, 그렇지 않은 경우는 텍스트 파일로 되어 있는 로그를 어떻게 분석해야 할지 막막하기만 합니다. 

이런저런 문제들 때문에, PostgreSQL 쪽에서는 서버 로그 분석 도구들이 여러 오픈 프로젝트로 진행되었거나 진행되고 있습니다. 
가장 대표적인 것은 pgbadger 이고, pgFouine 도 유용하게 쓰인답니다. (저는 실무에서 사용하지는 않았습니다.)

이런 로그 분석 도구들의 특징은 로그 분석 작업을 배치성 작업으로 진행한다는 것입니다. 전통적으로 이 부분을 실시간으로 처리해서 얻는 이익이 서버 운영 환경을 쾌적하게 만드는 것보다 덜 중요하기 때문입니다. 

하지만 관제 측면 - 서버 운영자가 서버 이상 징후에 대한 즉각적인 조치나, 그 상황을 실시간 감시를 해야 하는 측면에서 본다면, 일반 텍스트 파일로 저장되는 로그 사용하는 것은 꽤 번거로운 일입니다.

이 글은,
이런 번거로운 작업을 손쉽게 할 수 없을까?
이 문제에 대한 한 가지 방법을 소개하는 글입니다.

서버 로그를 fifo - 이름 있는 파이프로

유닉스 계열 시스템에서 프로세스 간 통신을 할 때 사용하는 fifo 파일을 로그 파일로 사용하는 것은 어떨까?를 생각해 보았습니다. 
fifo를 쓴다는 것은 다음 항목들을 꼭 함께 생각해야 합니다. 
  • 입력이 끊임없이 된다면, 그 출력 또한 끊임없이 되어야 한다.
  • 갑자기 많은 양의 입력이 유입될 경우, 그 출력에 대한 버퍼링을 고민해야 한다.
  • 그 출력의 지연으로 fifo의 버퍼량이 많아질 때, 대처 방안을 마련해 두어야 한다.
  • fifo 파일 자체가 어떤 이유로 사라져 버렸을 때, 그 fifo 파일을 사용하는 프로세스들의 대처 방안도 마련해 두어야 한다.
그 외, 제가 모르는 다른 부분들도 몇 가지 더 있겠죠. 
위와 같은 여러 상황에 대한 구체적인 대처안을 마련해야지, 서버 로그를 fifo로 바꿀 수 있을 것입니다. 

현재까지 찾은 그 대처안들은
  • 서버가 기동되면, 절대로 자동 종료되지 않는 fifo 파일 읽는 프로그램을 만들면 되고, 
  • 비정상적으로 종료되어도 다시 자동으로 실행되는 형태로 운영되면 되고, 
  • 해당 fifo 파일의 개별적인 fifo buffer 크기를 충분히 키워주면 되고, (아직 이 부분의 답은 못 찾았습니다)
  • 로그 수집량을 조절하는 방식으로 조절하면 되고, 
  • 그 감시 프로그램이 fifo 파일 자체를 감시하다가, 없으면 만들고, 서버 쪽에는 log rotate 작업을 해서, 그 로그 파일을 사용할 수 있도록 한다.


서버 로그 수집 방식을 CSV로

첫 번째 작업은 서버 로그를 로그 실시간 감시 응용 프로그램이 쉽게 분석할 수 있도록 로그 저장 방식을 csv(반점 구분자 자료) 형식으로 바꿉니다. postgresql.conf 파일에서 다음과 같이 환경 설정 매개변수들의 값을 바꾸고, 서버를 재실행합니다. (reload로는 반영이 안 되는 것들이어서 재실행이 꼭 필요합니다.)
log_destination = 'csvlog'
logging_collector = on
log_filename = 'postgresql.fifo'
log_rotation_age = 0
log_rotation_size = 0
여기서 관심을 가져야 사항은 postgresql.fifo 라는 파일 이름의 끝이 fifo 라는 것입니다. 문제는 PostgreSQL에서는 로그 파일을 fifo 로 만들어서 쓰겠다는 기능이 없기에, 먼저 fifo 파일을 만들어주어야 합니다. 그렇지 않으면 그 파일을 서버가 실행되면서 자동으로 일반 텍스트 파일 형식으로 .csv 파일을 만들어버립니다.
mkfifo $PGDATA/pg_log/postgresql.fifo.csv
DB서버를 실행하는 유닉스 OS 계정으로 해당 작업을 하며, $PGDATA 디렉터리는 DB 서버가 사용하는 데이터 디렉터리입니다. (물론 서버 로그를 다른 위치에 저장한다면 그 디렉터리를 지정합니다). 만들 파일은 postgresql.conf 파일에서 지정한 이름에다 .csv 를 추가해서 만듭니다.

서버가 재실행 되었다면, 이제부터 서버는 자신의 로그 내용을 저 csv fifo 파일에다 씁니다. 이 파일은 파이프이기 때문에, 쓰인 내용을 빼내지 않으면, 파이프가 막힙니다. 즉 더이상 로그를 기록하지 못해 서버의 모든 작업이 멈추게 됩니다.
서버 로그 내용을 유닉스 명령으로 빼내는 방법(그 서버 로그를 보는 방법)은 cat 명령을 이용하면 간단합니다.
cat < $PGDATA/pg_log/postgresql.fifo.csv
중지할 때는 ctl-c
이렇게 하면, 파이프가 깨집니다. 서버 쪽에서는 log rotate 작업을 해주어 다시 파이프를 만들어야합니다. (이 부분에 대해서 감시용 쓰레드가 필요해 보입니다.)

감시 프로그램 만들기

이제 이 파이프의 내용을 끄집어 내어 그 내용을 프로그램이 처리할 수 있는 (csv 문자열을 배열로 만드는) 프로그램을 만듭니다. 
이 감시용 프로그램은 위에서 언급한 여러 조건이 충족되야 실무에 쓸 수 있을 것입니다. 

일단 이 글에서는 가장 기본적인 프로토타입 형태의 스크립트를 소개합니다. 나머지는 프로그래머의 말랑말랑한 창의성으로 잘 만들어서 잘 사용하면 될 것 같네요. 

실재코드는 python 코드로 작성되었으며, 아마도 2.4 이상이면 무난히 실행될 것 같습니다. 

import os,sys,csv,time,signal,cStringIO
# realtime csv parser by ioseph, 2014
# 아래 코드는 python 여러 인터넷 사이트에서 올라온 샘플 코드 조각들을 조합했습니다.
# 실제 감시용 프로그램을 위해서는 아래 print() 부분이 감시 루틴으로 바뀌면 되겠죠.


import logging
# setting timestamp for this program log
logging.basicConfig(format='%(asctime)s %(message)s', level=logging.DEBUG);


# for signal
is_stop = False;

def closefile(sig, func=None):
        '''
        close fifo file handle && set stop value for escaping main loop
        '''
        global fd
        logging.error("break by kill");
        fd.close();
        is_stop = True;

# set signal
signal.signal(signal.SIGTERM, closefile);

# cvs memory limit 값을 100MB(linux)로 지정 , 안되는 1/10씩 줄여가며 될때까지
maxInt = sys.maxsize / 20
decrement = True
while decrement:
        # decrease the maxInt value by factor 10
        #as long as the OverflowError occurs.
        decrement = False
        try:
                csv.field_size_limit(maxInt)
        except OverflowError:
                maxInt = int(maxInt/10)
                decrement = True


try:
        aLine = cStringIO.StringIO();
        
        while True:
        # main loop because multiful server stop, start
                if is_stop == False:
                        #get file handle
                        fd = os.fdopen(os.open(sys.argv[1], os.O_RDONLY));
                        for chunk in iter(lambda: fd.read(1), ''):
                               if chunk != '':
                                       aLine.write(chunk);
                               if chunk == '\n':
                                       try:
                                               if aLine.getvalue() == "\n":
                                                       aLine.truncate(0);
                                                       continue;
                                               # parse csv
                                               csviter = csv.reader([aLine.getvalue()]);
                                               for row in csviter:
                                                       print(row);
                                               aLine.truncate(0); # 3.x 에서는 seek도 호출해야 한다네요.
                                       except csv.Error, e:
                                               if e.message == "newline inside string":
                                                       continue;
                                               else:
                                                       logging.error("%s : %s" % (e, aLine.getvalue()));
                        fd.close()
                else:
                        fd.close()
                        break;
except(KeyboardInterrupt, IOError):
        # signal exception
        closefile(2);
실행방법은
python parsecsv.py $PGDATA/pg_log/postgresql.fifo.csv

마치며

스크립트를 만들면서 꽤 많은 생각이 스쳐 지나갔습니다. 과연 이 작업이 실무에서 얼마나 쓸모가 있을까? 제대로 완성도가 어느 정도 갖춰진 녀석으로 변신하려면 어느 부분을 더 추가해야 할까? 운영 장비에서 어떻게 하면 이 감시 작업이 견딜 수는 있을까? 등등

아무튼 fifo를 이용한 서버 로그 실시간 감시는 한 번쯤 도전해 볼 만한 과제인 것 같습니다. 

이 발상을 기반으로 해서 누가 멋진 PostgreSQL용 실시간 감시 프로그램을 만들어도 좋고요.