본문 바로가기
Database/PostgreSQL

PostgreSQL Log 설정 - 1

갈색왜성 2018. 12. 4. 13:58
반응형

PostgreSQL 공식 문서에서 Log에 대한 부분은 설명이 잘 되어 있다. 다만 설정해야 하는 property들이 너무 많고 몇몇 Property 들은 서로 연관이 되어 있기 때문에 어떻게 설정해야 되는 지 조금은 어렵게 느껴졌다. 이번 포스팅에서는 이 부분에 대해 개인적인 지식들을 정리하고자 한다. 여기서는 필자가 사용하는 버전 9.6을 기준으로 설명하고 있지만 버전 별로 약간의 차이만 있으니 참고할 수 있을 것이다. 그리고 공식 문서에서도 설명이 잘된 편이니 아래 Reference를 잊지 않는 것을 권장한다.


Log에 대한 기본 설정은 대부분 postgre.conf 의 ERROR REPORTING AND LOGGING section에서 이루어 지며, 이  section은 하위 3개의 Sub-Section로 나누어진다. 각 Sub-Section의 이름은 'Where to Log', 'When to Log', 'What to Log'이고 대부분 각각 파트 이름과 관련된 설정이 아래에 위치하게 되는데 일부 설정 항목은 직관적으로 일치되지 않는 듯한 느낌도 준다. 개별 항목에 대한 설명들은 위에 언급한 Site를 보면 되고 각각의 항목들이 어떻게 연관되어서 설정되야 하는 지 위주로 쓰려고 한다.

Where to Log

여기서 제일 중요한 설정 값은 log_destination이다. 기본 값은 'stderr'인데 일반적으로 Background Service 형태로 실행되기 때문에 이 표준 오류 출력 내용을 확인할 방법은 마땅하지 않다. 이 설정이 순수한 의미대로 동작하려면 아래와 같이 pg_ctl을 -l option (Log 파일 설정 Option)없이 Foreground에서 실행시킬 때만 Console창을 통해 표준 오류를 출력한다. (아래 참고)


pg_ctl -D {data directory path} start


물론 이렇게 사용하는 경우는 거의 없으니 그냥 참고만 하면 되는 사항이고, 보통은 Log를 특정 위치에 저장하게 되는데 OS환경과 Log를 어떻게 처리하느냐에 따라 log_destination 값을 다르게 해야 하고, 이 값에 따라 연관되는 다른 parameter가 달라진다. 표로 정리하면 다음과 같다.


log_destination

 stderr

csvlog

syslog

 eventlog

종속 parameter

  • logging_collector : 이 값이 'on'일 때 하위 parameter들이 필요.
    • log_directory
    • log_filename
    • log_file_mode
    • log_rotation_age
    • log_rotation_size
    • log_truncate_on_rotation
  • syslog_facility
  • syslog_ident
  • syslog_sequence_numbers
  • syslog_split_messages
  •  event_source

 지원 OS

 Window, Linux 공통

Linux Only

Window Only

특징

 Local Path 에서 Standard Error Format으로 남겨짐.

 Local Path에서 CSV Format으로 남겨짐. Log를 DB로 관리할 때 유용.

 Linux System Log로 관리

Window Service Log로 관리


stderr, csvlog 설정 예제와 특징

이 두 개의 설정은 LOG를 사용자(혹은 DB 관리자)가 직접 관리하려고 할 때 사용한다. stderr은 Text형태로 로그를 저장하고 csvlog는 로그를 csv형태로 저장해서 추후에 DB로 Import 해서 관리할 때 사용한다. 각각의 로그 내용은 아래의 예와 같다. (csvlog는 사용자가 Log 내용을 바로 인지하기 어렵기 때문에 DB Import 과정이 필수적이다)


[strerr 설정 시 Log의 예]

...
LOG:  statement: SELECT nsp.oid, substr(nspname, 2) as clustername, nspname, pg_get_userbyid(nspowner) AS namespaceowner, description
	  FROM pg_namespace nsp
	  LEFT OUTER JOIN pg_description des ON des.objoid=nsp.oid
	  JOIN pg_proc pro ON pronamespace=nsp.oid AND proname = 'slonyversion'
	 ORDER BY nspname
LOG:  statement: SELECT COUNT(*) FROM
	   (SELECT tgargs from pg_trigger tr
	      LEFT JOIN pg_depend dep ON dep.objid=tr.oid AND deptype = 'i'
	      LEFT JOIN pg_constraint co ON refobjid = co.oid AND contype = 'f'
	     WHERE 
	tgisinternal
	     AND co.oid IS NULL
	     GROUP BY tgargs
	    HAVING count(1) = 3) AS foo
LOG:  statement: WITH configs AS (SELECT rolname, unnest(setconfig) AS config FROM pg_db_role_setting s LEFT JOIN pg_roles r ON r.oid=s.setrole WHERE s.setdatabase=13269)
	SELECT rolname, split_part(config, '=', 1) AS variable,        replace(config, split_part(config, '=', 1) || '=', '') AS value
	FROM configs
LOG:  statement: SELECT 1 FROM pg_available_extensions WHERE name='adminpack'
LOG:  statement: SELECT version();
...

[csvlog 설정 시 Log의 예]

...
2018-11-27 13:23:23.623 KST,,,23514,,5bfcc6bb.5bda,1,,2018-11-27 13:23:23 KST,,0,LOG,00000,"database system was shut down at 2018-11-27 13:23:03 KST",,,,,,,,,""
2018-11-27 13:23:23.840 KST,,,23514,,5bfcc6bb.5bda,2,,2018-11-27 13:23:23 KST,,0,LOG,00000,"MultiXact member wraparound protections are now enabled",,,,,,,,,""
2018-11-27 13:23:23.841 KST,,,23506,,5bfcc6bb.5bd2,2,,2018-11-27 13:23:23 KST,,0,LOG,00000,"database system is ready to accept connections",,,,,,,,,""
2018-11-27 13:23:23.841 KST,,,23518,,5bfcc6bb.5bde,1,,2018-11-27 13:23:23 KST,,0,LOG,00000,"autovacuum launcher started",,,,,,,,,""
2018-11-27 13:29:25.583 KST,,,23506,,5bfcc6bb.5bd2,3,,2018-11-27 13:23:23 KST,,0,LOG,00000,"received fast shutdown request",,,,,,,,,""
2018-11-27 13:29:25.583 KST,,,23506,,5bfcc6bb.5bd2,4,,2018-11-27 13:23:23 KST,,0,LOG,00000,"aborting any active transactions",,,,,,,,,""
2018-11-27 13:29:25.583 KST,"brown","BROWN_TEST",23560,"16.8.35.35:40630",5bfcc6de.5c08,1,"UPDATE",2018-11-27 13:23:58 KST,4/3442,801710767,FATAL,57P01,"terminating connection due to administrator command",,,,,,,,,"PostgreSQL JDBC Driver"
2018-11-27 13:29:25.583 KST,"brown","BROWN_TEST",23526,"16.8.35.35:40628",5bfcc6c1.5be6,1,"idle",2018-11-27 13:23:29 KST,3/0,0,FATAL,57P01,"terminating connection due to administrator command",,,,,,,,,"PostgreSQL JDBC Driver"
...


'stderr', 'csvlog'로 설정했을 때 영향을 주는 다른 설정 값들은 아래와 같다.

  • logging_collector : Log를 파일로 남길 지 여부를 나타내며 'csvlog' 방식으로 Log를 남길 때는 필수적으로 'on'으로 설정해야 한다.
  • log_directory : logging_collector가 on일 경우에 log file path를 나타낸다. 절대 경로를 입력하지 않을 경우 PGDATA path의 상대 경로로 지정된다. 기본 값은 PGDATA path 하위의 pg_log folder에 log file을 생성하게 되어 있다.
  • log_filename : logging_collector가 on일 경우에 log file name을 나타낸다. % character를 이용해서 시간 정보에 따라 Log File Name을 지정하게 되고 이때 사용되는 문법은 Open Group의 strftime 규칙을 따른다. 기본 값은 'postgresql-%a.log' 이고 요일에 따라 file name이 명명된다. (ex. postgresql-Mon.log, postgresql-Sun.log)
  • log_file_mode : Unix 시스템에서 Log 파일의 권한 설정할 때 사용되며 chmod 명령에서 사용하는 값과 동일한 의미이다. 기본값 600은 root만 read/write 할 수 있게 설정한 값이다. (단, Window에서 postgresql을 운영할 때는 이 값이 무시된다.)
  • log_rotation_age : 시간 기준으로 Log 파일을 나눌 때 시간 값을 정의한다. 숫자는 분단위를 의미하며 시간이나 일자를 기준으로 Log 파일을 작성하고 싶으면 숫자 뒤에 'h'나 'd'를 붙히면 된다. 예를 들어 매일마다 새로운 Log 파일을 작성할 때는 1440, 24h, 1d로 설정하면 된다. (물론 log_filename과 뒤에 언급할 log_truncate_on_rotation 값이 유의미하게 설정되어야 한다.) 0일 경우에는 이 설정을 사용하지 않게 된다.
  • log_rotation_size : Log File Size 기준으로 Log 파일을 나눌 때 Size 값을 정의한다. 그냥 숫자를 사용할 때는 kb 단위를 의미하고 MB, GB와 같은 단위를 명시해서 큰 Size로 설정할 수 있다. 값이 0일 경우에는 이 설정을 사용하지 않게 된다. 
  • log_truncate_on_rotation : 전체 Log File의 크기를 어느 정도 제한하고 싶을 때 사용하는 기능이다. 이 기능을 사용하게 되면 log_rotation_age에 설정한 값에 따라 일정 시간이 지난 같은 이름을 가진 Log File은 기존 내용이 없어지고 새로운 Log로 Over Write하게 된다. 가령 log_filename을  'postgresql-%a.log'으로 설정하고 log_rotation_age를 7d로 설정하게 되면 지난주 월요일에 만들어진 Log 파일 postgresql-mon.log에 있는 내용은 이번 주 월요일에 생기는 신규 Log들로 Overwrite되면서 내용이 없어지게 된다. Postgresql은 과거 Log를 삭제하는 기능이 없기 때문에 Log 증가에 따른 저장 공간 문제를 방지하려면 이 기능을 활용하는 것이 좋다.

syslog 설정 예제와 특징

log_destination을 'syslog'로 설정하면 Linux System Log에 저장되게 된다. 아래는 syslog로 설정했을 때의 Log 예제를 보여주고 있으며 highlight된 부분이 System Log중 PostgreSQL과 관련된 Log이다. Redhat Linux 계열에서 syslog에 대한 별다른 설정을 안했을 경우 rsyslog Service에 의해 동작하게 되고, Default로 /var/log/messages에 기록하게 된다. 아래는 이런 경우의 /var/log/messages 파일의 내용이며 Highlight된 부분이 Postgresql과 관련된 Log이다.


...
Apr 18 14:33:26 localhost systemd: [/usr/lib/systemd/system/bolt.service:11] Unknown lvalue 'MemoryDenyWriteExecute' in section 'Service'
Apr 18 14:33:26 localhost systemd: [/usr/lib/systemd/system/bolt.service:13] Unknown lvalue 'ProtectControlGroups' in section 'Service'
Apr 18 14:33:26 localhost systemd: [/usr/lib/systemd/system/bolt.service:15] Unknown lvalue 'ProtectKernelModules' in section 'Service'
Apr 18 14:33:26 localhost systemd: [/usr/lib/systemd/system/bolt.service:18] Unknown lvalue 'RestrictRealtime' in section 'Service'
Apr 18 14:33:26 localhost systemd: [/usr/lib/systemd/system/bolt.service:19] Unknown lvalue 'ReadWritePaths' in section 'Service'
Apr 18 14:33:27 localhost systemd: [/usr/lib/systemd/system/firstboot-graphical.service:14] Support for option SysVStartPriority= has been removed and it is ignored
Apr 18 14:33:27 localhost systemd: Stopping PostgreSQL 9.6 database server...
Apr 18 14:33:27 localhost postgres[5260]: [4-1] < 2019-04-18 14:33:27.857 EDT > LOG:  received fast shutdown request
Apr 18 14:33:27 localhost postgres[5260]: [5-1] < 2019-04-18 14:33:27.858 EDT > LOG:  aborting any active transactions
Apr 18 14:33:27 localhost postgres[5297]: [4-1] < 2019-04-18 14:33:27.858 EDT > LOG:  autovacuum launcher shutting down
Apr 18 14:33:27 localhost postgres[5294]: [3-1] < 2019-04-18 14:33:27.860 EDT > LOG:  shutting down
Apr 18 14:33:27 localhost postgres[5260]: [6-1] < 2019-04-18 14:33:27.872 EDT > LOG:  database system is shut down
Apr 18 14:33:27 localhost systemd: Stopped PostgreSQL 9.6 database server.
Apr 18 14:33:27 localhost systemd: Starting PostgreSQL 9.6 database server...
...

log_destination을 syslog로 설정했을 때 영향을 주는 다른 설정 값들은 다음과 같다.

  • syslog_facility : syslog에서 Log를 기록할 때 사용하는 Program들을 구분하기 위해 설정하는 값으로 LOCAL0, LOCAL1, LOCAL2, LOCAL3, LOCAL4, LOCAL5, LOCAL6, LOCAL7 들을 사용할 수 있다. 예를 들어 PostgreSQL Log를 System Log로 별도로 관리하고 싶은 경우 아래와 같이 설정할 수 있다.
...
[root@localhost log]vi /etc/rsyslog.conf  <-- System Log 설정 파일 수정
...
# 파일 제일 아래 아래 내용을 추가 ; local0 Group의 Log를 별도로 관리
local0.*                                              /var/log/postgres.log
...
[root@localhost log]systemctl restart rsyslog.service <-- System Log Service 재시작

그 후 syslog_facility값을 LOCAL0으로 설정한 후에 PostgreSQL Service를 재시작하면 /var/log/postgres.log 파일이 Log 파일로 남아있는 것을 확인할 수 있다.

...
[root@localhost ~]ls -la /var/log/postgres.log
-rw-------. 1 root root 1066 May 10 00:27 /var/log/postgres.log
...
[root@localhost ~]tail  /var/log/postgres.log
May 10 00:27:54 localhost postgres[6844]: [1-1] < 2019-05-09 11:27:54.744 EDT > LOG:  redirecting log output to logging collector process
May 10 00:27:54 localhost postgres[6844]: [1-2] < 2019-05-09 11:27:54.744 EDT > HINT:  Future log output will appear in directory "pg_log".
May 10 00:27:54 localhost postgres[6844]: [2-1] < 2019-05-09 11:27:54.745 EDT > LOG:  ending log output to stderr
May 10 00:27:54 localhost postgres[6844]: [2-2] < 2019-05-09 11:27:54.745 EDT > HINT:  Future log output will go to log destination "syslog".
May 10 00:27:54 localhost postgres[6848]: [3-1] < 2019-05-09 11:27:54.746 EDT > LOG:  database system was shut down at 2019-05-09 11:27:54 EDT
May 10 00:27:54 localhost postgres[6848]: [4-1] < 2019-05-09 11:27:54.748 EDT > LOG:  MultiXact member wraparound protections are now enabled
May 10 00:27:54 localhost postgres[6844]: [3-1] < 2019-05-09 11:27:54.751 EDT > LOG:  database system is ready to accept connections
May 10 00:27:54 localhost postgres[6852]: [3-1] < 2019-05-09 11:27:54.751 EDT > LOG:  autovacuum launcher started
...
  • syslog_ident : System Log로 Log가 저장될 때 Log를 찍는 Process를 식별하기 위해 사용되며 기본값은 'postgres'이다. 이 값을 변경하면 위에 보이는 Log에서 localhost 뒤에 오는 postgres라는 단어가 변경되서 Log를 남기게 된다. 
  • syslog_sequence_number : Log의 일련 번호를 기록해서 남길지 여부를 설정. 기본 값은 on이며 off로 변경하게 되면 위에 보여지는  Log들 중에 [3-1], [4-1]과 같은 Format이 [1], [1] 만 남게 된다.
  • syslog_split_message : System Log를 1024Byte 제한에 맞춰 Split해서 기록할 지 여부를 설정. 기본 값은 on이며 off로 변경하게 되면 위의 Log에서 HINT라는 단어로 이어지는 Split된 부분이 이어서 출력 되게 된다.
참고로 syslog_ident를 'browndwarf'로 syslog_sequence_number와 syslog_split_message를 off로 변경하면 Log가 다음과 같이 출력 된다.
...
[root@localhost ~]tail -f /var/log/postgres.log
May 10 01:03:25 localhost browndwarf[7457]: < 2019-05-09 12:03:25.554 EDT > LOG:  redirecting log output to logging collector process#012< 2019-05-09 12:03:25.554 EDT > HINT:  Future log output will appear in directory "pg_log".
May 10 01:03:25 localhost browndwarf[7457]: < 2019-05-09 12:03:25.554 EDT > LOG:  ending log output to stderr#012< 2019-05-09 12:03:25.554 EDT > HINT:  Future log output will go to log destination "syslog".
May 10 01:03:25 localhost browndwarf[7459]: < 2019-05-09 12:03:25.556 EDT > LOG:  database system was shut down at 2019-05-09 12:03:25 EDT
May 10 01:03:25 localhost browndwarf[7459]: < 2019-05-09 12:03:25.558 EDT > LOG:  MultiXact member wraparound protections are now enabled
May 10 01:03:25 localhost browndwarf[7457]: < 2019-05-09 12:03:25.561 EDT > LOG:  database system is ready to accept connections
May 10 01:03:25 localhost browndwarf[7463]: < 2019-05-09 12:03:25.561 EDT > LOG:  autovacuum launcher started
...

맺음말

마지막으로 event_source라는 property가 있는데 이 값은 윈도우에 설치되었을 때 사용하는 값이다. 윈도우가 Event Log를 남길 때 프로그램을 식별하기 위해 사용한다. 정리하다보니 글이 길어져서 다른 포스팅에서 나머지 내용을 정리하려 한다.


'Database > PostgreSQL' 카테고리의 다른 글

PostgreSQL Log 설정 - 2  (10) 2019.05.10
PostgreSQL DB Backup 및 Restore  (3) 2018.12.31
PostgreSQL HA 구성 - 3. PGPool을 활용한 FailOver 구현  (7) 2018.10.12
PostgreSQL HA 구성 - 2. PGPool을 활용한 Load Balance 구현  (1) 2018.10.05
PostgreSQL HA 구성 -1. Streaming Replication  (3) 2018.09.27

'Database/PostgreSQL' Related Articles

티스토리툴바