DBMS: PostgreSQL 14.9 |
[목차여기]
- auto_explain 사용 시 모든 SQL 실행통계 수집(성능저하 발생)
- auto_explain.log_min_duration 값은 postgres.log 파일에 로깅 여부만 관여(지정 값보다 빨리 끝나서 미사용시와 동일한 성능나오는거 아님)
- auto_explain.log_timing 값이 성능에 가장 많은 영향
- 꼭 사용하고 싶다면 auto_explain.log_timing 파라미터 off 고려해보자(구간별 수행시간 안나옴)
테스트 시나리오
auto_explain의 설정의 주요 파라미터인 아래 3개 파라미터의 값이 다른 환경에서 동일 SQL반복 수행
auto_explain.log_analyze
auto_explain.log_buffers
auto_explain.log_timing
auto_explain 미사용
테스트 SQL 평균 수행시간: 1초
auto_explain.log_analyze=off
auto_explain.log_buffers=off
auto_explain.log_timing=on -- log_analyze off 여서 의미없음
auto_explain.log_min_duration=0
sk1=# select count(*) from pg_tables a, pg_tables b, pg_tables c ;
count
----------
12649337
(1 row)
Time: 1139.514 ms (00:01.140)
sk1=# select count(*) from pg_tables a, pg_tables b, pg_tables c ;
count
----------
12649337
(1 row)
Time: 1045.749 ms (00:01.046)
sk1=# select count(*) from pg_tables a, pg_tables b, pg_tables c ;
count
----------
12649337
(1 row)
Time: 1041.942 ms (00:01.042)
postgres.log에 로깅된 explain 정보
실제 실행통계가 아닌 예상실행계획을 보여줍니다
Query Text: select count(*) from pg_tables a, pg_tables b, pg_tables c ;
Aggregate (cost=188148.39..188148.40 rows=1 width=8)
-> Nested Loop (cost=0.00..156930.47 rows=12487168 width=0)
-> Nested Loop (cost=0.00..784.65 rows=53824 width=0)
-> Seq Scan on pg_class c (cost=0.00..55.64 rows=232 width=8)
Filter: (relkind = ANY ('{r,p}'::"char"[]))
-> Materialize (cost=0.00..56.80 rows=232 width=8)
-> Seq Scan on pg_class c_1 (cost=0.00..55.64 rows=232 width=8)
Filter: (relkind = ANY ('{r,p}'::"char"[]))
-> Materialize (cost=0.00..56.80 rows=232 width=8)
-> Seq Scan on pg_class c_2 (cost=0.00..55.64 rows=232 width=8)
Filter: (relkind = ANY ('{r,p}'::"char"[]))
auto_explain 사용
log_analyze on, log_buffers on, log_timing on
테스트 SQL 평균 수행시간: 4.1초
auto_explain.log_analyze=on
auto_explain.log_buffers=on
auto_explain.log_timing=on
auto_explain.log_min_duration=0
sk1=# select count(*) from pg_tables a, pg_tables b, pg_tables c ;
count
----------
12649337
(1 row)
Time: 4004.535 ms (00:04.005)
sk1=# select count(*) from pg_tables a, pg_tables b, pg_tables c ;
count
----------
12649337
(1 row)
Time: 4328.121 ms (00:04.328)
sk1=# select count(*) from pg_tables a, pg_tables b, pg_tables c ;
count
----------
12649337
(1 row)
Time: 4047.608 ms (00:04.048)
postgres.log에 로깅된 explain 정보
구간별 수행시간 및 buffers 정보를 모두 보여줍니다
Query Text: select count(*) from pg_tables a, pg_tables b, pg_tables c ;
Aggregate (cost=188148.39..188148.40 rows=1 width=8) (actual time=4044.748..4044.751 rows=1 loops=1)
Buffers: shared hit=135
-> Nested Loop (cost=0.00..156930.47 rows=12487168 width=0) (actual time=0.029..2879.770 rows=12649337 loops=1)
Buffers: shared hit=135
-> Nested Loop (cost=0.00..784.65 rows=53824 width=0) (actual time=0.024..19.110 rows=54289 loops=1)
Buffers: shared hit=90
-> Seq Scan on pg_class c (cost=0.00..55.64 rows=232 width=8) (actual time=0.013..1.709 rows=233 loops=1)
Filter: (relkind = ANY ('{r,p}'::"char"[]))
Rows Removed by Filter: 619
Buffers: shared hit=45
-> Materialize (cost=0.00..56.80 rows=232 width=8) (actual time=0.000..0.036 rows=233 loops=233)
Buffers: shared hit=45
-> Seq Scan on pg_class c_1 (cost=0.00..55.64 rows=232 width=8) (actual time=0.003..0.382 rows=233 loops=1)
Filter: (relkind = ANY ('{r,p}'::"char"[]))
Rows Removed by Filter: 619
Buffers: shared hit=45
-> Materialize (cost=0.00..56.80 rows=232 width=8) (actual time=0.000..0.020 rows=233 loops=54289)
Buffers: shared hit=45
-> Seq Scan on pg_class c_2 (cost=0.00..55.64 rows=232 width=8) (actual time=0.002..0.233 rows=233 loops=1)
Filter: (relkind = ANY ('{r,p}'::"char"[]))
Rows Removed by Filter: 619
Buffers: shared hit=45반응형
log_analyze on, log_buffers off, log_timing on
테스트 SQL 평균 수행시간: 3.9초
auto_explain.log_analyze=on
auto_explain.log_buffers=off
auto_explain.log_timing=on
auto_explain.log_min_duration=0
sk1=# select count(*) from pg_tables a, pg_tables b, pg_tables c ;
count
----------
12649337
(1 row)
Time: 3910.558 ms (00:03.911)
sk1=# select count(*) from pg_tables a, pg_tables b, pg_tables c ;
count
----------
12649337
(1 row)
Time: 4269.640 ms (00:04.270)
sk1=# select count(*) from pg_tables a, pg_tables b, pg_tables c ;
count
----------
12649337
(1 row)
Time: 3718.625 ms (00:03.719)
postgres.log에 로깅된 explain 정보
구간별 수행시간 정보를 보여주고 buffers 정보는 없습니다
Query Text: select count(*) from pg_tables a, pg_tables b, pg_tables c ;
Aggregate (cost=188148.39..188148.40 rows=1 width=8) (actual time=3717.381..3717.384 rows=1 loops=1)
-> Nested Loop (cost=0.00..156930.47 rows=12487168 width=0) (actual time=0.033..2651.368 rows=12649337 loops=1)
-> Nested Loop (cost=0.00..784.65 rows=53824 width=0) (actual time=0.028..18.492 rows=54289 loops=1)
-> Seq Scan on pg_class c (cost=0.00..55.64 rows=232 width=8) (actual time=0.016..2.592 rows=233 loops=1)
Filter: (relkind = ANY ('{r,p}'::"char"[]))
Rows Removed by Filter: 619
-> Materialize (cost=0.00..56.80 rows=232 width=8) (actual time=0.000..0.034 rows=233 loops=233)
-> Seq Scan on pg_class c_1 (cost=0.00..55.64 rows=232 width=8) (actual time=0.004..0.257 rows=233 loops=1)
Filter: (relkind = ANY ('{r,p}'::"char"[]))
Rows Removed by Filter: 619
-> Materialize (cost=0.00..56.80 rows=232 width=8) (actual time=0.000..0.018 rows=233 loops=54289)
-> Seq Scan on pg_class c_2 (cost=0.00..55.64 rows=232 width=8) (actual time=0.003..0.274 rows=233 loops=1)
Filter: (relkind = ANY ('{r,p}'::"char"[]))
Rows Removed by Filter: 619
log_analyze on, log_buffers off, log_timing off
테스트 SQL 평균 수행시간: 1.9초
auto_explain.log_analyze=on
auto_explain.log_buffers=on
auto_explain.log_timing=off
auto_explain.log_min_duration=0
sk1=#
sk1=# select count(*) from pg_tables a, pg_tables b, pg_tables c ;
count
----------
12649337
(1 row)
Time: 1858.777 ms (00:01.859)
sk1=# select count(*) from pg_tables a, pg_tables b, pg_tables c ;
count
----------
12649337
(1 row)
Time: 1902.754 ms (00:01.903)
sk1=# select count(*) from pg_tables a, pg_tables b, pg_tables c ;
count
----------
12649337
(1 row)
Time: 2008.034 ms (00:02.008)
postgres.log에 로깅된 explain 정보
구간별 수행시간이 안 보입니다
Query Text: select count(*) from pg_tables a, pg_tables b, pg_tables c ;
Aggregate (cost=188148.39..188148.40 rows=1 width=8) (actual rows=1 loops=1)
Buffers: shared hit=135
-> Nested Loop (cost=0.00..156930.47 rows=12487168 width=0) (actual rows=12649337 loops=1)
Buffers: shared hit=135
-> Nested Loop (cost=0.00..784.65 rows=53824 width=0) (actual rows=54289 loops=1)
Buffers: shared hit=90
-> Seq Scan on pg_class c (cost=0.00..55.64 rows=232 width=8) (actual rows=233 loops=1)
Filter: (relkind = ANY ('{r,p}'::"char"[]))
Rows Removed by Filter: 619
Buffers: shared hit=45
-> Materialize (cost=0.00..56.80 rows=232 width=8) (actual rows=233 loops=233)
Buffers: shared hit=45
-> Seq Scan on pg_class c_1 (cost=0.00..55.64 rows=232 width=8) (actual rows=233 loops=1)
Filter: (relkind = ANY ('{r,p}'::"char"[]))
Rows Removed by Filter: 619
Buffers: shared hit=45
-> Materialize (cost=0.00..56.80 rows=232 width=8) (actual rows=233 loops=54289)
Buffers: shared hit=45
-> Seq Scan on pg_class c_2 (cost=0.00..55.64 rows=232 width=8) (actual rows=233 loops=1)
Filter: (relkind = ANY ('{r,p}'::"char"[]))
Rows Removed by Filter: 619
Buffers: shared hit=45
'DBMS > PostgreSQL' 카테고리의 다른 글
| [PostgreSQL] pg_dump 파일에서 테이블명 변경하여 복구 (0) | 2024.03.12 |
|---|---|
| [PostgreSQL] WAL 경로 변경하는법 (0) | 2024.03.07 |
| [PostgreSQL] 기본 권한 설정 default privilege(권한 자동 부여) (0) | 2024.02.15 |
| [PostgreSQL] pg_hba.conf 우선순위 (2) | 2024.02.01 |
| [PostgreSQL] 데이터 이관 시 ERROR: permission denied for schema (1) | 2024.01.29 |
댓글