이 글은,
7.1 버전부터 도입된 WAL (Write-Ahead Logging, 미리 써 놓는 작업
기록 - 구체적으로 전산용어로 이것을 무엇으로 번역하는지는 모릅니다.
아무튼 가장 적당한 우리말식 표현은 저놈인듯.)의 기능에 대한
실질적인 테스트 기록입니다.
사용한 환경은
CPU: Intel 1.5GHz
OS: M$ Windows XP (SP 2)
PostgreSQL: 8.0.1 (win32)
작업방법:
1. 정상적인 시스템 셧다운 경우.
다른 시스템에서 꽤 많은 시간이 걸리는 update 구문을 실행시키고
있는 도중에,
DB 서버가 가동중에 OS를 셧다운 명령을 내립니다.
당연히 예상되겠지만, OS는 현재 실행중인 모든 프로세스에게 작업
중지 명령을 내리고, 이 명령이 완료될때까지 기다립니다. 그래서,
셧다운 작업이 꽤 오래걸립니다. 테스팅 환경에서는 적어도 2분 이상이
소요된듯.
그리고 다시 리부팅하고, 프로세스 내역을 보면, 정상적으로
PostgreSQL 서버가 잘 가동되어있음을 볼 수 있었습니다.
그래서, 셧다운 명령에 대해서 db 서버는 과연 어떻게 반응했는지를
살펴보기 위해서 로그 파일을 열어보았습니다.
2005-03-08 09:09:59 ERROR: canceling query due to user
request
2005-03-08 09:09:59 STATEMENT: update kosearch set t =
replace(t, '가','각');
2005-03-08 09:09:59 LOG: received fast shutdown request
2005-03-08 09:09:59 LOG: aborting any active transactions
2005-03-08 09:09:59 FATAL: terminating connection due to
administrator command
2005-03-08 09:09:59 LOG: shutting down
2005-03-08 09:09:59 LOG: database system is shut down
2005-03-08 09:10:06 LOG: logger shutting down
위에서 보는 것처럼 update 작업 도중 사용자의 요청으로 이 작업은
중지되고, (rollback 됨) 서버는 fast 모드로 셧다운 작업을
진행합니다.
fast 모드는 현재 작업중인 세션은 작업중지명령을 내리고 중지될
때까지 기다리고, 작업중이지 않는 세션에 대해서는 무시하고, 셧다운
합니다.
이렇게 해서 현재 작업중이 모든 작업은 취소되면서 안전하게
셧다운했습니다.
당연히 시스템을 리부팅 해도 정상적으로 db 서버는 잘
가동되었지요.
2. 비정상적인 시스템 셧다운 경우.
위와 똑같은 작업을 하고 있는 도중에, 컴퓨터의 reset 단추를
누릅니다 (절대로 하지 말아야할 짓을 했습니다.)
이 경우는 컴퓨터가 켜질 때 오래걸리더군요. PGDATA 디렉토리가
있는 하드 디스크가 손상되었다면서 파일시스템 검사화면까지 볼 수
있었습니다.
아무튼 여저저차 일단 시스템은 정상적으로 부팅되었습니다. 다음
프로세스 내역을 보니, 여전히 db 서버는 정상가동중이였습니다. 그래서
이번에는 어떻게 서버가 반응했는지 로그파일을 살펴보았습니다.
2005-03-08 09:20:44 LOG: database system was interrupted at
2005-03-08 09:12:32 대한민국 표준시
2005-03-08 09:20:44 LOG: checkpoint record is at 0/4EFA0290
2005-03-08 09:20:44 LOG: redo record is at 0/4EFA0290; undo record
is at 0/0; shutdown TRUE
2005-03-08 09:20:44 LOG: next transaction ID: 80393; next OID:
684612
2005-03-08 09:20:44 LOG: database system was not properly shut
down; automatic recovery in progress
2005-03-08 09:20:44 LOG: redo starts at 0/4EFA02D0
2005-03-08 09:20:53 LOG: unexpected pageaddr 0/4C670000 in log
file 0, segment 79, offset 6750208
2005-03-08 09:20:53 LOG: redo done at 0/4F66E998
2005-03-08 09:20:53 LOG: database system is ready
로그는 친절하게, 이때의 상황을 잘 설명해주고 있습니다. :)
서버가 갑자기 중지 되었는데, 이때의 체크포인트 기록이 있는
위치는 0/4EFA0290 입니다. (앞에 0은 pg_clog/0000 파일을 의미하면,
뒤에 긴 16진수는 pg_xlog 의 파일과 그 위치를 의미합니다. - 더
자세히는 저도 모릅니다. 아무튼 체크포인트의 위치라고만
이해하시면됩니다.)
이렇게 비정상적으로 중지되었으니, 현재의
체크포인트위치(0/4EFA02D0) 부터 시작에서 거꾸로 거슬러 서버가
판단하기에, 작업 기록 로그 가운데, 가장 마지막으로 안전하다고
판단되는 체크포인트 위치까지 자료를 복구하기 시작합니다. 그래서,
최종 0/4F66E998 위치의 정보까지 복구 작업을 합니다. - redo 작업을
했다고 하지요.
여기서 하나 풀리지 않은 것이 있는데, "unexpected pageaddr
0/4C670000 in log file 0, segment 79, offset 6750208" 이 로그
부분인데, 이것은 아마 clog 파일에 리부팅 과정에서 미쳐 지우지 못한
처리완료된 정보인듯합니다. 그래서, 이미 물리적으로 자료파일에 이미
자료를 다 기록했음에도 불구하고, clog 파일에서 삭제하지 못한
체크포인트 정보인듯합니다. 그래서, 일단 그 정보를 보여주었는듯,
xlog 파일에는 이미 없기 때문에. 어차피 아무런 처리도 할 수
없지요.
여기까지입니다.
이 WAL 기능은 아주 오래된 기능입니다. 충분히, 기타 다른 OS에
대해서도 충분히 검증을 거쳤는 것인지라, DB 서버의 비정상적인 중지에
대한 자료 손실 이야기는 걱정을 안하셔도 될 것입니다. 문제는
물리적인 하드디스크의 손상입니다. 이것은 DB 서버 문제를 떠났는
것입니다. 이 문제에 대한 해결책은 백업뿐입니다.
|