[Postgres] troubleshooting

최대한·2023년 5월 6일
PostgreSQLTROUBLESHOOTING
0

Mastering postgresql 13 chatper 11 을 정리한 글입니다.

Approaching an unknown database

  • 충분한 데이터가 없을 경우 분석이 불가능.
  • pgwatch2 같은 모니터링 툴을 셋업해야함

Inspecting pg_stat_activity

 pg_stat_statements 을 확인할 때 아래 질문에 대해 답해보자.

  • How many concurrent queries are currently being executed on your system?
  • Do you see similar types of queries showing up in the query column all the time?
  • Do you see queries that have been running for a long time?
  • Are there any locks that have not been granted?
  • Do you see connections from suspicious hosts?

pg_stat_activity 는 항상 첫번째로 확인되어야함

Querying pg_stat_activity

SELECT datname,
		count(*) AS open,
		count(*) FILTER (WHERE state = 'active') AS active,
		count(*) FILTER (WHERE state = 'idle') AS idle,
		count(*) FILTER (WHERE state = 'idle in transaction') 
			AS idle_in_trans 
FROM  pg_stat_activity 
WHERE backend_type = 'client backend'
GROUP BY ROLLUP(1);
 datname | open | active | idle | idle_in_trans 
 ---------+------+--------+------+--------------- 
 test    | 2    | 1      | 0    | 1         
		 | 2    | 1      | 0    | 1

idle-in-transaction 쿼리가 얼마동안 open 이었는지 확인해야함

SELECT pid, xact_start, now() - xact_start AS duration
    FROM pg_stat_activity
    WHERE state LIKE '%transaction%'
    ORDER BY 3 DESC;
 pid    | xact_start                    | duration
 --------+-------------------------------+----------------- 
  19758 | 2020-09-26 20:27:08.168554+01 | 22:12:10.194363

아래 쿼리를 이용하여 오래 걸리는 쿼리를 확인할 수도 있다

SELECT 
  now() - query_start AS duration, 
  datname, 
  query 
FROM 
  pg_stat_activity 
WHERE 
  state = 'active' 
ORDER BY 
  1 DESC;
 duration         | datname | query
 ------------------+---------+--------------------------- 
 00:00:38.814526  | dev     | SELECT pg_sleep(10000); 
 00:00:00         | test    | SELECT now() - query_start AS duration,
                                       datname, query
                               FROM  pg_stat_activity
                               WHERE state = 'active'
							   ORDER BY 1 DESC;

Treating Hibernate statements

  • hibernate 와 같은 orm 들은 아주 긴 쿼리를 작성하는데, 기본적으로 postgresql 은 1024 byte 만 시스템 뷰에 저장.
  • postgresql.conf 의 값을 적당한 값으로 변경 가능 (32,768)
SHOW track_activity_query_size; 
track_activity_query_size 
--------------------------- 
1kB

Figuring out where queries come from

  • 같은 IP 에서만 올 경우 어떤 앱이 쿼리를 날렸는지 분간하기 어려움
  • 이 때, application_name 변수를 할당할 수 있음

Checking for slow queries

  • 느린 쿼리를 분석하기 위한 방법으로
    - Look for individual slow queries in the log
    - Look for types of queries that take too much time

log_min_duration_statement 를 설정하면 특정 threshold 를 넘었을 때 postgreSQL 은 로그를 남김
default = off

SHOW log_min_duration_statement;
log_min_duration_statement
----------------------------
                         -1
ALTER DATABASE test SET log_min_duration_statement TO 10000;
  • 우선 pg_stat_statements 를 확인하는 것을 추천
    - 단일 쿼리가 아닌 통합된 정보를 제공

Inspecting individual queries

  • Try and see where it is in the plan that time starts to skyrocket.
  • Check for missing indexes (one of the main reasons for bad performance).
  • Use the EXPLAIN clause (buffers true, analyze true, and so on) to see whether your query uses too many buffers.
  • Turn on the track_io_timing parameter to figure out whether there is an I/O problem or a CPU problem (explicitly check whether there is random I/O going on).
  • Look for incorrect estimates and try to fix them.
  • Look for stored procedures that are executed too frequently.
  • Try to figure out whether some of them can be marked as STABLE or IMMUTABLE, provided this is possible.

Digging deeper with perf

  • checklist 만으론 충분치 않을 수 있기 때문에 perf 명령어를 사용해서 어떤 c 함수가 시스템에 문제를 일으키는지 확인

  • perf top

  • spinlock contention 이라는 문제가 있을 수 있다.

    Spinlocks 란

    • postgreSQL 코어가 buffer access 를 동기화하기 위해 사용

  • Spinlock 이 의심되는 경우
    - 매우 높은 CPU 로드
    - 매우 낮은 쓰루풋
    - I/O 가 평소와 다르게 낮음 - cpu 가 lock 들을 교환하고 있기 때문

  • 보통 갑자기 발생

  • s_lock 인지 확인 가능

huge_pages = try # on, off, or try

huge_pages 를 try -> off 로 변경

Inspecting the log

에러 레벨은 3가지가 있다

  • ERROR
  • FATAL
  • PANIC

ERROR

  • syntax 에러
  • 권한 문제 등에 발생
    FATAL
  • ex) could not allocate memory for shared memory name or unexpected walreceiver state
    PANIC
  • 굉장히 위험
  • lock table 이 오염되었을 경우
  • 너무 많은 semaphore 가 생성됐을 경우 발생

Checking for missing indexes

  • RAID 레벨 최적화 및 커널 튜닝을 진행할 경우 인덱스가 누락되는 것으로 요약
  • 인덱스 빠진것 확인하는 쿼리
SELECT schemaname, relname, seq_scan, seq_tup_read,
		idx_scan, seq_tup_read / seq_scan AS avg 
FROM   pg_stat_user_tables 
WHERE  seq_scan > 0 
ORDER BY seq_tup_read 
DESC LIMIT 20;
 schemaname |  relname  | seq_scan | seq_tup_read | idx_scan | avg 
------------+-----------+----------+--------------+----------+-----
 public     | positives |        4 |            2 |          |   0
 public     | negatives |        2 |            1 |          |   0

avg 가 높은지 확인

Checking for memory and I/O

  • track_io_timing 을 on 하면 disk 로부터 얼마나 걸렸는지 확인 가능
  • 많은 경우에, temp_files 와 temp_bytes 가 높을 경우
    - blk_read_time,  blk_write_time 도 높음
    - work_mem 혹은 maintenance_work_mem 가 낮은건 아닌지 확인
    - 낮을 경우 disk 를 사용하기 때문에 temp_files 명령어로 확인 가능
    - 있다는 것은 disk wait time 이 좋지 않음을 의미

vmstat 명령어로 확인하자

vmstat 2
procs -----------memory------------  ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd    free   buff  cache    si   so    bi    bo   in   cs us sy id wa st
 0  0      0 2851432  62700 3042200    0    0    46    29   89  121  0  0 99  0  0
 0  0      0 2851432  62700 3042248    0    0     0     0  358  498  1  0 99  0  0
 0  0      0 2851432  62700 3042248    0    0     0     2  232  336  0  0 100  0  0
 0  0      0 2851180  62708 3042240    0    0     0    10  212  290  1  0 99  0  0
 0  0      0 2851180  62708 3042248    0    0     0     0  185  254  0  0 100  0  0
 0  0      0 2851180  62708 3042248    0    0     0     0  181  259  0  0 99  0  0
 0  0      0 2851180  62708 3042248    0    0     0     2  197  279  1  0 99  0  0
  • bi, bo, wa 를 들여다볼 필요가 있음
  • bi (block in) block read 숫자. 1,000 = 1Mbps
  • bo (block out) block write 숫자
    - 위 두개만으로는 위험도를 판단하긴 어려움
  • 하지만 wa (wait I/O) 값이 높을 경우, disck 보틀넥이 있다고 판단할 수 있다.
    - random I/O 가 많이 발생

    마냥 throughput 이 높다고 좋은 것은 아님.
    throughput이 높을 경우

    • OLTP 시스템에서는 ram 이 캐싱하기에 부족할 수도 있음
    • 인덱스가 누락

Understanding noteworthy error scenarios

Facing clog corruption

commit log (현재는 pg_xact)

  • 일반적으로 transaction 은 4개의 상태값을 가짐
    - TRANSACTION_STATUS_IN_PROGRESS 0x00
    - TRANSACTION_STATUS_COMMITTED 0x01
    - TRANSACTION_STATUS_ABORTED 0x02
    - TRANSACTION_STATUS_SUB_COMMITTED 0x03
  • 가끔은 오염됨

    ERROR: could not access status of transaction 118831

dd 령어로 상태값을 변경할 수 있다

dd if=/dev/zero of=<data directory location>/pg_clog/0001    
	bs=256K count=1

Careless connection management

  • PostgreSQL 에서 모든 커넥션은 분리된 프로세스
  • shared memory 를 이용해 동기화한다.
  • shared memory
    - I/O cache
    - 활성화된 커넥션 리스트
    - lock
    - 기타 활력징후
  • 일반적으로 커넥션이 종료되면 shared memory 로부터 제거되고 시스템을 정상상태로 남김
  • 하지만 crash 났을 경우 postmaster 는 child process 가 missing 됐음을 감지
    - 다른 모든 커넥션을 종료하고 roll-farward 프로세스가 시작됨
    - 비정상적으로 종료된 프로세스가 shared memory 를 오염시킬 수 있음
    - 따라서 postmaster 는 shared memory 가 오염되는 것을 막기 위해 모두 추방
    - 메모리 clean
    - 모두 재연결

Fighting table bloat

  • table bloat 은 실제 사이즈보다 더 많은 공간을 차지하고 있다는 것
 \d pg_stat_user_tables
    View "pg_catalog.pg_stat_user_tables" 
Column            | Type             | Modifiers
-------------------+------------------+-----------  
relid             | oid              | 
schemaname        | name             | 
relname           | name             | 
...
n_live_tup        | bigint           |
n_dead_tup        | bigint           |
  •  n_live_tup 과 n_dead_tup 로 판단할 수 있다.
  • table bloat 이 너무 클 경우 VACUUM FULL 커맨드를 수행할 수도 있다.
    - table lock 을 걸기 때문에 조심해서 사용해야 함
profile
최대한
Awesome Dev!
이전 포스트

[Postgres] 성능 분석

다음 포스트

[Querydsl] postgres array column intersect, contains 검색하기

0개의 댓글