PostgreSQL 로그 파일 완벽 가이드: 포맷팅부터 구조화된 로깅까지

이세현·2024년 9월 9일

PostgreSQL for DBA

목록 보기

10/19

PostgreSQL 로그 파일 커스터마이징

서론: PostgreSQL은 강력한 데이터베이스 시스템으로, 적절한 로그 설정은 성능 모니터링과 문제 해결에 필수적입니다. 이 블로그에서는 PostgreSQL 로그 파일을 커스터마이징하는 다양한 방법에 대해 알아보겠습니다. 특히 로그 포맷팅, JSON 형식의 구조화된 로깅, 쿼리 로깅 방법, 메시지 심각도 수준, 로그 상세도 줄이기, 연결 및 연결 해제 로깅, 사용자 정의 로그 메시지 생성, 그리고 PgBadger를 활용한 로그 파일 분석 등을 다룰 것입니다.

1. 로그 파일 커스터마이징(Customizing the log files)

PostgreSQL에서는 로그 파일 이름을 log_filename 옵션을 통해 커스터마이징할 수 있습니다.

/etc/postgresql/15/main/postgresql.conf

log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log'

이 설정은 파일 생성 시의 날짜와 시간이 포함된 로그 파일 이름을 생성합니다.
%로 시작하는 escape 문자는 Open Group의 strftime 사양에 따라 다양한 포맷으로 대체됩니다.

/etc/postgresql/15/main/postgresql.conf

log_filename = 'postgresql-%a.log'

이 설정은 요일의 약어가 포함된 파일을 생성합니다(예: postgresql-Thu.log). 이때 로그 파일 이름이 .log로 끝나지만, JSON 또는 CSV 형식이 활성화된 경우 파일 이름은 각각 .json 또는 .csv로 끝납니다(예: postgresql-Thu.json).

로그 파일의 생성 권한을 제어하려면 log_file_mode 옵션을 변경할 수 있습니다

/etc/postgresql/15/main/postgresql.conf

log_file_mode = 0600 # 기본값

0600 권한은 민감한 파일에 자주 사용되며, 파일의 소유자만이 이 파일에 접근, 조회, 수정할 수 있습니다. 이 설정은 PostgreSQL 로그에 민감한 정보가 자주 포함되므로 보안 조치로 유용합니다.

로그 파일 rotation 설정

로그 파일에 데이터를 기록하면 적절한 로그 회전 정책이 없을 경우 디스크 공간이 빠르게 소모될 수 있습니다. 특히 쿼리 로깅이 활성화된 PostgreSQL에서는 더욱 그렇습니다.

PostgreSQL에서는 로그 파일 회전을 제어할 수 있는 몇 가지 설정을 제공

log_rotation_age: 로그 파일이 rotation되기 전 최대 파일 age를 지정합니다. 기본값은 24시간(1일)입니다. 분(m), 일(d), 주(w)와 같은 단위를 사용할 수 있으며, 단위를 제공하지 않으면 분 단위가 기본값으로 사용됩니다. 시간 기반 로그 rotation을 비활성화하려면 0으로 설정할 수 있습니다.
log_rotation_size: 새로운 로그 파일로 회전되기 전의 최대 파일 크기를 결정합니다. 기본값은 10메가바이트(10MB)입니다. 크기 기반 로그 rotation을 비활성화하려면 0으로 설정할 수 있습니다.
log_truncate_on_rotation: 이 옵션은 시간 기반 rotation이 적용될 때만 유효합니다. 기존에 동일한 이름의 로그 파일이 있을 경우 덮어쓰기를 할지 여부를 결정합니다. 예를 들어, postgresql-%a.log와 같은 파일명을 사용할 때, 이 옵션을 활성화하고 log_rotation_age를 7일로 설정하면 매주 같은 파일명을 사용해 이전 주의 로그 파일을 덮어쓰게 됩니다.

PostgreSQL 로그 파일의 이름과 생성 권한을 사용자 정의할 수 있으며, 로그 파일 rotation을 통해 디스크 공간을 관리할 수 있습니다. 이 설정들은 보안 및 로그 관리에 있어 매우 유용하며, 필요에 따라 logrotate와 같은 추가 유틸리티를 활용 가능

2. 로그 포맷팅 (Log Formatting)

로그 파일의 포맷을 설정하여 분석과 모니터링을 더욱 효과적으로 할 수 있습니다. PostgreSQL은 다양한 로그 출력 포맷을 지원하며, 로그 라인의 구성 요소를 선택적으로 포함할 수 있습니다. 이 부분에서는 log_line_prefix 설정을 통해 로그에 추가할 수 있는 다양한 정보와 그 의미에 대해 설명할 것입니다.

PostgreSQL의 로그 형식은 기본적으로 log_destination 설정에 의해 제어되며, 기본값은 stderr로 설정되어 있습니다. 또한 로그를 JSON 또는 CSV 형식으로 출력하려면 각각 jsonlog 및 csvlog 옵션을 사용할 수 있습니다.

/etc/postgresql/15/main/postgresql.conf

log_destination = 'stderr'

stderr가 활성화되면, log_line_prefix 옵션을 통해 출력 형식을 수정할 수 있습니다. 이 옵션은 각 로그 기록의 시작 부분에 포함될 정보를 결정하는 printf 스타일의 문자열입니다.

SHOW log_line_prefix;

log_line_prefix
------------------
 %m [%p] %q%u@%d
(1 row)

이 값은 stderr로 전송되는 각 로그 기록에 다음과 같은 세부 정보를 포함하도록 설정

%m: 밀리초 단위의 이벤트 발생 시간.
%p: 로그를 생성한 특정 PostgreSQL 인스턴스의 프로세스 ID.
%q: 이 토큰은 출력이 없지만 백그라운드 프로세스가 이 지점 이후의 모든 것을 무시하도록 합니다. 다른 토큰(%u@%d)은 세션 프로세스에서만 사용할 수 있습니다.
%u: 이벤트를 트리거한 연결된 사용자.
%d: 사용자가 연결된 데이터베이스.

위에서 설명한 형식을 사용하여 생성된 로그 항목은 다음과 같습니다.

2023-07-30 08:31:50.628 UTC [2176] postgres@chinook LOG:  statement: select albumid, title from album where artistid = 2;

postgres@chinook 이후의 모든 내용은 log_line_prefix에 의해 제어되지 않으며, 로그 수준과 이 경우 SELECT 문과 같은 로그 메시지로 구성됩니다

로그 포맷 커스터마이징

stderr 로그 형식을 수정하는 유일한 방법은 log_line_prefix 설정을 통해서만 가능합니다. 사용할 수 있는 이스케이프 시퀀스의 전체 표를 참조하세요. 다음 변수를 포함하는 것을 권장합니다.

이스케이프 시퀀스	설명
`%a`	애플리케이션 이름 (PostgreSQL 연결 문자열의 `application_name` 매개변수로 설정)
`%p`	PostgreSQL 인스턴스의 프로세스 ID
`%u`	연결된 사용자
`%d`	데이터베이스 이름
`%m`	밀리초 단위의 이벤트 발생 시간 (UNIX epoch을 선호하는 경우 `%n`)
`%q`	세션 전용 변수와 모든 컨텍스트에서 유효한 변수 분리
`%i`	실행된 SQL 쿼리를 식별하는 명령 태그
`%e`	관련 PostgreSQL 오류 코드
`%c`	현재 세션의 ID

/etc/postgresql/15/main/postgresql.conf

log_line_prefix = 'time=%m pid=%p error=%e sess_id=%c %qtag=%i usr=%u db=%d app=%a '

이 구성으로 PostgreSQL 서버를 다시 시작하면 다음과 같은 형식의 로그를 확인할 수 있습니다

time=2023-07-30 22:02:27.929 UTC pid=17678 error=00000 sess_id=64c6ddf3.450e LOG:  database system is ready to accept connections
time=2023-07-30 22:03:33.613 UTC pid=17769 error=00000 sess_id=64c6de20.4569 tag=idle usr=postgres db=chinook app=psql LOG:  statement: UPDATE album SET title = 'Audioslave' WHERE albumid = 10;

첫 번째 기록은 비세션 프로세스(백그라운드 프로세스)에 의해 생성되었습니다. 이러한 프로세스는 유지 관리 작업, 백그라운드 작업 및 데이터베이스 운영을 지원하기 위한 기타 내부 기능을 수행합니다.

%q 이스케이프의 포함은 이후의 모든 항목을 제외합니다. 이러한 시퀀스는 비세션 프로세스에서 무효하기 때문입니다. %q가 제외되면 태그, 사용자, 데이터베이스, 앱 키가 로그에 표시되지만 비어 있게 됩니다.

반면, 세션 프로세스(사용자 백엔드 프로세스)는 특정 사용자와 데이터베이스에 직접 연결되어 실제 쿼리와 명령을 처리합니다. 이러한 컨텍스트에서는 모든 이스케이프 시퀀스가 유효하므로 %q 이스케이프는 효과가 없습니다.

3. JSON 형식의 구조화된 로깅 (Structured Logging in JSON)

로그 데이터를 구조화된 JSON 형식으로 기록하면, 로그 분석 도구와의 통합이 쉬워지고, 로그 데이터의 검색과 분석이 용이해집니다. 이 섹션에서는 PostgreSQL에서 JSON 형식의 로그를 생성하는 방법과 그 장점에 대해 다룰 것입니다.

PostgreSQL은 2008년 2월에 출시된 v8.3 릴리스부터 CSV 형식의 로깅을 지원했지만 JSON은 최근 v15 릴리스에서 지원되었습니다.
이제 다음과 같이 log_destination 설정에 jsonlog를 추가하여 PostgreSQL 로그를 구조화된 JSON 형식으로 작성할 수 있습니다.

/etc/postgresql/15/main/postgresql.conf
log_destination = 'stderr,jsonlog'

서버를 다시 시작하고 로그 디렉토리를 확인하면 동일한 이름을 가진 두 개의 새로운 로그 파일(.log 및 .json)이 생성된 것을 확인할 수 있습니다. 이 파일들은 동일한 로그를 다른 형식으로 포함하고 있습니다. .log 파일은 이전과 같이 stderr 형식을 따르며, .json 파일은 예측 가능하게 JSON 로그를 포함합니다.

/var/lib/postgresql/15/main/log/postgresql-Sun.log

time=2023-07-30 22:48:01.817 UTC pid=18254 error=00000 sess_id=64c6e836.474e tag=idle usr=postgres db=chinook app=psql LOG:  statement: SHOW data_directory;
time=2023-07-30 22:49:21.808 UTC pid=18254 error=00000 sess_id=64c6e836.474e tag=idle usr=postgres db=chinook app=psql LOG:  statement: TABLE albu limit 10;
time=2023-07-30 22:49:21.808 UTC pid=18254 error=42P01 sess_id=64c6e836.474e tag=SELECT usr=postgres db=chinook app=psql ERROR:  relation "albu" does not exist at character 7
time=2023-07-30 22:49:21.808 UTC pid=18254 error=42P01 sess_id=64c6e836.474e tag=SELECT usr=postgres db=chinook app=psql STATEMENT:  TABLE albu limit 10;

이 로그는 앞서 설명한 log_line_prefix 설정에 따라 포맷된 것입니다. 반면, JSON 로그는 null 값을 제외한 모든 사용 가능한 필드를 포함합니다.

/var/lib/postgresql/15/main/log/postgresql-Sun.json

{"timestamp":"2023-07-30 22:48:01.817 UTC","user":"postgres","dbname":"chinook","pid":18254,"remote_host":"[local]","session_id":"64c6e836.474e","line_num":1,"ps":"idle","session_start":"2023-07-30 22:46:14 UTC","vxid":"4/3","txid":0,"error_severity":"LOG","message":"statement: SHOW data_directory;","application_name":"psql","backend_type":"client backend","query_id":0}
{"timestamp":"2023-07-30 22:49:21.808 UTC","user":"postgres","dbname":"chinook","pid":18254,"remote_host":"[local]","session_id":"64c6e836.474e","line_num":2,"ps":"idle","session_start":"2023-07-30 22:46:14 UTC","vxid":"4/4","txid":0,"error_severity":"LOG","message":"statement: TABLE albu limit 10;","application_name":"psql","backend_type":"client backend","query_id":0}
{"timestamp":"2023-07-30 22:49:21.808 UTC","user":"postgres","dbname":"chinook","pid":18254,"remote_host":"[local]","session_id":"64c6e836.474e","line_num":3,"ps":"SELECT","session_start":"2023-07-30 22:46:14 UTC","vxid":"4/4","txid":0,"error_severity":"ERROR","state_code":"42P01","message":"relation \"albu\" does not exist","statement":"TABLE albu limit 10;","cursor_position":7,"application_name":"psql","backend_type":"client backend","query_id":0}

4. PostgreSQL 쿼리 로깅 방법 (How to Log PostgreSQL Queries)

데이터베이스 쿼리를 로그에 기록하는 것은 성능 문제를 파악하고 최적화하는 데 중요한 역할을 합니다. 이 섹션에서는 쿼리 로그를 활성화하고 구성하는 방법, 그리고 특정 쿼리만 로그에 기록하도록 필터링하는 방법에 대해 설명할 것입니다.

log_statement 설정

log_statement 설정은 서버 로그 파일에 기록될 SQL 쿼리를 제어합니다. 유효한 옵션은 다음과 같습니다.

none (기본값): SQL 쿼리를 기록하지 않습니다.
ddl: 데이터 정의어(DDL) 문장만 기록합니다. 예를 들어 CREATE, ALTER, DROP 문장이 포함됩니다.
mod: DDL 문장 외에 데이터 수정어(DML) 문장도 기록합니다. INSERT, UPDATE, DELETE 문장이 포함됩니다.
all: 실행 단계에서 파싱 오류로 실패한 쿼리를 제외한 모든 SQL 쿼리를 기록합니다.

/etc/postgresql/15/main/postgresql.conf
log_statement = mod

주의: all 설정을 사용하면 생산 환경에서는 많은 양의 데이터를 생성하게 되어 성능 저하를 초래할 수 있기에 모든 쿼리를 기록하는 이유가 감사 목적이라면, pgAudit를 사용하는 것이 더 나은 제어를 제공합니다.

쿼리 실행 시간 기록

쿼리 로그의 주요 용도 중 하나는 성능 최적화를 위해 느리게 실행되는 쿼리를 식별하는 것입니다. 그러나 log_statement 옵션은 쿼리 실행 시간을 추적하지 않습니다. 이를 위해 log_duration 설정을 사용해야 합니다. 이 설정은 불리언 값으로, off (0) 또는 on (1)으로 설정할 수 있습니다.

/etc/postgresql/15/main/postgresql.conf
log_duration = 1

서버를 재시작하고 로그를 다시 확인하면 밀리초 단위의 실행 시간 값이 포함된 로그 항목을 확인할 수 있습니다.

LOG:  statement: UPDATE album SET title = 'Audioslave' WHERE albumid = 10;
LOG:  duration: 18.498 ms

log_duration이 켜져 있으면, 서버에서 실행된 모든 명령에 대해 실행 시간 로그가 생성됩니다(심지어 간단한 SELECT 1도 포함). 이로 인해 엄청난 양의 로그가 생성될 수 있으며, 이는 성능 저하와 디스크 공간 소모를 초래할 수 있습니다.

또 다른 문제는 log_duration을 사용하면 쿼리 실행 시간이 어떤 쿼리에서 발생했는지 알 수 없다는 점입니다. 이를 테스트하기 위해 log_statement을 ddl로 설정하고 log_duration을 계속 켜 둡니다. 서버를 재시작하고 다음 쿼리를 psql에서 실행해보겠습니다.

UPDATE album SET title = 'Audioslave' WHERE albumid = 10;
쿼리가 성공적으로 완료되면 다음과 같은 로그를 확인할 수 있습니다
LOG:  duration: 13.492 ms

중요한 점은 이 로그 항목이 생성된 쿼리 자체는 기록되지 않으므로 사실상 유용성이 떨어집니다. log_duration을 반드시 사용해야 한다면, log_statement도 all로 설정하여 각 실행 시간 로그가 생성된 쿼리와 연관될 수 있도록 해야 합니다.

대안: log_min_duration_statement

log_min_duration_statement는 정수 값을 받아, 지정된 시간(밀리초)을 초과하는 쿼리만 로그에 기록합니다. 0으로 설정하면 모든 완료된 쿼리의 지속 시간이 기록됩니다.

/etc/postgresql/15/main/postgresql.conf
log_duration = 0
log_min_duration_statement = 0

log_min_duration_statement 설정은 불리언 값이 아니며, 밀리초 단위의 정수 값을 허용합니다. 지정된 값보다 실행 시간이 긴 쿼리만 로그로 기록됩니다. 위 예제에서는 0으로 설정하여 모든 완료된 쿼리의 실행 시간이 기록됩니다.

위의 업데이트된 설정을 적용하고 PostgreSQL 서버를 재시작한 후, log_statement을 ddl 모드로 유지합니다. 이후 UPDATE 쿼리를 반복해 실행해 보세요. 다음과 같은 실행 시간 로그를 확인할 수 있습니다

LOG:  duration: 13.504 ms  statement: UPDATE album SET title = 'Audioslave' WHERE albumid = 10;

이 설정은 log_duration 출력보다 개선된 점이 있으며, 쿼리와 실행 시간 로그가 모두 표시됩니다.

여전히 한 가지 약점이 남아 있습니다.

쿼리가 완료되기 전에 로그 파일에서 쿼리를 볼 수 없다는 점입니다. 서버가 쿼리 완료 전에 크래시가 발생하면, 크래시 전에 실행 중이었던 쿼리를 알 수 없습니다.

그러나 쿼리가 자체적으로 로그를 생성하는 경우에는 로그 동작이 변경됩니다. 이를 관찰하려면 log_statement을 all로 변경한 후 서버를 재시작합니다. psql에서 SELECT pg_sleep(5)를 실행하고 로그를 관찰하겠습니다.

LOG:  statement: SELECT pg_sleep(5);
LOG:  duration: 5005.975 ms

이 설정을 사용하면, 다섯 초가 지나기 전에 문제가 발생하더라도 어떤 쿼리가 사건에 영향을 미쳤을 가능성이 있는지 알 수 있습니다.

PostgreSQL 문서에서는 log_line_prefix에 프로세스 ID와 세션 ID를 포함시킬 것을 권장합니다. 이렇게 하면 로그를 읽고 분석할 때 두 항목을 쉽게 연관시킬 수 있습니다.

느리게 실행되는 쿼리 기록

모든 쿼리의 지속 시간을 기록하면 로그 파일이 불필요한 항목으로 가득 차게 됩니다. 따라서 느리게 실행되는 쿼리만 기록하는 것이 더 유용합니다. 이는 PostgreSQL 서버의 부담을 줄이는 데도 도움이 됩니다.

느리게 실행되는 쿼리를 정의하는 기준은 애플리케이션 유형과 특정 워크로드에 따라 달라집니다. 일반적으로 250ms 이상의 쿼리를 기록하는 것이 좋습니다

/etc/postgresql/15/main/postgresql.conf
log_min_duration_statement = 250

SELECT pg_sleep(1);

LOG:  statement: SELECT pg_sleep(1);
LOG:  duration: 1013.675 ms

결론

PostgreSQL 로그 파일을 효과적으로 관리하고 분석하는 것은 데이터베이스의 성능을 최적화하고 문제를 신속하게 해결하는 데 필수적입니다. 이 블로그에서 소개한 다양한 로그 커스터마이징 방법을 활용하여, 여러분의 PostgreSQL 로그 관리를 한층 더 향상시킬 수 있을 것입니다.