work_memと一時ファイルの容量の関係性について

PostgreSQL
PostgreSQLデータベース
PostgreSQL

PostgreSQLでのチューニングのアプローチとして、log_temp_filesを0に設定し、ログに記録された一時ファイルの容量を元にwork_memを調整するといったものがあるかと存じます。これで一時ファイルの作成が抑制され、パフォーマンスが向上するケースもございますが、今回、そのアプローチでは解決できない事象が確認できましたので、参考までに記録致します。

スポンサーリンク

結論

ワークロードによる部分もあるかとは存じますが、今回の検証の結論としましては、log_temp_filesによりログ出力された一時ファイルの容量は、必ずしも「work_memで不足している容量」を意味するわけではないことが確認できました。

言い換えますと、log_temp_filesを0に設定することで、一時ファイルが作成されたということは分かりますが、容量はあくまでも参考値であるということを意味します。

したがって、work_memの最適値を探る場合、最終的には、何パターンかの設定値を試していくという原始的なアプローチが必要になるものと推察致します。

また、容量が参考値であるということは、一時ファイルの作成についてログ出力を行うのであれば(-1以外)、log_temp_filesの値を0以外にする意味も薄いのではないかと考えます。

work_memと一時ファイル容量の検証

検証の流れ

具体的には次のような流れにて検証を実施しました。

なお、PostgreSQL 11.6を利用して検証を行っています。

  1. log_temp_filesを0に設定する
  2. サンプルテーブルを作成する(100万行)
  3. work_memを1MBに設定する
  4. サンプルテーブルを全件SELECT+ソートする
  5. 一時ファイルが作成されたことを確認する(約72MB)
  6. work_memの値を作成された一時ファイルの容量より大きな100MBまで増やす
  7. 再度サンプルテーブルを全件SELECT+ソートする
  8. 一時ファイルが作成されたことを確認する(約72MB)
  9. work_memの値を更に300MBまで増やす
  10. 再度サンプルテーブルを全件SELECT+ソートする
  11. 最終的に利用されたメモリ容量を確認する(約162MB)
  12. work_memの値を必要なメモリ量に合わせて162MBにする
  13. 再度サンプルテーブルを全件SELECT+ソートする
  14. 一時ファイルが作成されないことを確認する
  15. work_memの値を必要なメモリ量より若干少ない160MBにする
  16. 再度サンプルテーブルを全件SELECT+ソートする
  17. 一時ファイルが作成されたことを確認する(約72MB)

検証の事前準備

まずは、log_temp_filesの設定とサンプルテーブルの作成を行います。

postgres=> show log_temp_files;
 log_temp_files
----------------
 -1
(1 row)


postgres=> set log_temp_files to 0;
SET
postgres=> show log_temp_files;
 log_temp_files
----------------
 0
(1 row)


postgres=> create table sample_table as select seq_number as id, random() as random_number, md5(random()::text) as random_data from generate_series(1, 1000000) as seq_number;
SELECT 1000000

work_mem(1MB)での検証

まず、work_memを1MBに設定した際の挙動を確認します。external merge(一時ファイルでソートを行う処理)が選択されていますが、ソート処理を行う2つのワーカーが更に一時ファイルを作成している様子が見受けられます。つまり、合計3つの一時ファイルが作成されています。

最終的に、ログには合計で75218944(18743296+17203200+39272448)バイト、つまり、約72MBの一時ファイルが作成されている様子が記録されています。

SQL実行

postgres=> set work_mem to 1024;
SET
postgres=> show work_mem;
 work_mem
----------
 1MB
(1 row)


postgres=> explain analyze select 'work_mem: 1MB', * from sample_table order by random_number, random_data;
                                                                QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------
 Gather Merge  (cost=109914.50..207143.59 rows=833334 width=77) (actual time=891.912..1371.145 rows=1000000 loops=1)
   Workers Planned: 2
   Workers Launched: 2
   ->  Sort  (cost=108914.48..109956.15 rows=416667 width=77) (actual time=748.924..852.871 rows=333333 loops=3)
         Sort Key: random_number, random_data
         Sort Method: external merge  Disk: 38352kB
         Worker 0:  Sort Method: external merge  Disk: 16800kB
         Worker 1:  Sort Method: external merge  Disk: 18304kB
         ->  Parallel Seq Scan on sample_table  (cost=0.00..14476.67 rows=416667 width=77) (actual time=0.014..98.434 rows=333333 loops=3)
 Planning Time: 0.123 ms
 Execution Time: 1431.612 ms
(11 rows)

PostgreSQLログ

2020-12-25 11:15:15 UTC::@:[5608]:LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp5608.0", size 18743296
2020-12-25 11:15:15 UTC::@:[5608]:STATEMENT: explain analyze select 'work_mem: 1MB', * from sample_table order by random_number, random_data;
2020-12-25 11:15:15 UTC::@:[5609]:LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp5609.0", size 17203200
2020-12-25 11:15:15 UTC::@:[5609]:STATEMENT: explain analyze select 'work_mem: 1MB', * from sample_table order by random_number, random_data;
2020-12-25 11:15:15 UTC:xx.xx.xx.xx(63725):postgres@postgres:[19529]:LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp19529.1", size 39272448
2020-12-25 11:15:15 UTC:xx.xx.xx.xx(63725):postgres@postgres:[19529]:STATEMENT: explain analyze select 'work_mem: 1MB', * from sample_table order by random_number, random_data;

work_mem(100MB)での検証

さて、前述の検証にて、作成された一時ファイルは合計約72MBであることが確認できました。現在のwork_memは1MBなので、バッファも含んでwork_memを100MBに設定して確認を行ってみます。

ログ出力される一時ファイルの容量が、単純に不足しているメモリ量を表しているのであれば、これで一時ファイルが作成されなくなることが予測されます。

しかし、ワーカーが更に一時ファイルを作成するようなことはなくなりましたが、依然として一時ファイルが作成されている様子が確認できます。容量は75153408バイト、つまり、約72MBであり、先程の結果と変わりません。

SQL実行

postgres=> set work_mem to 102400;
SET
postgres=> show work_mem;
 work_mem
----------
 100MB
(1 row)


postgres=> explain analyze select 'work_mem: 100MB', * from sample_table order by random_number, random_data;
                                                          QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------
 Sort  (cost=119967.84..122467.84 rows=1000000 width=77) (actual time=939.331..1066.320 rows=1000000 loops=1)
   Sort Key: random_number, random_data
   Sort Method: external merge  Disk: 73392kB
   ->  Seq Scan on sample_table  (cost=0.00..20310.00 rows=1000000 width=77) (actual time=0.012..126.879 rows=1000000 loops=1)
 Planning Time: 0.038 ms
 Execution Time: 1115.965 ms
(6 rows)

PostgreSQLログ

2020-12-25 11:20:40 UTC:xx.xx.xx.xx(63725):postgres@postgres:[19529]:LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp19529.2", size 75153408
2020-12-25 11:20:40 UTC:xx.xx.xx.xx(63725):postgres@postgres:[19529]:STATEMENT: explain analyze select 'work_mem: 100MB', * from sample_table order by random_number, random_data;

work_mem(300MB)での検証

直前の結果から、作成された一時ファイルは約72MBであることが確認できましたが、もはや信じられなくなりましたので、一気にwork_memを300MBに増やして確認を行ってみます。

結果として、無事、全てメモリ上で処理が実行されるようになりました。実行計画から、必要なメモリは165202kB、つまり、約162MBであったことが分かりました。

一時ファイルは作成されていませんので、ログ出力はありません。

SQL実行

postgres=> set work_mem to 307200;
SET
postgres=> show work_mem;
 work_mem
----------
 300MB
(1 row)


postgres=> explain analyze select 'work_mem: 300MB', * from sample_table order by random_number, random_data;
                                                          QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------
 Sort  (cost=119967.84..122467.84 rows=1000000 width=77) (actual time=797.481..949.152 rows=1000000 loops=1)
   Sort Key: random_number, random_data
   Sort Method: quicksort  Memory: 165202kB
   ->  Seq Scan on sample_table  (cost=0.00..20310.00 rows=1000000 width=77) (actual time=0.010..143.166 rows=1000000 loops=1)
 Planning Time: 0.037 ms
 Execution Time: 992.700 ms
(6 rows)

work_mem(162MB)での検証

必要なメモリ量が分かったので、work_memを162MBに設定して確認してみます。無事にメモリ上だけで完結していることが確認できました。したがって、当該SQLでは約162MBが適正値であろうということが分かりました。

SQL実行

postgres=> set work_mem to 165888;
SET
postgres=> show work_mem;
 work_mem
----------
 162MB
(1 row)


postgres=> explain analyze select 'work_mem: 162MB', * from sample_table order by random_number, random_data;
                                                          QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------
 Sort  (cost=119967.84..122467.84 rows=1000000 width=77) (actual time=798.385..948.632 rows=1000000 loops=1)
   Sort Key: random_number, random_data
   Sort Method: quicksort  Memory: 164324kB
   ->  Seq Scan on sample_table  (cost=0.00..20310.00 rows=1000000 width=77) (actual time=0.011..155.280 rows=1000000 loops=1)
 Planning Time: 0.038 ms
 Execution Time: 990.769 ms
(6 rows)

work_mem(160MB)での検証

最後に、work_memを必要量より若干少ない160MBに設定して確認を行ってみます。2MB程度足らないだけですが、一時ファイルが作成されてしまったことが確認できました。

当該一時ファイルは、ログ出力上、75153408バイトとなっています。これまで作成されてきた一時ファイルと同様、約72MBです。正直に受け止め、work_memから約72MBあふれているものと捉えてしまうと、work_memは162MBで済むにも関わらず、232MB(160MB+72MB)と設定してしまうことになります。

SQL実行

postgres=> set work_mem to 163840;
SET
postgres=> show work_mem;
 work_mem
----------
 160MB
(1 row)


postgres=> explain analyze select 'work_mem: 160MB', * from sample_table order by random_number, random_data;
                                                          QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------
 Sort  (cost=119967.84..122467.84 rows=1000000 width=77) (actual time=1055.562..1185.475 rows=1000000 loops=1)
   Sort Key: random_number, random_data
   Sort Method: external merge  Disk: 73392kB
   ->  Seq Scan on sample_table  (cost=0.00..20310.00 rows=1000000 width=77) (actual time=0.011..144.824 rows=1000000 loops=1)
 Planning Time: 0.038 ms
 Execution Time: 1236.575 ms
(6 rows)

PostgreSQLログ

2020-12-25 11:34:48 UTC:xx.xx.xx.xx(63725):postgres@postgres:[19529]:LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp19529.3", size 75153408
2020-12-25 11:34:48 UTC:xx.xx.xx.xx(63725):postgres@postgres:[19529]:STATEMENT: explain analyze select 'work_mem: 160MB', * from sample_table order by random_number, random_data;

まとめ

ワークロードによるかとは存じますが、今回のケースですと、次のことが確認できました。PostgreSQLは奥が深いですね。

  • log_temp_filesの設定で出力された一時ファイルの容量は、必ずしもwork_memで不足している容量を意味しない
  • work_memの最適値を探るには、何パターンかの設定値を試していくという原始的なアプローチが必要になる
  • 一時ファイル作成についてログ出力するのであれば、log_temp_filesを0以外に設定する意味は薄い

コメント

タイトルとURLをコピーしました